add excutor creation trace timings

Cargo.lock

@@ -4419,6 +4419,7 @@ dependencies = [
  "rustversion",
  "sha3",
  "solana-measure",
+ "solana-metrics",
  "solana-runtime",
  "solana-sdk",
  "solana_rbpf",

programs/bpf/Cargo.lock

@@ -2750,6 +2750,7 @@ dependencies = [
  "rand_core 0.6.2",
  "sha3",
  "solana-measure",
+ "solana-metrics",
  "solana-runtime",
  "solana-sdk",
  "solana_rbpf",

programs/bpf_loader/Cargo.toml

@@ -19,6 +19,7 @@ rand_core = "0.6.2"
 libsecp256k1 = "0.5.0"
 sha3 = "0.9.1"
 solana-measure = { path = "../../measure", version = "=1.8.12" }
+solana-metrics = { path = "../../metrics", version = "=1.8.12" }
 solana-runtime = { path = "../../runtime", version = "=1.8.12" }
 solana-sdk = { path = "../../sdk", version = "=1.8.12" }
 solana_rbpf = "=0.2.21"

programs/bpf_loader/src/lib.rs

@@ -8,6 +8,9 @@ pub mod upgradeable;
 pub mod upgradeable_with_jit;
 pub mod with_jit;
 
+#[macro_use]
+extern crate solana_metrics;
+
 use {
     crate::{
         serialization::{deserialize_parameters, serialize_parameters},
@@ -103,24 +106,52 @@ pub fn create_executor(
         reject_all_writable_sections: invoke_context.is_feature_active(&reject_all_elf_rw::id()),
         ..Config::default()
     };
+    let program_id;
+    let load_elf_us: u64;
+    let verify_elf_us: u64;
+    let mut jit_compile_us = 0u64;
     let mut executable = {
         let keyed_accounts = invoke_context.get_keyed_accounts()?;
         let program = keyed_account_at_index(keyed_accounts, program_account_index)?;
+        program_id = *program.unsigned_key();
         let account = program.try_account_ref()?;
         let data = &account.data()[program_data_offset..];
-        Executable::<BpfError, ThisInstructionMeter>::from_elf(data, None, config, syscall_registry)
+        let mut load_elf_time = Measure::start("load_elf_time");
+        let executable = Executable::<BpfError, ThisInstructionMeter>::from_elf(
+            data,
+            None,
+            config,
+            syscall_registry,
+        );
+        load_elf_time.stop();
+        load_elf_us = 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();
+    verify_elf_us = 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();
+        jit_compile_us = 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);
         }
     }
+    datapoint_trace!(
+        "create_executor_trace",
+        ("program_id", program_id.to_string(), String),
+        ("load_elf_us", load_elf_us, i64),
+        ("verify_elf_us", verify_elf_us, i64),
+        ("jit_compile_us", jit_compile_us, i64),
+    );
     Ok(Arc::new(BpfExecutor { executable }))
 }