Add timing for accounts add_root (#21379)

runtime/src/accounts.rs

@@ -1,8 +1,8 @@
 use crate::{
     accounts_db::{
-        AccountShrinkThreshold, AccountsDb, AccountsDbConfig, BankHashInfo, ErrorCounters,
-        LoadHint, LoadedAccount, ScanStorageResult, ACCOUNTS_DB_CONFIG_FOR_BENCHMARKS,
-        ACCOUNTS_DB_CONFIG_FOR_TESTING,
+        AccountShrinkThreshold, AccountsAddRootTiming, AccountsDb, AccountsDbConfig, BankHashInfo,
+        ErrorCounters, LoadHint, LoadedAccount, ScanStorageResult,
+        ACCOUNTS_DB_CONFIG_FOR_BENCHMARKS, ACCOUNTS_DB_CONFIG_FOR_TESTING,
     },
     accounts_index::{AccountSecondaryIndexes, IndexKey, ScanConfig, ScanError, ScanResult},
     accounts_update_notifier_interface::AccountsUpdateNotifier,
@@ -1051,7 +1051,7 @@ impl Accounts {
     }
 
     /// Add a slot to root.  Root slots cannot be purged
-    pub fn add_root(&self, slot: Slot) {
+    pub fn add_root(&self, slot: Slot) -> AccountsAddRootTiming {
         self.accounts_db.add_root(slot)
     }
 

runtime/src/accounts_db.rs

@@ -140,6 +140,12 @@ pub const ACCOUNTS_DB_CONFIG_FOR_BENCHMARKS: AccountsDbConfig = AccountsDbConfig
 
 pub type BinnedHashData = Vec<Vec<CalculateHashIntermediate>>;
 
+pub struct AccountsAddRootTiming {
+    pub index_us: u64,
+    pub cache_us: u64,
+    pub store_us: u64,
+}
+
 #[derive(Debug, Default, Clone)]
 pub struct AccountsDbConfig {
     pub index: Option<AccountsIndexConfig>,
@@ -6545,16 +6551,28 @@ impl AccountsDb {
         }
     }
 
-    pub fn add_root(&self, slot: Slot) {
+    pub fn add_root(&self, slot: Slot) -> AccountsAddRootTiming {
+        let mut index_time = Measure::start("index_add_root");
         self.accounts_index.add_root(slot, self.caching_enabled);
+        index_time.stop();
+        let mut cache_time = Measure::start("cache_add_root");
         if self.caching_enabled {
             self.accounts_cache.add_root(slot);
         }
+        cache_time.stop();
+        let mut store_time = Measure::start("store_add_root");
         if let Some(slot_stores) = self.storage.get_slot_stores(slot) {
             for (store_id, store) in slot_stores.read().unwrap().iter() {
                 self.dirty_stores.insert((slot, *store_id), store.clone());
             }
         }
+        store_time.stop();
+
+        AccountsAddRootTiming {
+            index_us: index_time.as_us(),
+            cache_us: cache_time.as_us(),
+            store_us: store_time.as_us(),
+        }
     }
 
     pub fn get_snapshot_storages(

runtime/src/bank.rs

@@ -253,6 +253,10 @@ type RentCollectionCycleParams = (
 
 pub struct SquashTiming {
     pub squash_accounts_ms: u64,
+    pub squash_accounts_cache_ms: u64,
+    pub squash_accounts_index_ms: u64,
+    pub squash_accounts_store_ms: u64,
+
     pub squash_cache_ms: u64,
 }
 
@@ -2949,10 +2953,17 @@ impl Bank {
         let mut roots = vec![self.slot()];
         roots.append(&mut self.parents().iter().map(|p| p.slot()).collect());
 
+        let mut total_index_us = 0;
+        let mut total_cache_us = 0;
+        let mut total_store_us = 0;
+
         let mut squash_accounts_time = Measure::start("squash_accounts_time");
         for slot in roots.iter().rev() {
             // root forks cannot be purged
-            self.rc.accounts.add_root(*slot);
+            let add_root_timing = self.rc.accounts.add_root(*slot);
+            total_index_us += add_root_timing.index_us;
+            total_cache_us += add_root_timing.cache_us;
+            total_store_us += add_root_timing.store_us;
         }
         squash_accounts_time.stop();
 
@@ -2966,6 +2977,10 @@ impl Bank {
 
         SquashTiming {
             squash_accounts_ms: squash_accounts_time.as_ms(),
+            squash_accounts_index_ms: total_index_us / 1000,
+            squash_accounts_cache_ms: total_cache_us / 1000,
+            squash_accounts_store_ms: total_store_us / 1000,
+
             squash_cache_ms: squash_cache_time.as_ms(),
         }
     }

runtime/src/bank_forks.rs

@@ -19,6 +19,9 @@ struct SetRootTimings {
     total_parent_banks: i64,
     total_squash_cache_ms: i64,
     total_squash_accounts_ms: i64,
+    total_squash_accounts_index_ms: i64,
+    total_squash_accounts_cache_ms: i64,
+    total_squash_accounts_store_ms: i64,
     total_snapshot_ms: i64,
     tx_count: i64,
     prune_non_rooted_ms: i64,
@@ -226,6 +229,9 @@ impl BankForks {
         banks.extend(parents.iter());
         let total_parent_banks = banks.len();
         let mut total_squash_accounts_ms = 0;
+        let mut total_squash_accounts_index_ms = 0;
+        let mut total_squash_accounts_cache_ms = 0;
+        let mut total_squash_accounts_store_ms = 0;
         let mut total_squash_cache_ms = 0;
         let mut total_snapshot_ms = 0;
         for bank in banks.iter() {
@@ -236,6 +242,9 @@ impl BankForks {
                 self.last_accounts_hash_slot = bank_slot;
                 let squash_timing = bank.squash();
                 total_squash_accounts_ms += squash_timing.squash_accounts_ms as i64;
+                total_squash_accounts_index_ms += squash_timing.squash_accounts_index_ms as i64;
+                total_squash_accounts_cache_ms += squash_timing.squash_accounts_cache_ms as i64;
+                total_squash_accounts_store_ms += squash_timing.squash_accounts_store_ms as i64;
                 total_squash_cache_ms += squash_timing.squash_cache_ms as i64;
                 is_root_bank_squashed = bank_slot == root;
 
@@ -268,6 +277,9 @@ impl BankForks {
         if !is_root_bank_squashed {
             let squash_timing = root_bank.squash();
             total_squash_accounts_ms += squash_timing.squash_accounts_ms as i64;
+            total_squash_accounts_index_ms += squash_timing.squash_accounts_index_ms as i64;
+            total_squash_accounts_cache_ms += squash_timing.squash_accounts_cache_ms as i64;
+            total_squash_accounts_store_ms += squash_timing.squash_accounts_store_ms as i64;
             total_squash_cache_ms += squash_timing.squash_cache_ms as i64;
         }
         let new_tx_count = root_bank.transaction_count();
@@ -287,6 +299,9 @@ impl BankForks {
                 total_parent_banks: total_parent_banks as i64,
                 total_squash_cache_ms,
                 total_squash_accounts_ms,
+                total_squash_accounts_index_ms,
+                total_squash_accounts_cache_ms,
+                total_squash_accounts_store_ms,
                 total_snapshot_ms,
                 tx_count: (new_tx_count - root_tx_count) as i64,
                 prune_non_rooted_ms: prune_time.as_ms() as i64,
@@ -334,6 +349,21 @@ impl BankForks {
                 set_root_metrics.total_squash_accounts_ms,
                 i64
             ),
+            (
+                "total_squash_accounts_index_ms",
+                set_root_metrics.total_squash_accounts_index_ms,
+                i64
+            ),
+            (
+                "total_squash_accounts_cache_ms",
+                set_root_metrics.total_squash_accounts_cache_ms,
+                i64
+            ),
+            (
+                "total_squash_accounts_store_ms",
+                set_root_metrics.total_squash_accounts_store_ms,
+                i64
+            ),
             ("total_snapshot_ms", set_root_metrics.total_snapshot_ms, i64),
             ("tx_count", set_root_metrics.tx_count, i64),
             (