Implement tracing spans for data columm RPC requests and responses (#7831)

#7830

Author: jimmygchen

CLAUDE.md

@@ -293,6 +293,7 @@ async fn process_block(&self, block: Block) -> Result<(), Error> {
 ## Build and Development Notes
 - Full builds and tests take 5+ minutes - use large timeouts (300s+) for any `cargo build`, `cargo test`, or `make` commands
 - Use `cargo check` for faster iteration during development and always run after code changes
+- Use `cargo fmt --all && make lint-fix` to format code and fix linting issues once a task is complete
 - Prefer targeted package tests (`cargo test -p <package>`) and individual tests over full test suite when debugging specific issues
 - Always understand the broader codebase patterns before making changes
 - Minimum Supported Rust Version (MSRV) is documented in `lighthouse/Cargo.toml` - ensure Rust version meets or exceeds this requirement

Cargo.lock

@@ -11,6 +11,7 @@ members = [
     "beacon_node/http_api",
     "beacon_node/http_metrics",
     "beacon_node/lighthouse_network",
+    "beacon_node/lighthouse_tracing",
     "beacon_node/network",
     "beacon_node/operation_pool",
     "beacon_node/store",
@@ -173,6 +174,7 @@ itertools = "0.10"
 kzg = { path = "crypto/kzg" }
 libsecp256k1 = "0.7"
 lighthouse_network = { path = "beacon_node/lighthouse_network" }
+lighthouse_tracing = { path = "beacon_node/lighthouse_tracing" }
 lighthouse_validator_store = { path = "validator_client/lighthouse_validator_store" }
 lighthouse_version = { path = "common/lighthouse_version" }
 lockfile = { path = "common/lockfile" }

Cargo.toml

@@ -33,6 +33,7 @@ hex = { workspace = true }
 int_to_bytes = { workspace = true }
 itertools = { workspace = true }
 kzg = { workspace = true }
+lighthouse_tracing = { workspace = true }
 lighthouse_version = { workspace = true }
 logging = { workspace = true }
 lru = { workspace = true }

beacon_node/beacon_chain/Cargo.toml

@@ -826,7 +826,7 @@ impl<T: BeaconChainTypes> GossipVerifiedBlock<T> {
     /// on the p2p network.
     ///
     /// Returns an error if the block is invalid, or if the block was unable to be verified.
-    #[instrument(name = "verify_gossip_block", skip_all)]
+    #[instrument(name = "verify_gossip_block", skip_all, fields(block_root = tracing::field::Empty))]
     pub fn new(
         block: Arc<SignedBeaconBlock<T::EthSpec>>,
         chain: &BeaconChain<T>,
@@ -1227,27 +1227,20 @@ impl<T: BeaconChainTypes> SignatureVerifiedBlock<T> {
         signature_verifier
             .include_all_signatures_except_proposal(block.as_ref(), &mut consensus_context)?;
 
-        let sig_verify_span = info_span!("signature_verify", result = "started").entered();
-        let result = signature_verifier.verify();
+        let result = info_span!("signature_verify").in_scope(|| signature_verifier.verify());
         match result {
-            Ok(_) => {
-                sig_verify_span.record("result", "ok");
-                Ok(Self {
-                    block: MaybeAvailableBlock::AvailabilityPending {
-                        block_root: from.block_root,
-                        block,
-                    },
+            Ok(_) => Ok(Self {
+                block: MaybeAvailableBlock::AvailabilityPending {
                     block_root: from.block_root,
-                    parent: Some(parent),
-                    consensus_context,
-                })
-            }
-            Err(_) => {
-                sig_verify_span.record("result", "fail");
-                Err(BlockError::InvalidSignature(
-                    InvalidSignature::BlockBodySignatures,
-                ))
-            }
+                    block,
+                },
+                block_root: from.block_root,
+                parent: Some(parent),
+                consensus_context,
+            }),
+            Err(_) => Err(BlockError::InvalidSignature(
+                InvalidSignature::BlockBodySignatures,
+            )),
         }
     }
 

beacon_node/beacon_chain/src/block_verification.rs

@@ -9,6 +9,7 @@ use crate::block_verification_types::{
 };
 use crate::data_availability_checker::{Availability, AvailabilityCheckError};
 use crate::data_column_verification::KzgVerifiedCustodyDataColumn;
+use lighthouse_tracing::SPAN_PENDING_COMPONENTS;
 use lru::LruCache;
 use parking_lot::RwLock;
 use std::cmp::Ordering;
@@ -288,7 +289,7 @@ impl<E: EthSpec> PendingComponents<E> {
 
     /// Returns an empty `PendingComponents` object with the given block root.
     pub fn empty(block_root: Hash256, max_len: usize) -> Self {
-        let span = debug_span!(parent: None, "pending_components", %block_root);
+        let span = debug_span!(parent: None, SPAN_PENDING_COMPONENTS, %block_root);
         let _guard = span.clone().entered();
         Self {
             block_root,

beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs

@@ -0,0 +1,4 @@
+[package]
+name = "lighthouse_tracing"
+version = "0.1.0"
+edition = { workspace = true }

beacon_node/lighthouse_tracing/Cargo.toml

@@ -0,0 +1,61 @@
+//! This module contains root span identifiers for key code paths in the beacon node.
+//!
+//! TODO: These span identifiers will be used to implement selective tracing export (to be implemented),
+//! where only the listed root spans and their descendants will be exported to the tracing backend.
+
+/// Data Availability checker span identifiers
+pub const SPAN_PENDING_COMPONENTS: &str = "pending_components";
+
+/// Gossip methods root spans
+pub const SPAN_PROCESS_GOSSIP_DATA_COLUMN: &str = "process_gossip_data_column";
+pub const SPAN_PROCESS_GOSSIP_BLOB: &str = "process_gossip_blob";
+pub const SPAN_PROCESS_GOSSIP_BLOCK: &str = "process_gossip_block";
+
+/// Sync methods root spans
+pub const SPAN_SYNCING_CHAIN: &str = "syncing_chain";
+pub const SPAN_OUTGOING_RANGE_REQUEST: &str = "outgoing_range_request";
+pub const SPAN_OUTGOING_CUSTODY_REQUEST: &str = "outgoing_custody_request";
+pub const SPAN_PROCESS_RPC_BLOCK: &str = "process_rpc_block";
+pub const SPAN_PROCESS_RPC_BLOBS: &str = "process_rpc_blobs";
+pub const SPAN_PROCESS_RPC_CUSTODY_COLUMNS: &str = "process_rpc_custody_columns";
+pub const SPAN_PROCESS_CHAIN_SEGMENT: &str = "process_chain_segment";
+
+/// RPC methods root spans
+pub const SPAN_HANDLE_BLOCKS_BY_RANGE_REQUEST: &str = "handle_blocks_by_range_request";
+pub const SPAN_HANDLE_BLOBS_BY_RANGE_REQUEST: &str = "handle_blobs_by_range_request";
+pub const SPAN_HANDLE_DATA_COLUMNS_BY_RANGE_REQUEST: &str = "handle_data_columns_by_range_request";
+pub const SPAN_HANDLE_BLOCKS_BY_ROOT_REQUEST: &str = "handle_blocks_by_root_request";
+pub const SPAN_HANDLE_BLOBS_BY_ROOT_REQUEST: &str = "handle_blobs_by_root_request";
+pub const SPAN_HANDLE_DATA_COLUMNS_BY_ROOT_REQUEST: &str = "handle_data_columns_by_root_request";
+pub const SPAN_HANDLE_LIGHT_CLIENT_UPDATES_BY_RANGE: &str = "handle_light_client_updates_by_range";
+pub const SPAN_HANDLE_LIGHT_CLIENT_BOOTSTRAP: &str = "handle_light_client_bootstrap";
+pub const SPAN_HANDLE_LIGHT_CLIENT_OPTIMISTIC_UPDATE: &str =
+    "handle_light_client_optimistic_update";
+pub const SPAN_HANDLE_LIGHT_CLIENT_FINALITY_UPDATE: &str = "handle_light_client_finality_update";
+
+/// List of all root span names that are allowed to be exported to the tracing backend.
+/// Only these spans and their descendants will be processed to reduce noise from
+/// uninstrumented code paths. New root spans must be added to this list to be traced.
+pub const LH_BN_ROOT_SPAN_NAMES: &[&str] = &[
+    SPAN_SYNCING_CHAIN,
+    SPAN_PENDING_COMPONENTS,
+    SPAN_PROCESS_GOSSIP_DATA_COLUMN,
+    SPAN_PROCESS_GOSSIP_BLOB,
+    SPAN_PROCESS_GOSSIP_BLOCK,
+    SPAN_OUTGOING_RANGE_REQUEST,
+    SPAN_OUTGOING_CUSTODY_REQUEST,
+    SPAN_PROCESS_RPC_BLOCK,
+    SPAN_PROCESS_RPC_BLOBS,
+    SPAN_PROCESS_RPC_CUSTODY_COLUMNS,
+    SPAN_PROCESS_CHAIN_SEGMENT,
+    SPAN_HANDLE_BLOCKS_BY_RANGE_REQUEST,
+    SPAN_HANDLE_BLOBS_BY_RANGE_REQUEST,
+    SPAN_HANDLE_DATA_COLUMNS_BY_RANGE_REQUEST,
+    SPAN_HANDLE_BLOCKS_BY_ROOT_REQUEST,
+    SPAN_HANDLE_BLOBS_BY_ROOT_REQUEST,
+    SPAN_HANDLE_DATA_COLUMNS_BY_ROOT_REQUEST,
+    SPAN_HANDLE_LIGHT_CLIENT_UPDATES_BY_RANGE,
+    SPAN_HANDLE_LIGHT_CLIENT_BOOTSTRAP,
+    SPAN_HANDLE_LIGHT_CLIENT_OPTIMISTIC_UPDATE,
+    SPAN_HANDLE_LIGHT_CLIENT_FINALITY_UPDATE,
+];

beacon_node/lighthouse_tracing/src/lib.rs

@@ -28,6 +28,7 @@ hex = { workspace = true }
 igd-next = { version = "0.16", features = ["aio_tokio"] }
 itertools = { workspace = true }
 lighthouse_network = { workspace = true }
+lighthouse_tracing = { workspace = true }
 logging = { workspace = true }
 lru_cache = { workspace = true }
 metrics = { workspace = true }

beacon_node/network/Cargo.toml

@@ -21,6 +21,9 @@ use beacon_chain::{
 };
 use beacon_processor::{Work, WorkEvent};
 use lighthouse_network::{Client, MessageAcceptance, MessageId, PeerAction, PeerId, ReportSource};
+use lighthouse_tracing::{
+    SPAN_PROCESS_GOSSIP_BLOB, SPAN_PROCESS_GOSSIP_BLOCK, SPAN_PROCESS_GOSSIP_DATA_COLUMN,
+};
 use logging::crit;
 use operation_pool::ReceivedPreCapella;
 use slot_clock::SlotClock;
@@ -602,7 +605,13 @@ impl<T: BeaconChainTypes> NetworkBeaconProcessor<T> {
         }
     }
 
-    #[instrument(skip_all, level = "trace", fields(slot = ?column_sidecar.slot(), block_root = ?column_sidecar.block_root(), index = column_sidecar.index), parent = None)]
+    #[instrument(
+        name = SPAN_PROCESS_GOSSIP_DATA_COLUMN,
+        parent = None,
+        level = "debug",
+        skip_all,
+        fields(slot = ?column_sidecar.slot(), block_root = ?column_sidecar.block_root(), index = column_sidecar.index),
+    )]
     pub async fn process_gossip_data_column_sidecar(
         self: &Arc<Self>,
         message_id: MessageId,
@@ -760,7 +769,16 @@ impl<T: BeaconChainTypes> NetworkBeaconProcessor<T> {
     }
 
     #[allow(clippy::too_many_arguments)]
-    #[instrument(skip_all, level = "trace", fields(slot = ?blob_sidecar.slot(), block_root = ?blob_sidecar.block_root(), index = blob_sidecar.index), parent = None)]
+    #[instrument(
+        name = SPAN_PROCESS_GOSSIP_BLOB,
+        parent = None,
+        level = "debug",
+        skip_all,
+        fields(
+            slot = ?blob_sidecar.slot(),
+            block_root = ?blob_sidecar.block_root(),
+            index = blob_sidecar.index),
+    )]
     pub async fn process_gossip_blob(
         self: &Arc<Self>,
         message_id: MessageId,
@@ -1098,7 +1116,13 @@ impl<T: BeaconChainTypes> NetworkBeaconProcessor<T> {
     ///
     /// Raises a log if there are errors.
     #[allow(clippy::too_many_arguments)]
-    #[instrument(skip_all, fields(block_root = tracing::field::Empty), parent = None)]
+    #[instrument(
+        name = SPAN_PROCESS_GOSSIP_BLOCK,
+        parent = None,
+        level = "debug",
+        skip_all,
+        fields(block_root = tracing::field::Empty),
+    )]
     pub async fn process_gossip_block(
         self: Arc<Self>,
         message_id: MessageId,