ledger: confirm_slot_entries(): confirmation_elapsed metric (#30807)

Measure total time spent inside `confirm_slot_entries()`.  Useful metric
in addition to `replay_elapsed` and
`poh_verify_elapsed`/`transaction_verify_elapsed`, as it shows how PoH
and transaction verification interact with the replay process.

Cargo.lock

@@ -5781,6 +5781,7 @@ dependencies = [
  "reed-solomon-erasure",
  "rocksdb",
  "rustc_version 0.4.0",
+ "scopeguard",
  "serde",
  "serde_bytes",
  "sha2 0.10.6",

core/src/progress_map.rs

@@ -64,6 +64,7 @@ impl ReplaySlotStats {
                     self.transaction_verify_elapsed as i64,
                     i64
                 ),
+                ("confirmation_time_us", self.confirmation_elapsed as i64, i64),
                 ("replay_time", self.replay_elapsed as i64, i64),
                 ("execute_batches_us", self.batch_execute.wall_clock_us as i64, i64),
                 (

ledger/Cargo.toml

@@ -32,6 +32,7 @@ rand = { workspace = true }
 rand_chacha = { workspace = true }
 rayon = { workspace = true }
 reed-solomon-erasure = { workspace = true, features = ["simd-accel"] }
+scopeguard = { workspace = true }
 serde = { workspace = true }
 serde_bytes = { workspace = true }
 sha2 = { workspace = true }

ledger/src/blockstore_processor.rs

@@ -10,6 +10,7 @@ use {
     log::*,
     rand::{seq::SliceRandom, thread_rng},
     rayon::{prelude::*, ThreadPool},
+    scopeguard::defer,
     solana_entry::entry::{
         self, create_ticks, Entry, EntrySlice, EntryType, EntryVerificationStatus, VerifyRecyclers,
     },
@@ -934,6 +935,12 @@ pub struct ConfirmationTiming {
     /// slot is complete.
     pub started: Instant,
 
+    /// Wall clock time used by the slot confirmation code, including PoH/signature verification,
+    /// and replay.  As replay can run in parallel with the verification, this value can not be
+    /// recovered from the `replay_elapsed` and or `{poh,transaction}_verify_elapsed`.  This
+    /// includes failed cases, when `confirm_slot_entries` exist with an error.  In microseconds.
+    pub confirmation_elapsed: u64,
+
     /// Wall clock time used by the entry replay code.  Does not include the PoH or the transaction
     /// signature/precompiles verification, but can overlap with the PoH and signature verification.
     /// In microseconds.
@@ -962,6 +969,7 @@ impl Default for ConfirmationTiming {
     fn default() -> Self {
         Self {
             started: Instant::now(),
+            confirmation_elapsed: 0,
             replay_elapsed: 0,
             poh_verify_elapsed: 0,
             transaction_verify_elapsed: 0,
@@ -1096,6 +1104,7 @@ fn confirm_slot_entries(
     prioritization_fee_cache: &PrioritizationFeeCache,
 ) -> result::Result<(), BlockstoreProcessorError> {
     let ConfirmationTiming {
+        confirmation_elapsed,
         replay_elapsed,
         poh_verify_elapsed,
         transaction_verify_elapsed,
@@ -1103,6 +1112,11 @@ fn confirm_slot_entries(
         ..
     } = timing;
 
+    let confirmation_elapsed_timer = Measure::start("confirmation_elapsed");
+    defer! {
+        *confirmation_elapsed += confirmation_elapsed_timer.end_as_us();
+    };
+
     let slot = bank.slot();
     let (entries, num_shreds, slot_full) = slot_entries_load_result;
     let num_entries = entries.len();

programs/sbf/Cargo.lock

@@ -4923,6 +4923,7 @@ dependencies = [
  "reed-solomon-erasure",
  "rocksdb",
  "rustc_version 0.4.0",
+ "scopeguard",
  "serde",
  "serde_bytes",
  "sha2 0.10.6",