Better logging for Graphsync traversal (#167)

* log gs traversal * Apply suggestions from code review Co-authored-by: dirkmc <dirkmdev@gmail.com> * add debug logs * add debug logs Co-authored-by: dirkmc <dirkmdev@gmail.com>
ipfs · Apr 26, 2021 · fee8141 · fee8141
1 parent 9e42f21
commit fee8141
Show file tree

Hide file tree

Showing 2 changed files with 18 additions and 2 deletions.
diff --git a/go.mod b/go.mod
@@ -24,6 +24,7 @@ require (
 	github.com/ipfs/go-ipld-cbor v0.0.4 // indirect
 	github.com/ipfs/go-ipld-format v0.2.0
 	github.com/ipfs/go-log v1.0.4
+	github.com/ipfs/go-log/v2 v2.1.1
 	github.com/ipfs/go-merkledag v0.3.1
 	github.com/ipfs/go-peertaskqueue v0.2.0
 	github.com/ipfs/go-unixfs v0.2.4

diff --git a/responsemanager/runtraversal/runtraversal.go b/responsemanager/runtraversal/runtraversal.go
@@ -4,12 +4,14 @@ import (
 	"bytes"
 	"io"
 
+	"github.com/ipfs/go-graphsync/ipldutil"
+	logging "github.com/ipfs/go-log/v2"
 	ipld "github.com/ipld/go-ipld-prime"
 	"github.com/ipld/go-ipld-prime/traversal"
-
-	"github.com/ipfs/go-graphsync/ipldutil"
 )
 
+var logger = logging.Logger("gs-traversal")
+
 // ResponseSender sends responses over the network
 type ResponseSender func(
 	link ipld.Link,
@@ -22,15 +24,24 @@ func RunTraversal(
 	loader ipld.Loader,
 	traverser ipldutil.Traverser,
 	sendResponse ResponseSender) error {
+	nBlocksRead := 0
+
 	for {
 		isComplete, err := traverser.IsComplete()
 		if isComplete {
+			if err != nil {
+				logger.Infof("traversal completion check failed, nBlocksRead=%d, err=%s", nBlocksRead, err)
+			} else {
+				logger.Infof("traversal completed successfully, nBlocksRead=%d", nBlocksRead)
+			}
 			return err
 		}
 		lnk, lnkCtx := traverser.CurrentRequest()
+		logger.Debugf("will load link=%s", lnk)
 		result, err := loader(lnk, lnkCtx)
 		var data []byte
 		if err != nil {
+			logger.Errorf("failed to load link=%s, nBlocksRead=%d, err=%s", lnk, nBlocksRead, err)
 			traverser.Error(traversal.SkipMe{})
 		} else {
 			blockBuffer, ok := result.(*bytes.Buffer)
@@ -39,14 +50,18 @@ func RunTraversal(
 				_, err = io.Copy(blockBuffer, result)
 			}
 			if err != nil {
+				logger.Errorf("failed to write to buffer, link=%s, nBlocksRead=%d, err=%s", lnk, nBlocksRead, err)
 				traverser.Error(err)
 			} else {
 				data = blockBuffer.Bytes()
 				err = traverser.Advance(blockBuffer)
 				if err != nil {
+					logger.Errorf("failed to advance traversal, link=%s, nBlocksRead=%d, err=%s", lnk, nBlocksRead, err)
 					return err
 				}
 			}
+			nBlocksRead++
+			logger.Debugf("successfully loaded link=%s, nBlocksRead=%d", lnk, nBlocksRead)
 		}
 		err = sendResponse(lnk, data)
 		if err != nil {