Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: add decoding for individual trace steps #157

Merged
merged 4 commits into from
Jul 2, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions src/tracing/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -416,6 +416,7 @@ impl TracingInspector {
gas_remaining: interp.gas.remaining(),
gas_refund_counter: interp.gas.refunded() as u64,
gas_used,
decoded: None,

// fields will be populated end of call
gas_cost: 0,
Expand Down
27 changes: 27 additions & 0 deletions src/tracing/types.rs
Original file line number Diff line number Diff line change
Expand Up @@ -541,6 +541,31 @@ pub enum TraceMemberOrder {
Step(usize),
}

/// Represents a decoded internal function call.
#[derive(Clone, Debug, PartialEq, Eq)]
#[cfg_attr(feature = "serde", derive(serde::Serialize, serde::Deserialize))]
pub struct DecodedInternalCall {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe worth also adding an optional style field?

Copy link
Contributor Author

@klkvr klkvr Jul 1, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we don't separate contract name and function name for internal calls, so I think func_name can be styled directly?

I think this could be useful, though not sure how to deal with serde for it

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can be a follow-up where we add it to other structs as well

/// Name of the internal function.
pub func_name: String,
/// Input arguments of the internal function.
pub args: Option<Vec<String>>,
/// Optional decoded return data.
pub return_data: Option<Vec<String>>,
}

/// Represents a decoded trace step. Currently two formats are supported.
#[derive(Clone, Debug, PartialEq, Eq)]
#[cfg_attr(feature = "serde", derive(serde::Serialize, serde::Deserialize))]
pub enum DecodedTraceStep {
/// Decoded internal function call. Displayed similarly to external calls.
///
/// Keeps decoded internal call data and an index of the step where the internal call execution
/// ends.
InternalCall(DecodedInternalCall, usize),
/// Arbitrary line reperesenting the step. Might be used for displaying individual opcodes.
Line(String),
}

/// Represents a tracked call step during execution
#[derive(Clone, Debug, PartialEq, Eq)]
#[cfg_attr(feature = "serde", derive(serde::Serialize, serde::Deserialize))]
Expand Down Expand Up @@ -580,6 +605,8 @@ pub struct CallTraceStep {
///
/// This is set after the step was executed.
pub status: InstructionResult,
/// Optional complementary decoded step data.
pub decoded: Option<DecodedTraceStep>,
}

// === impl CallTraceStep ===
Expand Down
121 changes: 113 additions & 8 deletions src/tracing/writer.rs
Original file line number Diff line number Diff line change
@@ -1,5 +1,8 @@
use super::{
types::{CallKind, CallLog, CallTrace, CallTraceNode, DecodedCallData, TraceMemberOrder},
types::{
CallKind, CallLog, CallTrace, CallTraceNode, DecodedCallData, DecodedTraceStep,
TraceMemberOrder,
},
CallTraceArena,
};
use alloy_primitives::{address, hex, Address};
Expand Down Expand Up @@ -86,6 +89,56 @@ impl<W: Write> TraceWriter<W> {
self.writer.flush()
}

/// Writes a single item of a single node to the writer. Returns the index of the next item to
/// be written.
///
/// Note: this will return length of [CallTraceNode::ordering] when last item will get
/// processed.
fn write_item(
&mut self,
nodes: &[CallTraceNode],
node_idx: usize,
item_idx: usize,
) -> io::Result<usize> {
let node = &nodes[node_idx];
match &node.ordering[item_idx] {
TraceMemberOrder::Log(index) => {
self.write_log(&node.logs[*index])?;
Ok(item_idx + 1)
}
TraceMemberOrder::Call(index) => {
self.write_node(nodes, node.children[*index])?;
Ok(item_idx + 1)
}
TraceMemberOrder::Step(index) => self.write_step(nodes, node_idx, item_idx, *index),
}
}

/// Writes items of a single node to the writer, starting from the given index, and until the
/// given predicate is false.
///
/// Returns the index of the next item to be written.
fn write_items_until(
&mut self,
nodes: &[CallTraceNode],
node_idx: usize,
first_item_idx: usize,
f: impl Fn(usize) -> bool,
) -> io::Result<usize> {
let mut item_idx = first_item_idx;
while !f(item_idx) {
item_idx = self.write_item(nodes, node_idx, item_idx)?;
}
Ok(item_idx)
}

/// Writes all items of a single node to the writer.
fn write_items(&mut self, nodes: &[CallTraceNode], node_idx: usize) -> io::Result<()> {
let items_cnt = nodes[node_idx].ordering.len();
self.write_items_until(nodes, node_idx, 0, |idx| idx == items_cnt)?;
Ok(())
}

/// Writes a single node and its children to the writer.
fn write_node(&mut self, nodes: &[CallTraceNode], idx: usize) -> io::Result<()> {
let node = &nodes[idx];
Expand All @@ -97,13 +150,7 @@ impl<W: Write> TraceWriter<W> {

// Write logs and subcalls.
self.indentation_level += 1;
for child in &node.ordering {
match *child {
TraceMemberOrder::Log(index) => self.write_log(&node.logs[index]),
TraceMemberOrder::Call(index) => self.write_node(nodes, node.children[index]),
TraceMemberOrder::Step(_) => Ok(()),
}?;
}
self.write_items(nodes, idx)?;

// Write return data.
self.write_edge()?;
Expand Down Expand Up @@ -212,6 +259,64 @@ impl<W: Write> TraceWriter<W> {
Ok(())
}

/// Writes a single step of a single node to the writer. Returns the index of the next item to
/// be written.
fn write_step(
&mut self,
nodes: &[CallTraceNode],
node_idx: usize,
item_idx: usize,
step_idx: usize,
) -> io::Result<usize> {
let node = &nodes[node_idx];
let step = &node.trace.steps[step_idx];

let Some(decoded) = &step.decoded else {
// We only write explicitly decoded steps to avoid bloating the output.
return Ok(item_idx + 1);
};

match decoded {
DecodedTraceStep::InternalCall(call, end_idx) => {
let gas_used = node.trace.steps[*end_idx].gas_used.saturating_sub(step.gas_used);
self.write_branch()?;
self.indentation_level += 1;

writeln!(
self.writer,
"[{}] {}{}",
gas_used,
call.func_name,
call.args.as_ref().map(|v| format!("({})", v.join(", "))).unwrap_or_default()
)?;

let end_item_idx =
self.write_items_until(nodes, node_idx, item_idx + 1, |item_idx: usize| {
matches!(&node.ordering[item_idx], TraceMemberOrder::Step(idx) if *idx == *end_idx)
})?;

self.write_edge()?;
write!(self.writer, "{RETURN}")?;

if let Some(outputs) = &call.return_data {
write!(self.writer, "{}", outputs.join(", "))?;
}

writeln!(self.writer)?;

self.indentation_level -= 1;

Ok(end_item_idx + 1)
}
DecodedTraceStep::Line(line) => {
self.write_branch()?;
writeln!(self.writer, "{line}")?;

Ok(item_idx + 1)
}
}
}

/// Writes the footer of a call trace.
fn write_trace_footer(&mut self, trace: &CallTrace) -> io::Result<()> {
write!(
Expand Down
66 changes: 58 additions & 8 deletions tests/it/writer.rs
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,10 @@ use crate::utils::{write_traces, TestEvm};
use alloy_primitives::{bytes, Bytes, U256};
use alloy_sol_types::{sol, SolCall};
use expect_test::expect;
use revm_inspectors::tracing::{types::DecodedCallData, TracingInspector, TracingInspectorConfig};
use revm_inspectors::tracing::{
types::{DecodedCallData, DecodedInternalCall, DecodedTraceStep},
TracingInspector, TracingInspectorConfig,
};

#[test]
fn test_basic_trace_printing() {
Expand Down Expand Up @@ -194,7 +197,7 @@ fn test_decoded_trace_printing() {
let mut index = 0;

let mut call = |data: Vec<u8>| -> String {
let mut tracer = TracingInspector::new(TracingInspectorConfig::all().disable_steps());
let mut tracer = TracingInspector::new(TracingInspectorConfig::all());
let r = evm.call(address, data.into(), &mut tracer).unwrap();
assert!(r.is_success());

Expand Down Expand Up @@ -244,17 +247,33 @@ fn test_decoded_trace_printing() {
"#]]
.assert_eq(&s);

let mut s = call(Counter::log2Call {}.abi_encode());
patch_output(&mut s);
expect![[r#"
. [4642] Counter::log2()
├─ [sload] 0x0000000000000000000000000000000000000000000000000000000000000045
├─ emit Log2(foo: 0x0000000000000000000000000000000000000000000000000000000000000045, bar: 0x000000000000000000000000000000000000000000000000000000000000007b)
└─ ← [Stop]
"#]]
.assert_eq(&s);

let mut s = call(Counter::nest1Call {}.abi_encode());
patch_output(&mut s);
expect![[r#"
. [13556] Counter::nest1()
├─ emit Log1(foo: 0x0000000000000000000000000000000000000000000000000000000000000045)
├─ [8575] Counter::nest2()
│ ├─ [2337] Counter::nest3()
│ │ ├─ emit Log1(foo: 0x0000000000000000000000000000000000000000000000000000000000000046)
├─ [13264] Counter::_nest1()
│ ├─ emit Log1(foo: 0x0000000000000000000000000000000000000000000000000000000000000045)
│ ├─ [8575] Counter::nest2()
│ │ ├─ [2337] Counter::nest3()
│ │ │ ├─ [2220] Counter::_nest3Internal(arg1, arg2, 3)
│ │ │ │ ├─ [mstore]
│ │ │ │ ├─ emit Log1(foo: 0x0000000000000000000000000000000000000000000000000000000000000046)
│ │ │ │ └─ ← ret1
│ │ │ ├─ [before_return]
│ │ │ └─ ← [Return]
│ │ ├─ emit Log2(foo: 0x0000000000000000000000000000000000000000000000000000000000000046, bar: 0x000000000000000000000000000000000000000000000000000000000000007b)
│ │ └─ ← [Return]
│ ├─ emit Log2(foo: 0x0000000000000000000000000000000000000000000000000000000000000046, bar: 0x000000000000000000000000000000000000000000000000000000000000007b)
│ └─ ← [Return]
│ └─ ← ret1, ret2
└─ ← [Return]
"#]]
.assert_eq(&s);
Expand Down Expand Up @@ -368,6 +387,37 @@ fn patch_traces(patch: usize, t: &mut TracingInspector) {
node.trace.decoded.return_data = Some("69".to_string())
}
4 => node.trace.decoded.return_data = Some("69".to_string()),
5 => {
node.trace.steps[0].decoded = Some(DecodedTraceStep::Line(
"[sload] 0x0000000000000000000000000000000000000000000000000000000000000045"
.to_string(),
));
}
6 if node.trace.depth == 2 => {
node.trace.steps[30].decoded = Some(DecodedTraceStep::InternalCall(
DecodedInternalCall {
func_name: "Counter::_nest3Internal".to_string(),
args: Some(vec!["arg1".to_string(), "arg2".to_string(), "3".to_string()]),
return_data: Some(vec!["ret1".to_string()]),
},
89,
));
node.trace.steps[87].decoded = Some(DecodedTraceStep::Line("[mstore]".to_string()));
node.trace.steps[90].decoded =
Some(DecodedTraceStep::Line("[before_return]".to_string()));
println!("{:?}", node.ordering);
}
6 if node.trace.depth == 0 => {
node.trace.steps[10].decoded = Some(DecodedTraceStep::InternalCall(
DecodedInternalCall {
func_name: "Counter::_nest1".to_string(),
args: Some(vec![]),
return_data: Some(vec!["ret1".to_string(), "ret2".to_string()]),
},
150,
));
println!("{:?}", node.ordering);
}
_ => continue,
}
}
Expand Down
Loading