-
Notifications
You must be signed in to change notification settings - Fork 194
feat(l1): fullsync metrics #6466
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
a94044c
88a37f2
bdfef9e
47eda94
23ff4dd
28f3e58
24bfd57
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -112,6 +112,8 @@ use vm::StoreVmDatabase; | |
|
|
||
| #[cfg(feature = "metrics")] | ||
| use ethrex_metrics::blocks::METRICS_BLOCKS; | ||
| #[cfg(feature = "metrics")] | ||
| use ethrex_metrics::fullsync::METRICS_FULLSYNC; | ||
|
|
||
| #[cfg(feature = "c-kzg")] | ||
| use ethrex_common::types::BlobsBundle; | ||
|
|
@@ -2188,7 +2190,8 @@ impl Blockchain { | |
| let mut total_gas_used = 0; | ||
| let mut transactions_count = 0; | ||
|
|
||
| let interval = Instant::now(); | ||
| let interval = std::time::Instant::now(); | ||
| let exec_start = std::time::Instant::now(); | ||
| for (i, block) in blocks.iter().enumerate() { | ||
| if cancellation_token.is_cancelled() { | ||
| info!("Received shutdown signal, aborting"); | ||
|
|
@@ -2232,9 +2235,13 @@ impl Blockchain { | |
| tokio::task::yield_now().await; | ||
| } | ||
|
|
||
| let exec_ms = exec_start.elapsed().as_millis(); | ||
|
|
||
| let transitions_start = std::time::Instant::now(); | ||
| let account_updates = vm | ||
| .get_state_transitions() | ||
| .map_err(|err| (ChainError::EvmError(err), None))?; | ||
| let transitions_ms = transitions_start.elapsed().as_millis(); | ||
|
|
||
| let last_block = blocks | ||
| .last() | ||
|
|
@@ -2244,11 +2251,13 @@ impl Blockchain { | |
| let last_block_gas_limit = last_block.header.gas_limit; | ||
|
|
||
| // Apply the account updates over all blocks and compute the new state root | ||
| let merkle_start = std::time::Instant::now(); | ||
| let account_updates_list = self | ||
| .storage | ||
| .apply_account_updates_batch(first_block_header.parent_hash, &account_updates) | ||
| .map_err(|e| (e.into(), None))? | ||
| .ok_or((ChainError::ParentStateNotFound, None))?; | ||
| let merkle_ms = merkle_start.elapsed().as_millis(); | ||
|
|
||
| let new_state_root = account_updates_list.state_trie_hash; | ||
| let state_updates = account_updates_list.state_updates; | ||
|
|
@@ -2258,6 +2267,7 @@ impl Blockchain { | |
| // Check state root matches the one in block header | ||
| validate_state_root(&last_block.header, new_state_root).map_err(|e| (e, None))?; | ||
|
|
||
| let store_start = std::time::Instant::now(); | ||
| let update_batch = UpdateBatch { | ||
| account_updates: state_updates, | ||
| storage_updates: accounts_updates, | ||
|
|
@@ -2270,6 +2280,17 @@ impl Blockchain { | |
| self.storage | ||
| .store_block_updates(update_batch) | ||
| .map_err(|e| (e.into(), None))?; | ||
| let store_ms = store_start.elapsed().as_millis(); | ||
|
|
||
| info!( | ||
| "[FULLSYNC TIMING] Batch {}: exec={}ms, transitions={}ms, merkle={}ms, store={}ms, total={}ms", | ||
| blocks_len, | ||
| exec_ms, | ||
| transitions_ms, | ||
| merkle_ms, | ||
| store_ms, | ||
| interval.elapsed().as_millis() | ||
| ); | ||
|
Comment on lines
2190
to
+2293
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
All four timing Consider wrapping both the timing variables and the log under Prompt To Fix With AIThis is a comment left during a code review.
Path: crates/blockchain/blockchain.rs
Line: 2190-2293
Comment:
**Timing instrumentation always compiled regardless of `metrics` feature**
All four timing `Instant`s (`exec_start`, `transitions_start`, `merkle_start`, `store_start`) and the `[FULLSYNC TIMING]` `info!` log are unconditional — they run even when the `metrics` feature is disabled. The existing `metrics!` macro is specifically designed to gate this overhead. Similarly, `body_download_start` and its `[FULLSYNC TIMING]` info log in `full.rs` fire unconditionally. On a busy node this adds one `info!` line per batch and per body-download round, which can be verbose in non-metrics deployments.
Consider wrapping both the timing variables and the log under `metrics!(...)` / `fullsync_metrics!(...)`, or demoting the log to `debug!`.
How can I resolve this? If you propose a fix, please make it concise. |
||
|
|
||
| let elapsed_seconds = interval.elapsed().as_secs_f64(); | ||
| let throughput = if elapsed_seconds > 0.0 && total_gas_used != 0 { | ||
|
|
@@ -2285,6 +2306,9 @@ impl Blockchain { | |
| // Set the latest gas used as the average gas used per block in the batch | ||
| METRICS_BLOCKS.set_latest_gas_used(total_gas_used as f64 / blocks_len as f64); | ||
| METRICS_BLOCKS.set_latest_gigagas(throughput); | ||
| METRICS_FULLSYNC.set_batch_execution_ms(exec_ms as f64); | ||
| METRICS_FULLSYNC.set_batch_merkle_ms(merkle_ms as f64); | ||
| METRICS_FULLSYNC.set_batch_store_ms(store_ms as f64); | ||
| ); | ||
|
|
||
| if self.options.perf_logs_enabled { | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
transitions_msmeasured and logged but not exposed as a Prometheus metrictransitions_ms(time spent invm.get_state_transitions()) is included in the[FULLSYNC TIMING]log and clearly matters for profiling, but there is no correspondingbatch_transitions_msgauge inMetricsFullSync. The Grafana "Batch Time Breakdown" stacked-bar chart sumsbody_download + execution + merkle + store, so it will consistently under-report total batch time by the transitions duration. This gap will be invisible to operators using the dashboard.Prompt To Fix With AI