Aggregate executor update timing metrics

This commit is contained in:
Justin Starry 2022-04-21 00:20:29 +08:00
parent edf3f05ab5
commit b6bc5d2fa1
6 changed files with 101 additions and 75 deletions

View File

@ -22,8 +22,8 @@ use {
accounts_index::AccountSecondaryIndexes, accounts_index::AccountSecondaryIndexes,
accounts_update_notifier_interface::AccountsUpdateNotifier, accounts_update_notifier_interface::AccountsUpdateNotifier,
bank::{ bank::{
Bank, RentDebits, TransactionBalancesSet, TransactionExecutionResult, Bank, RentDebits, TransactionBalancesSet, TransactionExecutionDetails,
TransactionResults, TransactionExecutionResult, TransactionResults,
}, },
bank_forks::BankForks, bank_forks::BankForks,
bank_utils, bank_utils,
@ -1409,7 +1409,7 @@ pub enum TransactionStatusMessage {
pub struct TransactionStatusBatch { pub struct TransactionStatusBatch {
pub bank: Arc<Bank>, pub bank: Arc<Bank>,
pub transactions: Vec<SanitizedTransaction>, pub transactions: Vec<SanitizedTransaction>,
pub execution_results: Vec<TransactionExecutionResult>, pub execution_results: Vec<Option<TransactionExecutionDetails>>,
pub balances: TransactionBalancesSet, pub balances: TransactionBalancesSet,
pub token_balances: TransactionTokenBalancesSet, pub token_balances: TransactionTokenBalancesSet,
pub rent_debits: Vec<RentDebits>, pub rent_debits: Vec<RentDebits>,
@ -1437,7 +1437,13 @@ impl TransactionStatusSender {
.send(TransactionStatusMessage::Batch(TransactionStatusBatch { .send(TransactionStatusMessage::Batch(TransactionStatusBatch {
bank, bank,
transactions, transactions,
execution_results, execution_results: execution_results
.into_iter()
.map(|result| match result {
TransactionExecutionResult::Executed { details, .. } => Some(details),
TransactionExecutionResult::NotExecuted(_) => None,
})
.collect(),
balances, balances,
token_balances, token_balances,
rent_debits, rent_debits,

View File

@ -78,6 +78,7 @@ pub type Executors = HashMap<Pubkey, TransactionExecutor>;
/// Tracks whether a given executor is "dirty" and needs to updated in the /// Tracks whether a given executor is "dirty" and needs to updated in the
/// executors cache /// executors cache
#[derive(Debug)]
pub struct TransactionExecutor { pub struct TransactionExecutor {
executor: Arc<dyn Executor>, executor: Arc<dyn Executor>,
is_miss: bool, is_miss: bool,

View File

@ -387,7 +387,7 @@ fn execute_transactions(
post_token_balances, post_token_balances,
)| { )| {
match execution_result { match execution_result {
TransactionExecutionResult::Executed(details) => { TransactionExecutionResult::Executed { details, .. } => {
let TransactionExecutionDetails { let TransactionExecutionDetails {
status, status,
log_messages, log_messages,

View File

@ -6,9 +6,7 @@ use {
blockstore::Blockstore, blockstore::Blockstore,
blockstore_processor::{TransactionStatusBatch, TransactionStatusMessage}, blockstore_processor::{TransactionStatusBatch, TransactionStatusMessage},
}, },
solana_runtime::bank::{ solana_runtime::bank::{DurableNonceFee, TransactionExecutionDetails},
DurableNonceFee, TransactionExecutionDetails, TransactionExecutionResult,
},
solana_transaction_status::{ solana_transaction_status::{
extract_and_fmt_memos, InnerInstructions, Reward, TransactionStatusMeta, extract_and_fmt_memos, InnerInstructions, Reward, TransactionStatusMeta,
}, },
@ -95,7 +93,7 @@ impl TransactionStatusService {
token_balances.post_token_balances, token_balances.post_token_balances,
rent_debits, rent_debits,
) { ) {
if let TransactionExecutionResult::Executed(details) = execution_result { if let Some(details) = execution_result {
let TransactionExecutionDetails { let TransactionExecutionDetails {
status, status,
log_messages, log_messages,
@ -338,23 +336,22 @@ pub(crate) mod tests {
let mut rent_debits = RentDebits::default(); let mut rent_debits = RentDebits::default();
rent_debits.insert(&pubkey, 123, 456); rent_debits.insert(&pubkey, 123, 456);
let transaction_result = let transaction_result = Some(TransactionExecutionDetails {
TransactionExecutionResult::Executed(TransactionExecutionDetails { status: Ok(()),
status: Ok(()), log_messages: None,
log_messages: None, inner_instructions: None,
inner_instructions: None, durable_nonce_fee: Some(DurableNonceFee::from(
durable_nonce_fee: Some(DurableNonceFee::from( &NonceFull::from_partial(
&NonceFull::from_partial( rollback_partial,
rollback_partial, &SanitizedMessage::Legacy(message),
&SanitizedMessage::Legacy(message), &[(pubkey, nonce_account)],
&[(pubkey, nonce_account)], &rent_debits,
&rent_debits, )
) .unwrap(),
.unwrap(), )),
)), return_data: None,
return_data: None, executed_units: 0u64,
executed_units: 0u64, });
});
let balances = TransactionBalancesSet { let balances = TransactionBalancesSet {
pre_balances: vec![vec![123456]], pre_balances: vec![vec![123456]],

View File

@ -1203,7 +1203,7 @@ impl Accounts {
} }
let execution_status = match &execution_results[i] { let execution_status = match &execution_results[i] {
TransactionExecutionResult::Executed(details) => &details.status, TransactionExecutionResult::Executed { details, .. } => &details.status,
// Don't store any accounts if tx wasn't executed // Don't store any accounts if tx wasn't executed
TransactionExecutionResult::NotExecuted(_) => continue, TransactionExecutionResult::NotExecuted(_) => continue,
}; };
@ -1366,6 +1366,7 @@ mod tests {
rent_collector::RentCollector, rent_collector::RentCollector,
}, },
solana_address_lookup_table_program::state::LookupTableMeta, solana_address_lookup_table_program::state::LookupTableMeta,
solana_program_runtime::invoke_context::Executors,
solana_sdk::{ solana_sdk::{
account::{AccountSharedData, WritableAccount}, account::{AccountSharedData, WritableAccount},
epoch_schedule::EpochSchedule, epoch_schedule::EpochSchedule,
@ -1381,7 +1382,9 @@ mod tests {
}, },
std::{ std::{
borrow::Cow, borrow::Cow,
cell::RefCell,
convert::TryFrom, convert::TryFrom,
rc::Rc,
sync::atomic::{AtomicBool, AtomicU64, Ordering}, sync::atomic::{AtomicBool, AtomicU64, Ordering},
thread, time, thread, time,
}, },
@ -1403,14 +1406,17 @@ mod tests {
status: Result<()>, status: Result<()>,
nonce: Option<&NonceFull>, nonce: Option<&NonceFull>,
) -> TransactionExecutionResult { ) -> TransactionExecutionResult {
TransactionExecutionResult::Executed(TransactionExecutionDetails { TransactionExecutionResult::Executed {
status, details: TransactionExecutionDetails {
log_messages: None, status,
inner_instructions: None, log_messages: None,
durable_nonce_fee: nonce.map(DurableNonceFee::from), inner_instructions: None,
return_data: None, durable_nonce_fee: nonce.map(DurableNonceFee::from),
executed_units: 0u64, return_data: None,
}) executed_units: 0u64,
},
executors: Rc::new(RefCell::new(Executors::default())),
}
} }
fn load_accounts_with_fee_and_rent( fn load_accounts_with_fee_and_rent(

View File

@ -618,35 +618,38 @@ pub struct TransactionExecutionDetails {
/// make such checks hard to do incorrectly. /// make such checks hard to do incorrectly.
#[derive(Debug, Clone)] #[derive(Debug, Clone)]
pub enum TransactionExecutionResult { pub enum TransactionExecutionResult {
Executed(TransactionExecutionDetails), Executed {
details: TransactionExecutionDetails,
executors: Rc<RefCell<Executors>>,
},
NotExecuted(TransactionError), NotExecuted(TransactionError),
} }
impl TransactionExecutionResult { impl TransactionExecutionResult {
pub fn was_executed_successfully(&self) -> bool { pub fn was_executed_successfully(&self) -> bool {
match self { match self {
Self::Executed(details) => details.status.is_ok(), Self::Executed { details, .. } => details.status.is_ok(),
Self::NotExecuted { .. } => false, Self::NotExecuted { .. } => false,
} }
} }
pub fn was_executed(&self) -> bool { pub fn was_executed(&self) -> bool {
match self { match self {
Self::Executed(_) => true, Self::Executed { .. } => true,
Self::NotExecuted(_) => false, Self::NotExecuted(_) => false,
} }
} }
pub fn details(&self) -> Option<&TransactionExecutionDetails> { pub fn details(&self) -> Option<&TransactionExecutionDetails> {
match self { match self {
Self::Executed(details) => Some(details), Self::Executed { details, .. } => Some(details),
Self::NotExecuted(_) => None, Self::NotExecuted(_) => None,
} }
} }
pub fn flattened_result(&self) -> Result<()> { pub fn flattened_result(&self) -> Result<()> {
match self { match self {
Self::Executed(details) => details.status.clone(), Self::Executed { details, .. } => details.status.clone(),
Self::NotExecuted(err) => Err(err.clone()), Self::NotExecuted(err) => Err(err.clone()),
} }
} }
@ -3678,7 +3681,7 @@ impl Bank {
let mut status_cache = self.src.status_cache.write().unwrap(); let mut status_cache = self.src.status_cache.write().unwrap();
assert_eq!(sanitized_txs.len(), execution_results.len()); assert_eq!(sanitized_txs.len(), execution_results.len());
for (tx, execution_result) in sanitized_txs.iter().zip(execution_results) { for (tx, execution_result) in sanitized_txs.iter().zip(execution_results) {
if let TransactionExecutionResult::Executed(details) = execution_result { if let Some(details) = execution_result.details() {
// Add the message hash to the status cache to ensure that this message // Add the message hash to the status cache to ensure that this message
// won't be processed again with a different signature. // won't be processed again with a different signature.
status_cache.insert( status_cache.insert(
@ -3890,7 +3893,7 @@ impl Bank {
let execution_result = execution_results.pop().unwrap(); let execution_result = execution_results.pop().unwrap();
let flattened_result = execution_result.flattened_result(); let flattened_result = execution_result.flattened_result();
let (logs, return_data) = match execution_result { let (logs, return_data) = match execution_result {
TransactionExecutionResult::Executed(details) => { TransactionExecutionResult::Executed { details, .. } => {
(details.log_messages, details.return_data) (details.log_messages, details.return_data)
} }
TransactionExecutionResult::NotExecuted(_) => (None, None), TransactionExecutionResult::NotExecuted(_) => (None, None),
@ -4185,14 +4188,6 @@ impl Bank {
process_message_time.as_us() process_message_time.as_us()
); );
let mut update_executors_time = Measure::start("update_executors_time");
self.update_executors(process_result.is_ok(), executors);
update_executors_time.stop();
saturating_add_assign!(
timings.execute_accessories.update_executors_us,
update_executors_time.as_us()
);
let status = process_result let status = process_result
.and_then(|info| { .and_then(|info| {
let post_account_state_info = let post_account_state_info =
@ -4254,14 +4249,17 @@ impl Bank {
None None
}; };
TransactionExecutionResult::Executed(TransactionExecutionDetails { TransactionExecutionResult::Executed {
status, details: TransactionExecutionDetails {
log_messages, status,
inner_instructions, log_messages,
durable_nonce_fee, inner_instructions,
return_data, durable_nonce_fee,
executed_units, return_data,
}) executed_units,
},
executors,
}
} }
#[allow(clippy::type_complexity)] #[allow(clippy::type_complexity)]
@ -4443,11 +4441,11 @@ impl Bank {
}; };
if store { if store {
if let TransactionExecutionResult::Executed(TransactionExecutionDetails { if let Some(TransactionExecutionDetails {
status, status,
log_messages: Some(log_messages), log_messages: Some(log_messages),
.. ..
}) = execution_result }) = execution_result.details()
{ {
let mut transaction_log_collector = let mut transaction_log_collector =
self.transaction_log_collector.write().unwrap(); self.transaction_log_collector.write().unwrap();
@ -4623,7 +4621,7 @@ impl Bank {
.zip(execution_results) .zip(execution_results)
.map(|(tx, execution_result)| { .map(|(tx, execution_result)| {
let (execution_status, durable_nonce_fee) = match &execution_result { let (execution_status, durable_nonce_fee) = match &execution_result {
TransactionExecutionResult::Executed(details) => { TransactionExecutionResult::Executed { details, .. } => {
Ok((&details.status, details.durable_nonce_fee.as_ref())) Ok((&details.status, details.durable_nonce_fee.as_ref()))
} }
TransactionExecutionResult::NotExecuted(err) => Err(err.clone()), TransactionExecutionResult::NotExecuted(err) => Err(err.clone()),
@ -4743,6 +4741,18 @@ impl Bank {
sanitized_txs.len() sanitized_txs.len()
); );
let mut update_executors_time = Measure::start("update_executors_time");
for execution_result in &execution_results {
if let TransactionExecutionResult::Executed { details, executors } = execution_result {
self.update_executors(details.status.is_ok(), executors.clone());
}
}
update_executors_time.stop();
saturating_add_assign!(
timings.execute_accessories.update_executors_us,
update_executors_time.as_us()
);
timings.saturating_add_in_place(ExecuteTimingType::StoreUs, write_time.as_us()); timings.saturating_add_in_place(ExecuteTimingType::StoreUs, write_time.as_us());
timings.saturating_add_in_place( timings.saturating_add_in_place(
ExecuteTimingType::UpdateStakesCacheUs, ExecuteTimingType::UpdateStakesCacheUs,
@ -7186,14 +7196,17 @@ pub(crate) mod tests {
status: Result<()>, status: Result<()>,
nonce: Option<&NonceFull>, nonce: Option<&NonceFull>,
) -> TransactionExecutionResult { ) -> TransactionExecutionResult {
TransactionExecutionResult::Executed(TransactionExecutionDetails { TransactionExecutionResult::Executed {
status, details: TransactionExecutionDetails {
log_messages: None, status,
inner_instructions: None, log_messages: None,
durable_nonce_fee: nonce.map(DurableNonceFee::from), inner_instructions: None,
return_data: None, durable_nonce_fee: nonce.map(DurableNonceFee::from),
executed_units: 0u64, return_data: None,
}) executed_units: 0u64,
},
executors: Rc::new(RefCell::new(Executors::default())),
}
} }
#[test] #[test]
@ -12899,13 +12912,16 @@ pub(crate) mod tests {
// This is an InstructionError - fees charged // This is an InstructionError - fees charged
assert!(matches!( assert!(matches!(
transaction_results.execution_results[2], transaction_results.execution_results[2],
TransactionExecutionResult::Executed(TransactionExecutionDetails { TransactionExecutionResult::Executed {
status: Err(TransactionError::InstructionError( details: TransactionExecutionDetails {
0, status: Err(TransactionError::InstructionError(
InstructionError::Custom(1), 0,
)), InstructionError::Custom(1),
)),
..
},
.. ..
}), },
)); ));
assert_eq!(transaction_balances_set.pre_balances[2], vec![9, 0, 1]); assert_eq!(transaction_balances_set.pre_balances[2], vec![9, 0, 1]);
assert_eq!(transaction_balances_set.post_balances[2], vec![8, 0, 1]); assert_eq!(transaction_balances_set.post_balances[2], vec![8, 0, 1]);