diff --git a/crates/engine/tree/src/tree/mod.rs b/crates/engine/tree/src/tree/mod.rs index fba2eab20b5..c5069e14ebc 100644 --- a/crates/engine/tree/src/tree/mod.rs +++ b/crates/engine/tree/src/tree/mod.rs @@ -228,40 +228,6 @@ impl OnStateHook for MeteredStateHook { } } -/// Helper function to update block timing metrics for insert phase. -/// -/// This function handles the common pattern of: -/// 1. Getting existing timing metrics (if block was built locally) -/// 2. Creating new metrics (if block was received from network) -/// 3. Setting insert timing values -/// 4. Calculating total as the sum of validate_and_execute + insert_to_tree -/// 5. Storing the updated metrics -fn update_insert_timing_metrics( - block_hash: B256, - validate_and_execute: std::time::Duration, - insert_to_tree: std::time::Duration, -) { - use reth_node_metrics::block_timing::{ - get_block_timing, store_block_timing, BlockTimingMetrics, - }; - - let mut timing_metrics = if let Some(existing) = get_block_timing(&block_hash) { - // Block was built locally, update insert timing - existing - } else { - // Block was received from network, create timing metrics with insert timing only - BlockTimingMetrics::default() - }; - - timing_metrics.insert.validate_and_execute = validate_and_execute; - timing_metrics.insert.insert_to_tree = insert_to_tree; - // Total should be the sum of validate_and_execute + insert_to_tree - timing_metrics.insert.total = - timing_metrics.insert.validate_and_execute + timing_metrics.insert.insert_to_tree; - - store_block_timing(block_hash, timing_metrics); -} - /// The engine API tree handler implementation. /// /// This type is responsible for processing engine API requests, maintaining the canonical state and @@ -1427,17 +1393,6 @@ where self.metrics.engine.inserted_already_executed_blocks.increment(1); let elapsed = now.elapsed(); - // X Layer: Update timing metrics for InsertExecutedBlock path - // Note: validate_exec time is 0 because block was already executed during - // build - use std::time::Duration; - let block_hash = block.recovered_block().hash(); - update_insert_timing_metrics( - block_hash, - Duration::from_nanos(0), - insert_tree_elapsed, - ); - self.emit_event(EngineApiEvent::BeaconConsensus( ConsensusEngineEvent::CanonicalBlockAdded(block, elapsed), )); @@ -2500,20 +2455,6 @@ where // run the conversion to ensure that the block hash is valid. convert_to_block(self, input)?; - // X Layer: Even if block is already seen, update timing metrics if it was built - // locally Block was built locally but already exists in tree - // Set insert timing to 0 for now, will be updated in event handler if elapsed > 0 - use reth_node_metrics::block_timing::get_block_timing; - use std::time::Duration; - let block_hash = block_num_hash.hash; - if get_block_timing(&block_hash).is_some() { - update_insert_timing_metrics( - block_hash, - Duration::from_nanos(0), - Duration::from_nanos(0), - ); - } - return Ok(InsertPayloadOk::AlreadySeen(BlockStatus::Valid)) } _ => {} @@ -2558,12 +2499,21 @@ where let ctx = TreeCtx::new(&mut self.state, &self.canonical_in_memory_state); - // X Layer: Track insert timing - let validate_exec_start = Instant::now(); + // X Layer: Track insert timing with RAII let start = Instant::now(); - - let executed = execute(&mut self.payload_validator, input, ctx)?; - let validate_exec_elapsed = validate_exec_start.elapsed(); + let block_hash = block_num_hash.hash; + + // Create timing context with Prometheus support + // We'll create Prometheus metrics from the handler's metrics if needed + use reth_node_metrics::block_timing::{BlockTimingContext, BlockTimingPrometheusMetrics}; + let prom_metrics = BlockTimingPrometheusMetrics::default(); + let mut timing_ctx = BlockTimingContext::new_with_prometheus(block_hash, prom_metrics); + + // validate and execute + let executed = { + let _guard = timing_ctx.time_validate_and_execute(); + execute(&mut self.payload_validator, input, ctx)? + }; // if the parent is the canonical head, we can insert the block as the pending block if self.state.tree_state.canonical_block_hash() == executed.recovered_block().parent_hash() @@ -2572,17 +2522,18 @@ where self.canonical_in_memory_state.set_pending_block(executed.clone()); } - let insert_tree_start = Instant::now(); - self.state.tree_state.insert_executed(executed.clone()); - let insert_tree_elapsed = insert_tree_start.elapsed(); + // insert to tree + { + let _guard = timing_ctx.time_insert_to_tree(); + self.state.tree_state.insert_executed(executed.clone()); + } self.metrics.engine.executed_blocks.set(self.state.tree_state.block_count() as f64); // emit insert event let elapsed = start.elapsed(); - // X Layer: Update timing metrics with insert timing - let block_hash = executed.recovered_block().hash(); - update_insert_timing_metrics(block_hash, validate_exec_elapsed, insert_tree_elapsed); + // X Layer: Update timing metrics (auto-updates and stores on drop) + timing_ctx.update_totals(); let engine_event = if is_fork { ConsensusEngineEvent::ForkBlockAdded(executed.clone(), elapsed) } else { diff --git a/crates/node/metrics/src/block_timing.rs b/crates/node/metrics/src/block_timing.rs index 4098743e10b..66f1b968ca6 100644 --- a/crates/node/metrics/src/block_timing.rs +++ b/crates/node/metrics/src/block_timing.rs @@ -4,20 +4,24 @@ use alloy_primitives::B256; use indexmap::IndexMap; use std::{ sync::{Arc, Mutex}, - time::Duration, + time::{Duration, Instant}, }; +pub use crate::block_timing_prometheus::BlockTimingPrometheusMetrics; + /// Timing metrics for block building phase #[derive(Debug, Clone, Default)] pub struct BuildTiming { /// Time spent applying pre-execution changes pub apply_pre_execution_changes: Duration, /// Time spent executing sequencer transactions - pub execute_sequencer_transactions: Duration, + pub exec_sequencer_transactions: Duration, + /// Time spent selecting/packing mempool transactions + pub select_mempool_transactions: Duration, /// Time spent executing mempool transactions - pub execute_mempool_transactions: Duration, - /// Time spent finishing block build (state root calculation, etc.) - pub finish: Duration, + pub exec_mempool_transactions: Duration, + /// Time spent calculating state root + pub calc_state_root: Duration, /// Total build time pub total: Duration, } @@ -33,18 +37,6 @@ pub struct InsertTiming { pub total: Duration, } -/// Timing metrics for transaction execution -/// -/// Note: Individual transaction execution times (sequencer_txs, mempool_txs) are stored -/// in `BuildTiming` to avoid duplication. This struct only stores the total time. -#[derive(Debug, Clone, Default)] -pub struct DeliverTxsTiming { - /// Total transaction execution time - /// Note: Individual times are stored in BuildTiming (execute_sequencer_transactions, - /// execute_mempool_transactions) - pub total: Duration, -} - /// Complete timing metrics for a block #[derive(Debug, Clone, Default)] pub struct BlockTimingMetrics { @@ -52,22 +44,32 @@ pub struct BlockTimingMetrics { pub build: BuildTiming, /// Block insertion phase timing pub insert: InsertTiming, - /// Transaction execution timing - pub deliver_txs: DeliverTxsTiming, } impl BlockTimingMetrics { /// Format timing metrics for logging pub fn format_for_log(&self) -> String { let format_duration = |d: Duration| { - let ms = d.as_millis(); - let us = d.as_micros(); - if ms > 0 { - format!("{}ms", ms) - } else if us > 0 { - format!("{}µs", us) - } else { - format!("{}ns", d.as_nanos()) + let secs = d.as_secs_f64(); + match () { + _ if secs >= 1.0 => format!("{:.3}s", secs), + _ if secs >= 0.001 => { + let ms = secs * 1000.0; + if ms.fract() == 0.0 { + format!("{}ms", ms as u64) + } else { + format!("{:.3}ms", ms) + } + } + _ if secs >= 0.000001 => { + let us = secs * 1_000_000.0; + if us.fract() == 0.0 { + format!("{}µs", us as u64) + } else { + format!("{:.3}µs", us) + } + } + _ => format!("{}ns", d.as_nanos()), } }; @@ -75,22 +77,20 @@ impl BlockTimingMetrics { let is_locally_built = self.build.total.as_nanos() > 0; if is_locally_built { - // Block was built locally, show full timing including Build and DeliverTxs - // Note: DeliverTxs only shows total to avoid duplication with Build's seqTxs/mempoolTxs - let deliver_txs_total_time = - self.build.execute_sequencer_transactions + self.build.execute_mempool_transactions; - + // Block was built locally, show full timing including Build + // Note: Transaction execution times (execSeqTxs, selectMempoolTxs, execMempoolTxs) are + // already shown in Build phase format!( - "Produce[Build[applyPreExec<{}>, seqTxs<{}>, mempoolTxs<{}>, finish<{}>, total<{}>], Insert[validateExec<{}>, insertTree<{}>, total<{}>]], DeliverTxs[total<{}>]", + "Produce[Build[applyPreExec<{}>, execSeqTxs<{}>, selectMempoolTxs<{}>, execMempoolTxs<{}>, calcStateRoot<{}>, total<{}>], Insert[validateExec<{}>, insertTree<{}>, total<{}>]]", format_duration(self.build.apply_pre_execution_changes), - format_duration(self.build.execute_sequencer_transactions), - format_duration(self.build.execute_mempool_transactions), - format_duration(self.build.finish), + format_duration(self.build.exec_sequencer_transactions), + format_duration(self.build.select_mempool_transactions), + format_duration(self.build.exec_mempool_transactions), + format_duration(self.build.calc_state_root), format_duration(self.build.total), format_duration(self.insert.validate_and_execute), format_duration(self.insert.insert_to_tree), format_duration(self.insert.total), - format_duration(deliver_txs_total_time), ) } else { // Block was received from network, only show Insert timing @@ -153,5 +153,276 @@ pub fn get_block_timing(block_hash: &B256) -> Option { pub fn remove_block_timing(block_hash: &B256) { let store = get_timing_store(); let mut map = store.lock().unwrap(); - map.remove(block_hash); + map.shift_remove(block_hash); +} + +// ============================================================================ +// RAII-based timing helpers +// ============================================================================ + +/// RAII guard that automatically records timing to a mutable reference and optionally to Prometheus +/// when dropped. +/// +/// Usage: +/// ```rust +/// let mut timing = Duration::default(); +/// { +/// let _guard = TimingGuard::new(&mut timing); +/// // ... do work ... +/// } // Guard is dropped here and timing is automatically recorded +/// ``` +pub struct TimingGuard<'a> { + start: Option, + target: &'a mut Duration, + prometheus_histogram: Option<&'a metrics::Histogram>, +} + +impl<'a> TimingGuard<'a> { + /// Create a new timing guard that will record the elapsed time to `target` when dropped. + pub fn new(target: &'a mut Duration) -> Self { + Self { start: Some(Instant::now()), target, prometheus_histogram: None } + } + + /// Create a new timing guard that records to both `target` and Prometheus histogram. + pub fn new_with_prometheus( + target: &'a mut Duration, + prometheus_histogram: &'a metrics::Histogram, + ) -> Self { + Self { + start: Some(Instant::now()), + target, + prometheus_histogram: Some(prometheus_histogram), + } + } + + fn record(&mut self) -> Option { + let start = self.start.take()?; + let duration = start.elapsed(); + *self.target = duration; + if let Some(histogram) = self.prometheus_histogram { + histogram.record(duration.as_secs_f64()); + } + Some(duration) + } + + /// Manually finish timing and return the duration. + pub fn finish(mut self) -> Duration { + if let Some(start) = self.start.take() { + let duration = start.elapsed(); + *self.target = duration; + if let Some(histogram) = self.prometheus_histogram { + histogram.record(duration.as_secs_f64()); + } + duration + } else { + *self.target + } + } +} + +impl<'a> Drop for TimingGuard<'a> { + fn drop(&mut self) { + let _ = self.record(); + } +} + +/// Context for managing block timing metrics using RAII. +/// +/// This provides a cleaner API for recording timing metrics throughout the block +/// building and insertion process. The context automatically stores metrics when dropped. +/// +/// Supports both logging (via IndexMap) and Prometheus metrics recording. +pub struct BlockTimingContext { + block_hash: B256, + metrics: BlockTimingMetrics, + auto_store: bool, + prometheus_metrics: Option, +} + +impl BlockTimingContext { + /// Create a new timing context for a block. + /// + /// If timing metrics already exist for this block (e.g., from build phase), + /// they will be loaded. Otherwise, a new empty metrics structure is created. + /// + /// Metrics will be automatically stored when the context is dropped. + pub fn new(block_hash: B256) -> Self { + Self::with_metrics(block_hash, get_block_timing(&block_hash), None) + } + + /// Create a new timing context for a block, initializing with empty metrics. + /// + /// Metrics will be automatically stored when the context is dropped. + pub fn new_empty(block_hash: B256) -> Self { + Self::with_metrics(block_hash, None, None) + } + + /// Create a new timing context with Prometheus metrics support. + /// + /// This enables automatic recording to Prometheus in addition to logging. + pub fn new_with_prometheus( + block_hash: B256, + prometheus_metrics: BlockTimingPrometheusMetrics, + ) -> Self { + Self::with_metrics(block_hash, get_block_timing(&block_hash), Some(prometheus_metrics)) + } + + /// Create a new empty timing context with Prometheus metrics support. + pub fn new_empty_with_prometheus( + block_hash: B256, + prometheus_metrics: BlockTimingPrometheusMetrics, + ) -> Self { + Self::with_metrics(block_hash, None, Some(prometheus_metrics)) + } + + /// Internal helper to create a context with optional metrics and Prometheus support. + fn with_metrics( + block_hash: B256, + metrics: Option, + prometheus_metrics: Option, + ) -> Self { + Self { + block_hash, + metrics: metrics.unwrap_or_default(), + auto_store: true, + prometheus_metrics, + } + } + + /// Get a mutable reference to the metrics. + pub fn metrics_mut(&mut self) -> &mut BlockTimingMetrics { + &mut self.metrics + } + + /// Get a reference to the metrics. + pub fn metrics(&self) -> &BlockTimingMetrics { + &self.metrics + } + + /// Update the block hash for this context. + pub fn set_block_hash(&mut self, block_hash: B256) { + self.block_hash = block_hash; + } + + /// Create a timing guard for recording build phase: apply pre-execution changes. + pub fn time_apply_pre_execution_changes(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.build.apply_pre_execution_changes, + &prom_metrics.build_apply_pre_execution_changes, + ), + None => TimingGuard::new(&mut self.metrics.build.apply_pre_execution_changes), + } + } + + /// Create a timing guard for recording build phase: execute sequencer transactions. + pub fn time_exec_sequencer_transactions(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.build.exec_sequencer_transactions, + &prom_metrics.build_exec_sequencer_transactions, + ), + None => TimingGuard::new(&mut self.metrics.build.exec_sequencer_transactions), + } + } + + /// Create a timing guard for recording build phase: select/pack mempool transactions. + pub fn time_select_mempool_transactions(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.build.select_mempool_transactions, + &prom_metrics.build_select_mempool_transactions, + ), + None => TimingGuard::new(&mut self.metrics.build.select_mempool_transactions), + } + } + + /// Create a timing guard for recording build phase: execute mempool transactions. + pub fn time_exec_mempool_transactions(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.build.exec_mempool_transactions, + &prom_metrics.build_exec_mempool_transactions, + ), + None => TimingGuard::new(&mut self.metrics.build.exec_mempool_transactions), + } + } + + /// Create a timing guard for recording build phase: calculate state root. + pub fn time_calc_state_root(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.build.calc_state_root, + &prom_metrics.build_calc_state_root, + ), + None => TimingGuard::new(&mut self.metrics.build.calc_state_root), + } + } + + /// Create a timing guard for recording insert phase: validate and execute. + pub fn time_validate_and_execute(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.insert.validate_and_execute, + &prom_metrics.insert_validate_and_execute, + ), + None => TimingGuard::new(&mut self.metrics.insert.validate_and_execute), + } + } + + /// Create a timing guard for recording insert phase: insert to tree. + pub fn time_insert_to_tree(&mut self) -> TimingGuard<'_> { + match &self.prometheus_metrics { + Some(prom_metrics) => TimingGuard::new_with_prometheus( + &mut self.metrics.insert.insert_to_tree, + &prom_metrics.insert_insert_to_tree, + ), + None => TimingGuard::new(&mut self.metrics.insert.insert_to_tree), + } + } + + /// Manually store the current metrics to the global store. + /// This is called automatically on drop if `auto_store` is true. + pub fn store(&self) { + store_block_timing(self.block_hash, self.metrics.clone()); + } + + /// Set whether metrics should be automatically stored on drop. + pub fn set_auto_store(&mut self, auto_store: bool) { + self.auto_store = auto_store; + } + + /// Calculate total build time from individual components. + fn calculate_build_total(&self) -> Duration { + self.metrics.build.apply_pre_execution_changes + + self.metrics.build.exec_sequencer_transactions + + self.metrics.build.select_mempool_transactions + + self.metrics.build.exec_mempool_transactions + + self.metrics.build.calc_state_root + } + + /// Calculate total insert time from individual components. + fn calculate_insert_total(&self) -> Duration { + self.metrics.insert.validate_and_execute + self.metrics.insert.insert_to_tree + } + + /// Calculate and update total times. + pub fn update_totals(&mut self) { + self.metrics.build.total = self.calculate_build_total(); + self.metrics.insert.total = self.calculate_insert_total(); + + if let Some(prom_metrics) = self.prometheus_metrics.take() { + prom_metrics.build_total.record(self.metrics.build.total.as_secs_f64()); + prom_metrics.insert_total.record(self.metrics.insert.total.as_secs_f64()); + } + } +} + +impl Drop for BlockTimingContext { + fn drop(&mut self) { + if self.auto_store { + self.update_totals(); + self.store(); + } + } } diff --git a/crates/node/metrics/src/block_timing_prometheus.rs b/crates/node/metrics/src/block_timing_prometheus.rs new file mode 100644 index 00000000000..3e2788cef76 --- /dev/null +++ b/crates/node/metrics/src/block_timing_prometheus.rs @@ -0,0 +1,37 @@ +//! Prometheus metrics for block timing + +use reth_metrics::{metrics::Histogram, Metrics}; + +/// Prometheus metrics for block timing. +/// +/// These metrics track the duration of various phases in block production and insertion. +#[derive(Metrics, Clone)] +#[metrics(scope = "block.timing")] +pub struct BlockTimingPrometheusMetrics { + /// Time spent applying pre-execution changes during block building + pub build_apply_pre_execution_changes: Histogram, + + /// Time spent executing sequencer transactions during block building + pub build_exec_sequencer_transactions: Histogram, + + /// Time spent selecting/packing mempool transactions during block building + pub build_select_mempool_transactions: Histogram, + + /// Time spent executing mempool transactions during block building + pub build_exec_mempool_transactions: Histogram, + + /// Time spent calculating state root during block building + pub build_calc_state_root: Histogram, + + /// Total time spent in block building phase + pub build_total: Histogram, + + /// Time spent validating and executing the block during insertion + pub insert_validate_and_execute: Histogram, + + /// Time spent inserting to tree state + pub insert_insert_to_tree: Histogram, + + /// Total time spent in block insertion phase + pub insert_total: Histogram, +} diff --git a/crates/node/metrics/src/lib.rs b/crates/node/metrics/src/lib.rs index 8de5f07e94b..d76b6567ec7 100644 --- a/crates/node/metrics/src/lib.rs +++ b/crates/node/metrics/src/lib.rs @@ -9,6 +9,8 @@ /// Block timing metrics for tracking block production and execution times (X Layer) pub mod block_timing; +#[path = "block_timing_prometheus.rs"] +mod block_timing_prometheus; pub mod chain; /// The metrics hooks for prometheus. pub mod hooks; @@ -28,6 +30,6 @@ pub use transaction_trace_xlayer::{ }; // Re-export block timing module items for convenience pub use block_timing::{ - get_block_timing, remove_block_timing, store_block_timing, BlockTimingMetrics, BuildTiming, - DeliverTxsTiming, InsertTiming, + get_block_timing, remove_block_timing, store_block_timing, BlockTimingContext, + BlockTimingMetrics, BlockTimingPrometheusMetrics, BuildTiming, InsertTiming, TimingGuard, }; diff --git a/crates/optimism/payload/src/builder.rs b/crates/optimism/payload/src/builder.rs index 11d03a8fea8..4427710b7e0 100644 --- a/crates/optimism/payload/src/builder.rs +++ b/crates/optimism/payload/src/builder.rs @@ -21,7 +21,7 @@ use reth_evm::{ }; use reth_execution_types::ExecutionOutcome; use reth_node_metrics::{ - block_timing::{store_block_timing, BlockTimingMetrics, BuildTiming, DeliverTxsTiming}, + block_timing::{store_block_timing, BlockTimingContext, BlockTimingPrometheusMetrics}, transaction_trace_xlayer::{get_global_tracer, TransactionProcessId}, }; use reth_optimism_forks::OpHardforks; @@ -364,10 +364,6 @@ impl OpBuilder<'_, Txs> { .unwrap_or_default() .as_millis(); - // X Layer: Initialize timing metrics - let build_start = Instant::now(); - let mut timing_metrics = BlockTimingMetrics::default(); - let mut db = State::builder().with_database(db).with_bundle_update().build(); // Load the L1 block contract into the database cache. If the L1 block contract is not @@ -377,29 +373,47 @@ impl OpBuilder<'_, Txs> { let mut builder = ctx.block_builder(&mut db)?; + // X Layer: Initialize timing context with RAII and Prometheus support + // Note: We'll get the block hash after building, so we create an empty context first + // and update it later. For now, we use a placeholder hash. + let build_start = Instant::now(); + let prom_metrics = BlockTimingPrometheusMetrics::default(); + let mut timing_ctx = + BlockTimingContext::new_empty_with_prometheus(B256::ZERO, prom_metrics); + // 1. apply pre-execution changes - let pre_exec_start = Instant::now(); - builder.apply_pre_execution_changes().map_err(|err| { - warn!(target: "payload_builder", %err, "failed to apply pre-execution changes"); - PayloadBuilderError::Internal(err.into()) - })?; - timing_metrics.build.apply_pre_execution_changes = pre_exec_start.elapsed(); + { + let _guard = timing_ctx.time_apply_pre_execution_changes(); + builder.apply_pre_execution_changes().map_err(|err| { + warn!(target: "payload_builder", %err, "failed to apply pre-execution changes"); + PayloadBuilderError::Internal(err.into()) + })?; + } // 2. execute sequencer transactions - let seq_txs_start = Instant::now(); - let mut info = ctx.execute_sequencer_transactions(&mut builder)?; - let seq_txs_elapsed = seq_txs_start.elapsed(); - timing_metrics.build.execute_sequencer_transactions = seq_txs_elapsed; + let mut info = { + let _guard = timing_ctx.time_exec_sequencer_transactions(); + ctx.execute_sequencer_transactions(&mut builder)? + }; // 3. if mem pool transactions are requested we execute them if !ctx.attributes().no_tx_pool() { - let mempool_txs_start = Instant::now(); - let best_txs = best(ctx.best_transaction_attributes(builder.evm_mut().block())); - if ctx.execute_best_transactions_xlayer(&mut info, &mut builder, best_txs)?.is_some() { - return Ok(BuildOutcomeKind::Cancelled) + // 3.1. select/pack mempool transactions + let best_txs = { + let _guard = timing_ctx.time_select_mempool_transactions(); + best(ctx.best_transaction_attributes(builder.evm_mut().block())) + }; + + // 3.2. execute mempool transactions + { + let _guard = timing_ctx.time_exec_mempool_transactions(); + if ctx + .execute_best_transactions_xlayer(&mut info, &mut builder, best_txs)? + .is_some() + { + return Ok(BuildOutcomeKind::Cancelled) + } } - let mempool_txs_elapsed = mempool_txs_start.elapsed(); - timing_metrics.build.execute_mempool_transactions = mempool_txs_elapsed; // check if the new payload is even more valuable if !ctx.is_better_payload(info.total_fees) { @@ -408,14 +422,11 @@ impl OpBuilder<'_, Txs> { } } - let finish_start = Instant::now(); - let BlockBuilderOutcome { execution_result, hashed_state, trie_updates, block } = - builder.finish(state_provider)?; - timing_metrics.build.finish = finish_start.elapsed(); - timing_metrics.build.total = build_start.elapsed(); - // Calculate DeliverTxs total from BuildTiming to avoid duplication - timing_metrics.deliver_txs.total = timing_metrics.build.execute_sequencer_transactions + - timing_metrics.build.execute_mempool_transactions; + // 4. finish (calculate state root) + let BlockBuilderOutcome { execution_result, hashed_state, trie_updates, block } = { + let _guard = timing_ctx.time_calc_state_root(); + builder.finish(state_provider)? + }; let sealed_block = Arc::new(block.sealed_block().clone()); debug!(target: "payload_builder", id=%ctx.attributes().payload_id(), sealed_block_header = ?sealed_block.header(), "sealed built block"); @@ -441,8 +452,15 @@ impl OpBuilder<'_, Txs> { let block_hash = sealed_block.hash(); let block_number = sealed_block.number(); - // X Layer: Store timing metrics for this block (will be updated with insert timing later) - store_block_timing(block_hash, timing_metrics.clone()); + // X Layer: Update timing context with actual block hash and total times + timing_ctx.set_block_hash(block_hash); + // Note: update_totals() will calculate build.total from individual components, + // so we don't need to manually set it here + timing_ctx.update_totals(); + + // Store timing metrics for this block (will be updated with insert timing later) + // Context will auto-store on drop, but we can also manually store here + timing_ctx.store(); let payload = OpBuiltPayload::new(ctx.payload_id(), sealed_block, info.total_fees, Some(executed));