debug: engine-sync debug

krish-nr · Jan 2, 2024 · 60963cc · 60963cc
1 parent 90120a8
commit 60963cc
Show file tree

Hide file tree

Showing 5 changed files with 17 additions and 5 deletions.
diff --git a/eth/downloader/fetchers_concurrent.go b/eth/downloader/fetchers_concurrent.go
@@ -112,6 +112,7 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 		// be fulfilled by the remote side, but the dispatcher will not wait to
 		// deliver them since nobody's going to be listening.
 		for _, req := range stales {
+			log.Info("stales request: time sent", "sent time", req.Sent.String(), "sent peer", req.Peer)
 			req.Close()
 		}
 	}()
@@ -135,6 +136,8 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 			if len(pending) == 0 && finished {
 				return nil
 			}
+			log.Error("Krish Debug: no tasks but not finished")
+			time.Sleep(1000 * time.Millisecond)
 		} else {
 			// Send a download request to all idle peers, until throttled
 			var (
@@ -154,6 +157,7 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 						peer.log.Warn("Peer stalling, dropping", "waited", common.PrettyDuration(waited))
 						d.dropPeer(peer.id)
 					}
+					log.Error("Peer stale", "time duration ", time.Since(stale.Sent).String())
 				}
 			}
 			sort.Sort(&peerCapacitySort{idles, caps})
@@ -164,6 +168,7 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 				queued     = queue.pending()
 			)
 			for _, peer := range idles {
+				log.Info("Step into idles loop", "count", len(idles))
 				// Short circuit if throttling activated or there are no more
 				// queued tasks to be retrieved
 				if throttled {
@@ -189,14 +194,18 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 				// Fetch the chunk and make sure any errors return the hashes to the queue
 				req, err := queue.request(peer, request, responses)
 				if err != nil {
+					log.Error("fetch request error", "peer", peer.id, "err", err)
 					// Sending the request failed, which generally means the peer
 					// was disconnected in between assignment and network send.
 					// Although all peer removal operations return allocated tasks
 					// to the queue, that is async, and we can do better here by
 					// immediately pushing the unfulfilled requests.
-					queue.unreserve(peer.id) // TODO(karalabe): This needs a non-expiration method
+					fails := queue.unreserve(peer.id) // TODO(karalabe): This needs a non-expiration method
+					log.Error("fetch request error", "fails num", fails, "current idles", len(idles))
+
 					continue
 				}
+				log.Info("successfully assign task")
 				pending[peer.id] = req
 
 				ttl := d.peers.rates.TargetTimeout()
@@ -219,6 +228,7 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 			// If sync was cancelled, tear down the parallel retriever. Pending
 			// requests will be cancelled locally, and the remote responses will
 			// be dropped when they arrive
+			log.Info("receive cancel")
 			return errCanceled
 
 		case event := <-peering:
@@ -268,6 +278,7 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 			// below is purely for to catch programming errors, given the correct
 			// code, there's no possible order of events that should result in a
 			// timeout firing for a non-existent event.
+			log.Info("Timeout triggered")
 			req, exp := timeouts.Peek()
 			if now, at := time.Now(), time.Unix(0, -exp); now.Before(at) {
 				log.Error("Timeout triggered but not reached", "left", at.Sub(now))
@@ -328,6 +339,8 @@ func (d *Downloader) concurrentFetch(queue typedQueue, beaconMode bool) error {
 			}
 
 		case res := <-responses:
+			log.Info("receive responses")
+
 			// Response arrived, it may be for an existing or an already timed
 			// out request. If the former, update the timeout heap and perhaps
 			// reschedule the timeout timer.

diff --git a/eth/downloader/fetchers_concurrent_bodies.go b/eth/downloader/fetchers_concurrent_bodies.go
@@ -64,7 +64,7 @@ func (q *bodyQueue) reserve(peer *peerConnection, items int) (*fetchRequest, boo
 func (q *bodyQueue) unreserve(peer string) int {
 	fails := q.queue.ExpireBodies(peer)
 	if fails > 2 {
-		log.Trace("Body delivery timed out", "peer", peer)
+		log.Debug("Body delivery timed out", "peer", peer)
 	} else {
 		log.Debug("Body delivery stalling", "peer", peer)
 	}
@@ -74,7 +74,7 @@ func (q *bodyQueue) unreserve(peer string) int {
 // request is responsible for converting a generic fetch request into a body
 // one and sending it to the remote peer for fulfillment.
 func (q *bodyQueue) request(peer *peerConnection, req *fetchRequest, resCh chan *eth.Response) (*eth.Request, error) {
-	peer.log.Trace("Requesting new batch of bodies", "count", len(req.Headers), "from", req.Headers[0].Number)
+	peer.log.Debug("Requesting new batch of bodies", "count", len(req.Headers), "from", req.Headers[0].Number)
 	if q.bodyFetchHook != nil {
 		q.bodyFetchHook(req.Headers)
 	}

diff --git a/eth/downloader/queue.go b/eth/downloader/queue.go
@@ -646,6 +646,7 @@ func (q *queue) expire(peer string, pendPool map[string]*fetchRequest, taskQueue
 		return 0
 	}
 	delete(pendPool, peer)
+	log.Debug("delete pendPool", "peer", peer, "From", req.From)
 
 	// Return any non-satisfied requests to the pool
 	if req.From > 0 {

diff --git a/go.mod b/go.mod
@@ -82,7 +82,6 @@ require (
 	github.com/aws/aws-sdk-go-v2/service/sts v1.1.1 // indirect
 	github.com/aws/smithy-go v1.14.2 // indirect
 	github.com/beorn7/perks v1.0.1 // indirect
-	github.com/btcsuite/btcd/chaincfg/chainhash v1.0.1 // indirect
 	github.com/cespare/xxhash v1.1.0 // indirect
 	github.com/cespare/xxhash/v2 v2.2.0 // indirect
 	github.com/cockroachdb/errors v1.9.1 // indirect

diff --git a/go.sum b/go.sum
@@ -170,7 +170,6 @@ github.com/btcsuite/btcd/btcec/v2 v2.3.2 h1:5n0X6hX0Zk+6omWcihdYvdAlGf2DfasC0GMf
 github.com/btcsuite/btcd/btcec/v2 v2.3.2/go.mod h1:zYzJ8etWJQIv1Ogk7OzpWjowwOdXY1W/17j2MW85J04=
 github.com/btcsuite/btcd/btcutil v1.1.2 h1:XLMbX8JQEiwMcYft2EGi8zPUkoa0abKIU6/BJSRsjzQ=
 github.com/btcsuite/btcd/chaincfg/chainhash v1.0.1 h1:q0rUy8C/TYNBQS1+CGKw68tLOFYSNEs0TFnxxnS9+4U=
-github.com/btcsuite/btcd/chaincfg/chainhash v1.0.1/go.mod h1:7SFka0XMvUgj3hfZtydOrQY2mwhPclbT2snogU7SQQc=
 github.com/btcsuite/btclog v0.0.0-20170628155309-84c8d2346e9f/go.mod h1:TdznJufoqS23FtqVCzL0ZqgP5MqXbb4fg/WgDys70nA=
 github.com/btcsuite/btcutil v0.0.0-20190207003914-4c204d697803/go.mod h1:+5NJ2+qvTyV9exUAL/rxXi3DcLg2Ts+ymUAY5y4NvMg=
 github.com/btcsuite/btcutil v0.0.0-20190425235716-9e5f4b9a998d/go.mod h1:+5NJ2+qvTyV9exUAL/rxXi3DcLg2Ts+ymUAY5y4NvMg=