ConsumeWorker: collect and report bank waiting times (#477)

core/src/banking_stage/consume_worker.rs

@@ -5,6 +5,7 @@ use {
         scheduler_messages::{ConsumeWork, FinishedConsumeWork},
     },
     crossbeam_channel::{Receiver, RecvError, SendError, Sender},
+    solana_measure::measure_us,
     solana_poh::leader_bank_notifier::LeaderBankNotifier,
     solana_runtime::bank::Bank,
     solana_sdk::timing::AtomicInterval,
@@ -65,15 +66,33 @@ impl ConsumeWorker {
     }
 
     fn consume_loop(&self, work: ConsumeWork) -> Result<(), ConsumeWorkerError> {
-        let Some(mut bank) = self.get_consume_bank() else {
+        let (maybe_consume_bank, get_bank_us) = measure_us!(self.get_consume_bank());
+        let Some(mut bank) = maybe_consume_bank else {
+            self.metrics
+                .timing_metrics
+                .wait_for_bank_failure_us
+                .fetch_add(get_bank_us, Ordering::Relaxed);
             return self.retry_drain(work);
         };
+        self.metrics
+            .timing_metrics
+            .wait_for_bank_success_us
+            .fetch_add(get_bank_us, Ordering::Relaxed);
 
         for work in try_drain_iter(work, &self.consume_receiver) {
             if bank.is_complete() {
-                if let Some(new_bank) = self.get_consume_bank() {
+                let (maybe_new_bank, get_bank_us) = measure_us!(self.get_consume_bank());
+                if let Some(new_bank) = maybe_new_bank {
+                    self.metrics
+                        .timing_metrics
+                        .wait_for_bank_success_us
+                        .fetch_add(get_bank_us, Ordering::Relaxed);
                     bank = new_bank;
                 } else {
+                    self.metrics
+                        .timing_metrics
+                        .wait_for_bank_failure_us
+                        .fetch_add(get_bank_us, Ordering::Relaxed);
                     return self.retry_drain(work);
                 }
             }
@@ -471,6 +490,8 @@ struct ConsumeWorkerTimingMetrics {
     record_us: AtomicU64,
     commit_us: AtomicU64,
     find_and_send_votes_us: AtomicU64,
+    wait_for_bank_success_us: AtomicU64,
+    wait_for_bank_failure_us: AtomicU64,
 }
 
 impl ConsumeWorkerTimingMetrics {
@@ -510,6 +531,16 @@ impl ConsumeWorkerTimingMetrics {
                 self.find_and_send_votes_us.swap(0, Ordering::Relaxed),
                 i64
             ),
+            (
+                "wait_for_bank_success_us",
+                self.wait_for_bank_success_us.swap(0, Ordering::Relaxed),
+                i64
+            ),
+            (
+                "wait_for_bank_failure_us",
+                self.wait_for_bank_failure_us.swap(0, Ordering::Relaxed),
+                i64
+            ),
         );
     }
 }