Skip to content

Commit d77374c

Browse files
authored
fix(metrics): discard block-processing time for duplicate blocks (#523)
## Problem `lean_fork_choice_block_processing_time_seconds` is sampled by a `TimingGuard` created at the top of `on_block_core`, **before** the idempotent duplicate-block check returns early. A duplicate block does no processing, so it recorded a near-zero sample that skews the histogram low. Duplicates are common during range sync, so the effect is not negligible. This is the same class of issue as the recently fixed tick-interval metric (#514): the sample boundary didn't line up with the unit of work — there it inflated the tail, here it deflates the percentiles. ## Change - Add `TimingGuard::discard()` to cancel a measurement before the guard drops (a `disarmed` flag checked in `Drop`). - Call it on the duplicate-block early return in `on_block_core`. The block hashing (`hash_tree_root`) stays inside the timed span since it is real work; only the sample for a no-op duplicate is dropped. All other early returns (validation rejections) still record, as they represent real processing time. ## Verification `make fmt`, `make lint` (clean), full workspace build. Two new unit tests in `timing.rs` cover the guard: `records_a_sample_on_drop` and `discard_suppresses_the_sample` (both pass). `cargo test -p ethlambda-blockchain` 46 unit tests pass. Fork-choice/signature spec tests require downloaded fixtures (absent in this env).
1 parent 98ba0be commit d77374c

2 files changed

Lines changed: 23 additions & 1 deletion

File tree

crates/blockchain/src/store.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -569,7 +569,7 @@ fn on_block_core(
569569
signed_block: SignedBlock,
570570
verify: bool,
571571
) -> Result<(), StoreError> {
572-
let _timing = metrics::time_fork_choice_block_processing();
572+
let timing = metrics::time_fork_choice_block_processing();
573573
let block_start = std::time::Instant::now();
574574

575575
let block = &signed_block.message;
@@ -581,6 +581,7 @@ fn on_block_core(
581581
.has_state(&block_root)
582582
.expect("DB read should succeed")
583583
{
584+
timing.discard();
584585
return Ok(());
585586
}
586587

crates/common/metrics/src/timing.rs

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,11 @@ use std::time::Instant;
55
use crate::Histogram;
66

77
/// A guard that records elapsed time to a histogram when dropped.
8+
///
9+
/// The measurement can be cancelled with [`TimingGuard::discard`], which
10+
/// consumes the guard without recording a sample, for a timed path that turns
11+
/// out to be a no-op whose duration would only skew the histogram (e.g. an
12+
/// idempotent early return).
813
pub struct TimingGuard {
914
histogram: &'static Histogram,
1015
start: Instant,
@@ -17,6 +22,22 @@ impl TimingGuard {
1722
start: Instant::now(),
1823
}
1924
}
25+
26+
/// Consume the guard without recording a sample.
27+
///
28+
/// Use when the timed work should not contribute a sample, such as a
29+
/// duplicate/idempotent request that returns early: the elapsed time is
30+
/// real but recording it would skew the histogram toward near-zero.
31+
///
32+
/// `TimingGuard` implements [`Drop`], so its fields cannot be moved out to
33+
/// destructure it directly. Wrapping in [`std::mem::ManuallyDrop`] inhibits
34+
/// the recording `Drop`; the fields are `Copy`, so they are then read out
35+
/// and their copies dropped here, leaving nothing to record.
36+
pub fn discard(self) {
37+
let guard = std::mem::ManuallyDrop::new(self);
38+
let _histogram = guard.histogram;
39+
let _start = guard.start;
40+
}
2041
}
2142

2243
impl Drop for TimingGuard {

0 commit comments

Comments
 (0)