Add metrics for executor creation

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

program-runtime/src/timings.rs

@@ -125,6 +125,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<Pubkey, ProgramTiming>,
 }
 impl ExecuteDetailsTimings {
@@ -146,6 +150,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);

programs/bpf_loader/src/lib.rs

@@ -85,7 +85,14 @@ pub fn create_executor(
     use_jit: bool,
     reject_deployment_of_broken_elfs: bool,
 ) -> Result<Arc<BpfExecutor>, 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::<BpfError, ThisInstructionMeter>::from_elf(
+        let mut load_elf_time = Measure::start("load_elf_time");
+        let executable = Executable::<BpfError, ThisInstructionMeter>::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::<BpfError, ThisInstructionMeter>::jit_compile(&mut executable)
+        let mut jit_compile_time = Measure::start("jit_compile_time");
-        {
+        let jit_compile_result =
+            Executable::<BpfError, ThisInstructionMeter>::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);
         }