From 6130466a21831056710ddb5bb60cc531605b9fae Mon Sep 17 00:00:00 2001
From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com>
Date: Sat, 8 Jan 2022 02:19:36 +0000
Subject: [PATCH] Executor cache metrics (backport #22332) (#22367)

* Add helper macro for `AddAssign`ing with saturating arithmetic

* bank: Add executors cache metrics

Co-authored-by: Trent Nelson <trent@solana.com>
---
 runtime/src/bank.rs | 66 +++++++++++++++++++++++++++++++++++++++++++++
 sdk/src/lib.rs      | 24 +++++++++++++++++
 2 files changed, 90 insertions(+)

diff --git a/runtime/src/bank.rs b/runtime/src/bank.rs
index 38e3387467ab41..f5a2f6f8312d25 100644
--- a/runtime/src/bank.rs
+++ b/runtime/src/bank.rs
@@ -110,6 +110,7 @@ use {
         pubkey::Pubkey,
         recent_blockhashes_account,
         sanitize::Sanitize,
+        saturating_add_assign,
         signature::{Keypair, Signature},
         slot_hashes::SlotHashes,
         slot_history::SlotHistory,
@@ -292,6 +293,52 @@ impl AbiExample for Builtin {
     }
 }
 
+mod executor_cache {
+    use super::*;
+
+    #[derive(Debug, Default)]
+    pub struct Stats {
+        pub hits: u64,
+        pub misses: u64,
+        pub evictions: HashMap<Pubkey, u64>,
+    }
+
+    impl Stats {
+        pub fn submit(&self, slot: Slot) {
+            let evictions: u64 = self.evictions.values().sum();
+            datapoint_info!(
+                "bank-executor-cache-stats",
+                ("slot", slot, i64),
+                ("hits", self.hits, i64),
+                ("misses", self.misses, i64),
+                ("evictions", evictions, i64),
+            );
+            debug!(
+                "Executor Cache Stats -- Hits: {}, Misses: {}, Evictions: {}",
+                self.hits, self.misses, evictions
+            );
+            if log_enabled!(log::Level::Trace) && !self.evictions.is_empty() {
+                let mut evictions = self.evictions.iter().collect::<Vec<_>>();
+                evictions.sort_by_key(|e| e.1);
+                let evictions = evictions
+                    .into_iter()
+                    .rev()
+                    .map(|(program_id, evictions)| {
+                        format!("  {:<44}  {}", program_id.to_string(), evictions)
+                    })
+                    .collect::<Vec<_>>();
+                let evictions = evictions.join("\n");
+                trace!(
+                    "Eviction Details:\n  {:<44}  {}\n{}",
+                    "Program",
+                    "Count",
+                    evictions
+                );
+            }
+        }
+    }
+}
+
 #[derive(Clone, Debug)]
 pub struct Builtins {
     /// Builtin programs that are always available
@@ -314,6 +361,7 @@ struct CachedExecutors {
     max: usize,
     current_epoch: Epoch,
     executors: HashMap<Pubkey, CachedExecutorsEntry>,
+    stats: executor_cache::Stats,
 }
 impl Default for CachedExecutors {
     fn default() -> Self {
@@ -321,6 +369,7 @@ impl Default for CachedExecutors {
             max: MAX_CACHED_EXECUTORS,
             current_epoch: Epoch::default(),
             executors: HashMap::default(),
+            stats: executor_cache::Stats::default(),
         }
     }
 }
@@ -349,6 +398,7 @@ impl Clone for CachedExecutors {
             max: self.max,
             current_epoch: self.current_epoch,
             executors: executors.collect(),
+            stats: executor_cache::Stats::default(),
         }
     }
 }
@@ -372,6 +422,7 @@ impl CachedExecutors {
             max: self.max,
             current_epoch: epoch,
             executors: executors.collect(),
+            stats: executor_cache::Stats::default(),
         })
     }
 
@@ -380,6 +431,7 @@ impl CachedExecutors {
             max,
             current_epoch,
             executors: HashMap::new(),
+            stats: executor_cache::Stats::default(),
         }
     }
 
@@ -392,9 +444,11 @@ impl CachedExecutors {
 
     fn put(&mut self, pubkey: &Pubkey, executor: Arc<dyn Executor>) {
         let entry = if let Some(mut entry) = self.executors.remove(pubkey) {
+            saturating_add_assign!(self.stats.hits, 1);
             entry.executor = executor;
             entry
         } else {
+            saturating_add_assign!(self.stats.misses, 1);
             if self.executors.len() >= self.max {
                 let mut least = u64::MAX;
                 let default_key = Pubkey::default();
@@ -409,6 +463,11 @@ impl CachedExecutors {
                 }
                 let least_key = *least_key;
                 let _ = self.executors.remove(&least_key);
+                self.stats
+                    .evictions
+                    .entry(least_key)
+                    .and_modify(|c| saturating_add_assign!(*c, 1))
+                    .or_insert(1);
             }
             CachedExecutorsEntry {
                 prev_epoch_count: 0,
@@ -1381,6 +1440,13 @@ impl Bank {
             ("time_us", time.as_us(), i64),
         );
 
+        parent
+            .cached_executors
+            .read()
+            .unwrap()
+            .stats
+            .submit(parent.slot());
+
         new
     }
 
diff --git a/sdk/src/lib.rs b/sdk/src/lib.rs
index f11d04c04ce696..6a3a70948242ca 100644
--- a/sdk/src/lib.rs
+++ b/sdk/src/lib.rs
@@ -103,6 +103,15 @@ macro_rules! program_stubs {
     () => {};
 }
 
+/// Convenience macro for `AddAssign` with saturating arithmetic.
+/// Replace by `std::num::Saturating` once stable
+#[macro_export]
+macro_rules! saturating_add_assign {
+    ($i:expr, $v:expr) => {{
+        $i = $i.saturating_add($v)
+    }};
+}
+
 #[macro_use]
 extern crate serde_derive;
 pub extern crate bs58;
@@ -110,3 +119,18 @@ extern crate log as logger;
 
 #[macro_use]
 extern crate solana_frozen_abi_macro;
+
+#[cfg(test)]
+mod tests {
+    #[test]
+    fn test_saturating_add_assign() {
+        let mut i = 0u64;
+        let v = 1;
+        saturating_add_assign!(i, v);
+        assert_eq!(i, 1);
+
+        i = u64::MAX;
+        saturating_add_assign!(i, v);
+        assert_eq!(i, u64::MAX);
+    }
+}