Enable BPF program instruction traces (#15613)

Cargo.lock

@@ -4128,6 +4128,7 @@ dependencies = [
  "bincode",
  "byteorder",
  "curve25519-dalek 3.0.0",
+ "log 0.4.11",
  "num-derive",
  "num-traits",
  "rand 0.7.3",

program-test/src/lib.rs

@@ -430,8 +430,7 @@ impl Default for ProgramTest {
     ///
     fn default() -> Self {
         solana_logger::setup_with_default(
-            "solana_bpf_loader=debug,\
+            "solana_rbpf::vm=debug,\
-             solana_rbpf::vm=debug,\
              solana_runtime::message_processor=debug,\
              solana_runtime::system_instruction_processor=trace,\
              solana_program_test=info",
@@ -523,7 +522,7 @@ impl ProgramTest {
     /// directory.
     ///
     /// If `process_instruction` is provided, the natively built-program may be used instead of the
-    /// BPF shared object depending on the `bpf` environment variable.
+    /// BPF shared object depending on the `BPF_OUT_DIR` environment variable.
     pub fn add_program(
         &mut self,
         program_name: &str,

programs/bpf_loader/Cargo.toml

@@ -12,6 +12,7 @@ edition = "2018"
 bincode = "1.3.1"
 byteorder = "1.3.4"
 curve25519-dalek = "3"
+log = "0.4.11"
 num-derive = "0.3"
 num-traits = "0.2"
 rand_core = "0.6.2"

programs/bpf_loader/src/lib.rs

@@ -14,6 +14,7 @@ use crate::{
     serialization::{deserialize_parameters, serialize_parameters},
     syscalls::SyscallError,
 };
+use log::{log_enabled, trace, Level::Trace};
 use solana_rbpf::{
     ebpf::MM_HEAP_START,
     error::{EbpfError, UserDefinedError},
@@ -80,7 +81,7 @@ pub fn create_and_cache_executor(
             max_call_depth: bpf_compute_budget.max_call_depth,
             stack_frame_size: bpf_compute_budget.stack_frame_size,
             enable_instruction_meter: true,
-            enable_instruction_tracing: false,
+            enable_instruction_tracing: log_enabled!(Trace),
         },
     )
     .map_err(|e| map_ebpf_error(invoke_context, e))?;
@@ -804,6 +805,13 @@ impl Executor for BpfExecutor {
                 before - after,
                 before
             );
+            if log_enabled!(Trace) {
+                let mut trace_buffer = String::new();
+                vm.get_tracer()
+                    .write(&mut trace_buffer, vm.get_program())
+                    .unwrap();
+                trace!("BPF Program Instruction Trace:\n{}", trace_buffer);
+            }
             match result {
                 Ok(status) => {
                     if status != SUCCESS {