SVM: Return execute timings from API (#1604)

* SVM: add `execute_timings` to API return type

* SVM: message processor: rename `timings` to `execute_timings`

* SVM: remove `timings` mutable input

runtime/src/bank.rs

@@ -3703,13 +3703,15 @@ impl Bank {
                 self,
                 sanitized_txs,
                 &mut check_results,
-                timings,
                 &processing_config,
             );
 
         // Accumulate the errors returned by the batch processor.
         error_counters.accumulate(&sanitized_output.error_metrics);
 
+        // Accumulate the transaction batch execution timings.
+        timings.accumulate(&sanitized_output.execute_timings);
+
         let mut signature_count = 0;
 
         let mut executed_transactions_count: usize = 0;

svm/src/message_processor.rs

@@ -37,7 +37,7 @@ impl MessageProcessor {
         message: &SanitizedMessage,
         program_indices: &[Vec<IndexOfAccount>],
         invoke_context: &mut InvokeContext,
-        timings: &mut ExecuteTimings,
+        execute_timings: &mut ExecuteTimings,
         accumulated_consumed_units: &mut u64,
     ) -> Result<(), TransactionError> {
         debug_assert_eq!(program_indices.len(), message.instructions().len());
@@ -112,23 +112,26 @@ impl MessageProcessor {
                     &instruction_accounts,
                     program_indices,
                     &mut compute_units_consumed,
-                    timings,
+                    execute_timings,
                 );
                 let time = time.end_as_us();
                 *accumulated_consumed_units =
                     accumulated_consumed_units.saturating_add(compute_units_consumed);
-                timings.details.accumulate_program(
+                execute_timings.details.accumulate_program(
                     program_id,
                     time,
                     compute_units_consumed,
                     result.is_err(),
                 );
                 invoke_context.timings = {
-                    timings.details.accumulate(&invoke_context.timings);
+                    execute_timings.details.accumulate(&invoke_context.timings);
                     ExecuteDetailsTimings::default()
                 };
                 saturating_add_assign!(
-                    timings.execute_accessories.process_instructions.total_us,
+                    execute_timings
+                        .execute_accessories
+                        .process_instructions
+                        .total_us,
                     time
                 );
                 result

svm/src/transaction_processor.rs

@@ -62,6 +62,8 @@ pub type TransactionLogMessages = Vec<String>;
 pub struct LoadAndExecuteSanitizedTransactionsOutput {
     /// Error metrics for transactions that were processed.
     pub error_metrics: TransactionErrorMetrics,
+    /// Timings for transaction batch execution.
+    pub execute_timings: ExecuteTimings,
     // Vector of results indicating whether a transaction was executed or could not
     // be executed. Note executed transactions can still have failed!
     pub execution_results: Vec<TransactionExecutionResult>,
@@ -210,11 +212,11 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
         callbacks: &CB,
         sanitized_txs: &[SanitizedTransaction],
         check_results: &mut [TransactionCheckResult],
-        timings: &mut ExecuteTimings,
         config: &TransactionProcessingConfig,
     ) -> LoadAndExecuteSanitizedTransactionsOutput {
         // Initialize metrics.
         let mut error_metrics = TransactionErrorMetrics::default();
+        let mut execute_timings = ExecuteTimings::default();
 
         let mut program_cache_time = Measure::start("program_cache");
         let mut program_accounts_map = Self::filter_executable_program_accounts(
@@ -240,6 +242,7 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
                 vec![TransactionExecutionResult::NotExecuted(ERROR); sanitized_txs.len()];
             return LoadAndExecuteSanitizedTransactionsOutput {
                 error_metrics,
+                execute_timings,
                 execution_results,
                 loaded_transactions,
             };
@@ -277,7 +280,7 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
                             );
                             compute_budget_process_transaction_time.stop();
                             saturating_add_assign!(
-                                timings
+                                execute_timings
                                     .execute_accessories
                                     .compute_budget_process_transaction_us,
                                 compute_budget_process_transaction_time.as_us()
@@ -293,7 +296,7 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
                         tx,
                         loaded_transaction,
                         compute_budget,
-                        timings,
+                        &mut execute_timings,
                         &mut error_metrics,
                         &program_cache_for_tx_batch.borrow(),
                         config,
@@ -344,15 +347,17 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
             sanitized_txs.len(),
         );
 
-        timings.saturating_add_in_place(
+        execute_timings.saturating_add_in_place(
             ExecuteTimingType::ProgramCacheUs,
             program_cache_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());
+        execute_timings.saturating_add_in_place(ExecuteTimingType::LoadUs, load_time.as_us());
+        execute_timings
+            .saturating_add_in_place(ExecuteTimingType::ExecuteUs, execution_time.as_us());
 
         LoadAndExecuteSanitizedTransactionsOutput {
             error_metrics,
+            execute_timings,
             execution_results,
             loaded_transactions,
         }
@@ -561,7 +566,7 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
         tx: &SanitizedTransaction,
         loaded_transaction: &mut LoadedTransaction,
         compute_budget: ComputeBudget,
-        timings: &mut ExecuteTimings,
+        execute_timings: &mut ExecuteTimings,
         error_metrics: &mut TransactionErrorMetrics,
         program_cache_for_tx_batch: &ProgramCacheForTxBatch,
         config: &TransactionProcessingConfig,
@@ -640,15 +645,15 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
             tx.message(),
             &loaded_transaction.program_indices,
             &mut invoke_context,
-            timings,
+            execute_timings,
             &mut executed_units,
         );
         process_message_time.stop();
 
         drop(invoke_context);
 
         saturating_add_assign!(
-            timings.execute_accessories.process_message_us,
+            execute_timings.execute_accessories.process_message_us,
             process_message_time.as_us()
         );
 
@@ -715,10 +720,13 @@ impl<FG: ForkGraph> TransactionBatchProcessor<FG> {
 
         loaded_transaction.accounts = accounts;
         saturating_add_assign!(
-            timings.details.total_account_count,
+            execute_timings.details.total_account_count,
             loaded_transaction.accounts.len() as u64
         );
-        saturating_add_assign!(timings.details.changed_account_count, touched_account_count);
+        saturating_add_assign!(
+            execute_timings.details.changed_account_count,
+            touched_account_count
+        );
 
         let return_data = if config.recording_config.enable_return_data_recording
             && !return_data.data.is_empty()

svm/tests/conformance.rs

@@ -295,7 +295,6 @@ fn run_fixture(fixture: InstrFixture, filename: OsString, execute_as_instr: bool
         limit_to_load_programs: true,
         recording_config,
     };
-    let mut timings = ExecuteTimings::default();
 
     if execute_as_instr {
         execute_fixture_as_instr(
@@ -314,7 +313,6 @@ fn run_fixture(fixture: InstrFixture, filename: OsString, execute_as_instr: bool
         &mock_bank,
         &transactions,
         transaction_check.as_mut_slice(),
-        &mut timings,
         &processor_config,
     );
 

svm/tests/integration_test.rs

@@ -16,7 +16,6 @@ use {
             program::{BuiltinFunction, BuiltinProgram, FunctionRegistry},
             vm::Config,
         },
-        timings::ExecuteTimings,
     },
     solana_sdk::{
         account::{AccountSharedData, ReadableAccount, WritableAccount},
@@ -468,13 +467,11 @@ fn svm_integration() {
         },
         ..Default::default()
     };
-    let mut timings = ExecuteTimings::default();
 
     let result = batch_processor.load_and_execute_sanitized_transactions(
         &mock_bank,
         &transactions,
         check_results.as_mut_slice(),
-        &mut timings,
         &processing_config,
     );