From 002693ab7dfbca69074f9d131dcd37b3ba03be96 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Wed, 24 Nov 2021 16:00:45 +0000 Subject: [PATCH] Add timing for accounts add_root (backport #21379) (#21391) * Add timing for accounts add_root (#21379) (cherry picked from commit c4d68063c77a661151c77ec66f861ca9669f247f) # Conflicts: # runtime/src/accounts.rs # runtime/src/accounts_db.rs * Resolve conflicts Co-authored-by: sakridge Co-authored-by: Carl Lin --- runtime/src/accounts.rs | 6 +++--- runtime/src/accounts_db.rs | 20 +++++++++++++++++++- runtime/src/bank.rs | 17 ++++++++++++++++- runtime/src/bank_forks.rs | 30 ++++++++++++++++++++++++++++++ 4 files changed, 68 insertions(+), 5 deletions(-) diff --git a/runtime/src/accounts.rs b/runtime/src/accounts.rs index ddff6fe7ec..1f61e33303 100644 --- a/runtime/src/accounts.rs +++ b/runtime/src/accounts.rs @@ -1,7 +1,7 @@ use crate::{ accounts_db::{ - AccountShrinkThreshold, AccountsDb, BankHashInfo, ErrorCounters, LoadHint, LoadedAccount, - ScanStorageResult, + AccountShrinkThreshold, AccountsAddRootTiming, AccountsDb, BankHashInfo, ErrorCounters, + LoadHint, LoadedAccount, ScanStorageResult, }, accounts_index::{AccountSecondaryIndexes, IndexKey, ScanResult}, accounts_update_notifier_interface::AccountsUpdateNotifier, @@ -975,7 +975,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) } diff --git a/runtime/src/accounts_db.rs b/runtime/src/accounts_db.rs index b7103a41be..871986fd70 100644 --- a/runtime/src/accounts_db.rs +++ b/runtime/src/accounts_db.rs @@ -104,6 +104,12 @@ const CACHE_VIRTUAL_WRITE_VERSION: StoredMetaWriteVersion = 0; const CACHE_VIRTUAL_OFFSET: usize = 0; const CACHE_VIRTUAL_STORED_SIZE: usize = 0; +pub struct AccountsAddRootTiming { + pub index_us: u64, + pub cache_us: u64, + pub store_us: u64, +} + #[cfg(not(test))] const ABSURD_CONSECUTIVE_FAILED_ITERATIONS: usize = 100; @@ -5793,16 +5799,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( diff --git a/runtime/src/bank.rs b/runtime/src/bank.rs index 2805c285ee..ccd1f0b3bd 100644 --- a/runtime/src/bank.rs +++ b/runtime/src/bank.rs @@ -241,6 +241,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, } @@ -2831,10 +2835,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(); @@ -2848,6 +2859,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(), } } diff --git a/runtime/src/bank_forks.rs b/runtime/src/bank_forks.rs index 1992ca797b..d6d50c6a29 100644 --- a/runtime/src/bank_forks.rs +++ b/runtime/src/bank_forks.rs @@ -52,6 +52,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, @@ -255,6 +258,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() { @@ -265,6 +271,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; @@ -297,6 +306,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(); @@ -316,6 +328,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, @@ -363,6 +378,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), (