Skip to content

Commit b358a1a

Browse files
jimmygchenjimmygchen
committed
Instrument PendingComponents.
1 parent 61a772f commit b358a1a

File tree

2 files changed

+37
-11
lines changed

2 files changed

+37
-11
lines changed

‎beacon_node/beacon_chain/src/data_availability_checker/overflow_lru_cache.rs‎

Lines changed: 29 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@ use parking_lot::RwLock;
1414
use std::cmp::Ordering;
1515
use std::num::NonZeroUsize;
1616
use std::sync::Arc;
17-
use tracing::debug;
17+
use tracing::{debug, debug_span, Span};
1818
use types::blob_sidecar::BlobIdentifier;
1919
use types::{
2020
BlobSidecar, ChainSpec, ColumnIndex, DataColumnSidecar, DataColumnSidecarList, Epoch, EthSpec,
@@ -31,6 +31,7 @@ pub struct PendingComponents<E: EthSpec> {
3131
pub verified_data_columns: Vec<KzgVerifiedCustodyDataColumn<E>>,
3232
pub executed_block: Option<DietAvailabilityPendingExecutedBlock<E>>,
3333
pub reconstruction_started: bool,
34+
span: Span,
3435
}
3536

3637
impl<E: EthSpec> PendingComponents<E> {
@@ -87,14 +88,18 @@ impl<E: EthSpec> PendingComponents<E> {
8788

8889
/// Inserts a block into the cache.
8990
pub fn insert_block(&mut self, block: DietAvailabilityPendingExecutedBlock<E>) {
91+
let _guard = self.span.clone().entered();
92+
debug!("Block added to pending components");
9093
*self.get_cached_block_mut() = Some(block)
9194
}
9295

9396
/// Inserts a blob at a specific index in the cache.
9497
///
9598
/// Existing blob at the index will be replaced.
9699
pub fn insert_blob_at_index(&mut self, blob_index: usize, blob: KzgVerifiedBlob<E>) {
100+
let _guard = self.span.clone().entered();
97101
if let Some(b) = self.get_cached_blobs_mut().get_mut(blob_index) {
102+
debug!(blob_index, "Blob added to pending components");
98103
*b = Some(blob);
99104
}
100105
}
@@ -134,11 +139,17 @@ impl<E: EthSpec> PendingComponents<E> {
134139
&mut self,
135140
kzg_verified_data_columns: I,
136141
) -> Result<(), AvailabilityCheckError> {
142+
let _guard = self.span.clone().entered();
137143
for data_column in kzg_verified_data_columns {
138144
if self.get_cached_data_column(data_column.index()).is_none() {
145+
debug!(
146+
column_index = data_column.index(),
147+
"Data column added to pending components"
148+
);
139149
self.verified_data_columns.push(data_column);
140150
}
141151
}
152+
142153
Ok(())
143154
}
144155

@@ -165,6 +176,7 @@ impl<E: EthSpec> PendingComponents<E> {
165176
where
166177
R: FnOnce(
167178
DietAvailabilityPendingExecutedBlock<E>,
179+
&Span,
168180
) -> Result<AvailabilityPendingExecutedBlock<E>, AvailabilityCheckError>,
169181
{
170182
let Some(block) = &self.executed_block else {
@@ -255,7 +267,7 @@ impl<E: EthSpec> PendingComponents<E> {
255267
block,
256268
import_data,
257269
payload_verification_outcome,
258-
} = recover(block.clone())?;
270+
} = recover(block.clone(), &self.span)?;
259271

260272
let available_block = AvailableBlock {
261273
block_root: self.block_root,
@@ -264,6 +276,10 @@ impl<E: EthSpec> PendingComponents<E> {
264276
blobs_available_timestamp,
265277
spec: spec.clone(),
266278
};
279+
280+
self.span.in_scope(|| {
281+
debug!("Block and all data components are available");
282+
});
267283
Ok(Some(AvailableExecutedBlock::new(
268284
available_block,
269285
import_data,
@@ -273,12 +289,15 @@ impl<E: EthSpec> PendingComponents<E> {
273289

274290
/// Returns an empty `PendingComponents` object with the given block root.
275291
pub fn empty(block_root: Hash256, max_len: usize) -> Self {
292+
let span = debug_span!("pending_components", %block_root);
293+
let _guard = span.clone().entered();
276294
Self {
277295
block_root,
278296
verified_blobs: RuntimeFixedVector::new(vec![None; max_len]),
279297
verified_data_columns: vec![],
280298
executed_block: None,
281299
reconstruction_started: false,
300+
span,
282301
}
283302
}
284303

@@ -483,7 +502,7 @@ impl<T: BeaconChainTypes> DataAvailabilityCheckerInner<T> {
483502
&self.spec,
484503
self.custody_context
485504
.num_of_data_columns_to_sample(Some(epoch), &self.spec),
486-
|block| self.state_cache.recover_pending_executed_block(block),
505+
|block, span| self.state_cache.recover_pending_executed_block(block, span),
487506
)? {
488507
// We keep the pending components in the availability cache during block import (#5845).
489508
write_lock.put(block_root, pending_components);
@@ -538,8 +557,8 @@ impl<T: BeaconChainTypes> DataAvailabilityCheckerInner<T> {
538557
);
539558

540559
if let Some(available_block) =
541-
pending_components.make_available(&self.spec, num_expected_columns, |block| {
542-
self.state_cache.recover_pending_executed_block(block)
560+
pending_components.make_available(&self.spec, num_expected_columns, |block, span| {
561+
self.state_cache.recover_pending_executed_block(block, span)
543562
})?
544563
{
545564
// We keep the pending components in the availability cache during block import (#5845).
@@ -637,8 +656,8 @@ impl<T: BeaconChainTypes> DataAvailabilityCheckerInner<T> {
637656

638657
// Check if we have all components and entire set is consistent.
639658
if let Some(available_block) =
640-
pending_components.make_available(&self.spec, num_expected_columns, |block| {
641-
self.state_cache.recover_pending_executed_block(block)
659+
pending_components.make_available(&self.spec, num_expected_columns, |block, span| {
660+
self.state_cache.recover_pending_executed_block(block, span)
642661
})?
643662
{
644663
// We keep the pending components in the availability cache during block import (#5845).
@@ -712,7 +731,7 @@ mod test {
712731
use std::collections::VecDeque;
713732
use store::{database::interface::BeaconNodeBackend, HotColdDB, ItemStore, StoreConfig};
714733
use tempfile::{tempdir, TempDir};
715-
use tracing::info;
734+
use tracing::{debug_span, info};
716735
use types::non_zero_usize::new_non_zero_usize;
717736
use types::{ExecPayload, MinimalEthSpec};
718737

@@ -1107,7 +1126,7 @@ mod test {
11071126
// reconstruct the pending block by replaying the block on the parent state
11081127
let recovered_pending_block = cache
11091128
.state_lru_cache()
1110-
.recover_pending_executed_block(diet_block)
1129+
.recover_pending_executed_block(diet_block, &debug_span!("test"))
11111130
.expect("should reconstruct pending block");
11121131

11131132
// assert the recovered state is the same as the original
@@ -1133,7 +1152,7 @@ mod test {
11331152
// recover the pending block from the cache
11341153
let recovered_pending_block = cache
11351154
.state_lru_cache()
1136-
.recover_pending_executed_block(diet_block)
1155+
.recover_pending_executed_block(diet_block, &debug_span!("test"))
11371156
.expect("should reconstruct pending block");
11381157
// assert the recovered state is the same as the original
11391158
assert_eq!(

‎beacon_node/beacon_chain/src/data_availability_checker/state_lru_cache.rs‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ use parking_lot::RwLock;
99
use state_processing::BlockReplayer;
1010
use std::sync::Arc;
1111
use store::OnDiskConsensusContext;
12+
use tracing::{debug_span, instrument, Span};
1213
use types::beacon_block_body::KzgCommitments;
1314
use types::{BeaconState, BlindedPayload, ChainSpec, Epoch, EthSpec, Hash256, SignedBeaconBlock};
1415

@@ -106,9 +107,11 @@ impl<T: BeaconChainTypes> StateLRUCache<T> {
106107
/// This method will first check the cache and if the state is not found
107108
/// it will reconstruct the state by loading the parent state from disk and
108109
/// replaying the block.
110+
#[instrument(skip_all, parent = _span, level = "debug")]
109111
pub fn recover_pending_executed_block(
110112
&self,
111113
diet_executed_block: DietAvailabilityPendingExecutedBlock<T::EthSpec>,
114+
_span: &Span,
112115
) -> Result<AvailabilityPendingExecutedBlock<T::EthSpec>, AvailabilityCheckError> {
113116
let state = if let Some(state) = self.states.write().pop(&diet_executed_block.state_root) {
114117
state
@@ -132,6 +135,7 @@ impl<T: BeaconChainTypes> StateLRUCache<T> {
132135

133136
/// Reconstruct the state by loading the parent state from disk and replaying
134137
/// the block.
138+
#[instrument(skip_all, level = "debug")]
135139
fn reconstruct_state(
136140
&self,
137141
diet_executed_block: &DietAvailabilityPendingExecutedBlock<T::EthSpec>,
@@ -164,8 +168,11 @@ impl<T: BeaconChainTypes> StateLRUCache<T> {
164168
.state_root_iter(state_roots.into_iter())
165169
.minimal_block_root_verification();
166170

171+
let block_replayer = debug_span!("reconstruct_state_apply_blocks").in_scope(|| {
172+
block_replayer.apply_blocks(vec![diet_executed_block.block.clone_as_blinded()], None)
173+
});
174+
167175
block_replayer
168-
.apply_blocks(vec![diet_executed_block.block.clone_as_blinded()], None)
169176
.map(|block_replayer| block_replayer.into_state())
170177
.and_then(|mut state| {
171178
state

0 commit comments

Comments
 (0)