Refactor log (#3446)

* Refactor log

* Add new log methods

* Fix logger test

* Change all logging code

* Clean up pathObj

* Rebase to latest main

* Remove invoking method name after the dot
This commit is contained in:
yuhan6665 2024-06-29 14:32:57 -04:00 committed by GitHub
parent 8320732743
commit 079d0bd8a9
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
291 changed files with 1837 additions and 2368 deletions

View file

@ -47,11 +47,11 @@ func NewServer(ctx context.Context, config *ServerConfig) (*Server, error) {
for _, user := range config.Users {
u, err := user.ToMemoryUser()
if err != nil {
return nil, newError("failed to get trojan user").Base(err).AtError()
return nil, errors.New("failed to get trojan user").Base(err).AtError()
}
if err := validator.Add(u); err != nil {
return nil, newError("failed to add user").Base(err).AtError()
return nil, errors.New("failed to add user").Base(err).AtError()
}
}
@ -132,8 +132,6 @@ func (s *Server) Network() []net.Network {
// Process implements proxy.Inbound.Process().
func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Connection, dispatcher routing.Dispatcher) error {
sid := session.ExportIDToError(ctx)
iConn := conn
statConn, ok := iConn.(*stat.CounterConnection)
if ok {
@ -142,16 +140,16 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
sessionPolicy := s.policyManager.ForLevel(0)
if err := conn.SetReadDeadline(time.Now().Add(sessionPolicy.Timeouts.Handshake)); err != nil {
return newError("unable to set read deadline").Base(err).AtWarning()
return errors.New("unable to set read deadline").Base(err).AtWarning()
}
first := buf.FromBytes(make([]byte, buf.Size))
first.Clear()
firstLen, err := first.ReadFrom(conn)
if err != nil {
return newError("failed to read first request").Base(err)
return errors.New("failed to read first request").Base(err)
}
newError("firstLen = ", firstLen).AtInfo().WriteToLog(sid)
errors.LogInfo(ctx, "firstLen = ", firstLen)
bufferedReader := &buf.BufferedReader{
Reader: buf.NewReader(conn),
@ -166,7 +164,7 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
shouldFallback := false
if firstLen < 58 || first.Byte(56) != '\r' {
// invalid protocol
err = newError("not trojan protocol")
err = errors.New("not trojan protocol")
log.Record(&log.AccessMessage{
From: conn.RemoteAddr(),
To: "",
@ -179,7 +177,7 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
user = s.validator.Get(hexString(first.BytesTo(56)))
if user == nil {
// invalid user, let's fallback
err = newError("not a valid user")
err = errors.New("not a valid user")
log.Record(&log.AccessMessage{
From: conn.RemoteAddr(),
To: "",
@ -192,9 +190,9 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
}
if isfb && shouldFallback {
return s.fallback(ctx, sid, err, sessionPolicy, conn, iConn, napfb, first, firstLen, bufferedReader)
return s.fallback(ctx, err, sessionPolicy, conn, iConn, napfb, first, firstLen, bufferedReader)
} else if shouldFallback {
return newError("invalid protocol or invalid user")
return errors.New("invalid protocol or invalid user")
}
clientReader := &ConnReader{Reader: bufferedReader}
@ -205,12 +203,12 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
Status: log.AccessRejected,
Reason: err,
})
return newError("failed to create request from: ", conn.RemoteAddr()).Base(err)
return errors.New("failed to create request from: ", conn.RemoteAddr()).Base(err)
}
destination := clientReader.Target
if err := conn.SetReadDeadline(time.Time{}); err != nil {
return newError("unable to set read deadline").Base(err).AtWarning()
return errors.New("unable to set read deadline").Base(err).AtWarning()
}
inbound := session.InboundFromContext(ctx)
@ -231,7 +229,7 @@ func (s *Server) Process(ctx context.Context, network net.Network, conn stat.Con
Email: user.Email,
})
newError("received request for ", destination).WriteToLog(sid)
errors.LogInfo(ctx, "received request for ", destination)
return s.handleConnection(ctx, sessionPolicy, destination, clientReader, buf.NewWriter(conn), dispatcher)
}
@ -243,7 +241,7 @@ func (s *Server) handleUDPPayload(ctx context.Context, clientReader *PacketReade
}
if err := clientWriter.WriteMultiBuffer(buf.MultiBuffer{udpPayload}); err != nil {
newError("failed to write response").Base(err).AtWarning().WriteToLog(session.ExportIDToError(ctx))
errors.LogWarningInner(ctx, err, "failed to write response")
}
})
@ -260,7 +258,7 @@ func (s *Server) handleUDPPayload(ctx context.Context, clientReader *PacketReade
mb, err := clientReader.ReadMultiBuffer()
if err != nil {
if errors.Cause(err) != io.EOF {
return newError("unexpected EOF").Base(err)
return errors.New("unexpected EOF").Base(err)
}
return nil
}
@ -281,7 +279,7 @@ func (s *Server) handleUDPPayload(ctx context.Context, clientReader *PacketReade
Email: user.Email,
})
}
newError("tunnelling request to ", destination).WriteToLog(session.ExportIDToError(ctx))
errors.LogInfo(ctx, "tunnelling request to ", destination)
if !s.cone || dest == nil {
dest = &destination
@ -306,13 +304,13 @@ func (s *Server) handleConnection(ctx context.Context, sessionPolicy policy.Sess
link, err := dispatcher.Dispatch(ctx, destination)
if err != nil {
return newError("failed to dispatch request to ", destination).Base(err)
return errors.New("failed to dispatch request to ", destination).Base(err)
}
requestDone := func() error {
defer timer.SetTimeout(sessionPolicy.Timeouts.DownlinkOnly)
if buf.Copy(clientReader, link.Writer, buf.UpdateActivity(timer)) != nil {
return newError("failed to transfer request").Base(err)
return errors.New("failed to transfer request").Base(err)
}
return nil
}
@ -321,7 +319,7 @@ func (s *Server) handleConnection(ctx context.Context, sessionPolicy policy.Sess
defer timer.SetTimeout(sessionPolicy.Timeouts.UplinkOnly)
if err := buf.Copy(link.Reader, clientWriter, buf.UpdateActivity(timer)); err != nil {
return newError("failed to write response").Base(err)
return errors.New("failed to write response").Base(err)
}
return nil
}
@ -330,17 +328,17 @@ func (s *Server) handleConnection(ctx context.Context, sessionPolicy policy.Sess
if err := task.Run(ctx, requestDonePost, responseDone); err != nil {
common.Must(common.Interrupt(link.Reader))
common.Must(common.Interrupt(link.Writer))
return newError("connection ends").Base(err)
return errors.New("connection ends").Base(err)
}
return nil
}
func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err error, sessionPolicy policy.Session, connection stat.Connection, iConn stat.Connection, napfb map[string]map[string]map[string]*Fallback, first *buf.Buffer, firstLen int64, reader buf.Reader) error {
func (s *Server) fallback(ctx context.Context, err error, sessionPolicy policy.Session, connection stat.Connection, iConn stat.Connection, napfb map[string]map[string]map[string]*Fallback, first *buf.Buffer, firstLen int64, reader buf.Reader) error {
if err := connection.SetReadDeadline(time.Time{}); err != nil {
newError("unable to set back read deadline").Base(err).AtWarning().WriteToLog(sid)
errors.LogWarningInner(ctx, err, "unable to set back read deadline")
}
newError("fallback starts").Base(err).AtInfo().WriteToLog(sid)
errors.LogInfoInner(ctx, err, "fallback starts")
name := ""
alpn := ""
@ -348,14 +346,14 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
cs := tlsConn.ConnectionState()
name = cs.ServerName
alpn = cs.NegotiatedProtocol
newError("realName = " + name).AtInfo().WriteToLog(sid)
newError("realAlpn = " + alpn).AtInfo().WriteToLog(sid)
errors.LogInfo(ctx, "realName = " + name)
errors.LogInfo(ctx, "realAlpn = " + alpn)
} else if realityConn, ok := iConn.(*reality.Conn); ok {
cs := realityConn.ConnectionState()
name = cs.ServerName
alpn = cs.NegotiatedProtocol
newError("realName = " + name).AtInfo().WriteToLog(sid)
newError("realAlpn = " + alpn).AtInfo().WriteToLog(sid)
errors.LogInfo(ctx, "realName = " + name)
errors.LogInfo(ctx, "realAlpn = " + alpn)
}
name = strings.ToLower(name)
alpn = strings.ToLower(alpn)
@ -377,7 +375,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
}
apfb := napfb[name]
if apfb == nil {
return newError(`failed to find the default "name" config`).AtWarning()
return errors.New(`failed to find the default "name" config`).AtWarning()
}
if apfb[alpn] == nil {
@ -385,7 +383,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
}
pfb := apfb[alpn]
if pfb == nil {
return newError(`failed to find the default "alpn" config`).AtWarning()
return errors.New(`failed to find the default "alpn" config`).AtWarning()
}
path := ""
@ -405,7 +403,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
}
if k == '?' || k == ' ' {
path = string(firstBytes[i:j])
newError("realPath = " + path).AtInfo().WriteToLog(sid)
errors.LogInfo(ctx, "realPath = " + path)
if pfb[path] == nil {
path = ""
}
@ -419,7 +417,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
}
fb := pfb[path]
if fb == nil {
return newError(`failed to find the default "path" config`).AtWarning()
return errors.New(`failed to find the default "path" config`).AtWarning()
}
ctx, cancel := context.WithCancel(ctx)
@ -435,7 +433,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
}
return nil
}); err != nil {
return newError("failed to dial to " + fb.Dest).Base(err).AtWarning()
return errors.New("failed to dial to " + fb.Dest).Base(err).AtWarning()
}
defer conn.Close()
@ -495,11 +493,11 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
common.Must2(pro.Write([]byte{byte(p1 >> 8), byte(p1), byte(p2 >> 8), byte(p2)}))
}
if err := serverWriter.WriteMultiBuffer(buf.MultiBuffer{pro}); err != nil {
return newError("failed to set PROXY protocol v", fb.Xver).Base(err).AtWarning()
return errors.New("failed to set PROXY protocol v", fb.Xver).Base(err).AtWarning()
}
}
if err := buf.Copy(reader, serverWriter, buf.UpdateActivity(timer)); err != nil {
return newError("failed to fallback request payload").Base(err).AtInfo()
return errors.New("failed to fallback request payload").Base(err).AtInfo()
}
return nil
}
@ -509,7 +507,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
getResponse := func() error {
defer timer.SetTimeout(sessionPolicy.Timeouts.UplinkOnly)
if err := buf.Copy(serverReader, writer, buf.UpdateActivity(timer)); err != nil {
return newError("failed to deliver response payload").Base(err).AtInfo()
return errors.New("failed to deliver response payload").Base(err).AtInfo()
}
return nil
}
@ -517,7 +515,7 @@ func (s *Server) fallback(ctx context.Context, sid errors.ExportOption, err erro
if err := task.Run(ctx, task.OnSuccess(postRequest, task.Close(serverWriter)), task.OnSuccess(getResponse, task.Close(writer))); err != nil {
common.Must(common.Interrupt(serverReader))
common.Must(common.Interrupt(serverWriter))
return newError("fallback ends").Base(err).AtInfo()
return errors.New("fallback ends").Base(err).AtInfo()
}
return nil