Add stats for Accounts Background Service (#26298)

* Add stats for Accounts Background Service

* pr

runtime/src/accounts_background_service.rs

@@ -2,6 +2,7 @@
 //
 // This can be expensive since we have to walk the append vecs being cleaned up.
 
+mod stats;
 use {
     crate::{
         accounts_hash::CalcAccountsHashConfig,
@@ -19,6 +20,7 @@ use {
         clock::{BankId, Slot},
         hash::Hash,
     },
+    stats::StatsManager,
     std::{
         boxed::Box,
         fmt::{Debug, Formatter},
@@ -460,11 +462,13 @@ impl AccountsBackgroundService {
         let t_background = Builder::new()
             .name("solana-bg-accounts".to_string())
             .spawn(move || {
+                let mut stats = StatsManager::new();
                 let mut last_snapshot_end_time = None;
                 loop {
                     if exit.load(Ordering::Relaxed) {
                         break;
                     }
+                    let start_time = Instant::now();
 
                     // Grab the current root bank
                     let bank = bank_forks.read().unwrap().root_bank().clone();
@@ -559,6 +563,7 @@ impl AccountsBackgroundService {
                             last_cleaned_block_height = bank.block_height();
                         }
                     }
+                    stats.record_and_maybe_submit(start_time.elapsed());
                     sleep(Duration::from_millis(INTERVAL_MS));
                 }
             })

runtime/src/accounts_background_service/stats.rs

@@ -0,0 +1,184 @@
+//! Stats for Accounts Background Services
+
+use {
+    solana_metrics::datapoint_info,
+    std::time::{Duration, Instant},
+};
+
+const SUBMIT_INTERVAL: Duration = Duration::from_secs(60);
+
+/// Manage the Accounts Background Service stats
+///
+/// Used to record the stats and submit the datapoints.
+#[derive(Debug)]
+pub(super) struct StatsManager {
+    stats: Stats,
+    previous_submit: Instant,
+}
+
+impl StatsManager {
+    /// Make a new StatsManager
+    #[must_use]
+    pub(super) fn new() -> Self {
+        Self {
+            stats: Stats::default(),
+            previous_submit: Instant::now(),
+        }
+    }
+
+    /// Record stats from this iteration, and maybe submit the datapoints based on how long it has
+    /// been since the previous submission.
+    pub(super) fn record_and_maybe_submit(&mut self, runtime: Duration) {
+        self.stats.record(runtime);
+        self.maybe_submit();
+    }
+
+    /// Maybe submit the datapoints based on how long it has been since the previous submission.
+    fn maybe_submit(&mut self) {
+        let duration_since_previous_submit = Instant::now() - self.previous_submit;
+        if duration_since_previous_submit < SUBMIT_INTERVAL {
+            return;
+        }
+
+        datapoint_info!(
+            "accounts_background_service",
+            (
+                "duration_since_previous_submit-ms",
+                duration_since_previous_submit.as_millis() as i64,
+                i64
+            ),
+            ("num_iterations", self.stats.num_iterations as i64, i64),
+            (
+                "cumulative_runtime-ms",
+                self.stats.cumulative_runtime.as_millis() as i64,
+                i64
+            ),
+            (
+                "mean_runtime-ms",
+                self.stats.mean_runtime().as_millis() as i64,
+                i64
+            ),
+            (
+                "min_runtime-ms",
+                self.stats.min_runtime.as_millis() as i64,
+                i64
+            ),
+            (
+                "max_runtime-ms",
+                self.stats.max_runtime.as_millis() as i64,
+                i64
+            ),
+        );
+
+        // reset the stats back to default
+        *self = Self::new();
+    }
+}
+
+/// Stats for Accounts Background Services
+///
+/// Intended to record stats for each iteration of the ABS main loop.
+#[derive(Debug)]
+struct Stats {
+    /// Number of iterations recorded
+    num_iterations: usize,
+    /// Total runtime of all iterations
+    cumulative_runtime: Duration,
+    /// Minimum runtime seen for one iteration
+    min_runtime: Duration,
+    /// Maximum runtime seen for one iteration
+    max_runtime: Duration,
+}
+
+impl Stats {
+    /// Record stats from this iteration
+    fn record(&mut self, runtime: Duration) {
+        self.num_iterations += 1;
+        self.cumulative_runtime += runtime;
+        self.min_runtime = self.min_runtime.min(runtime);
+        self.max_runtime = self.max_runtime.max(runtime);
+    }
+
+    /// Calculate the mean runtime of all iterations
+    ///
+    /// Requires that the number of iterations recorded is in the range [0, u32::MAX].
+    fn mean_runtime(&self) -> Duration {
+        debug_assert!(self.num_iterations > 0);
+        debug_assert!(self.num_iterations <= u32::MAX as usize);
+        self.cumulative_runtime / self.num_iterations as u32
+    }
+}
+
+impl Default for Stats {
+    #[must_use]
+    fn default() -> Self {
+        Self {
+            num_iterations: 0,
+            cumulative_runtime: Duration::ZERO,
+            min_runtime: Duration::MAX,
+            max_runtime: Duration::ZERO,
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn test_stats_record() {
+        let mut stats = Stats::default();
+
+        // record first stat, will be both min and max
+        let runtime1 = Duration::from_secs(44);
+        stats.record(runtime1);
+        assert_eq!(stats.num_iterations, 1);
+        assert_eq!(stats.cumulative_runtime, runtime1);
+        assert_eq!(stats.min_runtime, runtime1);
+        assert_eq!(stats.max_runtime, runtime1);
+
+        // record a new max
+        let runtime2 = Duration::from_secs(99);
+        stats.record(runtime2);
+        assert_eq!(stats.num_iterations, 2);
+        assert_eq!(stats.cumulative_runtime, runtime1 + runtime2);
+        assert_eq!(stats.min_runtime, runtime1);
+        assert_eq!(stats.max_runtime, runtime2);
+
+        // record a new min
+        let runtime3 = Duration::from_secs(11);
+        stats.record(runtime3);
+        assert_eq!(stats.num_iterations, 3);
+        assert_eq!(stats.cumulative_runtime, runtime1 + runtime2 + runtime3);
+        assert_eq!(stats.min_runtime, runtime3);
+        assert_eq!(stats.max_runtime, runtime2);
+    }
+
+    #[test]
+    fn test_stats_mean_runtime() {
+        let mut stats = Stats::default();
+        stats.record(Duration::from_secs(1));
+        stats.record(Duration::from_secs(3));
+        stats.record(Duration::from_secs(5));
+        stats.record(Duration::from_secs(7));
+        assert_eq!(stats.mean_runtime().as_secs(), (1 + 3 + 5 + 7) / 4);
+    }
+
+    #[test]
+    #[should_panic]
+    fn test_stats_mean_runtime_panic_zero_iterations() {
+        let stats = Stats::default();
+        let _ = stats.mean_runtime();
+    }
+
+    #[test]
+    #[should_panic]
+    fn test_stats_mean_runtime_panic_too_many_iterations() {
+        let num_iterations = u32::MAX as usize + 1;
+        let stats = Stats {
+            num_iterations,
+            ..Stats::default()
+        };
+        let _ = stats.mean_runtime();
+    }
+}