Skip to content

Commit

Permalink
feat(tracer): Record function calls and returns
Browse files Browse the repository at this point in the history
This commit also records function calls and returns from functions,
without passing the actual arguments and values in either direction.
That would be a follow-up.

Details:
 * `get_variables` is now public in `tooling/debugger/src/context.rs`;
   it is needed to extract the stack frame from the debugger;
 * drive-by: `trace_metadata.json` is also stored, because the frontend
   expects that too;
 * `tail_diff_vecs` is a generic utility function to extract the
   difference between two vectors; it has good documentation, so details
   within;
 * a local structure `StackFrame` is introduced, because the `StackFrame` in
   the debugger does not own its data; here, we need to remember the
   previous stack trace (a vector of `StackFrame`'s) in order to discover
   function calls or returns, so we need to own the data;
 * a `stack_trace` field is added to `TracingContext`; see previous point;
 * the new `fn get_stack_trace` performs the conversion mentioned;
 * the old contents of `update_record` are the basis for
   `tail_diff_vecs`; the new contents use that function to perform the
   same operation as before; in addition, the core logic of the PR is
   here: return events are registered for dropped stack frames and call
   events are registered for new stack frames;
 * all tracing tests are updated, to reflect the new traces that are
   generated.

To test:

```
cargo test trace
```
  • Loading branch information
smanilov committed Jul 9, 2024
1 parent 8c6c2bd commit 8797550
Show file tree
Hide file tree
Showing 7 changed files with 121 additions and 23 deletions.
4 changes: 3 additions & 1 deletion test_programs/plonky2_trace/1_mul/expected_trace.json
Original file line number Diff line number Diff line change
Expand Up @@ -3,8 +3,10 @@
{ "Function": { "path_id": 0, "line": -1, "name": "<toplevel>" } },
{ "Call": { "function_id": 0, "args": [] } },
{ "Type": { "kind": 30, "lang_type": "None", "specific_info": { "kind": "None" } } },
{ "Path": "it-does-not-matter" },
{ "Path": "<relative-to-this>/src/main.nr" },
{ "Step": { "path_id": 1, "line": 3 } },
{ "Function": { "path_id": 1, "line": 4, "name": "main" } },
{ "Call": { "function_id": 1, "args": [] } },
{ "Step": { "path_id": 1, "line": 4 } },
{ "Step": { "path_id": 1, "line": 5 } },
{ "Step": { "path_id": 1, "line": 6 } },
Expand Down
15 changes: 14 additions & 1 deletion test_programs/plonky2_trace/2_function_calls/expected_trace.json
Original file line number Diff line number Diff line change
Expand Up @@ -3,22 +3,35 @@
{ "Function": { "path_id": 0, "line": -1, "name": "<toplevel>" } },
{ "Call": { "function_id": 0, "args": [] } },
{ "Type": { "kind": 30, "lang_type": "None", "specific_info": { "kind": "None" } } },
{ "Path": "it-does-not-matter" },
{ "Path": "<relative-to-this>/src/main.nr" },
{ "Step": { "path_id": 1, "line": 9 } },
{ "Function": { "path_id": 1, "line": 10, "name": "main" } },
{ "Call": { "function_id": 1, "args": [] } },
{ "Step": { "path_id": 1, "line": 10 } },
{ "Step": { "path_id": 1, "line": 5 } },
{ "Function": { "path_id": 1, "line": 6, "name": "foo" } },
{ "Call": { "function_id": 2, "args": [] } },
{ "Step": { "path_id": 1, "line": 6 } },
{ "Step": { "path_id": 1, "line": 1 } },
{ "Function": { "path_id": 1, "line": 2, "name": "bar" } },
{ "Call": { "function_id": 3, "args": [] } },
{ "Step": { "path_id": 1, "line": 2 } },
{ "Step": { "path_id": 1, "line": 3 } },
{ "Type": { "kind": 30, "lang_type": "()", "specific_info": { "kind": "None" } } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 1, "line": 7 } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 1, "line": 11 } },
{ "Step": { "path_id": 1, "line": 5 } },
{ "Call": { "function_id": 2, "args": [] } },
{ "Step": { "path_id": 1, "line": 6 } },
{ "Step": { "path_id": 1, "line": 1 } },
{ "Call": { "function_id": 3, "args": [] } },
{ "Step": { "path_id": 1, "line": 2 } },
{ "Step": { "path_id": 1, "line": 3 } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 1, "line": 7 } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 1, "line": 12 } },
{ "Step": { "path_id": 1, "line": 13 } }
]
15 changes: 12 additions & 3 deletions test_programs/plonky2_trace/3_two_files/expected_trace.json
Original file line number Diff line number Diff line change
Expand Up @@ -3,17 +3,26 @@
{ "Function": { "path_id": 0, "line": -1, "name": "<toplevel>" } },
{ "Call": { "function_id": 0, "args": [] } },
{ "Type": { "kind": 30, "lang_type": "None", "specific_info": { "kind": "None" } } },
{ "Path": "<relative-to-json>/src/main.nr" },
{ "Path": "<relative-to-this>/src/main.nr" },
{ "Step": { "path_id": 1, "line": 6 } },
{ "Function": { "path_id": 1, "line": 7, "name": "main" } },
{ "Call": { "function_id": 1, "args": [] } },
{ "Step": { "path_id": 1, "line": 7 } },
{ "Path": "<relative-to-json>/src/foo.nr" },
{ "Path": "<relative-to-this>/src/foo.nr" },
{ "Step": { "path_id": 2, "line": 3 } },
{ "Function": { "path_id": 2, "line": 4, "name": "foo" } },
{ "Call": { "function_id": 2, "args": [] } },
{ "Step": { "path_id": 2, "line": 4 } },
{ "Path": "<relative-to-json>/src/bar.nr" },
{ "Path": "<relative-to-this>/src/bar.nr" },
{ "Step": { "path_id": 3, "line": 1 } },
{ "Function": { "path_id": 3, "line": 2, "name": "bar" } },
{ "Call": { "function_id": 3, "args": [] } },
{ "Step": { "path_id": 3, "line": 2 } },
{ "Step": { "path_id": 3, "line": 3 } },
{ "Type": { "kind": 30, "lang_type": "()", "specific_info": { "kind": "None" } } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 2, "line": 5 } },
{ "Return": { "return_value": { "kind": "None", "type_id": 1 } } },
{ "Step": { "path_id": 1, "line": 8 } },
{ "Step": { "path_id": 1, "line": 9 } }
]
2 changes: 1 addition & 1 deletion tooling/debugger/src/context.rs
Original file line number Diff line number Diff line change
Expand Up @@ -490,7 +490,7 @@ impl<'a, B: BlackBoxFunctionSolver<FieldElement>> DebugContext<'a, B> {
}
}

pub(super) fn get_variables(&self) -> Vec<StackFrame<FieldElement>> {
pub fn get_variables(&self) -> Vec<StackFrame<FieldElement>> {
return self.foreign_call_executor.get_variables();
}

Expand Down
6 changes: 6 additions & 0 deletions tooling/nargo_cli/src/cli/trace_cmd.rs
Original file line number Diff line number Diff line change
Expand Up @@ -112,5 +112,11 @@ pub(crate) fn trace_program(
Err(_) => (),
}

let trace_path = Path::new(trace_dir).join("trace_metadata.json");
match tracer.store_trace_metadata(&trace_path) {
Ok(_) => println!("Saved trace to {:?}", trace_path),
Err(_) => (),
}

Ok(())
}
62 changes: 45 additions & 17 deletions tooling/tracer/src/lib.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,7 @@
pub mod tail_diff_vecs;

Check warning on line 1 in tooling/tracer/src/lib.rs

View workflow job for this annotation

GitHub Actions / Code

Unknown word (vecs)

use tail_diff_vecs::tail_diff_vecs;

Check warning on line 3 in tooling/tracer/src/lib.rs

View workflow job for this annotation

GitHub Actions / Code

Unknown word (vecs)

Check warning on line 3 in tooling/tracer/src/lib.rs

View workflow job for this annotation

GitHub Actions / Code

Unknown word (vecs)

use noir_debugger::context::{DebugCommandResult, DebugContext};

use acvm::{acir::circuit::Circuit, acir::native_types::WitnessMap};
Expand All @@ -9,15 +13,14 @@ use noir_debugger::foreign_calls::DefaultDebugForeignCallExecutor;
use noirc_artifacts::debug::DebugArtifact;

use fm::PathString;
use std::cmp::min;
use std::path::PathBuf;

use runtime_tracing::{Line, Tracer};

use nargo::NargoError;

/// A location in the source code: filename and line number (1-indexed).
#[derive(PartialEq)]
#[derive(Clone, Debug, PartialEq)]
struct SourceLocation {
filepath: PathString,
line_number: isize,
Expand All @@ -44,10 +47,17 @@ enum DebugStepResult<Error> {
Error(Error),
}

#[derive(Clone, Debug, PartialEq)]
struct StackFrame {
function_name: String,
}

pub struct TracingContext<'a, B: BlackBoxFunctionSolver<FieldElement>> {
debug_context: DebugContext<'a, B>,
/// The source location at the current moment of tracing.
source_locations: Vec<SourceLocation>,
/// The stack trace at the current moment; last call is last in the vector.
stack_trace: Vec<StackFrame>,
}

impl<'a, B: BlackBoxFunctionSolver<FieldElement>> TracingContext<'a, B> {
Expand All @@ -69,7 +79,7 @@ impl<'a, B: BlackBoxFunctionSolver<FieldElement>> TracingContext<'a, B> {
unconstrained_functions,
);

Self { debug_context, source_locations: vec![] }
Self { debug_context, source_locations: vec![], stack_trace: vec![] }
}

/// Extracts the current stack of source locations from the debugger, given that the relevant
Expand Down Expand Up @@ -151,23 +161,41 @@ impl<'a, B: BlackBoxFunctionSolver<FieldElement>> TracingContext<'a, B> {
}
}

/// Converts the debugger stack frames into a vector of stack frames that own their data.
fn get_stack_frames(&mut self) -> Vec<StackFrame> {
self.debug_context
.get_variables()
.iter()
.map(|f| StackFrame { function_name: String::from(f.function_name) })
.collect()
}

/// Propagates information about the current execution state to `tracer`.
fn update_record(&mut self, tracer: &mut Tracer, source_locations: &Vec<SourceLocation>) {
// Find the last index of the previous and current stack traces, until which they are
// identical.
let mut last_match: isize = -1;
for i in 0..min(self.source_locations.len(), source_locations.len()) {
if self.source_locations[i] == source_locations[i] {
last_match = i as isize;
continue;
}
break;
let stack_trace = self.get_stack_frames();
let (first_nomatch, dropped_frames, new_frames) =
tail_diff_vecs(&self.stack_trace, &stack_trace);

Check warning on line 177 in tooling/tracer/src/lib.rs

View workflow job for this annotation

GitHub Actions / Code

Unknown word (vecs)

for _ in dropped_frames {
let type_id = tracer.ensure_type_id(runtime_tracing::TypeKind::None, "()");
tracer.register_return(runtime_tracing::ValueRecord::None { type_id });
}

for i in 0..new_frames.len() {
let SourceLocation { filepath, line_number } = &source_locations[first_nomatch + i];
let path = &PathBuf::from(filepath.to_string());
let line = Line(*line_number as i64);
let file_id = tracer.ensure_function_id(&new_frames[i].function_name, path, line);
tracer.register_call(file_id, vec![]);
}
// For the rest of the indexes of the new call stack: register a step that was performed to
// reach that frame of the call stack.
for i in ((last_match + 1) as usize)..source_locations.len() {
let SourceLocation { filepath, line_number } = &source_locations[i];
tracer.register_step(&PathBuf::from(filepath.to_string()), Line(*line_number as i64));

self.stack_trace = stack_trace;

let (_, _, new_source_locations) = tail_diff_vecs(&self.source_locations, source_locations);
for SourceLocation { filepath, line_number } in new_source_locations {
let path = &PathBuf::from(filepath.to_string());
let line = Line(*line_number as i64);
tracer.register_step(path, line);
}
}
}
Expand Down
40 changes: 40 additions & 0 deletions tooling/tracer/src/tail_diff_vecs.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
/// Produce the "tail difference" of two vectors.
///
/// Here, this means that the common prefix of the two vectors is computed. The length of that
/// prefix is returned, together with the suffix of the first vector that follows the common
/// prefix, as well as the suffix of the second vector that follows the common prefix.
///
/// Example:
/// ```
/// use noir_tracer::tail_diff_vecs::tail_diff_vecs;
/// let a = 1;
/// let b = 2;
/// let c = 3;
/// let d = 4;
/// let e = 5;
/// let f = 6;
///
/// assert_eq!(tail_diff_vecs(&vec!(a, b, c), &vec!(a, b, e, f)), (2, vec!(&c), vec!(&e, &f)));
//
/// assert_eq!(tail_diff_vecs(&vec!(a, b, c), &vec!(e, f)), (0, vec!(&a, &b, &c), vec!(&e, &f)));
///
/// assert_eq!(tail_diff_vecs(&vec!(a, b, c), &vec!(a, b)), (2, vec!(&c), vec!()));
///
/// assert_eq!(tail_diff_vecs(&vec!(a, b, c, d), &vec!(a, b, e)), (2, vec!(&c, &d), vec!(&e)));
///
/// // Corner cases:
/// assert_eq!(tail_diff_vecs(&vec!(a, b), &vec!(a, b, c)), (2, vec!(), vec!(&c)));
/// assert_eq!(tail_diff_vecs::<usize>(&vec!(), &vec!()), (0, vec!(), vec!()));
/// ```
pub fn tail_diff_vecs<'a, T>(xs: &'a Vec<T>, ys: &'a Vec<T>) -> (usize, Vec<&'a T>, Vec<&'a T>)
where
T: PartialEq + Clone,
{
let min_len = std::cmp::min(xs.len(), ys.len());
let first_nomatch = xs.iter().zip(ys.iter()).position(|(x, y)| x != y).unwrap_or(min_len);

let xs_tail: Vec<&T> = xs[first_nomatch..].iter().collect();
let ys_tail: Vec<&T> = ys[first_nomatch..].iter().collect();

(first_nomatch, xs_tail, ys_tail)
}

0 comments on commit 8797550

Please sign in to comment.