Sync active request byrange ids logs (#6914)

Squashed commit of the following: commit cbc378a Author: dapplion <[email protected]> Date: Wed Feb 5 12:55:13 2025 -0300 De-duplicate code commit 4583116 Author: dapplion <[email protected]> Date: Sun Jan 26 14:16:55 2025 +0400 Add log when sending batch to processor commit cacfa06 Author: dapplion <[email protected]> Date: Sun Jan 26 13:01:02 2025 +0400 Concise request Ids for sync commit 4627f38 Author: dapplion <[email protected]> Date: Sun Jan 26 12:00:03 2025 +0400 Consistent logging in sync rpc requests
sigp · Feb 10, 2025 · 2319796 · 2319796
1 parent e22ec94
commit 2319796
Show file tree

Hide file tree

Showing 2 changed files with 224 additions and 98 deletions.
diff --git a/beacon_node/lighthouse_network/src/service/api_types.rs b/beacon_node/lighthouse_network/src/service/api_types.rs
@@ -1,16 +1,15 @@
-use std::sync::Arc;
-
+use crate::rpc::{
+    methods::{ResponseTermination, RpcResponse, RpcSuccessResponse, StatusMessage},
+    SubstreamId,
+};
 use libp2p::swarm::ConnectionId;
+use std::fmt::{Display, Formatter};
+use std::sync::Arc;
 use types::{
     BlobSidecar, DataColumnSidecar, Epoch, EthSpec, Hash256, LightClientBootstrap,
     LightClientFinalityUpdate, LightClientOptimisticUpdate, LightClientUpdate, SignedBeaconBlock,
 };
 
-use crate::rpc::{
-    methods::{ResponseTermination, RpcResponse, RpcSuccessResponse, StatusMessage},
-    SubstreamId,
-};
-
 /// Identifier of requests sent by a peer.
 pub type PeerRequestId = (ConnectionId, SubstreamId);
 
@@ -235,9 +234,108 @@ impl slog::Value for RequestId {
     }
 }
 
-// This custom impl reduces log boilerplate not printing `DataColumnsByRootRequestId` on each id log
-impl std::fmt::Display for DataColumnsByRootRequestId {
-    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
-        write!(f, "{} {:?}", self.id, self.requester)
+macro_rules! impl_display {
+    ($structname: ty, $format: literal, $($field:ident),*) => {
+        impl Display for $structname {
+            fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+                write!(f, $format, $(self.$field,)*)
+            }
+        }
+    };
+}
+
+// Since each request Id is deeply nested with various types, if rendered with Debug on logs they
+// take too much visual space. This custom Display implementations make the overall Id short while
+// not losing information
+impl_display!(BlocksByRangeRequestId, "{}/{}", id, parent_request_id);
+impl_display!(BlobsByRangeRequestId, "{}/{}", id, parent_request_id);
+impl_display!(DataColumnsByRangeRequestId, "{}/{}", id, parent_request_id);
+impl_display!(ComponentsByRangeRequestId, "{}/{}", id, requester);
+impl_display!(DataColumnsByRootRequestId, "{}/{}", id, requester);
+impl_display!(SingleLookupReqId, "{}/Lookup/{}", req_id, lookup_id);
+impl_display!(CustodyId, "{}", requester);
+impl_display!(SamplingId, "{}/{}", sampling_request_id, id);
+
+impl Display for DataColumnsByRootRequester {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        match self {
+            Self::Custody(id) => write!(f, "Custody/{id}"),
+            Self::Sampling(id) => write!(f, "Sampling/{id}"),
+        }
+    }
+}
+
+impl Display for CustodyRequester {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        write!(f, "{}", self.0)
+    }
+}
+
+impl Display for RangeRequestId {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        match self {
+            Self::RangeSync { chain_id, batch_id } => write!(f, "RangeSync/{batch_id}/{chain_id}"),
+            Self::BackfillSync { batch_id } => write!(f, "BackfillSync/{batch_id}"),
+        }
+    }
+}
+
+impl Display for SamplingRequestId {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        write!(f, "{}", self.0)
+    }
+}
+
+impl Display for SamplingRequester {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        match self {
+            Self::ImportedBlock(block) => write!(f, "ImportedBlock/{block}"),
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn display_id_data_columns_by_root_custody() {
+        let id = DataColumnsByRootRequestId {
+            id: 123,
+            requester: DataColumnsByRootRequester::Custody(CustodyId {
+                requester: CustodyRequester(SingleLookupReqId {
+                    req_id: 121,
+                    lookup_id: 101,
+                }),
+            }),
+        };
+        assert_eq!(format!("{id}"), "123/Custody/121/Lookup/101");
+    }
+
+    #[test]
+    fn display_id_data_columns_by_root_sampling() {
+        let id = DataColumnsByRootRequestId {
+            id: 123,
+            requester: DataColumnsByRootRequester::Sampling(SamplingId {
+                id: SamplingRequester::ImportedBlock(Hash256::ZERO),
+                sampling_request_id: SamplingRequestId(101),
+            }),
+        };
+        assert_eq!(format!("{id}"), "123/Sampling/101/ImportedBlock/0x0000000000000000000000000000000000000000000000000000000000000000");
+    }
+
+    #[test]
+    fn display_id_data_columns_by_range() {
+        let id = DataColumnsByRangeRequestId {
+            id: 123,
+            parent_request_id: ComponentsByRangeRequestId {
+                id: 122,
+                requester: RangeRequestId::RangeSync {
+                    chain_id: 54,
+                    batch_id: Epoch::new(0),
+                },
+            },
+        };
+        assert_eq!(format!("{id}"), "123/122/RangeSync/0/54");
     }
 }