From a32e1d5361b4d13f344dd1ac343fc265b04913d2 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Fri, 28 Jun 2024 16:09:36 -0500 Subject: [PATCH] v2.0: Refactor and additional metrics for cost tracking (backport of #1888) (#1900) * Refactor and additional metrics for cost tracking (#1888) * Refactor and add metrics: - Combine remove_* and update_* functions to reduce locking on cost-tracker and iteration. - Add method to calculate executed transaction cost by directly using actual execution cost and loaded accounts size; - Wireup histogram to report loaded accounts size; - Report time of block limits checking; - Move account counters from ExecuteDetailsTimings to ExecuteAccountsDetails; * Move committed transactions adjustment into its own function (cherry picked from commit c3fadacf69c4420e4bb024b1a81740ce8cde905a) * rename cost_tracker.account_data_size to better describe its purpose is to tracker per-block new account allocation --------- Co-authored-by: Tao Zhu <82401714+tao-stones@users.noreply.github.com> Co-authored-by: Tao Zhu --- Cargo.lock | 1 + core/benches/consumer.rs | 36 +---- core/src/banking_stage/consumer.rs | 39 +----- core/src/banking_stage/qos_service.rs | 126 ++++++----------- cost-model/src/cost_model.rs | 50 ++++++- cost-model/src/cost_tracker.rs | 45 +++--- cost-model/src/transaction_cost.rs | 10 +- ledger/src/blockstore_processor.rs | 192 +++++++++++++++++++++----- local-cluster/tests/local_cluster.rs | 2 +- program-runtime/Cargo.toml | 1 + program-runtime/src/timings.rs | 78 ++++++++--- programs/sbf/Cargo.lock | 1 + svm/src/transaction_processor.rs | 6 +- 13 files changed, 360 insertions(+), 227 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 1e62bbbe1f5452..b875034c41788f 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6746,6 +6746,7 @@ dependencies = [ "bincode", "eager", "enum-iterator", + "histogram", "itertools 0.12.1", "libc", "log", diff --git a/core/benches/consumer.rs b/core/benches/consumer.rs index 14010e8d91a875..6dd9eb5b8bf0fa 100644 --- a/core/benches/consumer.rs +++ b/core/benches/consumer.rs @@ -22,7 +22,6 @@ use { solana_runtime::bank::Bank, solana_sdk::{ account::{Account, ReadableAccount}, - feature_set::apply_cost_tracker_during_replay, signature::Keypair, signer::Signer, stake_history::Epoch, @@ -97,7 +96,7 @@ struct BenchFrame { signal_receiver: Receiver<(Arc, (Entry, u64))>, } -fn setup(apply_cost_tracker_during_replay: bool) -> BenchFrame { +fn setup() -> BenchFrame { let mint_total = u64::MAX; let GenesisConfigInfo { mut genesis_config, .. @@ -109,10 +108,6 @@ fn setup(apply_cost_tracker_during_replay: bool) -> BenchFrame { let mut bank = Bank::new_for_benches(&genesis_config); - if !apply_cost_tracker_during_replay { - bank.deactivate_feature(&apply_cost_tracker_during_replay::id()); - } - // Allow arbitrary transaction processing time for the purposes of this bench bank.ns_per_slot = u128::MAX; @@ -139,11 +134,7 @@ fn setup(apply_cost_tracker_during_replay: bool) -> BenchFrame { } } -fn bench_process_and_record_transactions( - bencher: &mut Bencher, - batch_size: usize, - apply_cost_tracker_during_replay: bool, -) { +fn bench_process_and_record_transactions(bencher: &mut Bencher, batch_size: usize) { const TRANSACTIONS_PER_ITERATION: usize = 64; assert_eq!( TRANSACTIONS_PER_ITERATION % batch_size, @@ -161,7 +152,7 @@ fn bench_process_and_record_transactions( poh_recorder, poh_service, signal_receiver: _signal_receiver, - } = setup(apply_cost_tracker_during_replay); + } = setup(); let consumer = create_consumer(&poh_recorder); let transactions = create_transactions(&bank, 2_usize.pow(20)); let mut transaction_iter = transactions.chunks(batch_size); @@ -186,30 +177,15 @@ fn bench_process_and_record_transactions( #[bench] fn bench_process_and_record_transactions_unbatched(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 1, true); + bench_process_and_record_transactions(bencher, 1); } #[bench] fn bench_process_and_record_transactions_half_batch(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 32, true); + bench_process_and_record_transactions(bencher, 32); } #[bench] fn bench_process_and_record_transactions_full_batch(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 64, true); -} - -#[bench] -fn bench_process_and_record_transactions_unbatched_disable_tx_cost_update(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 1, false); -} - -#[bench] -fn bench_process_and_record_transactions_half_batch_disable_tx_cost_update(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 32, false); -} - -#[bench] -fn bench_process_and_record_transactions_full_batch_disable_tx_cost_update(bencher: &mut Bencher) { - bench_process_and_record_transactions(bencher, 64, false); + bench_process_and_record_transactions(bencher, 64); } diff --git a/core/src/banking_stage/consumer.rs b/core/src/banking_stage/consumer.rs index 377741e415e8ef..6ae0881da45d8a 100644 --- a/core/src/banking_stage/consumer.rs +++ b/core/src/banking_stage/consumer.rs @@ -518,27 +518,14 @@ impl Consumer { // Costs of all transactions are added to the cost_tracker before processing. // To ensure accurate tracking of compute units, transactions that ultimately - // were not included in the block should have their cost removed. - QosService::remove_costs( + // were not included in the block should have their cost removed, the rest + // should update with their actually consumed units. + QosService::remove_or_update_costs( transaction_qos_cost_results.iter(), commit_transactions_result.as_ref().ok(), bank, ); - // once feature `apply_cost_tracker_during_replay` is activated, leader shall no longer - // adjust block with executed cost (a behavior more inline with bankless leader), it - // should use requested, or default `compute_unit_limit` as transaction's execution cost. - if !bank - .feature_set - .is_active(&feature_set::apply_cost_tracker_during_replay::id()) - { - QosService::update_costs( - transaction_qos_cost_results.iter(), - commit_transactions_result.as_ref().ok(), - bank, - ); - } - retryable_transaction_indexes .iter_mut() .for_each(|x| *x += chunk_offset); @@ -1432,16 +1419,6 @@ mod tests { #[test] fn test_bank_process_and_record_transactions_cost_tracker() { - for apply_cost_tracker_during_replay_enabled in [true, false] { - bank_process_and_record_transactions_cost_tracker( - apply_cost_tracker_during_replay_enabled, - ); - } - } - - fn bank_process_and_record_transactions_cost_tracker( - apply_cost_tracker_during_replay_enabled: bool, - ) { solana_logger::setup(); let GenesisConfigInfo { genesis_config, @@ -1450,9 +1427,6 @@ mod tests { } = create_slow_genesis_config(10_000); let mut bank = Bank::new_for_tests(&genesis_config); bank.ns_per_slot = u128::MAX; - if !apply_cost_tracker_during_replay_enabled { - bank.deactivate_feature(&feature_set::apply_cost_tracker_during_replay::id()); - } let bank = bank.wrap_with_bank_forks_for_tests().0; let pubkey = solana_sdk::pubkey::new_rand(); @@ -1521,8 +1495,7 @@ mod tests { // TEST: it's expected that the allocation will execute but the transfer will not // because of a shared write-lock between mint_keypair. Ensure only the first transaction - // takes compute units in the block AND the apply_cost_tracker_during_replay_enabled feature - // is applied correctly + // takes compute units in the block let allocate_keypair = Keypair::new(); let transactions = sanitize_transactions(vec![ system_transaction::allocate( @@ -1561,7 +1534,7 @@ mod tests { ); assert_eq!(retryable_transaction_indexes, vec![1]); - let expected_block_cost = if !apply_cost_tracker_during_replay_enabled { + let expected_block_cost = { let (actual_programs_execution_cost, actual_loaded_accounts_data_size_cost) = match commit_transactions_result.first().unwrap() { CommitTransactionDetails::Committed { @@ -1587,8 +1560,6 @@ mod tests { } block_cost + cost.sum() - } else { - block_cost + CostModel::calculate_cost(&transactions[0], &bank.feature_set).sum() }; assert_eq!(get_block_cost(), expected_block_cost); diff --git a/core/src/banking_stage/qos_service.rs b/core/src/banking_stage/qos_service.rs index 23d4ebd97619bd..bf8b7df963e392 100644 --- a/core/src/banking_stage/qos_service.rs +++ b/core/src/banking_stage/qos_service.rs @@ -132,39 +132,28 @@ impl QosService { (select_results, num_included) } - /// Updates the transaction costs for committed transactions. Does not handle removing costs - /// for transactions that didn't get recorded or committed - pub fn update_costs<'a>( - transaction_cost_results: impl Iterator>, - transaction_committed_status: Option<&Vec>, - bank: &Bank, - ) { - if let Some(transaction_committed_status) = transaction_committed_status { - Self::update_committed_transaction_costs( - transaction_cost_results, - transaction_committed_status, - bank, - ) - } - } - - /// Removes transaction costs from the cost tracker if not committed or recorded - pub fn remove_costs<'a>( + /// Removes transaction costs from the cost tracker if not committed or recorded, or + /// updates the transaction costs for committed transactions. + pub fn remove_or_update_costs<'a>( transaction_cost_results: impl Iterator>, transaction_committed_status: Option<&Vec>, bank: &Bank, ) { match transaction_committed_status { - Some(transaction_committed_status) => Self::remove_uncommitted_transaction_costs( - transaction_cost_results, - transaction_committed_status, - bank, - ), - None => Self::remove_transaction_costs(transaction_cost_results, bank), + Some(transaction_committed_status) => { + Self::remove_or_update_recorded_transaction_costs( + transaction_cost_results, + transaction_committed_status, + bank, + ) + } + None => Self::remove_unrecorded_transaction_costs(transaction_cost_results, bank), } } - fn remove_uncommitted_transaction_costs<'a>( + /// For recorded transactions, remove units reserved by uncommitted transaction, or update + /// units for committed transactions. + fn remove_or_update_recorded_transaction_costs<'a>( transaction_cost_results: impl Iterator>, transaction_committed_status: &Vec, bank: &Bank, @@ -178,45 +167,31 @@ impl QosService { // checked for update if let Ok(tx_cost) = tx_cost { num_included += 1; - if *transaction_committed_details == CommitTransactionDetails::NotCommitted { - cost_tracker.remove(tx_cost) + match transaction_committed_details { + CommitTransactionDetails::Committed { + compute_units, + loaded_accounts_data_size, + } => { + cost_tracker.update_execution_cost( + tx_cost, + *compute_units, + CostModel::calculate_loaded_accounts_data_size_cost( + *loaded_accounts_data_size, + &bank.feature_set, + ), + ); + } + CommitTransactionDetails::NotCommitted => { + cost_tracker.remove(tx_cost); + } } } }); cost_tracker.sub_transactions_in_flight(num_included); } - fn update_committed_transaction_costs<'a>( - transaction_cost_results: impl Iterator>, - transaction_committed_status: &Vec, - bank: &Bank, - ) { - let mut cost_tracker = bank.write_cost_tracker().unwrap(); - transaction_cost_results - .zip(transaction_committed_status) - .for_each(|(estimated_tx_cost, transaction_committed_details)| { - // Only transactions that the qos service included have to be - // checked for update - if let Ok(estimated_tx_cost) = estimated_tx_cost { - if let CommitTransactionDetails::Committed { - compute_units, - loaded_accounts_data_size, - } = transaction_committed_details - { - cost_tracker.update_execution_cost( - estimated_tx_cost, - *compute_units, - CostModel::calculate_loaded_accounts_data_size_cost( - *loaded_accounts_data_size, - &bank.feature_set, - ), - ) - } - } - }); - } - - fn remove_transaction_costs<'a>( + /// Remove reserved units for transaction batch that unsuccessfully recorded. + fn remove_unrecorded_transaction_costs<'a>( transaction_cost_results: impl Iterator>, bank: &Bank, ) { @@ -784,18 +759,11 @@ mod tests { + (execute_units_adjustment + loaded_accounts_data_size_cost_adjustment) * transaction_count; - // All transactions are committed, no costs should be removed - QosService::remove_costs(qos_cost_results.iter(), Some(&committed_status), &bank); - assert_eq!( - total_txs_cost, - bank.read_cost_tracker().unwrap().block_cost() - ); - assert_eq!( - transaction_count, - bank.read_cost_tracker().unwrap().transaction_count() + QosService::remove_or_update_costs( + qos_cost_results.iter(), + Some(&committed_status), + &bank, ); - - QosService::update_costs(qos_cost_results.iter(), Some(&committed_status), &bank); assert_eq!( final_txs_cost, bank.read_cost_tracker().unwrap().block_cost() @@ -843,18 +811,7 @@ mod tests { bank.read_cost_tracker().unwrap().block_cost() ); - // update costs doesn't impact non-committed - QosService::update_costs(qos_cost_results.iter(), None, &bank); - assert_eq!( - total_txs_cost, - bank.read_cost_tracker().unwrap().block_cost() - ); - assert_eq!( - transaction_count, - bank.read_cost_tracker().unwrap().transaction_count() - ); - - QosService::remove_costs(qos_cost_results.iter(), None, &bank); + QosService::remove_or_update_costs(qos_cost_results.iter(), None, &bank); assert_eq!(0, bank.read_cost_tracker().unwrap().block_cost()); assert_eq!(0, bank.read_cost_tracker().unwrap().transaction_count()); } @@ -926,8 +883,11 @@ mod tests { }) .collect(); - QosService::remove_costs(qos_cost_results.iter(), Some(&committed_status), &bank); - QosService::update_costs(qos_cost_results.iter(), Some(&committed_status), &bank); + QosService::remove_or_update_costs( + qos_cost_results.iter(), + Some(&committed_status), + &bank, + ); // assert the final block cost let mut expected_final_txs_count = 0u64; diff --git a/cost-model/src/cost_model.rs b/cost-model/src/cost_model.rs index d319bbac1f2530..c444ad0885566f 100644 --- a/cost-model/src/cost_model.rs +++ b/cost-model/src/cost_model.rs @@ -43,13 +43,45 @@ impl CostModel { Self::get_signature_cost(&mut tx_cost, transaction); Self::get_write_lock_cost(&mut tx_cost, transaction, feature_set); Self::get_transaction_cost(&mut tx_cost, transaction, feature_set); - tx_cost.account_data_size = Self::calculate_account_data_size(transaction); + tx_cost.allocated_accounts_data_size = + Self::calculate_allocated_accounts_data_size(transaction); debug!("transaction {:?} has cost {:?}", transaction, tx_cost); TransactionCost::Transaction(tx_cost) } } + // Calculate executed transaction CU cost, with actual execution and loaded accounts size + // costs. + pub fn calculate_cost_for_executed_transaction( + transaction: &SanitizedTransaction, + actual_programs_execution_cost: u64, + actual_loaded_accounts_data_size_bytes: usize, + feature_set: &FeatureSet, + ) -> TransactionCost { + if transaction.is_simple_vote_transaction() { + TransactionCost::SimpleVote { + writable_accounts: Self::get_writable_accounts(transaction), + } + } else { + let mut tx_cost = UsageCostDetails::new_with_default_capacity(); + + Self::get_signature_cost(&mut tx_cost, transaction); + Self::get_write_lock_cost(&mut tx_cost, transaction, feature_set); + Self::get_instructions_data_cost(&mut tx_cost, transaction); + tx_cost.allocated_accounts_data_size = + Self::calculate_allocated_accounts_data_size(transaction); + + tx_cost.programs_execution_cost = actual_programs_execution_cost; + tx_cost.loaded_accounts_data_size_cost = Self::calculate_loaded_accounts_data_size_cost( + actual_loaded_accounts_data_size_bytes, + feature_set, + ); + + TransactionCost::Transaction(tx_cost) + } + } + fn get_signature_cost(tx_cost: &mut UsageCostDetails, transaction: &SanitizedTransaction) { let signatures_count_detail = transaction.message().get_signature_details(); tx_cost.num_transaction_signatures = signatures_count_detail.num_transaction_signatures(); @@ -168,6 +200,20 @@ impl CostModel { tx_cost.data_bytes_cost = data_bytes_len_total / INSTRUCTION_DATA_BYTES_COST; } + fn get_instructions_data_cost( + tx_cost: &mut UsageCostDetails, + transaction: &SanitizedTransaction, + ) { + let ix_data_bytes_len_total: u64 = transaction + .message() + .instructions() + .iter() + .map(|instruction| instruction.data.len() as u64) + .sum(); + + tx_cost.data_bytes_cost = ix_data_bytes_len_total / INSTRUCTION_DATA_BYTES_COST; + } + pub fn calculate_loaded_accounts_data_size_cost( loaded_accounts_data_size: usize, _feature_set: &FeatureSet, @@ -218,7 +264,7 @@ impl CostModel { /// eventually, potentially determine account data size of all writable accounts /// at the moment, calculate account data size of account creation - fn calculate_account_data_size(transaction: &SanitizedTransaction) -> u64 { + fn calculate_allocated_accounts_data_size(transaction: &SanitizedTransaction) -> u64 { transaction .message() .program_instructions_iter() diff --git a/cost-model/src/cost_tracker.rs b/cost-model/src/cost_tracker.rs index f891cb22a5697b..49ccbbb035f9bb 100644 --- a/cost-model/src/cost_tracker.rs +++ b/cost-model/src/cost_tracker.rs @@ -67,7 +67,7 @@ pub struct CostTracker { block_cost: u64, vote_cost: u64, transaction_count: u64, - account_data_size: u64, + allocated_accounts_data_size: u64, transaction_signature_count: u64, secp256k1_instruction_signature_count: u64, ed25519_instruction_signature_count: u64, @@ -96,7 +96,7 @@ impl Default for CostTracker { block_cost: 0, vote_cost: 0, transaction_count: 0, - account_data_size: 0, + allocated_accounts_data_size: 0, transaction_signature_count: 0, secp256k1_instruction_signature_count: 0, ed25519_instruction_signature_count: 0, @@ -111,7 +111,7 @@ impl CostTracker { self.block_cost = 0; self.vote_cost = 0; self.transaction_count = 0; - self.account_data_size = 0; + self.allocated_accounts_data_size = 0; self.transaction_signature_count = 0; self.secp256k1_instruction_signature_count = 0; self.ed25519_instruction_signature_count = 0; @@ -213,7 +213,11 @@ impl CostTracker { // ("number_of_accounts", self.number_of_accounts() as i64, i64), // ("costliest_account", costliest_account.to_string(), String), // ("costliest_account_cost", costliest_account_cost as i64, i64), - // ("account_data_size", self.account_data_size, i64), + // ( + // "allocated_accounts_data_size", + // self.allocated_accounts_data_size, + // i64 + // ), // ( // "transaction_signature_count", // self.transaction_signature_count, @@ -265,11 +269,11 @@ impl CostTracker { return Err(CostTrackerError::WouldExceedAccountMaxLimit); } - let account_data_size = self - .account_data_size - .saturating_add(tx_cost.account_data_size()); + let allocated_accounts_data_size = self + .allocated_accounts_data_size + .saturating_add(tx_cost.allocated_accounts_data_size()); - if account_data_size > MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA { + if allocated_accounts_data_size > MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA { return Err(CostTrackerError::WouldExceedAccountDataBlockLimit); } @@ -292,7 +296,10 @@ impl CostTracker { // Returns the highest account cost for all write-lock accounts `TransactionCost` updated fn add_transaction_cost(&mut self, tx_cost: &TransactionCost) -> u64 { - saturating_add_assign!(self.account_data_size, tx_cost.account_data_size()); + saturating_add_assign!( + self.allocated_accounts_data_size, + tx_cost.allocated_accounts_data_size() + ); saturating_add_assign!(self.transaction_count, 1); saturating_add_assign!( self.transaction_signature_count, @@ -312,9 +319,9 @@ impl CostTracker { fn remove_transaction_cost(&mut self, tx_cost: &TransactionCost) { let cost = tx_cost.sum(); self.sub_transaction_execution_cost(tx_cost, cost); - self.account_data_size = self - .account_data_size - .saturating_sub(tx_cost.account_data_size()); + self.allocated_accounts_data_size = self + .allocated_accounts_data_size + .saturating_sub(tx_cost.allocated_accounts_data_size()); self.transaction_count = self.transaction_count.saturating_sub(1); self.transaction_signature_count = self .transaction_signature_count @@ -504,7 +511,7 @@ mod tests { let (mint_keypair, start_hash) = test_setup(); let (_tx, mut tx_cost) = build_simple_transaction(&mint_keypair, &start_hash); if let TransactionCost::Transaction(ref mut usage_cost) = tx_cost { - usage_cost.account_data_size = 1; + usage_cost.allocated_accounts_data_size = 1; } else { unreachable!(); } @@ -513,9 +520,9 @@ mod tests { // build testee to have capacity for one simple transaction let mut testee = CostTracker::new(cost, cost, cost); assert!(testee.would_fit(&tx_cost).is_ok()); - let old = testee.account_data_size; + let old = testee.allocated_accounts_data_size; testee.add_transaction_cost(&tx_cost); - assert_eq!(old + 1, testee.account_data_size); + assert_eq!(old + 1, testee.allocated_accounts_data_size); } #[test] @@ -652,12 +659,12 @@ mod tests { let (_tx1, mut tx_cost1) = build_simple_transaction(&mint_keypair, &start_hash); let (_tx2, mut tx_cost2) = build_simple_transaction(&second_account, &start_hash); if let TransactionCost::Transaction(ref mut usage_cost) = tx_cost1 { - usage_cost.account_data_size = MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA; + usage_cost.allocated_accounts_data_size = MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA; } else { unreachable!(); } if let TransactionCost::Transaction(ref mut usage_cost) = tx_cost2 { - usage_cost.account_data_size = MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA + 1; + usage_cost.allocated_accounts_data_size = MAX_BLOCK_ACCOUNTS_DATA_SIZE_DELTA + 1; } else { unreachable!(); } @@ -945,7 +952,7 @@ mod tests { assert_eq!(1, cost_tracker.number_of_accounts()); assert_eq!(cost, cost_tracker.block_cost); assert_eq!(0, cost_tracker.vote_cost); - assert_eq!(0, cost_tracker.account_data_size); + assert_eq!(0, cost_tracker.allocated_accounts_data_size); cost_tracker.remove_transaction_cost(&tx_cost); // assert cost_tracker is reverted to default @@ -953,6 +960,6 @@ mod tests { assert_eq!(0, cost_tracker.number_of_accounts()); assert_eq!(0, cost_tracker.block_cost); assert_eq!(0, cost_tracker.vote_cost); - assert_eq!(0, cost_tracker.account_data_size); + assert_eq!(0, cost_tracker.allocated_accounts_data_size); } } diff --git a/cost-model/src/transaction_cost.rs b/cost-model/src/transaction_cost.rs index ee280c873312f9..4951e50036ca8b 100644 --- a/cost-model/src/transaction_cost.rs +++ b/cost-model/src/transaction_cost.rs @@ -56,10 +56,10 @@ impl TransactionCost { } } - pub fn account_data_size(&self) -> u64 { + pub fn allocated_accounts_data_size(&self) -> u64 { match self { Self::SimpleVote { .. } => 0, - Self::Transaction(usage_cost) => usage_cost.account_data_size, + Self::Transaction(usage_cost) => usage_cost.allocated_accounts_data_size, } } @@ -125,7 +125,7 @@ pub struct UsageCostDetails { pub data_bytes_cost: u64, pub programs_execution_cost: u64, pub loaded_accounts_data_size_cost: u64, - pub account_data_size: u64, + pub allocated_accounts_data_size: u64, pub num_transaction_signatures: u64, pub num_secp256k1_instruction_signatures: u64, pub num_ed25519_instruction_signatures: u64, @@ -140,7 +140,7 @@ impl Default for UsageCostDetails { data_bytes_cost: 0u64, programs_execution_cost: 0u64, loaded_accounts_data_size_cost: 0u64, - account_data_size: 0u64, + allocated_accounts_data_size: 0u64, num_transaction_signatures: 0u64, num_secp256k1_instruction_signatures: 0u64, num_ed25519_instruction_signatures: 0u64, @@ -160,7 +160,7 @@ impl PartialEq for UsageCostDetails { && self.data_bytes_cost == other.data_bytes_cost && self.programs_execution_cost == other.programs_execution_cost && self.loaded_accounts_data_size_cost == other.loaded_accounts_data_size_cost - && self.account_data_size == other.account_data_size + && self.allocated_accounts_data_size == other.allocated_accounts_data_size && self.num_transaction_signatures == other.num_transaction_signatures && self.num_secp256k1_instruction_signatures == other.num_secp256k1_instruction_signatures diff --git a/ledger/src/blockstore_processor.rs b/ledger/src/blockstore_processor.rs index 84deb781806768..4a7e84f9d9ea33 100644 --- a/ledger/src/blockstore_processor.rs +++ b/ledger/src/blockstore_processor.rs @@ -62,7 +62,8 @@ use { solana_svm::{ transaction_processor::ExecutionRecordingConfig, transaction_results::{ - TransactionExecutionDetails, TransactionExecutionResult, TransactionResults, + TransactionExecutionDetails, TransactionExecutionResult, + TransactionLoadedAccountsStats, TransactionResults, }, }, solana_transaction_status::token_balances::TransactionTokenBalancesSet, @@ -181,11 +182,40 @@ pub fn execute_batch( let TransactionResults { fee_collection_results, + loaded_accounts_stats, execution_results, rent_debits, .. } = tx_results; + let (check_block_cost_limits_result, check_block_cost_limits_time): (Result<()>, Measure) = + measure!(if bank + .feature_set + .is_active(&feature_set::apply_cost_tracker_during_replay::id()) + { + check_block_cost_limits( + bank, + &loaded_accounts_stats, + &execution_results, + batch.sanitized_transactions(), + ) + } else { + Ok(()) + }); + + timings.saturating_add_in_place( + ExecuteTimingType::CheckBlockLimitsUs, + check_block_cost_limits_time.as_us(), + ); + for tx_loaded_accounts_stats in loaded_accounts_stats.iter().flatten() { + timings + .execute_accounts_details + .increment_loaded_accounts_data_size( + tx_loaded_accounts_stats.loaded_accounts_data_size as u64, + ); + } + check_block_cost_limits_result?; + let executed_transactions = execution_results .iter() .zip(batch.sanitized_transactions()) @@ -220,6 +250,49 @@ pub fn execute_batch( first_err.map(|(result, _)| result).unwrap_or(Ok(())) } +// collect transactions actual execution costs, subject to block limits; +// block will be marked as dead if exceeds cost limits, details will be +// reported to metric `replay-stage-mark_dead_slot` +fn check_block_cost_limits( + bank: &Bank, + loaded_accounts_stats: &[Result], + execution_results: &[TransactionExecutionResult], + sanitized_transactions: &[SanitizedTransaction], +) -> Result<()> { + assert_eq!(loaded_accounts_stats.len(), execution_results.len()); + + let tx_costs_with_actual_execution_units: Vec<_> = execution_results + .iter() + .zip(loaded_accounts_stats) + .zip(sanitized_transactions) + .filter_map(|((execution_result, loaded_accounts_stats), tx)| { + if let Some(details) = execution_result.details() { + let tx_cost = CostModel::calculate_cost_for_executed_transaction( + tx, + details.executed_units, + loaded_accounts_stats + .as_ref() + .map_or(0, |stats| stats.loaded_accounts_data_size), + &bank.feature_set, + ); + Some(tx_cost) + } else { + None + } + }) + .collect(); + + { + let mut cost_tracker = bank.write_cost_tracker().unwrap(); + for tx_cost in &tx_costs_with_actual_execution_units { + cost_tracker + .try_add(tx_cost) + .map_err(TransactionError::from)?; + } + } + Ok(()) +} + #[derive(Default)] pub struct ExecuteBatchesInternalMetrics { execution_timings_per_thread: HashMap, @@ -456,22 +529,10 @@ fn rebatch_and_execute_batches( let cost = tx_cost.sum(); minimal_tx_cost = std::cmp::min(minimal_tx_cost, cost); total_cost = total_cost.saturating_add(cost); - tx_cost + cost }) .collect::>(); - if bank - .feature_set - .is_active(&feature_set::apply_cost_tracker_during_replay::id()) - { - let mut cost_tracker = bank.write_cost_tracker().unwrap(); - for tx_cost in &tx_costs { - cost_tracker - .try_add(tx_cost) - .map_err(TransactionError::from)?; - } - } - let target_batch_count = get_thread_count() as u64; let mut tx_batches: Vec = vec![]; @@ -479,26 +540,23 @@ fn rebatch_and_execute_batches( let target_batch_cost = total_cost / target_batch_count; let mut batch_cost: u64 = 0; let mut slice_start = 0; - tx_costs - .into_iter() - .enumerate() - .for_each(|(index, tx_cost)| { - let next_index = index + 1; - batch_cost = batch_cost.saturating_add(tx_cost.sum()); - if batch_cost >= target_batch_cost || next_index == sanitized_txs.len() { - let tx_batch = rebatch_transactions( - &lock_results, - bank, - &sanitized_txs, - slice_start, - index, - &transaction_indexes, - ); - slice_start = next_index; - tx_batches.push(tx_batch); - batch_cost = 0; - } - }); + tx_costs.into_iter().enumerate().for_each(|(index, cost)| { + let next_index = index + 1; + batch_cost = batch_cost.saturating_add(cost); + if batch_cost >= target_batch_cost || next_index == sanitized_txs.len() { + let tx_batch = rebatch_transactions( + &lock_results, + bank, + &sanitized_txs, + slice_start, + index, + &transaction_indexes, + ); + slice_start = next_index; + tx_batches.push(tx_batch); + batch_cost = 0; + } + }); &tx_batches[..] } else { batches @@ -2198,6 +2256,7 @@ pub mod tests { }, assert_matches::assert_matches, rand::{thread_rng, Rng}, + solana_cost_model::transaction_cost::TransactionCost, solana_entry::entry::{create_ticks, next_entry, next_entry_mut}, solana_program_runtime::declare_process_instruction, solana_runtime::{ @@ -5022,4 +5081,69 @@ pub mod tests { } } } + + #[test] + fn test_check_block_cost_limit() { + let dummy_leader_pubkey = solana_sdk::pubkey::new_rand(); + let GenesisConfigInfo { + genesis_config, + mint_keypair, + .. + } = create_genesis_config_with_leader(500, &dummy_leader_pubkey, 100); + let bank = Bank::new_for_tests(&genesis_config); + + let tx = SanitizedTransaction::from_transaction_for_tests(system_transaction::transfer( + &mint_keypair, + &Pubkey::new_unique(), + 1, + genesis_config.hash(), + )); + let mut tx_cost = CostModel::calculate_cost(&tx, &bank.feature_set); + let actual_execution_cu = 1; + let actual_loaded_accounts_data_size = 64 * 1024; + let TransactionCost::Transaction(ref mut usage_cost_details) = tx_cost else { + unreachable!("test tx is non-vote tx"); + }; + usage_cost_details.programs_execution_cost = actual_execution_cu; + usage_cost_details.loaded_accounts_data_size_cost = + CostModel::calculate_loaded_accounts_data_size_cost( + actual_loaded_accounts_data_size, + &bank.feature_set, + ); + // set block-limit to be able to just have one transaction + let block_limit = tx_cost.sum(); + + bank.write_cost_tracker() + .unwrap() + .set_limits(u64::MAX, block_limit, u64::MAX); + let txs = vec![tx.clone(), tx]; + let results = vec![ + TransactionExecutionResult::Executed { + details: TransactionExecutionDetails { + status: Ok(()), + log_messages: None, + inner_instructions: None, + fee_details: solana_sdk::fee::FeeDetails::default(), + return_data: None, + executed_units: actual_execution_cu, + accounts_data_len_delta: 0, + }, + programs_modified_by_tx: HashMap::new(), + }, + TransactionExecutionResult::NotExecuted(TransactionError::AccountNotFound), + ]; + let loaded_accounts_stats = vec![ + Ok(TransactionLoadedAccountsStats { + loaded_accounts_data_size: actual_loaded_accounts_data_size, + loaded_accounts_count: 2 + }); + 2 + ]; + + assert!(check_block_cost_limits(&bank, &loaded_accounts_stats, &results, &txs).is_ok()); + assert_eq!( + Err(TransactionError::WouldExceedMaxBlockCostLimit), + check_block_cost_limits(&bank, &loaded_accounts_stats, &results, &txs) + ); + } } diff --git a/local-cluster/tests/local_cluster.rs b/local-cluster/tests/local_cluster.rs index f4e1a927c3f00e..3977170416c174 100644 --- a/local-cluster/tests/local_cluster.rs +++ b/local-cluster/tests/local_cluster.rs @@ -386,7 +386,7 @@ fn test_restart_node() { ); cluster.exit_restart_node(&nodes[0], validator_config, SocketAddrSpace::Unspecified); cluster_tests::sleep_n_epochs( - 0.5, + 0.6, &cluster.genesis_config.poh_config, clock::DEFAULT_TICKS_PER_SLOT, slots_per_epoch, diff --git a/program-runtime/Cargo.toml b/program-runtime/Cargo.toml index 8c8a1010051105..ed18a5aee09eba 100644 --- a/program-runtime/Cargo.toml +++ b/program-runtime/Cargo.toml @@ -14,6 +14,7 @@ base64 = { workspace = true } bincode = { workspace = true } eager = { workspace = true } enum-iterator = { workspace = true } +histogram = { workspace = true } itertools = { workspace = true } libc = { workspace = true } log = { workspace = true } diff --git a/program-runtime/src/timings.rs b/program-runtime/src/timings.rs index 5255c24094dbbe..05b9688630a448 100644 --- a/program-runtime/src/timings.rs +++ b/program-runtime/src/timings.rs @@ -53,6 +53,7 @@ pub enum ExecuteTimingType { TotalBatchesLen, UpdateTransactionStatuses, ProgramCacheUs, + CheckBlockLimitsUs, } pub struct Metrics([u64; ExecuteTimingType::CARDINALITY]); @@ -177,6 +178,11 @@ eager_macro_rules! { $eager_1 .index(ExecuteTimingType::UpdateTransactionStatuses), i64 ), + ( + "check_block_limits_us", + *$self.metrics.index(ExecuteTimingType::CheckBlockLimitsUs), + i64 + ), ( "execute_details_serialize_us", $self.details.serialize_us, @@ -202,16 +208,6 @@ eager_macro_rules! { $eager_1 $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_create_executor_register_syscalls_us", $self @@ -288,6 +284,36 @@ eager_macro_rules! { $eager_1 .verify_callee_us, i64 ), + ( + "execute_accounts_details_loaded_accounts_data_size_90pct", + $self.execute_accounts_details.loaded_accounts_data_size_hist.percentile(90.0).unwrap_or(0), + i64 + ), + ( + "execute_accounts_details_loaded_accounts_data_size_min", + $self.execute_accounts_details.loaded_accounts_data_size_hist.minimum().unwrap_or(0), + i64 + ), + ( + "execute_accounts_details_loaded_accounts_data_size_max", + $self.execute_accounts_details.loaded_accounts_data_size_hist.maximum().unwrap_or(0), + i64 + ), + ( + "execute_accounts_details_loaded_accounts_data_size_mean", + $self.execute_accounts_details.loaded_accounts_data_size_hist.mean().unwrap_or(0), + i64 + ), + ( + "execute_accounts_details_changed_account_count", + $self.execute_accounts_details.changed_account_count, + i64 + ), + ( + "execute_accounts_details_total_account_count", + $self.execute_accounts_details.total_account_count, + i64 + ), } } } @@ -297,6 +323,7 @@ pub struct ExecuteTimings { pub metrics: Metrics, pub details: ExecuteDetailsTimings, pub execute_accessories: ExecuteAccessoryTimings, + pub execute_accounts_details: ExecuteAccountsDetails, } impl ExecuteTimings { @@ -307,6 +334,8 @@ impl ExecuteTimings { self.details.accumulate(&other.details); self.execute_accessories .accumulate(&other.execute_accessories); + self.execute_accounts_details + .accumulate(&other.execute_accounts_details); } pub fn saturating_add_in_place(&mut self, timing_type: ExecuteTimingType, value_to_add: u64) { @@ -365,8 +394,6 @@ pub struct ExecuteDetailsTimings { pub execute_us: u64, pub deserialize_us: u64, pub get_or_create_executor_us: u64, - pub changed_account_count: u64, - pub total_account_count: u64, pub create_executor_register_syscalls_us: u64, pub create_executor_load_elf_us: u64, pub create_executor_verify_code_us: u64, @@ -384,8 +411,6 @@ impl ExecuteDetailsTimings { self.get_or_create_executor_us, other.get_or_create_executor_us ); - saturating_add_assign!(self.changed_account_count, other.changed_account_count); - saturating_add_assign!(self.total_account_count, other.total_account_count); saturating_add_assign!( self.create_executor_register_syscalls_us, other.create_executor_register_syscalls_us @@ -433,6 +458,28 @@ impl ExecuteDetailsTimings { } } +#[derive(Default, Debug)] +pub struct ExecuteAccountsDetails { + pub loaded_accounts_data_size_hist: histogram::Histogram, + pub changed_account_count: u64, + pub total_account_count: u64, +} + +impl ExecuteAccountsDetails { + pub fn accumulate(&mut self, other: &ExecuteAccountsDetails) { + self.loaded_accounts_data_size_hist + .merge(&other.loaded_accounts_data_size_hist); + saturating_add_assign!(self.changed_account_count, other.changed_account_count); + saturating_add_assign!(self.total_account_count, other.total_account_count); + } + + pub fn increment_loaded_accounts_data_size(&mut self, account_size: u64) { + self.loaded_accounts_data_size_hist + .increment(account_size) + .unwrap(); + } +} + #[cfg(test)] mod tests { use super::*; @@ -500,13 +547,10 @@ mod tests { // Construct another separate instance of ExecuteDetailsTimings with non default fields let mut other_execute_details_timings = construct_execute_timings_with_program(&program_id, us, compute_units_consumed); - let account_count = 1; other_execute_details_timings.serialize_us = us; other_execute_details_timings.create_vm_us = us; other_execute_details_timings.execute_us = us; other_execute_details_timings.deserialize_us = us; - other_execute_details_timings.changed_account_count = account_count; - other_execute_details_timings.total_account_count = account_count; // Accumulate the other instance into the current instance execute_details_timings.accumulate(&other_execute_details_timings); diff --git a/programs/sbf/Cargo.lock b/programs/sbf/Cargo.lock index 80ccd49888ed64..2da35bf198abbb 100644 --- a/programs/sbf/Cargo.lock +++ b/programs/sbf/Cargo.lock @@ -5325,6 +5325,7 @@ dependencies = [ "bincode", "eager", "enum-iterator", + "histogram", "itertools 0.12.1", "libc", "log", diff --git a/svm/src/transaction_processor.rs b/svm/src/transaction_processor.rs index 2037489c0477f0..a225ed1ff1d4e0 100644 --- a/svm/src/transaction_processor.rs +++ b/svm/src/transaction_processor.rs @@ -858,11 +858,13 @@ impl TransactionBatchProcessor { loaded_transaction.accounts = accounts; saturating_add_assign!( - execute_timings.details.total_account_count, + execute_timings.execute_accounts_details.total_account_count, loaded_transaction.accounts.len() as u64 ); saturating_add_assign!( - execute_timings.details.changed_account_count, + execute_timings + .execute_accounts_details + .changed_account_count, touched_account_count );