feat: add forkchoice timing metrics

Cargo.toml

@@ -7,6 +7,7 @@ members = [
     "crates/blockchain/fork_choice",
     "crates/blockchain/state_transition",
     "crates/common/crypto",
+    "crates/common/metrics",
     "crates/common/types",
     "crates/net/p2p",
     "crates/net/rpc",
@@ -28,6 +29,7 @@ ethlambda-blockchain = { path = "crates/blockchain" }
 ethlambda-fork-choice = { path = "crates/blockchain/fork_choice" }
 ethlambda-state-transition = { path = "crates/blockchain/state_transition" }
 ethlambda-crypto = { path = "crates/common/crypto" }
+ethlambda-metrics = { path = "crates/common/metrics" }
 ethlambda-types = { path = "crates/common/types" }
 ethlambda-p2p = { path = "crates/net/p2p" }
 ethlambda-rpc = { path = "crates/net/rpc" }

crates/blockchain/Cargo.toml

@@ -18,6 +18,7 @@ ethlambda-storage.workspace = true
 ethlambda-state-transition.workspace = true
 ethlambda-fork-choice.workspace = true
 ethlambda-crypto.workspace = true
+ethlambda-metrics.workspace = true
 ethlambda-types.workspace = true
 
 spawned-concurrency.workspace = true
@@ -27,7 +28,6 @@ tokio.workspace = true
 thiserror.workspace = true
 tracing.workspace = true
 
-prometheus.workspace = true
 hex.workspace = true
 
 [dev-dependencies]

crates/blockchain/src/metrics.rs

@@ -1,78 +1,71 @@
 //! Prometheus metrics for the blockchain module.
 
+use ethlambda_metrics::*;
+
 pub fn update_head_slot(slot: u64) {
-    static LEAN_HEAD_SLOT: std::sync::LazyLock<prometheus::IntGauge> =
-        std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!("lean_head_slot", "Latest slot of the lean chain")
-                .unwrap()
-        });
+    static LEAN_HEAD_SLOT: std::sync::LazyLock<IntGauge> = std::sync::LazyLock::new(|| {
+        register_int_gauge!("lean_head_slot", "Latest slot of the lean chain").unwrap()
+    });
     LEAN_HEAD_SLOT.set(slot.try_into().unwrap());
 }
 
 pub fn update_latest_justified_slot(slot: u64) {
-    static LEAN_LATEST_JUSTIFIED_SLOT: std::sync::LazyLock<prometheus::IntGauge> =
+    static LEAN_LATEST_JUSTIFIED_SLOT: std::sync::LazyLock<IntGauge> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!("lean_latest_justified_slot", "Latest justified slot")
-                .unwrap()
+            register_int_gauge!("lean_latest_justified_slot", "Latest justified slot").unwrap()
         });
     LEAN_LATEST_JUSTIFIED_SLOT.set(slot.try_into().unwrap());
 }
 
 pub fn update_latest_finalized_slot(slot: u64) {
-    static LEAN_LATEST_FINALIZED_SLOT: std::sync::LazyLock<prometheus::IntGauge> =
+    static LEAN_LATEST_FINALIZED_SLOT: std::sync::LazyLock<IntGauge> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!("lean_latest_finalized_slot", "Latest finalized slot")
-                .unwrap()
+            register_int_gauge!("lean_latest_finalized_slot", "Latest finalized slot").unwrap()
         });
     LEAN_LATEST_FINALIZED_SLOT.set(slot.try_into().unwrap());
 }
 
 pub fn update_current_slot(slot: u64) {
-    static LEAN_CURRENT_SLOT: std::sync::LazyLock<prometheus::IntGauge> =
-        std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!("lean_current_slot", "Current slot of the lean chain")
-                .unwrap()
-        });
+    static LEAN_CURRENT_SLOT: std::sync::LazyLock<IntGauge> = std::sync::LazyLock::new(|| {
+        register_int_gauge!("lean_current_slot", "Current slot of the lean chain").unwrap()
+    });
     LEAN_CURRENT_SLOT.set(slot.try_into().unwrap());
 }
 
 pub fn update_validators_count(count: u64) {
-    static LEAN_VALIDATORS_COUNT: std::sync::LazyLock<prometheus::IntGauge> =
-        std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!(
-                "lean_validators_count",
-                "Number of validators managed by a node"
-            )
-            .unwrap()
-        });
+    static LEAN_VALIDATORS_COUNT: std::sync::LazyLock<IntGauge> = std::sync::LazyLock::new(|| {
+        register_int_gauge!(
+            "lean_validators_count",
+            "Number of validators managed by a node"
+        )
+        .unwrap()
+    });
     LEAN_VALIDATORS_COUNT.set(count.try_into().unwrap());
 }
 
 pub fn update_safe_target_slot(slot: u64) {
-    static LEAN_SAFE_TARGET_SLOT: std::sync::LazyLock<prometheus::IntGauge> =
-        std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!("lean_safe_target_slot", "Safe target slot").unwrap()
-        });
+    static LEAN_SAFE_TARGET_SLOT: std::sync::LazyLock<IntGauge> = std::sync::LazyLock::new(|| {
+        register_int_gauge!("lean_safe_target_slot", "Safe target slot").unwrap()
+    });
     LEAN_SAFE_TARGET_SLOT.set(slot.try_into().unwrap());
 }
 
 pub fn set_node_info(name: &str, version: &str) {
-    static LEAN_NODE_INFO: std::sync::LazyLock<prometheus::IntGaugeVec> =
-        std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge_vec!(
-                "lean_node_info",
-                "Node information (always 1)",
-                &["name", "version"]
-            )
-            .unwrap()
-        });
+    static LEAN_NODE_INFO: std::sync::LazyLock<IntGaugeVec> = std::sync::LazyLock::new(|| {
+        register_int_gauge_vec!(
+            "lean_node_info",
+            "Node information (always 1)",
+            &["name", "version"]
+        )
+        .unwrap()
+    });
     LEAN_NODE_INFO.with_label_values(&[name, version]).set(1);
 }
 
 pub fn set_node_start_time() {
-    static LEAN_NODE_START_TIME_SECONDS: std::sync::LazyLock<prometheus::IntGauge> =
+    static LEAN_NODE_START_TIME_SECONDS: std::sync::LazyLock<IntGauge> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_gauge!(
+            register_int_gauge!(
                 "lean_node_start_time_seconds",
                 "Timestamp when node started"
             )
@@ -87,9 +80,9 @@ pub fn set_node_start_time() {
 
 /// Increment the valid attestations counter.
 pub fn inc_attestations_valid(source: &str) {
-    static LEAN_ATTESTATIONS_VALID_TOTAL: std::sync::LazyLock<prometheus::IntCounterVec> =
+    static LEAN_ATTESTATIONS_VALID_TOTAL: std::sync::LazyLock<IntCounterVec> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_counter_vec!(
+            register_int_counter_vec!(
                 "lean_attestations_valid_total",
                 "Count of valid attestations",
                 &["source"]
@@ -103,9 +96,9 @@ pub fn inc_attestations_valid(source: &str) {
 
 /// Increment the invalid attestations counter.
 pub fn inc_attestations_invalid(source: &str) {
-    static LEAN_ATTESTATIONS_INVALID_TOTAL: std::sync::LazyLock<prometheus::IntCounterVec> =
+    static LEAN_ATTESTATIONS_INVALID_TOTAL: std::sync::LazyLock<IntCounterVec> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_counter_vec!(
+            register_int_counter_vec!(
                 "lean_attestations_invalid_total",
                 "Count of invalid attestations",
                 &["source"]
@@ -119,13 +112,41 @@ pub fn inc_attestations_invalid(source: &str) {
 
 /// Increment the fork choice reorgs counter.
 pub fn inc_fork_choice_reorgs() {
-    static LEAN_FORK_CHOICE_REORGS_TOTAL: std::sync::LazyLock<prometheus::IntCounter> =
+    static LEAN_FORK_CHOICE_REORGS_TOTAL: std::sync::LazyLock<IntCounter> =
         std::sync::LazyLock::new(|| {
-            prometheus::register_int_counter!(
+            register_int_counter!(
                 "lean_fork_choice_reorgs_total",
                 "Count of fork choice reorganizations"
             )
             .unwrap()
         });
     LEAN_FORK_CHOICE_REORGS_TOTAL.inc();
 }
+
+/// Start timing fork choice block processing. Records duration when the guard is dropped.
+pub fn time_fork_choice_block_processing() -> TimingGuard {
+    static LEAN_FORK_CHOICE_BLOCK_PROCESSING_TIME_SECONDS: std::sync::LazyLock<Histogram> =
+        std::sync::LazyLock::new(|| {
+            register_histogram!(
+                "lean_fork_choice_block_processing_time_seconds",
+                "Duration to process a block",
+                vec![0.005, 0.01, 0.025, 0.05, 0.1, 1.0]
+            )
+            .unwrap()
+        });
+    TimingGuard::new(&LEAN_FORK_CHOICE_BLOCK_PROCESSING_TIME_SECONDS)
+}
+
+/// Start timing attestation validation. Records duration when the guard is dropped.
+pub fn time_attestation_validation() -> TimingGuard {
+    static LEAN_ATTESTATION_VALIDATION_TIME_SECONDS: std::sync::LazyLock<Histogram> =
+        std::sync::LazyLock::new(|| {
+            register_histogram!(
+                "lean_attestation_validation_time_seconds",
+                "Duration to validate an attestation",
+                vec![0.005, 0.01, 0.025, 0.05, 0.1, 1.0]
+            )
+            .unwrap()
+        });
+    TimingGuard::new(&LEAN_ATTESTATION_VALIDATION_TIME_SECONDS)
+}

crates/blockchain/src/store.rs

@@ -70,6 +70,7 @@ fn update_safe_target(store: &mut Store) {
 ///     2. A vote cannot span backwards in time (source > target).
 ///     3. A vote cannot be for a future slot.
 fn validate_attestation(store: &Store, attestation: &Attestation) -> Result<(), StoreError> {
+    let _timing = metrics::time_attestation_validation();
     let data = &attestation.data;
 
     // Availability Check - We cannot count a vote if we haven't seen the blocks involved.
@@ -285,6 +286,8 @@ pub fn on_block(
     store: &mut Store,
     signed_block: SignedBlockWithAttestation,
 ) -> Result<(), StoreError> {
+    let _timing = metrics::time_fork_choice_block_processing();
+
     // Unpack block components
     let block = signed_block.message.block.clone();
     let proposer_attestation = signed_block.message.proposer_attestation.clone();
@@ -1027,6 +1030,6 @@ fn is_reorg(old_head: H256, new_head: H256, store: &Store) -> bool {
     }
 
     // Couldn't walk back far enough (missing blocks in chain)
-    // Conservative: assume no reorg if we can't determine
+    // Assume the ancestor is behind the latest finalized block
     false
 }

crates/blockchain/state_transition/Cargo.toml

@@ -11,9 +11,9 @@ version.workspace = true
 
 [dependencies]
 ethlambda-types.workspace = true
+ethlambda-metrics.workspace = true
 
 thiserror.workspace = true
-prometheus.workspace = true
 
 [dev-dependencies]
 serde.workspace = true

crates/blockchain/state_transition/src/metrics.rs

@@ -1,11 +1,8 @@
 //! Prometheus metrics for state transition.
 
 use std::sync::LazyLock;
-use std::time::Instant;
 
-use prometheus::{
-    Histogram, IntCounter, IntCounterVec, register_int_counter, register_int_counter_vec,
-};
+use ethlambda_metrics::*;
 
 static LEAN_STATE_TRANSITION_SLOTS_PROCESSED_TOTAL: LazyLock<IntCounter> = LazyLock::new(|| {
     register_int_counter!(
@@ -49,7 +46,7 @@ pub fn inc_finalizations(result: &str) {
 }
 
 static LEAN_STATE_TRANSITION_TIME_SECONDS: LazyLock<Histogram> = LazyLock::new(|| {
-    prometheus::register_histogram!(
+    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]
@@ -59,7 +56,7 @@ static LEAN_STATE_TRANSITION_TIME_SECONDS: LazyLock<Histogram> = LazyLock::new(|
 
 static LEAN_STATE_TRANSITION_SLOTS_PROCESSING_TIME_SECONDS: LazyLock<Histogram> =
     LazyLock::new(|| {
-        prometheus::register_histogram!(
+        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]
@@ -69,7 +66,7 @@ static LEAN_STATE_TRANSITION_SLOTS_PROCESSING_TIME_SECONDS: LazyLock<Histogram>
 
 static LEAN_STATE_TRANSITION_BLOCK_PROCESSING_TIME_SECONDS: LazyLock<Histogram> =
     LazyLock::new(|| {
-        prometheus::register_histogram!(
+        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]
@@ -79,35 +76,14 @@ static LEAN_STATE_TRANSITION_BLOCK_PROCESSING_TIME_SECONDS: LazyLock<Histogram>
 
 static LEAN_STATE_TRANSITION_ATTESTATIONS_PROCESSING_TIME_SECONDS: LazyLock<Histogram> =
     LazyLock::new(|| {
-        prometheus::register_histogram!(
+        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)