From fb77ce9e192e6e478e56ce5423ffe0b43b3c4519 Mon Sep 17 00:00:00 2001 From: Jimmy Chen Date: Fri, 12 Sep 2025 15:11:30 +1000 Subject: [PATCH] Add missing event in `PendingComponent` span and clean up sync logs (#8033) I was looking into some long `PendingComponents` span and noticed the block event wasn't added to the span, so it wasn't possible to see when the block was added from the trace view, this PR fixes this. image Additionally I've noticed a lot of noises and confusion in sync logs due to the initial`peer_id` being included as part of the syncing chain span, causing all logs under the span to have that `peer_id`, which may not be accurate for some sync logs, I've removed `peer_id` from the `SyncingChain` span, and also cleaned up a bunch of spans to use `%` (display) for slots and epochs to make logs easier to read. Co-Authored-By: Jimmy Chen --- beacon_node/beacon_chain/src/block_verification.rs | 2 +- .../data_availability_checker/overflow_lru_cache.rs | 12 +++++++----- .../src/network_beacon_processor/gossip_methods.rs | 2 +- beacon_node/network/src/sync/range_sync/batch.rs | 5 ++++- beacon_node/network/src/sync/range_sync/chain.rs | 10 ++++++++-- beacon_node/store/src/hot_cold_store.rs | 4 ++-- beacon_node/store/src/state_cache.rs | 2 +- 7 files changed, 24 insertions(+), 13 deletions(-) diff --git a/beacon_node/beacon_chain/src/block_verification.rs b/beacon_node/beacon_chain/src/block_verification.rs index 1d6e050f7e..1d10fae0a4 100644 --- a/beacon_node/beacon_chain/src/block_verification.rs +++ b/beacon_node/beacon_chain/src/block_verification.rs @@ -2061,7 +2061,7 @@ impl BlockBlobError for GossipDataColumnError { /// and `Cow::Borrowed(state)` will be returned. Otherwise, the state will be cloned, cheaply /// advanced and then returned as a `Cow::Owned`. The end result is that the given `state` is never /// mutated to be invalid (in fact, it is never changed beyond a simple committee cache build). -#[instrument(skip(state, spec), level = "debug")] +#[instrument(skip_all, fields(?state_root_opt, %block_slot), level = "debug")] pub fn cheap_state_advance_to_obtain_committees<'a, E: EthSpec, Err: BlockBlobError>( state: &'a mut BeaconState, state_root_opt: Option, diff --git a/beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs b/beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs index 7f083139ee..9de63f6126 100644 --- a/beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs +++ b/beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs @@ -666,11 +666,13 @@ impl DataAvailabilityCheckerInner { None }; - debug!( - component = "block", - status = pending_components.status_str(num_expected_columns_opt), - "Component added to data availability checker" - ); + pending_components.span.in_scope(|| { + debug!( + component = "block", + status = pending_components.status_str(num_expected_columns_opt), + "Component added to data availability checker" + ); + }); self.check_availability_and_cache_components( block_root, diff --git a/beacon_node/network/src/network_beacon_processor/gossip_methods.rs b/beacon_node/network/src/network_beacon_processor/gossip_methods.rs index cb6d63fe91..cbe441b419 100644 --- a/beacon_node/network/src/network_beacon_processor/gossip_methods.rs +++ b/beacon_node/network/src/network_beacon_processor/gossip_methods.rs @@ -610,7 +610,7 @@ impl NetworkBeaconProcessor { parent = None, level = "debug", skip_all, - fields(slot = ?column_sidecar.slot(), block_root = ?column_sidecar.block_root(), index = column_sidecar.index), + 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, diff --git a/beacon_node/network/src/sync/range_sync/batch.rs b/beacon_node/network/src/sync/range_sync/batch.rs index 1f51613996..31e6594139 100644 --- a/beacon_node/network/src/sync/range_sync/batch.rs +++ b/beacon_node/network/src/sync/range_sync/batch.rs @@ -1,4 +1,5 @@ use beacon_chain::block_verification_types::RpcBlock; +use derivative::Derivative; use lighthouse_network::PeerId; use lighthouse_network::rpc::methods::BlocksByRangeRequest; use lighthouse_network::service::api_types::Id; @@ -96,7 +97,8 @@ pub enum BatchProcessingResult { NonFaultyFailure, } -#[derive(Debug)] +#[derive(Derivative)] +#[derivative(Debug)] /// A segment of a chain. pub struct BatchInfo { /// Start slot of the batch. @@ -114,6 +116,7 @@ pub struct BatchInfo { /// Whether this batch contains all blocks or all blocks and blobs. batch_type: ByRangeRequestType, /// Pin the generic + #[derivative(Debug = "ignore")] marker: std::marker::PhantomData, } diff --git a/beacon_node/network/src/sync/range_sync/chain.rs b/beacon_node/network/src/sync/range_sync/chain.rs index a8c85e44d2..3b816c0922 100644 --- a/beacon_node/network/src/sync/range_sync/chain.rs +++ b/beacon_node/network/src/sync/range_sync/chain.rs @@ -131,8 +131,14 @@ impl SyncingChain { name = SPAN_SYNCING_CHAIN, parent = None, level="debug", - skip(id), - fields(chain_id = %id) + skip_all, + fields( + chain_id = %id, + start_epoch = %start_epoch, + target_head_slot = %target_head_slot, + target_head_root = %target_head_root, + chain_type = ?chain_type, + ) )] pub fn new( id: Id, diff --git a/beacon_node/store/src/hot_cold_store.rs b/beacon_node/store/src/hot_cold_store.rs index 7b390b39f3..7156c75f11 100644 --- a/beacon_node/store/src/hot_cold_store.rs +++ b/beacon_node/store/src/hot_cold_store.rs @@ -1040,7 +1040,7 @@ impl, Cold: ItemStore> HotColdDB /// - `result_state_root == state.canonical_root()` /// - `state.slot() <= max_slot` /// - `state.get_latest_block_root(result_state_root) == block_root` - #[instrument(skip(self, max_slot), level = "debug")] + #[instrument(skip_all, fields(?block_root, %max_slot, ?state_root), level = "debug")] pub fn get_advanced_hot_state( &self, block_root: Hash256, @@ -1112,7 +1112,7 @@ impl, Cold: ItemStore> HotColdDB /// If this function returns `Some(state)` then that `state` will always have /// `latest_block_header` matching `block_root` but may not be advanced all the way through to /// `max_slot`. - #[instrument(skip(self), level = "debug")] + #[instrument(skip_all, fields(?block_root, %max_slot), level = "debug")] pub fn get_advanced_hot_state_from_cache( &self, block_root: Hash256, diff --git a/beacon_node/store/src/state_cache.rs b/beacon_node/store/src/state_cache.rs index 05930c7b71..4b0d1ee016 100644 --- a/beacon_node/store/src/state_cache.rs +++ b/beacon_node/store/src/state_cache.rs @@ -299,7 +299,7 @@ impl StateCache { None } - #[instrument(skip(self), level = "debug")] + #[instrument(skip_all, fields(?block_root, %slot), level = "debug")] pub fn get_by_block_root( &mut self, block_root: Hash256,