Skip to content

Commit

Permalink
Add end-to-end replay slot metrics (#25752)
Browse files Browse the repository at this point in the history
(cherry picked from commit ce39c14)

# Conflicts:
#	Cargo.lock
#	core/src/progress_map.rs
#	ledger/src/blockstore_processor.rs
#	program-runtime/Cargo.toml
#	programs/bpf/Cargo.lock
  • Loading branch information
carllin authored and mergify[bot] committed Jul 5, 2022
1 parent 64a3242 commit 09010d8
Show file tree
Hide file tree
Showing 10 changed files with 534 additions and 232 deletions.
13 changes: 13 additions & 0 deletions Cargo.lock

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

1 change: 1 addition & 0 deletions core/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ bs58 = "0.4.0"
chrono = { version = "0.4.11", features = ["serde"] }
crossbeam-channel = "0.5"
dashmap = { version = "4.0.2", features = ["rayon", "raw-api"] }
eager = "0.1.0"
etcd-client = { version = "0.8.1", features = ["tls"] }
fs_extra = "1.2.0"
histogram = "0.6.9"
Expand Down
4 changes: 4 additions & 0 deletions core/src/lib.rs
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
#![cfg_attr(RUSTC_WITH_SPECIALIZATION, feature(min_specialization))]
#![allow(clippy::integer_arithmetic)]
#![recursion_limit = "2048"]
//! The `solana` library implements the Solana high-performance blockchain architecture.
//! It includes a full Rust implementation of the architecture (see
//! [Validator](server/struct.Validator.html)) as well as hooks to GPU implementations of its most
Expand Down Expand Up @@ -76,6 +77,9 @@ pub mod voting_service;
pub mod warm_quic_cache_service;
pub mod window_service;

#[macro_use]
extern crate eager;

#[macro_use]
extern crate log;

Expand Down
255 changes: 42 additions & 213 deletions core/src/progress_map.rs
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,13 @@ use {
replay_stage::SUPERMINORITY_THRESHOLD,
},
solana_ledger::blockstore_processor::{ConfirmationProgress, ConfirmationTiming},
<<<<<<< HEAD
solana_program_runtime::timings::ExecuteTimingType,
solana_runtime::{bank::Bank, bank_forks::BankForks, vote_account::VoteAccount},
=======
solana_program_runtime::{report_execute_timings, timings::ExecuteTimingType},
solana_runtime::{bank::Bank, bank_forks::BankForks, vote_account::VoteAccountsHashMap},
>>>>>>> ce39c1402 (Add end-to-end replay slot metrics (#25752))
solana_sdk::{clock::Slot, hash::Hash, pubkey::Pubkey},
std::{
collections::{BTreeMap, HashMap, HashSet},
Expand Down Expand Up @@ -43,219 +48,43 @@ impl ReplaySlotStats {
num_shreds: u64,
bank_complete_time_us: u64,
) {
datapoint_info!(
"replay-slot-stats",
("slot", slot as i64, i64),
("fetch_entries_time", self.fetch_elapsed as i64, i64),
(
"fetch_entries_fail_time",
self.fetch_fail_elapsed as i64,
i64
),
(
"entry_poh_verification_time",
self.poh_verify_elapsed as i64,
i64
),
(
"entry_transaction_verification_time",
self.transaction_verify_elapsed as i64,
i64
),
("replay_time", self.replay_elapsed as i64, i64),
(
"replay_total_elapsed",
self.started.elapsed().as_micros() as i64,
i64
),
("total_entries", num_entries as i64, i64),
("total_shreds", num_shreds as i64, 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
.metrics
.index(ExecuteTimingType::UpdateStakesCacheUs),
i64
),
("bank_complete_time_us", bank_complete_time_us, i64),
(
"total_batches_len",
*self
.execute_timings
.metrics
.index(ExecuteTimingType::TotalBatchesLen),
i64
),
(
"num_execute_batches",
*self
.execute_timings
.metrics
.index(ExecuteTimingType::NumExecuteBatches),
i64
),
(
"execute_details_serialize_us",
self.execute_timings.details.serialize_us,
i64
),
(
"execute_details_create_vm_us",
self.execute_timings.details.create_vm_us,
i64
),
(
"execute_details_execute_inner_us",
self.execute_timings.details.execute_us,
i64
),
(
"execute_details_deserialize_us",
self.execute_timings.details.deserialize_us,
i64
),
(
"execute_details_get_or_create_executor_us",
self.execute_timings.details.get_or_create_executor_us,
i64
),
(
"execute_details_changed_account_count",
self.execute_timings.details.changed_account_count,
i64
),
(
"execute_details_total_account_count",
self.execute_timings.details.total_account_count,
i64
),
(
"execute_details_total_data_size",
self.execute_timings.details.total_data_size,
i64
),
(
"execute_details_data_size_changed",
self.execute_timings.details.data_size_changed,
i64
),
(
"execute_details_create_executor_register_syscalls_us",
self.execute_timings
.details
.create_executor_register_syscalls_us,
i64
),
(
"execute_details_create_executor_load_elf_us",
self.execute_timings.details.create_executor_load_elf_us,
i64
),
(
"execute_details_create_executor_verify_code_us",
self.execute_timings.details.create_executor_verify_code_us,
i64
),
(
"execute_details_create_executor_jit_compile_us",
self.execute_timings.details.create_executor_jit_compile_us,
i64
),
(
"execute_accessories_feature_set_clone_us",
self.execute_timings
.execute_accessories
.feature_set_clone_us,
i64
),
(
"execute_accessories_compute_budget_process_transaction_us",
self.execute_timings
.execute_accessories
.compute_budget_process_transaction_us,
i64
),
(
"execute_accessories_get_executors_us",
self.execute_timings.execute_accessories.get_executors_us,
i64
),
(
"execute_accessories_process_message_us",
self.execute_timings.execute_accessories.process_message_us,
i64
),
(
"execute_accessories_update_executors_us",
self.execute_timings.execute_accessories.update_executors_us,
i64
),
(
"execute_accessories_process_instructions_total_us",
self.execute_timings
.execute_accessories
.process_instructions
.total_us,
i64
),
(
"execute_accessories_process_instructions_verify_caller_us",
self.execute_timings
.execute_accessories
.process_instructions
.verify_caller_us,
i64
),
(
"execute_accessories_process_instructions_process_executable_chain_us",
self.execute_timings
.execute_accessories
.process_instructions
.process_executable_chain_us,
i64
),
(
"execute_accessories_process_instructions_verify_callee_us",
self.execute_timings
.execute_accessories
.process_instructions
.verify_callee_us,
i64
),
);
lazy! {
datapoint_info!(
"replay-slot-stats",
("slot", slot as i64, i64),
("fetch_entries_time", self.fetch_elapsed as i64, i64),
(
"fetch_entries_fail_time",
self.fetch_fail_elapsed as i64,
i64
),
(
"entry_poh_verification_time",
self.poh_verify_elapsed as i64,
i64
),
(
"entry_transaction_verification_time",
self.transaction_verify_elapsed as i64,
i64
),
("replay_time", self.replay_elapsed as i64, i64),
("execute_batches_us", self.execute_batches_us as i64, i64),
(
"replay_total_elapsed",
self.started.elapsed().as_micros() as i64,
i64
),
("bank_complete_time_us", bank_complete_time_us, i64),
("total_entries", num_entries as i64, i64),
("total_shreds", num_shreds as i64, i64),
// Everything inside the `eager!` block will be eagerly expanded before
// evaluation of the rest of the surrounding macro.
eager!{report_execute_timings!(self.execute_timings)}
);
};

self.end_to_end_execute_timings.report_stats(slot);

let mut per_pubkey_timings: Vec<_> = self
.execute_timings
Expand Down
Loading

0 comments on commit 09010d8

Please sign in to comment.