diff --git a/Cargo.lock b/Cargo.lock index 41bbb391050861..ddf570f44d138a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1163,6 +1163,12 @@ version = "0.3.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "fea41bba32d969b513997752735605054bc0dfa92b4c56bf1189f2e174be7a10" +[[package]] +name = "eager" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "abe71d579d1812060163dff96056261deb5bf6729b100fa2e36a68b9649ba3d3" + [[package]] name = "ed25519" version = "1.2.0" @@ -4749,6 +4755,7 @@ dependencies = [ "chrono", "crossbeam-channel", "dashmap", + "eager", "etcd-client", "fs_extra", "histogram", @@ -5519,6 +5526,7 @@ version = "1.11.0" dependencies = [ "base64 0.13.0", "bincode", + "eager", "enum-iterator", "itertools", "libc", @@ -5532,6 +5540,7 @@ dependencies = [ "solana-frozen-abi-macro 1.11.0", "solana-logger 1.11.0", "solana-measure", + "solana-metrics", "solana-sdk 1.11.0", "thiserror", ] diff --git a/core/Cargo.toml b/core/Cargo.toml index a59060a1861851..97b23112a3f06e 100644 --- a/core/Cargo.toml +++ b/core/Cargo.toml @@ -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" diff --git a/core/src/lib.rs b/core/src/lib.rs index 2af5f786edf7e2..9dce1bd84aea60 100644 --- a/core/src/lib.rs +++ b/core/src/lib.rs @@ -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 @@ -77,6 +78,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; diff --git a/core/src/progress_map.rs b/core/src/progress_map.rs index 950f986270c1fd..579bc6250b2744 100644 --- a/core/src/progress_map.rs +++ b/core/src/progress_map.rs @@ -6,7 +6,7 @@ use { replay_stage::SUPERMINORITY_THRESHOLD, }, solana_ledger::blockstore_processor::{ConfirmationProgress, ConfirmationTiming}, - solana_program_runtime::timings::ExecuteTimingType, + solana_program_runtime::{report_execute_timings, timings::ExecuteTimingType}, solana_runtime::{bank::Bank, bank_forks::BankForks, vote_account::VoteAccountsHashMap}, solana_sdk::{clock::Slot, hash::Hash, pubkey::Pubkey}, std::{ @@ -37,218 +37,39 @@ impl std::ops::DerefMut for ReplaySlotStats { impl ReplaySlotStats { pub fn report_stats(&self, slot: Slot, num_entries: usize, num_shreds: 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 - ), - ( - "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), + ( + "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), + 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 diff --git a/program-runtime/Cargo.toml b/program-runtime/Cargo.toml index 91936e4d22aebf..02854d5c2c6055 100644 --- a/program-runtime/Cargo.toml +++ b/program-runtime/Cargo.toml @@ -12,6 +12,7 @@ edition = "2021" [dependencies] base64 = "0.13" bincode = "1.3.3" +eager = "0.1.0" itertools = "0.10.1" libc = "0.2.101" libloading = "0.7.0" @@ -22,6 +23,7 @@ serde = { version = "1.0.129", features = ["derive", "rc"] } solana-frozen-abi = { path = "../frozen-abi", version = "=1.11.0" } solana-frozen-abi-macro = { path = "../frozen-abi/macro", version = "=1.11.0" } solana-measure = { path = "../measure", version = "=1.11.0" } +solana-metrics = { path = "../metrics", version = "=1.11.0" } solana-sdk = { path = "../sdk", version = "=1.11.0" } thiserror = "1.0" enum-iterator = "0.8.1" diff --git a/program-runtime/src/lib.rs b/program-runtime/src/lib.rs index cb135bb112d7b0..9f97e02ffdacfe 100644 --- a/program-runtime/src/lib.rs +++ b/program-runtime/src/lib.rs @@ -1,6 +1,13 @@ #![cfg_attr(RUSTC_WITH_SPECIALIZATION, feature(min_specialization))] #![deny(clippy::integer_arithmetic)] #![deny(clippy::indexing_slicing)] +#![recursion_limit = "2048"] + +#[macro_use] +extern crate eager; + +#[macro_use] +extern crate solana_metrics; pub mod accounts_data_meter; pub mod compute_budget; diff --git a/program-runtime/src/timings.rs b/program-runtime/src/timings.rs index 21360c86580c14..10d7d15bc53d04 100644 --- a/program-runtime/src/timings.rs +++ b/program-runtime/src/timings.rs @@ -1,7 +1,7 @@ use { core::fmt, enum_iterator::IntoEnumIterator, - solana_sdk::{pubkey::Pubkey, saturating_add_assign}, + solana_sdk::{clock::Slot, pubkey::Pubkey, saturating_add_assign}, std::{ collections::HashMap, ops::{Index, IndexMut}, @@ -79,6 +79,188 @@ impl core::fmt::Debug for Metrics { } } +eager_macro_rules! { $eager_1 + #[macro_export] + macro_rules! report_execute_timings { + ($self: expr) => { + ( + "load_us", + *$self + .metrics + .index(ExecuteTimingType::LoadUs), + i64 + ), + ( + "execute_us", + *$self + .metrics + .index(ExecuteTimingType::ExecuteUs), + i64 + ), + ( + "store_us", + *$self + + .metrics + .index(ExecuteTimingType::StoreUs), + i64 + ), + ( + "update_stakes_cache_us", + *$self + + .metrics + .index(ExecuteTimingType::UpdateStakesCacheUs), + i64 + ), + ( + "total_batches_len", + *$self + + .metrics + .index(ExecuteTimingType::TotalBatchesLen), + i64 + ), + ( + "num_execute_batches", + *$self + + .metrics + .index(ExecuteTimingType::NumExecuteBatches), + i64 + ), + ( + "execute_details_serialize_us", + $self.details.serialize_us, + i64 + ), + ( + "execute_details_create_vm_us", + $self.details.create_vm_us, + i64 + ), + ( + "execute_details_execute_inner_us", + $self.details.execute_us, + i64 + ), + ( + "execute_details_deserialize_us", + $self.details.deserialize_us, + i64 + ), + ( + "execute_details_get_or_create_executor_us", + $self.details.get_or_create_executor_us, + i64 + ), + ( + "execute_details_changed_account_count", + $self.details.changed_account_count, + i64 + ), + ( + "execute_details_total_account_count", + $self.details.total_account_count, + i64 + ), + ( + "execute_details_total_data_size", + $self.details.total_data_size, + i64 + ), + ( + "execute_details_data_size_changed", + $self.details.data_size_changed, + i64 + ), + ( + "execute_details_create_executor_register_syscalls_us", + $self + .details + .create_executor_register_syscalls_us, + i64 + ), + ( + "execute_details_create_executor_load_elf_us", + $self.details.create_executor_load_elf_us, + i64 + ), + ( + "execute_details_create_executor_verify_code_us", + $self.details.create_executor_verify_code_us, + i64 + ), + ( + "execute_details_create_executor_jit_compile_us", + $self.details.create_executor_jit_compile_us, + i64 + ), + ( + "execute_accessories_feature_set_clone_us", + $self + .execute_accessories + .feature_set_clone_us, + i64 + ), + ( + "execute_accessories_compute_budget_process_transaction_us", + $self + .execute_accessories + .compute_budget_process_transaction_us, + i64 + ), + ( + "execute_accessories_get_executors_us", + $self.execute_accessories.get_executors_us, + i64 + ), + ( + "execute_accessories_process_message_us", + $self.execute_accessories.process_message_us, + i64 + ), + ( + "execute_accessories_update_executors_us", + $self.execute_accessories.update_executors_us, + i64 + ), + ( + "execute_accessories_process_instructions_total_us", + $self + .execute_accessories + .process_instructions + .total_us, + i64 + ), + ( + "execute_accessories_process_instructions_verify_caller_us", + $self + .execute_accessories + .process_instructions + .verify_caller_us, + i64 + ), + ( + "execute_accessories_process_instructions_process_executable_chain_us", + $self + .execute_accessories + .process_instructions + .process_executable_chain_us, + i64 + ), + ( + "execute_accessories_process_instructions_verify_callee_us", + $self + .execute_accessories + .process_instructions + .verify_callee_us, + i64 + ), + } + } +} + #[derive(Default)] pub struct ThreadExecuteTimings { pub total_thread_us: u64, @@ -87,6 +269,18 @@ pub struct ThreadExecuteTimings { } impl ThreadExecuteTimings { + pub fn report_stats(&self, slot: Slot) { + lazy! { + datapoint_info!( + "replay-slot-end-to-end-stats", + ("slot", slot as i64, i64), + ("total_thread_us", self.total_thread_us as i64, i64), + ("total_transactions_executed", self.total_transactions_executed as i64, i64), + eager!{report_execute_timings!(self.execute_timings)} + ); + }; + } + pub fn accumulate(&mut self, other: &ThreadExecuteTimings) { self.execute_timings.saturating_add_in_place( ExecuteTimingType::TotalBatchesLen, diff --git a/programs/bpf/Cargo.lock b/programs/bpf/Cargo.lock index 9a2265217f9fb3..124c504d755315 100644 --- a/programs/bpf/Cargo.lock +++ b/programs/bpf/Cargo.lock @@ -973,6 +973,12 @@ dependencies = [ "syn 0.15.44", ] +[[package]] +name = "eager" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "abe71d579d1812060163dff96056261deb5bf6729b100fa2e36a68b9649ba3d3" + [[package]] name = "ed25519" version = "1.0.1" @@ -4399,6 +4405,7 @@ dependencies = [ "chrono", "crossbeam-channel", "dashmap", + "eager", "etcd-client", "fs_extra", "histogram", @@ -4899,6 +4906,7 @@ version = "1.11.0" dependencies = [ "base64 0.13.0", "bincode", + "eager", "enum-iterator", "itertools", "libc", @@ -4911,6 +4919,7 @@ dependencies = [ "solana-frozen-abi 1.11.0", "solana-frozen-abi-macro 1.11.0", "solana-measure", + "solana-metrics", "solana-sdk 1.11.0", "thiserror", ]