Ledger processing speed tracking (#9005)

ledger/src/blockstore_processor.rs

@@ -453,18 +453,17 @@ pub fn verify_ticks(
 fn confirm_full_slot(
     blockstore: &Blockstore,
     bank: &Arc<Bank>,
-    last_entry_hash: &Hash,
     opts: &ProcessOptions,
     recyclers: &VerifyRecyclers,
+    progress: &mut ConfirmationProgress,
 ) -> result::Result<(), BlockstoreProcessorError> {
     let mut timing = ConfirmationTiming::default();
-    let mut progress = ConfirmationProgress::new(*last_entry_hash);
     let skip_verification = !opts.poh_verify;
     confirm_slot(
         blockstore,
         bank,
         &mut timing,
-        &mut progress,
+        progress,
         skip_verification,
         None,
         opts.entry_callback.as_ref(),
@@ -625,7 +624,8 @@ fn process_bank_0(
     recyclers: &VerifyRecyclers,
 ) -> result::Result<(), BlockstoreProcessorError> {
     assert_eq!(bank0.slot(), 0);
-    confirm_full_slot(blockstore, bank0, &bank0.last_blockhash(), opts, recyclers)
+    let mut progress = ConfirmationProgress::new(bank0.last_blockhash());
+    confirm_full_slot(blockstore, bank0, opts, recyclers, &mut progress)
         .expect("processing for bank 0 must succceed");
     bank0.freeze();
     Ok(())
@@ -706,6 +706,8 @@ fn process_pending_slots(
     let mut last_status_report = Instant::now();
     let mut pending_slots = vec![];
     let mut last_root_slot = root_bank.slot();
+    let mut slots_elapsed = 0;
+    let mut txs = 0;
     process_next_slots(
         root_bank,
         root_meta,
@@ -720,19 +722,28 @@ fn process_pending_slots(
         let (meta, bank, last_entry_hash) = pending_slots.pop().unwrap();
         let slot = bank.slot();
         if last_status_report.elapsed() > Duration::from_secs(2) {
+            let secs = last_status_report.elapsed().as_secs() as f32;
             info!(
-                "processing ledger: slot={}, last root slot={}",
+                "processing ledger: slot={}, last root slot={} slots={} slots/s={:?} txs/s={}",
-                slot, last_root_slot
+                slot,
+                last_root_slot,
+                slots_elapsed,
+                slots_elapsed as f32 / secs,
+                txs as f32 / secs,
             );
             last_status_report = Instant::now();
+            slots_elapsed = 0;
+            txs = 0;
         }
 
         let allocated = thread_mem_usage::Allocatedp::default();
         let initial_allocation = allocated.get();
 
-        if process_single_slot(blockstore, &bank, &last_entry_hash, opts, recyclers).is_err() {
+        let mut progress = ConfirmationProgress::new(last_entry_hash);
+        if process_single_slot(blockstore, &bank, opts, recyclers, &mut progress).is_err() {
             continue;
         }
+        txs += progress.num_txs;
 
         if blockstore.is_root(slot) {
             let parents = bank.parents().into_iter().map(|b| b.slot()).rev().skip(1);
@@ -745,6 +756,7 @@ fn process_pending_slots(
             fork_info.clear();
             last_root_slot = slot;
         }
+        slots_elapsed += 1;
 
         trace!(
             "Bank for {}slot {} is complete. {} bytes allocated",
@@ -775,13 +787,13 @@ fn process_pending_slots(
 fn process_single_slot(
     blockstore: &Blockstore,
     bank: &Arc<Bank>,
-    last_entry_hash: &Hash,
     opts: &ProcessOptions,
     recyclers: &VerifyRecyclers,
+    progress: &mut ConfirmationProgress,
 ) -> result::Result<(), BlockstoreProcessorError> {
     // Mark corrupt slots as dead so validators don't replay this slot and
     // see DuplicateSignature errors later in ReplayStage
-    confirm_full_slot(blockstore, bank, last_entry_hash, opts, recyclers).map_err(|err| {
+    confirm_full_slot(blockstore, bank, opts, recyclers, progress).map_err(|err| {
         let slot = bank.slot();
         blockstore
             .set_dead_slot(slot)
@@ -2441,9 +2453,9 @@ pub mod tests {
         confirm_full_slot(
             &blockstore,
             &bank1,
-            &bank0.last_blockhash(),
             &opts,
             &recyclers,
+            &mut ConfirmationProgress::new(bank0.last_blockhash()),
         )
         .unwrap();
         bank1.squash();