diff --git a/crates/blockchain/state_transition/src/lib.rs b/crates/blockchain/state_transition/src/lib.rs index 742ff67d..2c9b4f2d 100644 --- a/crates/blockchain/state_transition/src/lib.rs +++ b/crates/blockchain/state_transition/src/lib.rs @@ -29,6 +29,8 @@ pub enum Error { /// /// Similar to the spec's `State.state_transition`: https://github.com/leanEthereum/leanSpec/blob/bf0f606a75095cf1853529bc770516b1464d9716/src/lean_spec/subspecs/containers/state/state.py#L569 pub fn state_transition(state: &mut State, block: &Block) -> Result<(), Error> { + let _timing = metrics::time_state_transition(); + process_slots(state, block.slot)?; process_block(state, block)?; @@ -56,6 +58,8 @@ pub fn state_transition(state: &mut State, block: &Block) -> Result<(), Error> { /// Advance the state through empty slots up to, but not including, target_slot. pub fn process_slots(state: &mut State, target_slot: u64) -> Result<(), Error> { + let _timing = metrics::time_slots_processing(); + if state.slot >= target_slot { return Err(Error::StateSlotIsNewer { target_slot, @@ -74,8 +78,11 @@ pub fn process_slots(state: &mut State, target_slot: u64) -> Result<(), Error> { /// Apply full block processing including header and body. pub fn process_block(state: &mut State, block: &Block) -> Result<(), Error> { + let _timing = metrics::time_block_processing(); + process_block_header(state, block)?; process_attestations(state, &block.body.attestations)?; + Ok(()) } @@ -184,6 +191,7 @@ fn process_attestations( state: &mut State, attestations: &AggregatedAttestations, ) -> Result<(), Error> { + let _timing = metrics::time_attestations_processing(); let validator_count = state.validators.len(); let mut attestations_processed: u64 = 0; let mut justifications: HashMap> = state @@ -308,6 +316,8 @@ fn process_attestations( let slot = root_to_slot[root]; slot > state.latest_finalized.slot }); + } else { + metrics::inc_finalizations("error"); } } } diff --git a/crates/blockchain/state_transition/src/metrics.rs b/crates/blockchain/state_transition/src/metrics.rs index 59785f5c..3e3c8fb0 100644 --- a/crates/blockchain/state_transition/src/metrics.rs +++ b/crates/blockchain/state_transition/src/metrics.rs @@ -1,8 +1,11 @@ //! Prometheus metrics for state transition. use std::sync::LazyLock; +use std::time::Instant; -use prometheus::{IntCounter, IntCounterVec, register_int_counter, register_int_counter_vec}; +use prometheus::{ + Histogram, IntCounter, IntCounterVec, register_int_counter, register_int_counter_vec, +}; static LEAN_STATE_TRANSITION_SLOTS_PROCESSED_TOTAL: LazyLock = LazyLock::new(|| { register_int_counter!( @@ -44,3 +47,83 @@ pub fn inc_attestations_processed(count: u64) { pub fn inc_finalizations(result: &str) { LEAN_FINALIZATIONS_TOTAL.with_label_values(&[result]).inc(); } + +static LEAN_STATE_TRANSITION_TIME_SECONDS: LazyLock = LazyLock::new(|| { + prometheus::register_histogram!( + "lean_state_transition_time_seconds", + "Duration of the entire state transition", + vec![0.25, 0.5, 0.75, 1.0, 1.25, 1.5, 2.0, 2.5, 3.0, 4.0] + ) + .unwrap() +}); + +static LEAN_STATE_TRANSITION_SLOTS_PROCESSING_TIME_SECONDS: LazyLock = + LazyLock::new(|| { + prometheus::register_histogram!( + "lean_state_transition_slots_processing_time_seconds", + "Duration to process slots", + vec![0.005, 0.01, 0.025, 0.05, 0.1, 1.0] + ) + .unwrap() + }); + +static LEAN_STATE_TRANSITION_BLOCK_PROCESSING_TIME_SECONDS: LazyLock = + LazyLock::new(|| { + prometheus::register_histogram!( + "lean_state_transition_block_processing_time_seconds", + "Duration to process a block in state transition", + vec![0.005, 0.01, 0.025, 0.05, 0.1, 1.0] + ) + .unwrap() + }); + +static LEAN_STATE_TRANSITION_ATTESTATIONS_PROCESSING_TIME_SECONDS: LazyLock = + LazyLock::new(|| { + prometheus::register_histogram!( + "lean_state_transition_attestations_processing_time_seconds", + "Duration to process attestations", + vec![0.005, 0.01, 0.025, 0.05, 0.1, 1.0] + ) + .unwrap() + }); + +/// A guard that records elapsed time to a histogram when dropped. +pub struct TimingGuard { + histogram: &'static Histogram, + start: Instant, +} + +impl TimingGuard { + fn new(histogram: &'static Histogram) -> Self { + Self { + histogram, + start: Instant::now(), + } + } +} + +impl Drop for TimingGuard { + fn drop(&mut self) { + self.histogram.observe(self.start.elapsed().as_secs_f64()); + } +} + +/// Start timing state transition. Records duration when the guard is dropped. +pub fn time_state_transition() -> TimingGuard { + TimingGuard::new(&LEAN_STATE_TRANSITION_TIME_SECONDS) +} + +/// Start timing slots processing. Records duration when the guard is dropped. +pub fn time_slots_processing() -> TimingGuard { + TimingGuard::new(&LEAN_STATE_TRANSITION_SLOTS_PROCESSING_TIME_SECONDS) +} + +/// Start timing block processing. Records duration when the guard is dropped. +pub fn time_block_processing() -> TimingGuard { + TimingGuard::new(&LEAN_STATE_TRANSITION_BLOCK_PROCESSING_TIME_SECONDS) +} + +/// Start timing attestations processing. Records duration when the guard is dropped. +pub fn time_attestations_processing() -> TimingGuard { + TimingGuard::new(&LEAN_STATE_TRANSITION_ATTESTATIONS_PROCESSING_TIME_SECONDS) +} diff --git a/docs/metrics.md b/docs/metrics.md index 3ab60245..5bfbd1e1 100644 --- a/docs/metrics.md +++ b/docs/metrics.md @@ -48,12 +48,12 @@ The exposed metrics follow [the leanMetrics specification](https://github.com/le | `lean_latest_justified_slot` | Gauge | Latest justified slot | On state transition | | | ✅ | | `lean_latest_finalized_slot` | Gauge | Latest finalized slot | On state transition | | | ✅ | | `lean_finalizations_total` | Counter | Total number of finalization attempts | On finalization attempt | result=success,error | | ✅ | -|`lean_state_transition_time_seconds`| Histogram | Time to process state transition | On state transition | | 0.25, 0.5, 0.75, 1, 1.25, 1.5, 2, 2.5, 3, 4 | □ | +|`lean_state_transition_time_seconds`| Histogram | Time to process state transition | On state transition | | 0.25, 0.5, 0.75, 1, 1.25, 1.5, 2, 2.5, 3, 4 | ✅ | |`lean_state_transition_slots_processed_total`| Counter | Total number of processed slots | On state transition process slots | | | ✅ | -|`lean_state_transition_slots_processing_time_seconds`| Histogram | Time taken to process slots | On state transition process slots | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | □ | -|`lean_state_transition_block_processing_time_seconds`| Histogram | Time taken to process block | On state transition process block | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | □ | +|`lean_state_transition_slots_processing_time_seconds`| Histogram | Time taken to process slots | On state transition process slots | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | ✅ | +|`lean_state_transition_block_processing_time_seconds`| Histogram | Time taken to process block | On state transition process block | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | ✅ | |`lean_state_transition_attestations_processed_total`| Counter | Total number of processed attestations | On state transition process attestations | | | ✅ | -|`lean_state_transition_attestations_processing_time_seconds`| Histogram | Time taken to process attestations | On state transition process attestations | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | □ | +|`lean_state_transition_attestations_processing_time_seconds`| Histogram | Time taken to process attestations | On state transition process attestations | | 0.005, 0.01, 0.025, 0.05, 0.1, 1 | ✅ | ## Validator Metrics