snix_eval/
observer.rs

1//! Implements traits for things that wish to observe internal state
2//! changes of snix-eval.
3//!
4//! This can be used to gain insights from compilation, to trace the
5//! runtime, and so on.
6//!
7//! All methods are optional, that is, observers can implement only
8/// what they are interested in observing.
9use std::io::Write;
10use std::rc::Rc;
11use std::time::Instant;
12use tabwriter::TabWriter;
13
14use crate::chunk::Chunk;
15use crate::generators::VMRequest;
16use crate::opcode::{CodeIdx, Op};
17use crate::value::Lambda;
18use crate::SourceCode;
19use crate::Value;
20
21/// Implemented by types that wish to observe internal happenings of
22/// the Snix compiler.
23pub trait CompilerObserver {
24    /// Called when the compiler finishes compilation of the top-level
25    /// of an expression (usually the root Nix expression of a file).
26    fn observe_compiled_toplevel(&mut self, _: &Rc<Lambda>) {}
27
28    /// Called when the compiler finishes compilation of a
29    /// user-defined function.
30    ///
31    /// Note that in Nix there are only single argument functions, so
32    /// in an expression like `a: b: c: ...` this method will be
33    /// called three times.
34    fn observe_compiled_lambda(&mut self, _: &Rc<Lambda>) {}
35
36    /// Called when the compiler finishes compilation of a thunk.
37    fn observe_compiled_thunk(&mut self, _: &Rc<Lambda>) {}
38}
39
40/// Implemented by types that wish to observe internal happenings of
41/// the Snix virtual machine at runtime.
42pub trait RuntimeObserver {
43    /// Called when the runtime enters a new call frame.
44    fn observe_enter_call_frame(&mut self, _arg_count: usize, _: &Rc<Lambda>, _call_depth: usize) {}
45
46    /// Called when the runtime exits a call frame.
47    fn observe_exit_call_frame(&mut self, _frame_at: usize, _stack: &[Value]) {}
48
49    /// Called when the runtime suspends a call frame.
50    fn observe_suspend_call_frame(&mut self, _frame_at: usize, _stack: &[Value]) {}
51
52    /// Called when the runtime enters a generator frame.
53    fn observe_enter_generator(&mut self, _frame_at: usize, _name: &str, _stack: &[Value]) {}
54
55    /// Called when the runtime exits a generator frame.
56    fn observe_exit_generator(&mut self, _frame_at: usize, _name: &str, _stack: &[Value]) {}
57
58    /// Called when the runtime suspends a generator frame.
59    fn observe_suspend_generator(&mut self, _frame_at: usize, _name: &str, _stack: &[Value]) {}
60
61    /// Called when a generator requests an action from the VM.
62    fn observe_generator_request(&mut self, _name: &str, _msg: &VMRequest) {}
63
64    /// Called when the runtime replaces the current call frame for a
65    /// tail call.
66    fn observe_tail_call(&mut self, _frame_at: usize, _: &Rc<Lambda>) {}
67
68    /// Called when the runtime enters a builtin.
69    fn observe_enter_builtin(&mut self, _name: &'static str) {}
70
71    /// Called when the runtime exits a builtin.
72    fn observe_exit_builtin(&mut self, _name: &'static str, _stack: &[Value]) {}
73
74    /// Called when the runtime *begins* executing an instruction. The
75    /// provided stack is the state at the beginning of the operation.
76    fn observe_execute_op(&mut self, _ip: CodeIdx, _: &Op, _: &[Value]) {}
77}
78
79#[derive(Default)]
80pub struct NoOpObserver {}
81
82impl CompilerObserver for NoOpObserver {}
83impl RuntimeObserver for NoOpObserver {}
84
85/// An observer that prints disassembled chunk information to its
86/// internal writer whenwever the compiler emits a toplevel function,
87/// closure or thunk.
88pub struct DisassemblingObserver<W: Write> {
89    source: SourceCode,
90    writer: TabWriter<W>,
91}
92
93impl<W: Write> DisassemblingObserver<W> {
94    pub fn new(source: SourceCode, writer: W) -> Self {
95        Self {
96            source,
97            writer: TabWriter::new(writer),
98        }
99    }
100
101    fn lambda_header(&mut self, kind: &str, lambda: &Rc<Lambda>) {
102        let _ = writeln!(
103            &mut self.writer,
104            "=== compiled {} @ {:p} ({} ops) ===",
105            kind,
106            *lambda,
107            lambda.chunk.code.len()
108        );
109    }
110
111    fn disassemble_chunk(&mut self, chunk: &Chunk) {
112        // calculate width of the widest address in the chunk
113        let width = format!("{:#x}", chunk.code.len() - 1).len();
114
115        let mut idx = 0;
116        while idx < chunk.code.len() {
117            let size = chunk
118                .disassemble_op(&mut self.writer, &self.source, width, CodeIdx(idx))
119                .expect("writing debug output should work");
120            idx += size;
121        }
122    }
123}
124
125impl<W: Write> CompilerObserver for DisassemblingObserver<W> {
126    fn observe_compiled_toplevel(&mut self, lambda: &Rc<Lambda>) {
127        self.lambda_header("toplevel", lambda);
128        self.disassemble_chunk(&lambda.chunk);
129        let _ = self.writer.flush();
130    }
131
132    fn observe_compiled_lambda(&mut self, lambda: &Rc<Lambda>) {
133        self.lambda_header("lambda", lambda);
134        self.disassemble_chunk(&lambda.chunk);
135        let _ = self.writer.flush();
136    }
137
138    fn observe_compiled_thunk(&mut self, lambda: &Rc<Lambda>) {
139        self.lambda_header("thunk", lambda);
140        self.disassemble_chunk(&lambda.chunk);
141        let _ = self.writer.flush();
142    }
143}
144
145/// An observer that collects a textual representation of an entire
146/// runtime execution.
147pub struct TracingObserver<W: Write> {
148    // If timing is enabled, contains the timestamp of the last-emitted trace event
149    last_event: Option<Instant>,
150    writer: TabWriter<W>,
151}
152
153impl<W: Write> TracingObserver<W> {
154    pub fn new(writer: W) -> Self {
155        Self {
156            last_event: None,
157            writer: TabWriter::new(writer),
158        }
159    }
160
161    /// Write the time of each runtime event, relative to when this method is called
162    pub fn enable_timing(&mut self) {
163        self.last_event = Some(Instant::now());
164    }
165
166    fn maybe_write_time(&mut self) {
167        if let Some(last_event) = &mut self.last_event {
168            let _ = write!(&mut self.writer, "+{}ns\t", last_event.elapsed().as_nanos());
169            *last_event = Instant::now();
170        }
171    }
172
173    fn write_value(&mut self, val: &Value) {
174        let _ = match val {
175            // Potentially large types which we only want to print
176            // the type of (and avoid recursing).
177            Value::List(l) => write!(&mut self.writer, "list[{}] ", l.len()),
178            Value::Attrs(a) => write!(&mut self.writer, "attrs[{}] ", a.len()),
179            Value::Thunk(t) if t.is_evaluated() => {
180                self.write_value(&t.value());
181                Ok(())
182            }
183
184            // For other value types, defer to the standard value printer.
185            _ => write!(&mut self.writer, "{} ", val),
186        };
187    }
188
189    fn write_stack(&mut self, stack: &[Value]) {
190        let _ = write!(&mut self.writer, "[ ");
191
192        // Print out a maximum of 6 values from the top of the stack,
193        // before abbreviating it to `...`.
194        for (i, val) in stack.iter().rev().enumerate() {
195            if i == 6 {
196                let _ = write!(&mut self.writer, "...");
197                break;
198            }
199
200            self.write_value(val);
201        }
202
203        let _ = writeln!(&mut self.writer, "]");
204    }
205}
206
207impl<W: Write> RuntimeObserver for TracingObserver<W> {
208    fn observe_enter_call_frame(
209        &mut self,
210        arg_count: usize,
211        lambda: &Rc<Lambda>,
212        call_depth: usize,
213    ) {
214        self.maybe_write_time();
215
216        let _ = write!(&mut self.writer, "=== entering ");
217
218        let _ = if arg_count == 0 {
219            write!(&mut self.writer, "thunk ")
220        } else {
221            write!(&mut self.writer, "closure ")
222        };
223
224        if let Some(name) = &lambda.name {
225            let _ = write!(&mut self.writer, "'{}' ", name);
226        }
227
228        let _ = writeln!(
229            &mut self.writer,
230            "in frame[{}] @ {:p} ===",
231            call_depth, *lambda
232        );
233    }
234
235    /// Called when the runtime exits a call frame.
236    fn observe_exit_call_frame(&mut self, frame_at: usize, stack: &[Value]) {
237        self.maybe_write_time();
238        let _ = write!(&mut self.writer, "=== exiting frame {} ===\t ", frame_at);
239        self.write_stack(stack);
240    }
241
242    fn observe_suspend_call_frame(&mut self, frame_at: usize, stack: &[Value]) {
243        self.maybe_write_time();
244        let _ = write!(&mut self.writer, "=== suspending frame {} ===\t", frame_at);
245
246        self.write_stack(stack);
247    }
248
249    fn observe_enter_generator(&mut self, frame_at: usize, name: &str, stack: &[Value]) {
250        self.maybe_write_time();
251        let _ = write!(
252            &mut self.writer,
253            "=== entering generator frame '{}' [{}] ===\t",
254            name, frame_at,
255        );
256
257        self.write_stack(stack);
258    }
259
260    fn observe_exit_generator(&mut self, frame_at: usize, name: &str, stack: &[Value]) {
261        self.maybe_write_time();
262        let _ = write!(
263            &mut self.writer,
264            "=== exiting generator '{}' [{}] ===\t",
265            name, frame_at
266        );
267
268        self.write_stack(stack);
269    }
270
271    fn observe_suspend_generator(&mut self, frame_at: usize, name: &str, stack: &[Value]) {
272        self.maybe_write_time();
273        let _ = write!(
274            &mut self.writer,
275            "=== suspending generator '{}' [{}] ===\t",
276            name, frame_at
277        );
278
279        self.write_stack(stack);
280    }
281
282    fn observe_generator_request(&mut self, name: &str, msg: &VMRequest) {
283        self.maybe_write_time();
284        let _ = writeln!(
285            &mut self.writer,
286            "=== generator '{}' requested {} ===",
287            name, msg
288        );
289    }
290
291    fn observe_enter_builtin(&mut self, name: &'static str) {
292        self.maybe_write_time();
293        let _ = writeln!(&mut self.writer, "=== entering builtin {} ===", name);
294    }
295
296    fn observe_exit_builtin(&mut self, name: &'static str, stack: &[Value]) {
297        self.maybe_write_time();
298        let _ = write!(&mut self.writer, "=== exiting builtin {} ===\t", name);
299        self.write_stack(stack);
300    }
301
302    fn observe_tail_call(&mut self, frame_at: usize, lambda: &Rc<Lambda>) {
303        self.maybe_write_time();
304        let _ = writeln!(
305            &mut self.writer,
306            "=== tail-calling {:p} in frame[{}] ===",
307            *lambda, frame_at
308        );
309    }
310
311    fn observe_execute_op(&mut self, ip: CodeIdx, op: &Op, stack: &[Value]) {
312        self.maybe_write_time();
313        let _ = write!(&mut self.writer, "{:04} {:?}\t", ip.0, op);
314        self.write_stack(stack);
315    }
316}
317
318impl<W: Write> Drop for TracingObserver<W> {
319    fn drop(&mut self) {
320        let _ = self.writer.flush();
321    }
322}