Skip to content

Commit

Permalink
Add SBF instruction tracing to the rbpf-tests driver. (anza-xyz#193)
Browse files Browse the repository at this point in the history
This patch allows the user to turn on SBF instruction tracing/disassembly
for a rbpf case. This is an extremely valuable debugging tool when an rbpf
test crashes in the move-native library-- or perhaps worse-- in core rust
libraries.  This code is copied and integrated from the Solana ledger-tool.

To enable, set environment variable TRACE to a filename where the output
will be directed. Setting TRACE= or TRACE=stdout writes output to stdout:
  TRACE=foo.txt cargo test -p move-mv-llvm-compiler --test rbpf-tests foo-test

Co-authored-by: Dmitri Makarov <dmakarov@users.noreply.github.com>
  • Loading branch information
2 people authored and ksolana committed Jul 6, 2023
1 parent 8dcb5c3 commit 72e8bb8
Show file tree
Hide file tree
Showing 2 changed files with 81 additions and 3 deletions.
24 changes: 22 additions & 2 deletions language/tools/move-mv-llvm-compiler/docs/Development.md
Original file line number Diff line number Diff line change
Expand Up @@ -103,10 +103,20 @@ to "expected" files. This can be done like
```sh
PROMOTE_LLVM_IR=1 cargo test -p move-mv-llvm-compiler --test move-ir-tests
```

Most new tests should be `move-ir-tests` or `rbpf-tests`,
as the Move IR is not stable nor easy to work with.

### Environment variables to control rbpf-tests
#### `TRACE`
Enable SBF instruction tracing/disassembly for a rbpf case. This is an extremely valuable debugging tool when an rbpf test crashes in the `move-native` library-- or perhaps worse-- in core rust libraries. To enable, set environment variable `TRACE` to a filename where the output will be directed. Setting `TRACE=` or `TRACE=stdout` writes the output to stdout.
```sh
TRACE=foo.txt cargo test -p move-mv-llvm-compiler --test rbpf-tests my_test_case
```
#### `DUMP`
Setting this environment variable will enable the test driver to output `// log` messages.
```sh
DUMP=1 cargo test -p move-mv-llvm-compiler --test rbpf-tests
```

## Test directives

Expand All @@ -130,9 +140,19 @@ Supported directives include:
- `// ignore` - don't run the test, for broken tests.
- `// abort {code}` - expect an abort with code.
- `// log {string}` - expect a string to be logged by the `debug::print` function.
- `// signers {signer0,signer1,...}` - provide a list of signers to script `main`. Each signer is injected into a corresponding argument of main with type `signer`. See example below.

`abort` and `log` are only supported by the `rbpf-tests` runner.
```move
// signers 0xcafe,0xf00d,0xc0ffee,0xb00
...
script {
fun main(s1: signer, s2: signer, s3: signer, s4: signer) {
...
}
}
```

`abort`, `log`, and `signers` are only supported by the `rbpf-tests` runner.

## Debugging

Expand Down
60 changes: 59 additions & 1 deletion language/tools/move-mv-llvm-compiler/tests/rbpf-tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@ use solana_program_runtime::{
loaded_programs::{LoadProgramMetrics, LoadedProgramType},
with_mock_invoke_context,
};
use solana_rbpf::{elf::Executable, verifier::RequisiteVerifier};
use solana_rbpf::{elf::Executable, static_analysis::Analysis, verifier::RequisiteVerifier};
use solana_sdk::{
account::AccountSharedData,
bpf_loader_upgradeable,
Expand Down Expand Up @@ -313,6 +313,46 @@ fn check_abort_code(expected_code: u64, message: String) {
}
}

struct LazyAnalysis<'a, 'b> {
analysis: Option<Analysis<'a>>,
executable: &'a Executable<RequisiteVerifier, InvokeContext<'b>>,
}

impl<'a, 'b> LazyAnalysis<'a, 'b> {
fn new(executable: &'a Executable<RequisiteVerifier, InvokeContext<'b>>) -> Self {
Self {
analysis: None,
executable,
}
}

fn analyze(&mut self) -> &Analysis {
if let Some(ref analysis) = self.analysis {
return analysis;
}
self.analysis
.insert(Analysis::from_executable(self.executable).unwrap())
}
}

fn output_trace(filename: &str, trace: &[[u64; 12]], frame: usize, analysis: &mut LazyAnalysis) {
use std::{fs::File, io::Write};
if filename.is_empty() || filename == "stdout" {
writeln!(&mut std::io::stdout(), "Frame {frame}").unwrap();
analysis
.analyze()
.disassemble_trace_log(&mut std::io::stdout(), trace)
.unwrap();
} else {
let mut fd = File::create(filename).unwrap();
writeln!(&fd, "Frame {frame}").unwrap();
analysis
.analyze()
.disassemble_trace_log(&mut fd, trace)
.unwrap();
}
}

fn run_rbpf(test_plan: &tc::TestPlan, exe: &Path) -> anyhow::Result<()> {
let mut transaction_accounts = Vec::new();
let mut instruction_accounts = Vec::new();
Expand Down Expand Up @@ -392,6 +432,9 @@ fn run_rbpf(test_plan: &tc::TestPlan, exe: &Path) -> anyhow::Result<()> {
true, // copy_account_data
)
.unwrap();

let mut analysis = LazyAnalysis::new(&verified_executable);

create_vm!(
vm,
&verified_executable,
Expand All @@ -405,6 +448,21 @@ fn run_rbpf(test_plan: &tc::TestPlan, exe: &Path) -> anyhow::Result<()> {

let result = Result::from(result);

let trace_var = std::env::var("TRACE");
if let Ok(trace_filename) = trace_var {
if let Some(Some(syscall_context)) = vm.env.context_object_pointer.syscall_context.last() {
let trace = syscall_context.trace_log.as_slice();
output_trace(&trace_filename, trace, 0, &mut analysis);

// The remaining traces are saved in InvokeContext when
// corresponding syscall_contexts are popped.
let traces = vm.env.context_object_pointer.get_traces();
for (frame, trace) in traces.iter().filter(|t| !t.is_empty()).enumerate() {
output_trace(&trace_filename, trace, frame + 1, &mut analysis);
}
}
}

drop(vm);

let mut all_logs = invoke_context
Expand Down

0 comments on commit 72e8bb8

Please sign in to comment.