refactor log and error

app/dns/config.go

@@ -4,6 +4,7 @@ import (
 	"net"
 
 	"v2ray.com/core/app/log"
+	"v2ray.com/core/common/errors"
 )
 
 func (v *Config) GetInternalHosts() map[string]net.IP {
@@ -11,7 +12,7 @@ func (v *Config) GetInternalHosts() map[string]net.IP {
 	for domain, ipOrDomain := range v.GetHosts() {
 		address := ipOrDomain.AsAddress()
 		if address.Family().IsDomain() {
-			log.Warning("DNS: Ignoring domain address in static hosts: ", address.Domain())
+			log.Trace(errors.New("DNS: Ignoring domain address in static hosts: ", address.Domain()).AtWarning())
 			continue
 		}
 		hosts[domain] = address.IP()

app/dns/server/nameserver.go

@@ -89,7 +89,7 @@ func (v *UDPNameServer) AssignUnusedID(response chan<- *ARecord) uint16 {
 		if _, found := v.requests[id]; found {
 			continue
 		}
-		log.Debug("DNS: Add pending request id ", id)
+		log.Trace(errors.New("DNS: Add pending request id ", id).AtDebug())
 		v.requests[id] = &PendingRequest{
 			expire:   time.Now().Add(time.Second * 8),
 			response: response,
@@ -105,7 +105,7 @@ func (v *UDPNameServer) HandleResponse(payload *buf.Buffer) {
 	msg := new(dns.Msg)
 	err := msg.Unpack(payload.Bytes())
 	if err != nil {
-		log.Warning("DNS: Failed to parse DNS response: ", err)
+		log.Trace(errors.New("DNS: Failed to parse DNS response: ", err).AtWarning())
 		return
 	}
 	record := &ARecord{
@@ -113,7 +113,7 @@ func (v *UDPNameServer) HandleResponse(payload *buf.Buffer) {
 	}
 	id := msg.Id
 	ttl := DefaultTTL
-	log.Debug("DNS: Handling response for id ", id, " content: ", msg.String())
+	log.Trace(errors.New("DNS: Handling response for id ", id, " content: ", msg.String()).AtDebug())
 
 	v.Lock()
 	request, found := v.requests[id]

app/dns/server/server.go

@@ -113,13 +113,13 @@ func (v *CacheServer) Get(domain string) []net.IP {
 				A: a,
 			}
 			v.Unlock()
-			log.Debug("DNS: Returning ", len(a.IPs), " IPs for domain ", domain)
+			log.Trace(errors.New("DNS: Returning ", len(a.IPs), " IPs for domain ", domain).AtDebug())
 			return a.IPs
 		case <-time.After(QueryTimeout):
 		}
 	}
 
-	log.Debug("DNS: Returning nil for domain ", domain)
+	log.Trace(errors.New("DNS: Returning nil for domain ", domain).AtDebug())
 	return nil
 }
 

app/log/log.go

@@ -49,32 +49,32 @@ func InitErrorLogger(file string) error {
 	return nil
 }
 
-// Debug outputs a debug log with given format and optional arguments.
+// writeDebug outputs a debug log with given format and optional arguments.
-func Debug(val ...interface{}) {
+func writeDebug(val ...interface{}) {
 	debugLogger.Log(&internal.ErrorLog{
 		Prefix: "[Debug]",
 		Values: val,
 	})
 }
 
-// Info outputs an info log with given format and optional arguments.
+// writeInfo outputs an info log with given format and optional arguments.
-func Info(val ...interface{}) {
+func writeInfo(val ...interface{}) {
 	infoLogger.Log(&internal.ErrorLog{
 		Prefix: "[Info]",
 		Values: val,
 	})
 }
 
-// Warning outputs a warning log with given format and optional arguments.
+// writeWarning outputs a warning log with given format and optional arguments.
-func Warning(val ...interface{}) {
+func writeWarning(val ...interface{}) {
 	warningLogger.Log(&internal.ErrorLog{
 		Prefix: "[Warning]",
 		Values: val,
 	})
 }
 
-// Error outputs an error log with given format and optional arguments.
+// writeError outputs an error log with given format and optional arguments.
-func Error(val ...interface{}) {
+func writeError(val ...interface{}) {
 	errorLogger.Log(&internal.ErrorLog{
 		Prefix: "[Error]",
 		Values: val,
@@ -85,15 +85,15 @@ func Trace(err error) {
 	s := errors.GetSeverity(err)
 	switch s {
 	case errors.SeverityDebug:
-		Debug(err)
+		writeDebug(err)
 	case errors.SeverityInfo:
-		Info(err)
+		writeInfo(err)
 	case errors.SeverityWarning:
-		Warning(err)
+		writeWarning(err)
 	case errors.SeverityError:
-		Error(err)
+		writeError(err)
 	default:
-		Info(err)
+		writeInfo(err)
 	}
 }
 

app/proxyman/inbound/always.go

@@ -7,6 +7,7 @@ import (
 	"v2ray.com/core/app/proxyman"
 	"v2ray.com/core/app/proxyman/mux"
 	"v2ray.com/core/common/dice"
+	"v2ray.com/core/common/errors"
 	"v2ray.com/core/common/net"
 	"v2ray.com/core/proxy"
 )
@@ -36,7 +37,7 @@ func NewAlwaysOnInboundHandler(ctx context.Context, tag string, receiverConfig *
 	}
 	for port := pr.From; port <= pr.To; port++ {
 		if nl.HasNetwork(net.Network_TCP) {
-			log.Debug("Proxyman|DefaultInboundHandler: creating tcp worker on ", address, ":", port)
+			log.Trace(errors.New("Proxyman|DefaultInboundHandler: creating tcp worker on ", address, ":", port).AtDebug())
 			worker := &tcpWorker{
 				address:      address,
 				port:         net.Port(port),

app/proxyman/inbound/dynamic.go

@@ -9,6 +9,7 @@ import (
 	"v2ray.com/core/app/proxyman"
 	"v2ray.com/core/app/proxyman/mux"
 	"v2ray.com/core/common/dice"
+	"v2ray.com/core/common/errors"
 	v2net "v2ray.com/core/common/net"
 	"v2ray.com/core/proxy"
 )
@@ -92,7 +93,7 @@ func (h *DynamicInboundHandler) refresh() error {
 		port := h.allocatePort()
 		p, err := proxy.CreateInboundHandler(ctx, h.proxyConfig)
 		if err != nil {
-			log.Warning("Proxyman|DefaultInboundHandler: Failed to create proxy instance: ", err)
+			log.Trace(errors.New("failed to create proxy instance").Base(err).Path("Proxyman", "Inbound", "DynamicInboundHandler").AtWarning())
 			continue
 		}
 		nl := p.Network()
@@ -107,7 +108,7 @@ func (h *DynamicInboundHandler) refresh() error {
 				dispatcher:   h.mux,
 			}
 			if err := worker.Start(); err != nil {
-				log.Warning("Proxyman:InboundHandler: Failed to create TCP worker: ", err)
+				log.Trace(errors.New("Proxyman:InboundHandler: Failed to create TCP worker: ", err).AtWarning())
 				continue
 			}
 			workers = append(workers, worker)
@@ -123,7 +124,7 @@ func (h *DynamicInboundHandler) refresh() error {
 				dispatcher:   h.mux,
 			}
 			if err := worker.Start(); err != nil {
-				log.Warning("Proxyman:InboundHandler: Failed to create UDP worker: ", err)
+				log.Trace(errors.New("Proxyman:InboundHandler: Failed to create UDP worker: ", err).AtWarning())
 				continue
 			}
 			workers = append(workers, worker)

app/proxyman/mux/mux.go

@@ -200,16 +200,16 @@ func fetchInput(ctx context.Context, s *session, output buf.Writer) {
 	defer writer.Close()
 	defer s.closeUplink()
 
-	log.Info("Proxyman|Mux|Client: Dispatching request to ", dest)
+	log.Trace(errors.New("dispatching request to ", dest).Path("Proxyman", "Mux", "Client"))
 	data, _ := s.input.ReadTimeout(time.Millisecond * 500)
 	if data != nil {
 		if err := writer.Write(data); err != nil {
-			log.Info("Proxyman|Mux|Client: Failed to write first payload: ", err)
+			log.Trace(errors.New("failed to write first payload").Base(err).Path("Proxyman", "Mux", "Client"))
 			return
 		}
 	}
 	if err := buf.PipeUntilEOF(signal.BackgroundTimer(), s.input, writer); err != nil {
-		log.Info("Proxyman|Mux|Client: Failed to fetch all input: ", err)
+		log.Trace(errors.New("failed to fetch all input").Base(err).Path("Proxyman", "Mux", "Client"))
 	}
 }
 
@@ -287,7 +287,7 @@ func (m *Client) fetchOutput() {
 	for {
 		meta, err := reader.ReadMetadata()
 		if err != nil {
-			log.Info("Proxyman|Mux|Client: Failed to read metadata: ", err)
+			log.Trace(errors.New("failed to read metadata").Base(err).Path("Proxyman", "Mux", "Client"))
 			break
 		}
 		m.access.RLock()
@@ -308,7 +308,7 @@ func (m *Client) fetchOutput() {
 		}
 
 		if err != nil {
-			log.Info("Proxyman|Mux|Client: Failed to read data: ", err)
+			log.Trace(errors.New("failed to read data").Base(err).Path("Proxyman", "Mux", "Client"))
 			break
 		}
 	}
@@ -324,7 +324,7 @@ func NewServer(ctx context.Context) *Server {
 	space.OnInitialize(func() error {
 		d := dispatcher.FromSpace(space)
 		if d == nil {
-			return errors.New("Proxyman|Mux: No dispatcher in space.")
+			return errors.New("no dispatcher in space").Path("Proxyman", "Mux", "Server")
 		}
 		s.dispatcher = d
 		return nil
@@ -363,7 +363,7 @@ func (w *ServerWorker) remove(id uint16) {
 func handle(ctx context.Context, s *session, output buf.Writer) {
 	writer := NewResponseWriter(s.id, output)
 	if err := buf.PipeUntilEOF(signal.BackgroundTimer(), s.input, writer); err != nil {
-		log.Info("Proxyman|Mux|ServerWorker: Session ", s.id, " ends: ", err)
+		log.Trace(errors.New("session ", s.id, " ends: ").Base(err).Path("Proxyman", "Mux", "ServerWorker"))
 	}
 	writer.Close()
 	s.closeDownlink()
@@ -381,7 +381,7 @@ func (w *ServerWorker) run(ctx context.Context) {
 
 		meta, err := reader.ReadMetadata()
 		if err != nil {
-			log.Info("Proxyman|Mux|ServerWorker: Failed to read metadata: ", err)
+			log.Trace(errors.New("failed to read metadata").Base(err).Path("Proxyman", "Mux", "ServerWorker"))
 			return
 		}
 
@@ -395,10 +395,10 @@ func (w *ServerWorker) run(ctx context.Context) {
 		}
 
 		if meta.SessionStatus == SessionStatusNew {
-			log.Info("Proxyman|Mux|Server: Received request for ", meta.Target)
+			log.Trace(errors.New("received request for ", meta.Target).Path("Proxyman", "Mux", "ServerWorker"))
 			inboundRay, err := w.dispatcher.Dispatch(ctx, meta.Target)
 			if err != nil {
-				log.Info("Proxyman|Mux: Failed to dispatch request: ", err)
+				log.Trace(errors.New("failed to dispatch request.").Base(err).Path("Proxymann", "Mux", "ServerWorker"))
 				continue
 			}
 			s = &session{
@@ -424,7 +424,7 @@ func (w *ServerWorker) run(ctx context.Context) {
 		}
 
 		if err != nil {
-			log.Info("Proxyman|Mux|ServerWorker: Failed to read data: ", err)
+			log.Trace(errors.New("failed to read data").Base(err).Path("Proxymann", "Mux", "ServerWorker"))
 			break
 		}
 	}

app/proxyman/outbound/handler.go

@@ -102,7 +102,7 @@ func (h *Handler) Dial(ctx context.Context, dest v2net.Destination) (internet.Co
 				return NewConnection(stream), nil
 			}
 
-			log.Warning("Proxyman|OutboundHandler: Failed to get outbound handler with tag: ", tag)
+			log.Trace(errors.New("Proxyman|OutboundHandler: Failed to get outbound handler with tag: ", tag).AtWarning())
 		}
 
 		if h.senderSettings.Via != nil {

app/router/router.go

@@ -76,7 +76,7 @@ func (v *Router) TakeDetour(ctx context.Context) (string, error) {
 	}
 
 	if v.domainStrategy == Config_IpIfNonMatch && dest.Address.Family().IsDomain() {
-		log.Info("Router: Looking up IP for ", dest)
+		log.Trace(errors.New("looking up IP for ", dest).Path("App", "Router"))
 		ipDests := v.resolveIP(dest)
 		if ipDests != nil {
 			ctx = proxy.ContextWithResolveIPs(ctx, ipDests)

common/errors/errors_test.go

@@ -8,7 +8,7 @@ import (
 	"v2ray.com/core/testing/assert"
 )
 
-func TestActionRequired(t *testing.T) {
+func TestError(t *testing.T) {
 	assert := assert.On(t)
 
 	err := New("TestError")
@@ -25,3 +25,25 @@ func TestActionRequired(t *testing.T) {
 	assert.Bool(GetSeverity(err) == SeverityWarning).IsTrue()
 	assert.String(err.Error()).Contains("EOF")
 }
+
+func TestErrorMessage(t *testing.T) {
+	assert := assert.On(t)
+
+	data := []struct {
+		err error
+		msg string
+	}{
+		{
+			err: New("a").Base(New("b")).Path("c", "d", "e"),
+			msg: "c|d|e: a > b",
+		},
+		{
+			err: New("a").Base(New("b").Path("c")).Path("d", "e"),
+			msg: "d|e: a > c: b",
+		},
+	}
+
+	for _, d := range data {
+		assert.String(d.err.Error()).Equals(d.msg)
+	}
+}

common/net/address.go

@@ -4,6 +4,7 @@ import (
 	"net"
 
 	"v2ray.com/core/app/log"
+	"v2ray.com/core/common/errors"
 	"v2ray.com/core/common/predicate"
 )
 
@@ -94,7 +95,7 @@ func IPAddress(ip []byte) Address {
 		}
 		return addr
 	default:
-		log.Error("Net: Invalid IP format: ", ip)
+		log.Trace(errors.New("Net: Invalid IP format: ", ip).AtError())
 		return nil
 	}
 }

proxy/dokodemo/dokodemo.go

@@ -44,7 +44,7 @@ func (d *DokodemoDoor) Network() net.NetworkList {
 }
 
 func (d *DokodemoDoor) Process(ctx context.Context, network net.Network, conn internet.Connection, dispatcher dispatcher.Interface) error {
-	log.Debug("Dokodemo: processing connection from: ", conn.RemoteAddr())
+	log.Trace(errors.New("Dokodemo: processing connection from: ", conn.RemoteAddr()).AtDebug())
 	conn.SetReusable(false)
 	dest := net.Destination{
 		Network: network,
@@ -57,8 +57,7 @@ func (d *DokodemoDoor) Process(ctx context.Context, network net.Network, conn in
 		}
 	}
 	if !dest.IsValid() || dest.Address == nil {
-		log.Info("Dokodemo: Invalid destination. Discarding...")
+		return errors.New("unable to get destination").Path("Proxy", "Dokodemo")
-		return errors.New("Dokodemo: Unable to get destination.")
 	}
 
 	timeout := time.Second * time.Duration(d.config.Timeout)
@@ -78,8 +77,7 @@ func (d *DokodemoDoor) Process(ctx context.Context, network net.Network, conn in
 		chunkReader := buf.NewReader(conn)
 
 		if err := buf.PipeUntilEOF(timer, chunkReader, inboundRay.InboundInput()); err != nil {
-			log.Info("Dokodemo: Failed to transport request: ", err)
+			return errors.New("failed to transport request").Base(err).Path("Proxy", "Dokodemo")
-			return err
 		}
 
 		return nil
@@ -89,8 +87,7 @@ func (d *DokodemoDoor) Process(ctx context.Context, network net.Network, conn in
 		v2writer := buf.NewWriter(conn)
 
 		if err := buf.PipeUntilEOF(timer, inboundRay.InboundOutput(), v2writer); err != nil {
-			log.Info("Dokodemo: Failed to transport response: ", err)
+			return errors.New("failed to transport response").Base(err).Path("Proxy", "Dokodemo")
-			return err
 		}
 		return nil
 	})
@@ -98,8 +95,7 @@ func (d *DokodemoDoor) Process(ctx context.Context, network net.Network, conn in
 	if err := signal.ErrorOrFinish2(ctx, requestDone, responseDone); err != nil {
 		inboundRay.InboundInput().CloseError()
 		inboundRay.InboundOutput().CloseError()
-		log.Info("Dokodemo: Connection ends with ", err)
+		return errors.New("connection ends").Base(err).Path("Proxy", "Dokodemo")
-		return err
 	}
 
 	runtime.KeepAlive(timer)

proxy/freedom/freedom.go

@@ -31,7 +31,7 @@ type Handler struct {
 func New(ctx context.Context, config *Config) (*Handler, error) {
 	space := app.SpaceFromContext(ctx)
 	if space == nil {
-		return nil, errors.New("Freedom: No space in context.")
+		return nil, errors.New("no space in context").Path("Proxy", "Freedom")
 	}
 	f := &Handler{
 		domainStrategy: config.DomainStrategy,
@@ -42,7 +42,7 @@ func New(ctx context.Context, config *Config) (*Handler, error) {
 		if config.DomainStrategy == Config_USE_IP {
 			f.dns = dns.FromSpace(space)
 			if f.dns == nil {
-				return errors.New("Freedom: DNS server is not found in the space.")
+				return errors.New("DNS server is not found in the space").Path("Proxy", "Freedom")
 			}
 		}
 		return nil
@@ -50,7 +50,6 @@ func New(ctx context.Context, config *Config) (*Handler, error) {
 	return f, nil
 }
 
-// Private: Visible for testing.
 func (v *Handler) ResolveIP(destination net.Destination) net.Destination {
 	if !destination.Address.Family().IsDomain() {
 		return destination
@@ -58,7 +57,7 @@ func (v *Handler) ResolveIP(destination net.Destination) net.Destination {
 
 	ips := v.dns.Get(destination.Address.Domain())
 	if len(ips) == 0 {
-		log.Info("Freedom: DNS returns nil answer. Keep domain as is.")
+		log.Trace(errors.New("DNS returns nil answer. Keep domain as is.").Path("Proxy", "Freedom"))
 		return destination
 	}
 
@@ -69,7 +68,7 @@ func (v *Handler) ResolveIP(destination net.Destination) net.Destination {
 	} else {
 		newDest = net.UDPDestination(net.IPAddress(ip), destination.Port)
 	}
-	log.Info("Freedom: Changing destination from ", destination, " to ", newDest)
+	log.Trace(errors.New("changing destination from ", destination, " to ", newDest).Path("Proxy", "Freedom"))
 	return newDest
 }
 
@@ -83,7 +82,7 @@ func (v *Handler) Process(ctx context.Context, outboundRay ray.OutboundRay, dial
 			Port:    net.Port(server.Port),
 		}
 	}
-	log.Info("Freedom: Opening connection to ", destination)
+	log.Trace(errors.New("opening connection to ", destination).Path("Proxy", "Freedom"))
 
 	input := outboundRay.OutboundInput()
 	output := outboundRay.OutboundOutput()
@@ -102,7 +101,7 @@ func (v *Handler) Process(ctx context.Context, outboundRay ray.OutboundRay, dial
 		return nil
 	})
 	if err != nil {
-		return errors.New("failed to open connection to ", destination).Base(err).Path("Freedom")
+		return errors.New("failed to open connection to ", destination).Base(err).Path("Proxy", "Freedom")
 	}
 	defer conn.Close()
 
@@ -112,7 +111,6 @@ func (v *Handler) Process(ctx context.Context, outboundRay ray.OutboundRay, dial
 	if timeout == 0 {
 		timeout = time.Minute * 5
 	}
-	log.Debug("Freedom: Cancel after ", timeout)
 	ctx, timer := signal.CancelAfterInactivity(ctx, timeout)
 
 	requestDone := signal.ExecuteAsync(func() error {
@@ -136,7 +134,7 @@ func (v *Handler) Process(ctx context.Context, outboundRay ray.OutboundRay, dial
 	if err := signal.ErrorOrFinish2(ctx, requestDone, responseDone); err != nil {
 		input.CloseError()
 		output.CloseError()
-		return errors.New("connection ends").Base(err).Path("Freedom")
+		return errors.New("connection ends").Base(err).Path("Proxy", "Freedom")
 	}
 
 	runtime.KeepAlive(timer)

proxy/http/server.go

@@ -77,11 +77,11 @@ func (s *Server) Process(ctx context.Context, network v2net.Network, conn intern
 	request, err := http.ReadRequest(reader)
 	if err != nil {
 		if errors.Cause(err) != io.EOF {
-			log.Warning("HTTP: Failed to read http request: ", err)
+			log.Trace(errors.New("HTTP: Failed to read http request: ", err).AtWarning())
 		}
 		return err
 	}
-	log.Info("HTTP: Request to Method [", request.Method, "] Host [", request.Host, "] with URL [", request.URL, "]")
+	log.Trace(errors.New("request to Method [", request.Method, "] Host [", request.Host, "] with URL [", request.URL, "]").Path("Proxy", "HTTP", "Server"))
 	conn.SetReadDeadline(time.Time{})
 
 	defaultPort := v2net.Port(80)
@@ -234,7 +234,7 @@ func (s *Server) handlePlainHTTP(ctx context.Context, request *http.Request, rea
 		responseReader := bufio.NewReader(buf.ToBytesReader(ray.InboundOutput()))
 		response, err := http.ReadResponse(responseReader, request)
 		if err != nil {
-			log.Warning("HTTP: Failed to read response: ", err)
+			log.Trace(errors.New("HTTP: Failed to read response: ", err).AtWarning())
 			response = generateResponse(503, "Service Unavailable")
 		}
 		responseWriter := buf.NewBufferedWriter(writer)

proxy/shadowsocks/client.go

@@ -62,7 +62,7 @@ func (v *Client) Process(ctx context.Context, outboundRay ray.OutboundRay, diale
 	if err != nil {
 		return errors.New("failed to find an available destination").AtWarning().Base(err).Path("Shadowsocks", "Client")
 	}
-	log.Info("Shadowsocks|Client: Tunneling request to ", destination, " via ", server.Destination())
+	log.Trace(errors.New("Shadowsocks|Client: Tunneling request to ", destination, " via ", server.Destination()))
 
 	defer conn.Close()
 	conn.SetReusable(false)

proxy/socks/server.go

@@ -78,14 +78,14 @@ func (s *Server) processTCP(ctx context.Context, conn internet.Connection, dispa
 		if source, ok := proxy.SourceFromContext(ctx); ok {
 			log.Access(source, "", log.AccessRejected, err)
 		}
-		log.Info("Socks|Server: Failed to read request: ", err)
+		log.Trace(errors.New("Socks|Server: Failed to read request: ", err))
 		return err
 	}
 	conn.SetReadDeadline(time.Time{})
 
 	if request.Command == protocol.RequestCommandTCP {
 		dest := request.Destination()
-		log.Info("Socks|Server: TCP Connect request to ", dest)
+		log.Trace(errors.New("Socks|Server: TCP Connect request to ", dest))
 		if source, ok := proxy.SourceFromContext(ctx); ok {
 			log.Access(source, dest, log.AccessAccepted, "")
 		}
@@ -169,7 +169,7 @@ func (v *Server) handleUDPPayload(ctx context.Context, conn internet.Connection,
 		request, data, err := DecodeUDPPacket(payload.Bytes())
 
 		if err != nil {
-			log.Info("Socks|Server: Failed to parse UDP request: ", err)
+			log.Trace(errors.New("Socks|Server: Failed to parse UDP request: ", err))
 			continue
 		}
 
@@ -177,7 +177,7 @@ func (v *Server) handleUDPPayload(ctx context.Context, conn internet.Connection,
 			continue
 		}
 
-		log.Info("Socks: Send packet to ", request.Destination(), " with ", len(data), " bytes")
+		log.Trace(errors.New("Socks: Send packet to ", request.Destination(), " with ", len(data), " bytes"))
 		if source, ok := proxy.SourceFromContext(ctx); ok {
 			log.Access(source, request.Destination, log.AccessAccepted, "")
 		}
@@ -187,7 +187,7 @@ func (v *Server) handleUDPPayload(ctx context.Context, conn internet.Connection,
 		udpServer.Dispatch(ctx, request.Destination(), dataBuf, func(payload *buf.Buffer) {
 			defer payload.Release()
 
-			log.Info("Socks|Server: Writing back UDP response with ", payload.Len(), " bytes")
+			log.Trace(errors.New("Socks|Server: Writing back UDP response with ", payload.Len(), " bytes"))
 
 			udpMessage := EncodeUDPPacket(request, payload.Bytes())
 			defer udpMessage.Release()

proxy/vmess/account.go

@@ -3,6 +3,7 @@ package vmess
 import (
 	"v2ray.com/core/app/log"
 	"v2ray.com/core/common/dice"
+	"v2ray.com/core/common/errors"
 	"v2ray.com/core/common/protocol"
 	"v2ray.com/core/common/uuid"
 )
@@ -32,7 +33,7 @@ func (v *InternalAccount) Equals(account protocol.Account) bool {
 func (v *Account) AsAccount() (protocol.Account, error) {
 	id, err := uuid.ParseString(v.Id)
 	if err != nil {
-		log.Error("VMess: Failed to parse ID: ", err)
+		log.Trace(errors.New("failed to parse ID").Path("VMess", "Account").Base(err).AtError())
 		return nil, err
 	}
 	protoID := protocol.NewID(id)

proxy/vmess/encoding/client.go

@@ -63,7 +63,7 @@ func (v *ClientSession) EncodeRequestHeader(header *protocol.RequestHeader, writ
 	timestamp := protocol.NewTimestampGenerator(protocol.NowTime(), 30)()
 	account, err := header.User.GetTypedAccount()
 	if err != nil {
-		log.Error("VMess: Failed to get user account: ", err)
+		log.Trace(errors.New("VMess: Failed to get user account: ", err).AtError())
 		return
 	}
 	idHash := v.idHash(account.(*vmess.InternalAccount).AnyValidID().Bytes())
@@ -186,7 +186,7 @@ func (v *ClientSession) DecodeResponseHeader(reader io.Reader) (*protocol.Respon
 
 	_, err := io.ReadFull(v.responseReader, buffer[:4])
 	if err != nil {
-		log.Info("VMess|Client: Failed to read response header: ", err)
+		log.Trace(errors.New("VMess|Client: Failed to read response header: ", err))
 		return nil, err
 	}
 
@@ -203,7 +203,7 @@ func (v *ClientSession) DecodeResponseHeader(reader io.Reader) (*protocol.Respon
 		dataLen := int(buffer[3])
 		_, err := io.ReadFull(v.responseReader, buffer[:dataLen])
 		if err != nil {
-			log.Info("VMess|Client: Failed to read response command: ", err)
+			log.Trace(errors.New("VMess|Client: Failed to read response command: ", err))
 			return nil, err
 		}
 		data := buffer[:dataLen]

proxy/vmess/inbound/inbound.go

@@ -179,13 +179,13 @@ func (v *Handler) Process(ctx context.Context, network net.Network, connection i
 	if err != nil {
 		if errors.Cause(err) != io.EOF {
 			log.Access(connection.RemoteAddr(), "", log.AccessRejected, err)
-			log.Info("VMess|Inbound: Invalid request from ", connection.RemoteAddr(), ": ", err)
+			log.Trace(errors.New("VMess|Inbound: Invalid request from ", connection.RemoteAddr(), ": ", err))
 		}
 		connection.SetReusable(false)
 		return err
 	}
 	log.Access(connection.RemoteAddr(), request.Destination(), log.AccessAccepted, "")
-	log.Info("VMess|Inbound: Received request for ", request.Destination())
+	log.Trace(errors.New("VMess|Inbound: Received request for ", request.Destination()))
 
 	connection.SetReadDeadline(time.Time{})
 
@@ -245,7 +245,7 @@ func (v *Handler) generateCommand(ctx context.Context, request *protocol.Request
 		if v.inboundHandlerManager != nil {
 			handler, err := v.inboundHandlerManager.GetHandler(ctx, tag)
 			if err != nil {
-				log.Warning("VMess|Inbound: Failed to get detour handler: ", tag, err)
+				log.Trace(errors.New("VMess|Inbound: Failed to get detour handler: ", tag, err).AtWarning())
 				return nil
 			}
 			proxyHandler, port, availableMin := handler.GetRandomInboundProxy()
@@ -255,7 +255,7 @@ func (v *Handler) generateCommand(ctx context.Context, request *protocol.Request
 					availableMin = 255
 				}
 
-				log.Info("VMess|Inbound: Pick detour handler for port ", port, " for ", availableMin, " minutes.")
+				log.Trace(errors.New("VMess|Inbound: Pick detour handler for port ", port, " for ", availableMin, " minutes."))
 				user := inboundHandler.GetUser(request.User.Email)
 				if user == nil {
 					return nil

proxy/vmess/outbound/outbound.go

@@ -69,7 +69,7 @@ func (v *Handler) Process(ctx context.Context, outboundRay ray.OutboundRay, dial
 	if !ok {
 		return errors.New("VMess|Outbound: Target not specified.")
 	}
-	log.Info("VMess|Outbound: Tunneling request to ", target, " via ", rec.Destination())
+	log.Trace(errors.New("VMess|Outbound: Tunneling request to ", target, " via ", rec.Destination()))
 
 	command := protocol.RequestCommandTCP
 	if target.Network == net.Network_UDP {

testing/scenarios/common.go

@@ -16,6 +16,7 @@ import (
 	"v2ray.com/core"
 	"v2ray.com/core/app/log"
 	"v2ray.com/core/common"
+	"v2ray.com/core/common/errors"
 	v2net "v2ray.com/core/common/net"
 	"v2ray.com/core/common/retry"
 )
@@ -106,11 +107,11 @@ func GetSourcePath() string {
 }
 
 func CloseAllServers() {
-	log.Info("Closing all servers.")
+	log.Trace(errors.New("Closing all servers."))
 	for _, server := range runningServers {
 		server.Process.Signal(os.Interrupt)
 		server.Process.Wait()
 	}
 	runningServers = make([]*exec.Cmd, 0, 10)
-	log.Info("All server closed.")
+	log.Trace(errors.New("All server closed."))
 }

tools/conf/router.go

@@ -228,7 +228,7 @@ func parseChinaSitesRule(data []byte) (*router.RoutingRule, error) {
 	rawRule := new(RouterRule)
 	err := json.Unmarshal(data, rawRule)
 	if err != nil {
-		log.Error("Router: Invalid router rule: ", err)
+		log.Trace(errors.New("Router: Invalid router rule: ", err).AtError())
 		return nil, err
 	}
 	return &router.RoutingRule{

transport/internet/kcp/connection.go

@@ -203,7 +203,7 @@ type Connection struct {
 
 // NewConnection create a new KCP connection between local and remote.
 func NewConnection(conv uint16, sysConn SystemConnection, recycler internal.ConnectionRecyler, config *Config) *Connection {
-	log.Info("KCP|Connection: creating connection ", conv)
+	log.Trace(errors.New("KCP|Connection: creating connection ", conv))
 
 	conn := &Connection{
 		conv:         conv,
@@ -341,7 +341,7 @@ func (v *Connection) SetState(state State) {
 	current := v.Elapsed()
 	atomic.StoreInt32((*int32)(&v.state), int32(state))
 	atomic.StoreUint32(&v.stateBeginTime, current)
-	log.Debug("KCP|Connection: #", v.conv, " entering state ", state, " at ", current)
+	log.Trace(errors.New("KCP|Connection: #", v.conv, " entering state ", state, " at ", current).AtDebug())
 
 	switch state {
 	case StateReadyToClose:
@@ -378,7 +378,7 @@ func (v *Connection) Close() error {
 	if state.Is(StateReadyToClose, StateTerminating, StateTerminated) {
 		return ErrClosedConnection
 	}
-	log.Info("KCP|Connection: Closing connection to ", v.conn.RemoteAddr())
+	log.Trace(errors.New("KCP|Connection: Closing connection to ", v.conn.RemoteAddr()))
 
 	if state == StateActive {
 		v.SetState(StateReadyToClose)
@@ -455,7 +455,7 @@ func (v *Connection) Terminate() {
 	if v == nil {
 		return
 	}
-	log.Info("KCP|Connection: Terminating connection to ", v.RemoteAddr())
+	log.Trace(errors.New("KCP|Connection: Terminating connection to ", v.RemoteAddr()))
 
 	//v.SetState(StateTerminated)
 	v.OnDataInput()
@@ -549,7 +549,7 @@ func (v *Connection) flush() {
 	}
 
 	if v.State() == StateTerminating {
-		log.Debug("KCP|Connection: #", v.conv, " sending terminating cmd.")
+		log.Trace(errors.New("KCP|Connection: #", v.conv, " sending terminating cmd.").AtDebug())
 		v.Ping(current, CommandTerminate)
 
 		if current-atomic.LoadUint32(&v.stateBeginTime) > 8000 {

transport/internet/kcp/dialer.go

@@ -111,7 +111,7 @@ func (o *ClientConnection) Run() {
 
 func DialKCP(ctx context.Context, dest v2net.Destination) (internet.Connection, error) {
 	dest.Network = v2net.Network_UDP
-	log.Info("KCP|Dialer: Dialing KCP to ", dest)
+	log.Trace(errors.New("KCP|Dialer: Dialing KCP to ", dest))
 
 	src := internet.DialerSourceFromContext(ctx)
 	id := internal.NewConnectionID(src, dest)
@@ -119,7 +119,7 @@ func DialKCP(ctx context.Context, dest v2net.Destination) (internet.Connection,
 	if conn == nil {
 		rawConn, err := internet.DialSystem(ctx, src, dest)
 		if err != nil {
-			log.Error("KCP|Dialer: Failed to dial to dest: ", err)
+			log.Trace(errors.New("KCP|Dialer: Failed to dial to dest: ", err).AtError())
 			return nil, err
 		}
 		c := &ClientConnection{

transport/internet/kcp/listener.go

@@ -130,7 +130,7 @@ func NewListener(ctx context.Context, address v2net.Address, port v2net.Port, co
 	l.Lock()
 	l.hub = hub
 	l.Unlock()
-	log.Info("KCP|Listener: listening on ", address, ":", port)
+	log.Trace(errors.New("KCP|Listener: listening on ", address, ":", port))
 	return l, nil
 }
 
@@ -139,7 +139,7 @@ func (v *Listener) OnReceive(payload *buf.Buffer, src v2net.Destination, origina
 
 	segments := v.reader.Read(payload.Bytes())
 	if len(segments) == 0 {
-		log.Info("KCP|Listener: discarding invalid payload from ", src)
+		log.Trace(errors.New("KCP|Listener: discarding invalid payload from ", src))
 		return
 	}
 

transport/internet/tcp/dialer.go

@@ -19,7 +19,7 @@ var (
 )
 
 func Dial(ctx context.Context, dest v2net.Destination) (internet.Connection, error) {
-	log.Info("Internet|TCP: Dailing TCP to ", dest)
+	log.Trace(errors.New("Internet|TCP: Dailing TCP to ", dest))
 	src := internet.DialerSourceFromContext(ctx)
 
 	tcpSettings := internet.TransportSettingsFromContext(ctx).(*Config)

transport/internet/tcp/hub.go

@@ -37,7 +37,7 @@ func ListenTCP(ctx context.Context, address v2net.Address, port v2net.Port, conn
 	if err != nil {
 		return nil, err
 	}
-	log.Info("TCP|Listener: Listening on ", address, ":", port)
+	log.Trace(errors.New("TCP|Listener: Listening on ", address, ":", port))
 	networkSettings := internet.TransportSettingsFromContext(ctx)
 	tcpSettings := networkSettings.(*Config)
 
@@ -85,7 +85,7 @@ func (v *TCPListener) KeepAccepting() {
 			return nil
 		})
 		if err != nil {
-			log.Warning("TCP|Listener: Failed to accepted raw connections: ", err)
+			log.Trace(errors.New("TCP|Listener: Failed to accepted raw connections: ", err).AtWarning())
 			continue
 		}
 

transport/internet/tcp/sockopt_linux.go

@@ -15,18 +15,18 @@ const SO_ORIGINAL_DST = 80
 func GetOriginalDestination(conn internet.Connection) net.Destination {
 	tcpConn, ok := conn.(internet.SysFd)
 	if !ok {
-		log.Info("Dokodemo: Failed to get sys fd.")
+		log.Trace(errors.New("Dokodemo: Failed to get sys fd."))
 		return net.Destination{}
 	}
 	fd, err := tcpConn.SysFd()
 	if err != nil {
-		log.Info("Dokodemo: Failed to get original destination: ", err)
+		log.Trace(errors.New("Dokodemo: Failed to get original destination: ", err))
 		return net.Destination{}
 	}
 
 	addr, err := syscall.GetsockoptIPv6Mreq(fd, syscall.IPPROTO_IP, SO_ORIGINAL_DST)
 	if err != nil {
-		log.Info("Dokodemo: Failed to call getsockopt: ", err)
+		log.Trace(errors.New("Dokodemo: Failed to call getsockopt: ", err))
 		return net.Destination{}
 	}
 	ip := net.IPAddress(addr.Multiaddr[4:8])

transport/internet/tls/config.go

@@ -4,6 +4,7 @@ import (
 	"crypto/tls"
 
 	"v2ray.com/core/app/log"
+	"v2ray.com/core/common/errors"
 )
 
 var (
@@ -15,7 +16,7 @@ func (v *Config) BuildCertificates() []tls.Certificate {
 	for _, entry := range v.Certificate {
 		keyPair, err := tls.X509KeyPair(entry.Certificate, entry.Key)
 		if err != nil {
-			log.Warning("TLS: ignoring invalid X509 key pair: ", err)
+			log.Trace(errors.New("TLS: ignoring invalid X509 key pair").Base(err).AtWarning())
 			continue
 		}
 		certs = append(certs, keyPair)

transport/internet/udp/dispatcher.go

@@ -7,6 +7,7 @@ import (
 	"v2ray.com/core/app/dispatcher"
 	"v2ray.com/core/app/log"
 	"v2ray.com/core/common/buf"
+	"v2ray.com/core/common/errors"
 	v2net "v2ray.com/core/common/net"
 	"v2ray.com/core/transport/ray"
 )
@@ -44,7 +45,7 @@ func (v *Dispatcher) getInboundRay(ctx context.Context, dest v2net.Destination)
 		return entry, true
 	}
 
-	log.Info("UDP|Server: establishing new connection for ", dest)
+	log.Trace(errors.New("UDP|Server: establishing new connection for ", dest))
 	inboundRay, _ := v.dispatcher.Dispatch(ctx, dest)
 	v.conns[dest] = inboundRay
 	return inboundRay, false
@@ -52,7 +53,7 @@ func (v *Dispatcher) getInboundRay(ctx context.Context, dest v2net.Destination)
 
 func (v *Dispatcher) Dispatch(ctx context.Context, destination v2net.Destination, payload *buf.Buffer, callback ResponseCallback) {
 	// TODO: Add user to destString
-	log.Debug("UDP|Server: Dispatch request: ", destination)
+	log.Trace(errors.New("UDP|Server: Dispatch request: ", destination).AtDebug())
 
 	inboundRay, existing := v.getInboundRay(ctx, destination)
 	outputStream := inboundRay.InboundInput()

transport/internet/udp/hub.go

@@ -93,7 +93,7 @@ func ListenUDP(address v2net.Address, port v2net.Port, option ListenOption) (*Hu
 	if err != nil {
 		return nil, err
 	}
-	log.Info("UDP|Hub: Listening on ", address, ":", port)
+	log.Trace(errors.New("UDP|Hub: Listening on ", address, ":", port))
 	if option.ReceiveOriginalDest {
 		fd, err := internal.GetSysFd(udpConn)
 		if err != nil {
@@ -148,7 +148,7 @@ L:
 		})
 
 		if err != nil {
-			log.Info("UDP|Hub: Failed to read UDP msg: ", err)
+			log.Trace(errors.New("UDP|Hub: Failed to read UDP msg: ", err))
 			buffer.Release()
 			continue
 		}

transport/internet/websocket/dialer.go

@@ -19,7 +19,7 @@ var (
 )
 
 func Dial(ctx context.Context, dest v2net.Destination) (internet.Connection, error) {
-	log.Info("WebSocket|Dialer: Creating connection to ", dest)
+	log.Trace(errors.New("WebSocket|Dialer: Creating connection to ", dest))
 	src := internet.DialerSourceFromContext(ctx)
 	wsSettings := internet.TransportSettingsFromContext(ctx).(*Config)
 

transport/internet/websocket/hub.go

@@ -35,7 +35,7 @@ func (h *requestHandler) ServeHTTP(writer http.ResponseWriter, request *http.Req
 	}
 	conn, err := converttovws(writer, request)
 	if err != nil {
-		log.Info("WebSocket|Listener: Failed to convert to WebSocket connection: ", err)
+		log.Trace(errors.New("WebSocket|Listener: Failed to convert to WebSocket connection: ", err))
 		return
 	}