From 54c4646971f78b3c54f487931be8bb1e270bb50b Mon Sep 17 00:00:00 2001 From: Dan Cline <6798349+Rjected@users.noreply.github.com> Date: Fri, 7 Feb 2025 13:20:18 -0500 Subject: [PATCH] feat: add granular prewarm metrics (#14282) --- crates/engine/tree/src/tree/metrics.rs | 24 ++++++++++++++++++++++-- crates/engine/tree/src/tree/mod.rs | 20 ++++++++++++++++++-- 2 files changed, 40 insertions(+), 4 deletions(-) diff --git a/crates/engine/tree/src/tree/metrics.rs b/crates/engine/tree/src/tree/metrics.rs index 6bced3095..839b6c920 100644 --- a/crates/engine/tree/src/tree/metrics.rs +++ b/crates/engine/tree/src/tree/metrics.rs @@ -16,6 +16,8 @@ pub(crate) struct EngineApiMetrics { pub(crate) block_validation: BlockValidationMetrics, /// A copy of legacy blockchain tree metrics, to be replaced when we replace the old tree pub(crate) tree: TreeMetrics, + /// Metrics for transaction prewarming threads + pub(crate) prewarm: PrewarmThreadMetrics, } /// Metrics for the entire blockchain tree @@ -69,8 +71,6 @@ pub(crate) struct BlockValidationMetrics { pub(crate) state_root_duration: Gauge, /// Trie input computation duration pub(crate) trie_input_duration: Gauge, - /// Prewarm spawn duration - pub(crate) prewarm_spawn_duration: Gauge, /// Cache saving duration pub(crate) cache_saving_duration: Gauge, /// State root config creation duration @@ -87,6 +87,26 @@ impl BlockValidationMetrics { } } +/// Metrics for prewarming threads +#[derive(Metrics, Clone)] +#[metrics(scope = "sync.prewarm")] +pub(crate) struct PrewarmThreadMetrics { + /// Prewarm thread spawn duration + pub(crate) spawn_duration: Gauge, + /// A histogram of the prewarm thread spawn duration + pub(crate) spawn_duration_histogram: Histogram, + /// The number of transactions in the block + pub(crate) transactions: Gauge, + /// A histogram of the number of transactions in the block + pub(crate) transactions_histogram: Histogram, + /// A histogram of total runtime durations for prewarm threads + pub(crate) total_runtime: Histogram, + /// A histogram of execution durations for prewarm threads + pub(crate) execution_duration: Histogram, + /// A histogram for total prefetch targets in prewarm threads + pub(crate) prefetch_storage_targets: Histogram, +} + /// Metrics for the blockchain tree block buffer #[derive(Metrics)] #[metrics(scope = "blockchain_tree.block_buffer")] diff --git a/crates/engine/tree/src/tree/mod.rs b/crates/engine/tree/src/tree/mod.rs index 4b1f631d7..cbfa51662 100644 --- a/crates/engine/tree/src/tree/mod.rs +++ b/crates/engine/tree/src/tree/mod.rs @@ -20,6 +20,7 @@ use alloy_rpc_types_engine::{ }; use cached_state::{ProviderCaches, SavedCache}; use error::{InsertBlockError, InsertBlockErrorKind, InsertBlockFatalError}; +use metrics::PrewarmThreadMetrics; use persistence_state::CurrentPersistenceAction; use reth_chain_state::{ CanonicalInMemoryState, ExecutedBlock, ExecutedBlockWithTrieUpdates, @@ -2485,6 +2486,7 @@ where if self.config.use_caching_and_prewarming() { debug!(target: "engine::tree", "Spawning prewarm threads"); let prewarm_start = Instant::now(); + let prewarm_metrics = self.metrics.prewarm.clone(); // Prewarm transactions for (tx_idx, tx) in block.transactions_recovered().enumerate() { @@ -2499,16 +2501,21 @@ where state_root_sender, cancel_execution.clone(), prewarm_task_lock.clone(), + prewarm_metrics.clone(), )?; let elapsed = start.elapsed(); debug!(target: "engine::tree", ?tx_idx, elapsed = ?elapsed, "Spawned transaction prewarm"); } + prewarm_metrics.transactions.set(block.transaction_count() as f64); + prewarm_metrics.transactions_histogram.record(block.transaction_count() as f64); + drop(state_root_sender); let elapsed = prewarm_start.elapsed(); debug!(target: "engine::tree", ?elapsed, "Done spawning prewarm threads"); - self.metrics.block_validation.prewarm_spawn_duration.set(elapsed.as_secs_f64()); + self.metrics.prewarm.spawn_duration.set(elapsed); + self.metrics.prewarm.spawn_duration_histogram.record(elapsed); } trace!(target: "engine::tree", block=?block_num_hash, "Executing block"); @@ -2711,6 +2718,7 @@ where state_root_sender: Option>, cancel_execution: ManualCancel, task_finished: Arc>, + metrics: PrewarmThreadMetrics, ) -> Result<(), InsertBlockErrorKind> { // Get the builder once, outside the thread let Some(state_provider_builder) = self.state_provider_builder(block.parent_hash())? else { @@ -2723,6 +2731,7 @@ where // spawn task executing the individual tx self.thread_pool.spawn(move || { + let thread_start = Instant::now(); let in_progress = task_finished.read().unwrap(); // Create the state provider inside the thread @@ -2755,6 +2764,7 @@ where return } + let execution_start = Instant::now(); let ResultAndState { state, .. } = match evm.transact(tx_env) { Ok(res) => res, Err(err) => { @@ -2762,6 +2772,7 @@ where return } }; + metrics.execution_duration.record(execution_start.elapsed()); // execution no longer in progress, so we can drop the lock drop(in_progress); @@ -2795,15 +2806,20 @@ where targets.insert(keccak256(addr), storage_set); } + let storage_targets = targets.values().map(|slots| slots.len()).sum::(); debug!( target: "engine::tree", tx_hash = ?tx.tx_hash(), targets = targets.len(), - storage_targets = targets.values().map(|slots| slots.len()).sum::(), + storage_targets, "Prefetching proofs for a transaction" ); + metrics.prefetch_storage_targets.record(storage_targets as f64); let _ = state_root_sender.send(StateRootMessage::PrefetchProofs(targets)); + + // record final metrics + metrics.total_runtime.record(thread_start.elapsed()); }); Ok(())