diff --git a/core/src/progress_map.rs b/core/src/progress_map.rs index 2308421fc5e39f..565dd05614d328 100644 --- a/core/src/progress_map.rs +++ b/core/src/progress_map.rs @@ -126,6 +126,28 @@ impl ReplaySlotStats { 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 diff --git a/program-runtime/src/timings.rs b/program-runtime/src/timings.rs index e4919d028e7393..10dca0f5f1c0f0 100644 --- a/program-runtime/src/timings.rs +++ b/program-runtime/src/timings.rs @@ -137,6 +137,10 @@ pub struct ExecuteDetailsTimings { pub total_account_count: u64, pub total_data_size: usize, pub data_size_changed: usize, + pub create_executor_register_syscalls_us: u64, + pub create_executor_load_elf_us: u64, + pub create_executor_verify_code_us: u64, + pub create_executor_jit_compile_us: u64, pub per_program_timings: HashMap, } impl ExecuteDetailsTimings { @@ -158,6 +162,18 @@ impl ExecuteDetailsTimings { self.data_size_changed = self .data_size_changed .saturating_add(other.data_size_changed); + self.create_executor_register_syscalls_us = self + .create_executor_register_syscalls_us + .saturating_add(other.create_executor_register_syscalls_us); + self.create_executor_load_elf_us = self + .create_executor_load_elf_us + .saturating_add(other.create_executor_load_elf_us); + self.create_executor_verify_code_us = self + .create_executor_verify_code_us + .saturating_add(other.create_executor_verify_code_us); + self.create_executor_jit_compile_us = self + .create_executor_jit_compile_us + .saturating_add(other.create_executor_jit_compile_us); for (id, other) in &other.per_program_timings { let program_timing = self.per_program_timings.entry(*id).or_default(); program_timing.accumulate_program_timings(other); diff --git a/programs/bpf_loader/src/lib.rs b/programs/bpf_loader/src/lib.rs index 01c61cde6627fb..39011ad2cc760e 100644 --- a/programs/bpf_loader/src/lib.rs +++ b/programs/bpf_loader/src/lib.rs @@ -85,7 +85,14 @@ pub fn create_executor( use_jit: bool, reject_deployment_of_broken_elfs: bool, ) -> Result, InstructionError> { - let syscall_registry = syscalls::register_syscalls(invoke_context).map_err(|e| { + let mut register_syscalls_time = Measure::start("register_syscalls_time"); + let register_syscall_result = syscalls::register_syscalls(invoke_context); + register_syscalls_time.stop(); + invoke_context.timings.create_executor_register_syscalls_us = invoke_context + .timings + .create_executor_register_syscalls_us + .saturating_add(register_syscalls_time.as_us()); + let syscall_registry = register_syscall_result.map_err(|e| { ic_msg!(invoke_context, "Failed to register syscalls: {}", e); InstructionError::ProgramEnvironmentSetupFailure })?; @@ -116,20 +123,40 @@ pub fn create_executor( let mut executable = { let keyed_accounts = invoke_context.get_keyed_accounts()?; let programdata = keyed_account_at_index(keyed_accounts, programdata_account_index)?; - Executable::::from_elf( + let mut load_elf_time = Measure::start("load_elf_time"); + let executable = Executable::::from_elf( &programdata.try_account_ref()?.data()[programdata_offset..], None, config, syscall_registry, - ) + ); + load_elf_time.stop(); + invoke_context.timings.create_executor_load_elf_us = invoke_context + .timings + .create_executor_load_elf_us + .saturating_add(load_elf_time.as_us()); + executable } .map_err(|e| map_ebpf_error(invoke_context, e))?; let text_bytes = executable.get_text_bytes().1; + let mut verify_code_time = Measure::start("verify_code_time"); verifier::check(text_bytes, &config) .map_err(|e| map_ebpf_error(invoke_context, EbpfError::UserError(e.into())))?; + verify_code_time.stop(); + invoke_context.timings.create_executor_verify_code_us = invoke_context + .timings + .create_executor_verify_code_us + .saturating_add(verify_code_time.as_us()); if use_jit { - if let Err(err) = Executable::::jit_compile(&mut executable) - { + let mut jit_compile_time = Measure::start("jit_compile_time"); + let jit_compile_result = + Executable::::jit_compile(&mut executable); + jit_compile_time.stop(); + invoke_context.timings.create_executor_jit_compile_us = invoke_context + .timings + .create_executor_jit_compile_us + .saturating_add(jit_compile_time.as_us()); + if let Err(err) = jit_compile_result { ic_msg!(invoke_context, "Failed to compile program {:?}", err); return Err(InstructionError::ProgramFailedToCompile); }