Refactor ExecuteTimings w/ enum-indexed array (#23085)

This commit is contained in:
Gavin Chan
2022-02-22 16:46:56 -06:00
committed by GitHub
parent 5766567e9f
commit 20d031e2b8
7 changed files with 138 additions and 33 deletions

1
Cargo.lock generated
View File

@ -5701,6 +5701,7 @@ version = "1.10.0"
dependencies = [ dependencies = [
"base64 0.13.0", "base64 0.13.0",
"bincode", "bincode",
"enum-iterator",
"itertools 0.10.3", "itertools 0.10.3",
"libc", "libc",
"libloading", "libloading",

View File

@ -1,3 +1,6 @@
use solana_program_runtime::timings::ExecuteTimingType;
use std::ops::Index;
use { use {
crate::{ crate::{
cluster_info_vote_listener::SlotVoteTracker, cluster_info_vote_listener::SlotVoteTracker,
@ -62,23 +65,60 @@ impl ReplaySlotStats {
), ),
("total_entries", num_entries as i64, i64), ("total_entries", num_entries as i64, i64),
("total_shreds", num_shreds as i64, i64), ("total_shreds", num_shreds as i64, i64),
("check_us", self.execute_timings.check_us, i64), (
("load_us", self.execute_timings.load_us, i64), "check_us",
("execute_us", self.execute_timings.execute_us, i64), *self
("store_us", self.execute_timings.store_us, i64), .execute_timings
.metrics
.index(ExecuteTimingType::CheckUs),
i64
),
(
"load_us",
*self
.execute_timings
.metrics
.index(ExecuteTimingType::LoadUs),
i64
),
(
"execute_us",
*self
.execute_timings
.metrics
.index(ExecuteTimingType::ExecuteUs),
i64
),
(
"store_us",
*self
.execute_timings
.metrics
.index(ExecuteTimingType::StoreUs),
i64
),
( (
"update_stakes_cache_us", "update_stakes_cache_us",
self.execute_timings.update_stakes_cache_us, *self
.execute_timings
.metrics
.index(ExecuteTimingType::UpdateStakesCacheUs),
i64 i64
), ),
( (
"total_batches_len", "total_batches_len",
self.execute_timings.total_batches_len, *self
.execute_timings
.metrics
.index(ExecuteTimingType::TotalBatchesLen),
i64 i64
), ),
( (
"num_execute_batches", "num_execute_batches",
self.execute_timings.num_execute_batches, *self
.execute_timings
.metrics
.index(ExecuteTimingType::NumExecuteBatches),
i64 i64
), ),
( (

View File

@ -1,3 +1,5 @@
use solana_program_runtime::timings::ExecuteTimingType;
use { use {
crate::{ crate::{
block_error::BlockError, blockstore::Blockstore, blockstore_db::BlockstoreError, block_error::BlockError, blockstore::Blockstore, blockstore_db::BlockstoreError,
@ -283,8 +285,8 @@ fn execute_batches_internal(
}) })
}); });
timings.total_batches_len += batches.len(); timings.saturating_add_in_place(ExecuteTimingType::TotalBatchesLen, batches.len() as u64);
timings.num_execute_batches += 1; timings.saturating_add_in_place(ExecuteTimingType::NumExecuteBatches, 1);
for timing in new_timings { for timing in new_timings {
timings.accumulate(&timing); timings.accumulate(&timing);
} }

View File

@ -24,6 +24,7 @@ solana-frozen-abi-macro = { path = "../frozen-abi/macro", version = "=1.10.0" }
solana-measure = { path = "../measure", version = "=1.10.0" } solana-measure = { path = "../measure", version = "=1.10.0" }
solana-sdk = { path = "../sdk", version = "=1.10.0" } solana-sdk = { path = "../sdk", version = "=1.10.0" }
thiserror = "1.0" thiserror = "1.0"
enum-iterator = "0.7.0"
[dev-dependencies] [dev-dependencies]
solana-logger = { path = "../logger", version = "=1.10.0" } solana-logger = { path = "../logger", version = "=1.10.0" }

View File

@ -1,3 +1,7 @@
use core::fmt;
use enum_iterator::IntoEnumIterator;
use std::ops::{Index, IndexMut};
use { use {
solana_sdk::{pubkey::Pubkey, saturating_add_assign}, solana_sdk::{pubkey::Pubkey, saturating_add_assign},
std::collections::HashMap, std::collections::HashMap,
@ -34,34 +38,73 @@ impl ProgramTiming {
} }
} }
#[derive(Default, Debug)] /// Used as an index for `Metrics`.
#[derive(Debug, IntoEnumIterator)]
pub enum ExecuteTimingType {
CheckUs,
LoadUs,
ExecuteUs,
StoreUs,
UpdateStakesCacheUs,
NumExecuteBatches,
CollectLogsUs,
TotalBatchesLen,
}
pub struct Metrics([u64; ExecuteTimingType::VARIANT_COUNT]);
impl Index<ExecuteTimingType> for Metrics {
type Output = u64;
fn index(&self, index: ExecuteTimingType) -> &Self::Output {
self.0.index(index as usize)
}
}
impl IndexMut<ExecuteTimingType> for Metrics {
fn index_mut(&mut self, index: ExecuteTimingType) -> &mut Self::Output {
self.0.index_mut(index as usize)
}
}
impl Default for Metrics {
fn default() -> Self {
Metrics([0; ExecuteTimingType::VARIANT_COUNT])
}
}
impl core::fmt::Debug for Metrics {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
self.0.fmt(f)
}
}
#[derive(Debug, Default)]
pub struct ExecuteTimings { pub struct ExecuteTimings {
pub check_us: u64, pub metrics: Metrics,
pub load_us: u64,
pub execute_us: u64,
pub store_us: u64,
pub update_stakes_cache_us: u64,
pub total_batches_len: usize,
pub num_execute_batches: u64,
pub collect_logs_us: u64,
pub details: ExecuteDetailsTimings, pub details: ExecuteDetailsTimings,
pub execute_accessories: ExecuteAccessoryTimings, pub execute_accessories: ExecuteAccessoryTimings,
} }
impl ExecuteTimings { impl ExecuteTimings {
pub fn accumulate(&mut self, other: &ExecuteTimings) { pub fn accumulate(&mut self, other: &ExecuteTimings) {
saturating_add_assign!(self.check_us, other.check_us); for (t1, t2) in self.metrics.0.iter_mut().zip(other.metrics.0.iter()) {
saturating_add_assign!(self.load_us, other.load_us); saturating_add_assign!(*t1, *t2);
saturating_add_assign!(self.execute_us, other.execute_us); }
saturating_add_assign!(self.store_us, other.store_us);
saturating_add_assign!(self.update_stakes_cache_us, other.update_stakes_cache_us);
saturating_add_assign!(self.total_batches_len, other.total_batches_len);
saturating_add_assign!(self.num_execute_batches, other.num_execute_batches);
saturating_add_assign!(self.collect_logs_us, other.collect_logs_us);
self.details.accumulate(&other.details); self.details.accumulate(&other.details);
self.execute_accessories self.execute_accessories
.accumulate(&other.execute_accessories); .accumulate(&other.execute_accessories);
} }
pub fn saturating_add_in_place(&mut self, timing_type: ExecuteTimingType, value_to_add: u64) {
let idx = timing_type as usize;
match self.metrics.0.get_mut(idx) {
Some(elem) => *elem = elem.saturating_add(value_to_add),
None => debug_assert!(
idx < ExecuteTimingType::VARIANT_COUNT,
"Index out of bounds"
),
}
}
} }
#[derive(Default, Debug)] #[derive(Default, Debug)]
@ -275,4 +318,16 @@ mod tests {
// Check that the two instances are equal // Check that the two instances are equal
assert_eq!(execute_details_timings, other_execute_details_timings); assert_eq!(execute_details_timings, other_execute_details_timings);
} }
#[test]
fn execute_timings_saturating_add_in_place() {
let mut timings = ExecuteTimings::default();
timings.saturating_add_in_place(ExecuteTimingType::CheckUs, 1);
let check_us = timings.metrics.index(ExecuteTimingType::CheckUs);
assert_eq!(1, *check_us);
timings.saturating_add_in_place(ExecuteTimingType::CheckUs, 2);
let check_us = timings.metrics.index(ExecuteTimingType::CheckUs);
assert_eq!(3, *check_us);
}
} }

View File

@ -3445,6 +3445,7 @@ version = "1.10.0"
dependencies = [ dependencies = [
"base64 0.13.0", "base64 0.13.0",
"bincode", "bincode",
"enum-iterator",
"itertools 0.10.3", "itertools 0.10.3",
"libc", "libc",
"libloading", "libloading",

View File

@ -33,6 +33,7 @@
//! It offers a high-level API that signs transactions //! It offers a high-level API that signs transactions
//! on behalf of the caller, and a low-level API for when they have //! on behalf of the caller, and a low-level API for when they have
//! already been signed and verified. //! already been signed and verified.
use solana_program_runtime::timings::ExecuteTimingType;
#[allow(deprecated)] #[allow(deprecated)]
use solana_sdk::recent_blockhashes_account; use solana_sdk::recent_blockhashes_account;
use { use {
@ -4066,9 +4067,10 @@ impl Bank {
execution_time.as_us(), execution_time.as_us(),
sanitized_txs.len(), sanitized_txs.len(),
); );
timings.check_us = timings.check_us.saturating_add(check_time.as_us());
timings.load_us = timings.load_us.saturating_add(load_time.as_us()); timings.saturating_add_in_place(ExecuteTimingType::CheckUs, check_time.as_us());
timings.execute_us = timings.execute_us.saturating_add(execution_time.as_us()); timings.saturating_add_in_place(ExecuteTimingType::LoadUs, load_time.as_us());
timings.saturating_add_in_place(ExecuteTimingType::ExecuteUs, execution_time.as_us());
let mut executed_transactions_count: usize = 0; let mut executed_transactions_count: usize = 0;
let mut executed_with_successful_result_count: usize = 0; let mut executed_with_successful_result_count: usize = 0;
@ -4411,10 +4413,13 @@ impl Bank {
write_time.as_us(), write_time.as_us(),
sanitized_txs.len() sanitized_txs.len()
); );
timings.store_us = timings.store_us.saturating_add(write_time.as_us());
timings.update_stakes_cache_us = timings timings.saturating_add_in_place(ExecuteTimingType::StoreUs, write_time.as_us());
.update_stakes_cache_us timings.saturating_add_in_place(
.saturating_add(update_stakes_cache_time.as_us()); ExecuteTimingType::UpdateStakesCacheUs,
update_stakes_cache_time.as_us(),
);
self.update_transaction_statuses(sanitized_txs, &execution_results); self.update_transaction_statuses(sanitized_txs, &execution_results);
let fee_collection_results = let fee_collection_results =
self.filter_program_errors_and_collect_fee(sanitized_txs, &execution_results); self.filter_program_errors_and_collect_fee(sanitized_txs, &execution_results);