From 9d24844f500ba550b1bb9bdf1cd5fc84ded80d3f Mon Sep 17 00:00:00 2001
From: realbigsean <sean@sigmaprime.io>
Date: Wed, 27 Mar 2024 09:24:04 -0400
Subject: [PATCH] Lookup log improvements (#5491)

* log improvements
---
 .../network/src/sync/block_lookups/mod.rs     | 35 +++++++------
 beacon_node/network/src/sync/manager.rs       | 52 +++++++------------
 2 files changed, 38 insertions(+), 49 deletions(-)

diff --git a/beacon_node/network/src/sync/block_lookups/mod.rs b/beacon_node/network/src/sync/block_lookups/mod.rs
index 8d869243c..13246dc0b 100644
--- a/beacon_node/network/src/sync/block_lookups/mod.rs
+++ b/beacon_node/network/src/sync/block_lookups/mod.rs
@@ -152,7 +152,6 @@ impl<T: BeaconChainTypes> BlockLookups<T> {
             if let Some(components) = child_components {
                 lookup.add_child_components(components);
             }
-            debug!(self.log, "Already searching for block"; "block_root" => ?block_root);
             return;
         }
 
@@ -163,7 +162,7 @@ impl<T: BeaconChainTypes> BlockLookups<T> {
 
             // If the block was already downloaded, or is being downloaded in this moment, do not
             // request it.
-            debug!(self.log, "Already searching for block in a parent lookup request"; "block_root" => ?block_root);
+            trace!(self.log, "Already searching for block in a parent lookup request"; "block_root" => ?block_root);
             return;
         }
 
@@ -173,7 +172,7 @@ impl<T: BeaconChainTypes> BlockLookups<T> {
             .any(|(hashes, _last_parent_request)| hashes.contains(&block_root))
         {
             // we are already processing this block, ignore it.
-            debug!(self.log, "Already processing block in a parent request"; "block_root" => ?block_root);
+            trace!(self.log, "Already processing block in a parent request"; "block_root" => ?block_root);
             return;
         }
 
@@ -309,12 +308,15 @@ impl<T: BeaconChainTypes> BlockLookups<T> {
         };
 
         let expected_block_root = lookup.block_root();
-        debug!(self.log,
-            "Peer returned block for single lookup";
-            "peer_id" => %peer_id ,
-            "id" => ?id,
-            "block_root" => ?expected_block_root,
-        );
+        if response.is_some() {
+            debug!(self.log,
+                "Peer returned response for single lookup";
+                "peer_id" => %peer_id ,
+                "id" => ?id,
+                "block_root" => ?expected_block_root,
+                "response_type" => ?response_type,
+            );
+        }
 
         match self.single_lookup_response_inner::<R>(peer_id, response, seen_timestamp, cx, lookup)
         {
@@ -495,12 +497,15 @@ impl<T: BeaconChainTypes> BlockLookups<T> {
             return;
         };
 
-        debug!(self.log,
-            "Peer returned block for parent lookup";
-            "peer_id" => %peer_id ,
-            "id" => ?id,
-            "block_root" => ?parent_lookup.current_parent_request.block_request_state.requested_block_root,
-        );
+        if response.is_some() {
+            debug!(self.log,
+                "Peer returned response for parent lookup";
+                "peer_id" => %peer_id ,
+                "id" => ?id,
+                "block_root" => ?parent_lookup.current_parent_request.block_request_state.requested_block_root,
+                "response_type" => ?R::response_type(),
+            );
+        }
 
         match self.parent_lookup_response_inner::<R>(
             peer_id,
diff --git a/beacon_node/network/src/sync/manager.rs b/beacon_node/network/src/sync/manager.rs
index 0e965457e..61a25789a 100644
--- a/beacon_node/network/src/sync/manager.rs
+++ b/beacon_node/network/src/sync/manager.rs
@@ -915,44 +915,28 @@ impl<T: BeaconChainTypes> SyncManager<T> {
             RequestId::SingleBlock { .. } => {
                 crit!(self.log, "Single blob received during block request"; "peer_id" => %peer_id  );
             }
-            RequestId::SingleBlob { id } => {
-                if let Some(blob) = blob.as_ref() {
-                    debug!(self.log,
-                        "Peer returned blob for single lookup";
-                        "peer_id" => %peer_id ,
-                        "blob_id" =>?blob.id()
-                    );
-                }
-                self.block_lookups
-                    .single_lookup_response::<BlobRequestState<Current, T::EthSpec>>(
-                        id,
-                        peer_id,
-                        blob,
-                        seen_timestamp,
-                        &self.network,
-                    )
-            }
+            RequestId::SingleBlob { id } => self
+                .block_lookups
+                .single_lookup_response::<BlobRequestState<Current, T::EthSpec>>(
+                    id,
+                    peer_id,
+                    blob,
+                    seen_timestamp,
+                    &self.network,
+                ),
 
             RequestId::ParentLookup { id: _ } => {
                 crit!(self.log, "Single blob received during parent block request"; "peer_id" => %peer_id  );
             }
-            RequestId::ParentLookupBlob { id } => {
-                if let Some(blob) = blob.as_ref() {
-                    debug!(self.log,
-                        "Peer returned blob for parent lookup";
-                        "peer_id" => %peer_id ,
-                        "blob_id" =>?blob.id()
-                    );
-                }
-                self.block_lookups
-                    .parent_lookup_response::<BlobRequestState<Parent, T::EthSpec>>(
-                        id,
-                        peer_id,
-                        blob,
-                        seen_timestamp,
-                        &self.network,
-                    )
-            }
+            RequestId::ParentLookupBlob { id } => self
+                .block_lookups
+                .parent_lookup_response::<BlobRequestState<Parent, T::EthSpec>>(
+                    id,
+                    peer_id,
+                    blob,
+                    seen_timestamp,
+                    &self.network,
+                ),
             RequestId::BackFillBlocks { id: _ } => {
                 crit!(self.log, "Blob received during backfill block request"; "peer_id" => %peer_id  );
             }