Skip to content

Commit

Permalink
Refactor ExecuteTimings w/ enum-indexed array (solana-labs#23085)
Browse files Browse the repository at this point in the history
  • Loading branch information
Gavin Chan authored and jeffwashington committed Mar 4, 2022
1 parent 3e8012f commit 4ac25a9
Show file tree
Hide file tree
Showing 7 changed files with 138 additions and 33 deletions.
1 change: 1 addition & 0 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

54 changes: 47 additions & 7 deletions core/src/progress_map.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,6 @@
use solana_program_runtime::timings::ExecuteTimingType;
use std::ops::Index;

use {
crate::{
cluster_info_vote_listener::SlotVoteTracker,
Expand Down Expand Up @@ -68,23 +71,60 @@ impl ReplaySlotStats {
),
("total_entries", num_entries 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),
("execute_us", self.execute_timings.execute_us, i64),
("store_us", self.execute_timings.store_us, i64),
(
"check_us",
*self
.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",
self.execute_timings.update_stakes_cache_us,
*self
.execute_timings
.metrics
.index(ExecuteTimingType::UpdateStakesCacheUs),
i64
),
(
"total_batches_len",
self.execute_timings.total_batches_len,
*self
.execute_timings
.metrics
.index(ExecuteTimingType::TotalBatchesLen),
i64
),
(
"num_execute_batches",
self.execute_timings.num_execute_batches,
*self
.execute_timings
.metrics
.index(ExecuteTimingType::NumExecuteBatches),
i64
),
(
Expand Down
6 changes: 4 additions & 2 deletions ledger/src/blockstore_processor.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,5 @@
use solana_program_runtime::timings::ExecuteTimingType;

use {
crate::{
block_error::BlockError, blockstore::Blockstore, blockstore_db::BlockstoreError,
Expand Down Expand Up @@ -283,8 +285,8 @@ fn execute_batches_internal(
})
});

timings.total_batches_len += batches.len();
timings.num_execute_batches += 1;
timings.saturating_add_in_place(ExecuteTimingType::TotalBatchesLen, batches.len() as u64);
timings.saturating_add_in_place(ExecuteTimingType::NumExecuteBatches, 1);
for timing in new_timings {
timings.accumulate(&timing);
}
Expand Down
1 change: 1 addition & 0 deletions program-runtime/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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-sdk = { path = "../sdk", version = "=1.10.0" }
thiserror = "1.0"
enum-iterator = "0.7.0"

[dev-dependencies]
solana-logger = { path = "../logger", version = "=1.10.0" }
Expand Down
89 changes: 72 additions & 17 deletions program-runtime/src/timings.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,7 @@
use core::fmt;
use enum_iterator::IntoEnumIterator;
use std::ops::{Index, IndexMut};

use {
solana_sdk::{pubkey::Pubkey, saturating_add_assign},
std::collections::HashMap,
Expand Down Expand Up @@ -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 check_us: u64,
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 metrics: Metrics,
pub details: ExecuteDetailsTimings,
pub execute_accessories: ExecuteAccessoryTimings,
}

impl ExecuteTimings {
pub fn accumulate(&mut self, other: &ExecuteTimings) {
saturating_add_assign!(self.check_us, other.check_us);
saturating_add_assign!(self.load_us, other.load_us);
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);
for (t1, t2) in self.metrics.0.iter_mut().zip(other.metrics.0.iter()) {
saturating_add_assign!(*t1, *t2);
}
self.details.accumulate(&other.details);
self.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)]
Expand Down Expand Up @@ -275,4 +318,16 @@ mod tests {
// Check that the two instances are equal
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);
}
}
1 change: 1 addition & 0 deletions programs/bpf/Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

19 changes: 12 additions & 7 deletions runtime/src/bank.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
//! It offers a high-level API that signs transactions
//! on behalf of the caller, and a low-level API for when they have
//! already been signed and verified.
use solana_program_runtime::timings::ExecuteTimingType;
#[allow(deprecated)]
use solana_sdk::recent_blockhashes_account;
use {
Expand Down Expand Up @@ -4078,9 +4079,10 @@ impl Bank {
execution_time.as_us(),
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.execute_us = timings.execute_us.saturating_add(execution_time.as_us());

timings.saturating_add_in_place(ExecuteTimingType::CheckUs, check_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_with_successful_result_count: usize = 0;
Expand Down Expand Up @@ -4423,10 +4425,13 @@ impl Bank {
write_time.as_us(),
sanitized_txs.len()
);
timings.store_us = timings.store_us.saturating_add(write_time.as_us());
timings.update_stakes_cache_us = timings
.update_stakes_cache_us
.saturating_add(update_stakes_cache_time.as_us());

timings.saturating_add_in_place(ExecuteTimingType::StoreUs, write_time.as_us());
timings.saturating_add_in_place(
ExecuteTimingType::UpdateStakesCacheUs,
update_stakes_cache_time.as_us(),
);

self.update_transaction_statuses(sanitized_txs, &execution_results);
let fee_collection_results =
self.filter_program_errors_and_collect_fee(sanitized_txs, &execution_results);
Expand Down

0 comments on commit 4ac25a9

Please sign in to comment.