Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Refactor Execute Timings to use an enum-indexed array structure #23085

Merged
merged 1 commit into from
Feb 22, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
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 @@ -62,23 +65,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;
jackcmay marked this conversation as resolved.
Show resolved Hide resolved
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 @@ -274,4 +317,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 @@ -4037,9 +4038,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 @@ -4320,10 +4322,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