Merge pull request #4392 from ipfs/feat/log/uuid

Feat/log/uuid

Author: whyrusleeping

commands/http/handler.go

@@ -18,6 +18,7 @@ import (
 	cors "gx/ipfs/QmPG2kW5t27LuHgHnvhUwbHCNHAt2eUcb4gPHqofrESUdB/cors"
 	cmdkit "gx/ipfs/QmSNbH2A1evCCbJSDC6u3RV3GGDhgu6pRGbXHvrN89tMKf/go-ipfs-cmdkit"
 	logging "gx/ipfs/QmSpJByNKFX1sCsHBEp3R73FL4NF6FnQTEGyNAXHm2GS52/go-log"
+	loggables "gx/ipfs/QmT4PgCNdv73hnFAqzHqwW44q7M9PWpykSswHDxndquZbc/go-libp2p-loggables"
 )
 
 var log = logging.Logger("commands/http")
@@ -139,6 +140,7 @@ func (i internalHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	ctx, cancel := context.WithCancel(node.Context())
 	defer cancel()
+	ctx = logging.ContextWithLoggable(ctx, loggables.Uuid("requestId"))
 	if cn, ok := w.(http.CloseNotifier); ok {
 		clientGone := cn.CloseNotify()
 		go func() {

core/pathresolver.go

@@ -10,6 +10,7 @@ import (
 
 	cid "gx/ipfs/QmNp85zy9RLrQ5oQD4hPyS39ezrrXpcaa7R4Y9kxdWQLLQ/go-cid"
 	node "gx/ipfs/QmPN7cwmpcc4DWXb4KTB9dNAJgjuPY69h3npsMfhRrQL9c/go-ipld-format"
+	logging "gx/ipfs/QmSpJByNKFX1sCsHBEp3R73FL4NF6FnQTEGyNAXHm2GS52/go-log"
 )
 
 // ErrNoNamesys is an explicit error for when an IPFS node doesn't
@@ -22,33 +23,40 @@ var ErrNoNamesys = errors.New(
 // entries and returning the final node.
 func Resolve(ctx context.Context, nsys namesys.NameSystem, r *path.Resolver, p path.Path) (node.Node, error) {
 	if strings.HasPrefix(p.String(), "/ipns/") {
+		evt := log.EventBegin(ctx, "resolveIpnsPath")
+		defer evt.Done()
 		// resolve ipns paths
 
 		// TODO(cryptix): we sould be able to query the local cache for the path
 		if nsys == nil {
+			evt.Append(logging.LoggableMap{"error": ErrNoNamesys.Error()})
 			return nil, ErrNoNamesys
 		}
 
 		seg := p.Segments()
 
 		if len(seg) < 2 || seg[1] == "" { // just "/<protocol/>" without further segments
+			evt.Append(logging.LoggableMap{"error": path.ErrNoComponents.Error()})
 			return nil, path.ErrNoComponents
 		}
 
 		extensions := seg[2:]
 		resolvable, err := path.FromSegments("/", seg[0], seg[1])
 		if err != nil {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return nil, err
 		}
 
 		respath, err := nsys.Resolve(ctx, resolvable.String())
 		if err != nil {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return nil, err
 		}
 
 		segments := append(respath.Segments(), extensions...)
 		p, err = path.FromSegments("/", segments...)
 		if err != nil {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return nil, err
 		}
 	}

path/resolver.go

@@ -131,14 +131,19 @@ func ResolveSingle(ctx context.Context, ds dag.DAGService, nd node.Node, names [
 // It uses the first path component as a hash (key) of the first node, then
 // resolves all other components walking the links, with ResolveLinks.
 func (s *Resolver) ResolvePathComponents(ctx context.Context, fpath Path) ([]node.Node, error) {
+	evt := log.EventBegin(ctx, "resolvePathComponents", logging.LoggableMap{"fpath": fpath})
+	defer evt.Done()
+
 	h, parts, err := SplitAbsPath(fpath)
 	if err != nil {
+		evt.Append(logging.LoggableMap{"error": err.Error()})
 		return nil, err
 	}
 
 	log.Debug("resolve dag get")
 	nd, err := s.DAG.Get(ctx, h)
 	if err != nil {
+		evt.Append(logging.LoggableMap{"error": err.Error()})
 		return nil, err
 	}
 
@@ -154,6 +159,8 @@ func (s *Resolver) ResolvePathComponents(ctx context.Context, fpath Path) ([]nod
 // would retrieve "baz" in ("bar" in ("foo" in nd.Links).Links).Links
 func (s *Resolver) ResolveLinks(ctx context.Context, ndd node.Node, names []string) ([]node.Node, error) {
 
+	evt := log.EventBegin(ctx, "resolveLinks", logging.LoggableMap{"names": names})
+	defer evt.Done()
 	result := make([]node.Node, 0, len(names)+1)
 	result = append(result, ndd)
 	nd := ndd // dup arg workaround
@@ -166,13 +173,16 @@ func (s *Resolver) ResolveLinks(ctx context.Context, ndd node.Node, names []stri
 
 		lnk, rest, err := s.ResolveOnce(ctx, s.DAG, nd, names)
 		if err == dag.ErrLinkNotFound {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return result, ErrNoLink{Name: names[0], Node: nd.Cid()}
 		} else if err != nil {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return result, err
 		}
 
 		nextnode, err := lnk.GetNode(ctx, s.DAG)
 		if err != nil {
+			evt.Append(logging.LoggableMap{"error": err.Error()})
 			return result, err
 		}