miden_debug/debug/
stacktrace.rs

1use std::{
2    borrow::Cow,
3    cell::{OnceCell, RefCell},
4    collections::{BTreeMap, BTreeSet, VecDeque},
5    fmt,
6    path::Path,
7    rc::Rc,
8    sync::Arc,
9};
10
11use miden_core::AssemblyOp;
12use miden_debug_types::{Location, SourceFile, SourceManager, SourceManagerExt, SourceSpan};
13use miden_processor::{Operation, RowIndex, VmState};
14
15use crate::exec::TraceEvent;
16
17#[derive(Debug, Clone)]
18struct SpanContext {
19    frame_index: usize,
20    location: Option<Location>,
21}
22
23pub struct CallStack {
24    trace_events: Rc<RefCell<BTreeMap<RowIndex, TraceEvent>>>,
25    contexts: BTreeSet<Rc<str>>,
26    frames: Vec<CallFrame>,
27    block_stack: Vec<Option<SpanContext>>,
28}
29impl CallStack {
30    pub fn new(trace_events: Rc<RefCell<BTreeMap<RowIndex, TraceEvent>>>) -> Self {
31        Self {
32            trace_events,
33            contexts: BTreeSet::default(),
34            frames: vec![],
35            block_stack: vec![],
36        }
37    }
38
39    pub fn stacktrace<'a>(
40        &'a self,
41        recent: &'a VecDeque<Operation>,
42        source_manager: &'a dyn SourceManager,
43    ) -> StackTrace<'a> {
44        StackTrace::new(self, recent, source_manager)
45    }
46
47    pub fn current_frame(&self) -> Option<&CallFrame> {
48        self.frames.last()
49    }
50
51    pub fn current_frame_mut(&mut self) -> Option<&mut CallFrame> {
52        self.frames.last_mut()
53    }
54
55    pub fn frames(&self) -> &[CallFrame] {
56        self.frames.as_slice()
57    }
58
59    /// Updates the call stack from `state`
60    ///
61    /// Returns the call frame exited this cycle, if any
62    pub fn next(&mut self, state: &VmState) -> Option<CallFrame> {
63        if let Some(op) = state.op {
64            // Do not do anything if this cycle is a continuation of the last instruction
65            //let skip = state.asmop.as_ref().map(|op| op.cycle_idx() > 1).unwrap_or(false);
66            //if skip {
67            //return;
68            //}
69
70            // Get the current procedure name context, if available
71            let procedure =
72                state.asmop.as_ref().map(|op| self.cache_procedure_name(op.context_name()));
73            /*
74                       if procedure.is_none() {
75                           dbg!(self.frames.last().map(|frame| frame.procedure.as_deref()));
76                           dbg!(self.block_stack.last().map(|ctx| ctx.as_ref()));
77                       }
78            */
79            // Handle trace events for this cycle
80            let event = self.trace_events.borrow().get(&state.clk).copied();
81            log::trace!("handling {op} at cycle {}: {:?}", state.clk, &event);
82            let popped_frame = self.handle_trace_event(event, procedure.as_ref());
83            let is_frame_end = popped_frame.is_some();
84
85            // These ops we do not record in call frame details
86            let ignore = matches!(
87                op,
88                Operation::Join
89                    | Operation::Split
90                    | Operation::Span
91                    | Operation::Respan
92                    | Operation::End
93            );
94
95            // Manage block stack
96            match op {
97                Operation::Span => {
98                    if let Some(asmop) = state.asmop.as_ref() {
99                        log::debug!("{asmop:#?}");
100                        self.block_stack.push(Some(SpanContext {
101                            frame_index: self.frames.len().saturating_sub(1),
102                            location: asmop.as_ref().location().cloned(),
103                        }));
104                    } else {
105                        self.block_stack.push(None);
106                    }
107                }
108                Operation::End => {
109                    self.block_stack.pop();
110                }
111                Operation::Join | Operation::Split => {
112                    self.block_stack.push(None);
113                }
114                _ => (),
115            }
116
117            if ignore || is_frame_end {
118                return popped_frame;
119            }
120
121            // Attempt to supply procedure context from the current span context, if needed +
122            // available
123            let (procedure, asmop) = match procedure {
124                proc @ Some(_) => {
125                    (proc, state.asmop.as_ref().map(|info| info.as_ref()).map(Cow::Borrowed))
126                }
127                None => match self.block_stack.last() {
128                    Some(Some(span_ctx)) => {
129                        let proc =
130                            self.frames.get(span_ctx.frame_index).and_then(|f| f.procedure.clone());
131                        let info = state
132                            .asmop
133                            .as_ref()
134                            .map(|info| info.as_ref())
135                            .map(Cow::Borrowed)
136                            .or_else(|| {
137                                let context_name =
138                                    proc.as_deref().unwrap_or("<unknown>").to_string();
139                                let raw_asmop = miden_core::AssemblyOp::new(
140                                    span_ctx.location.clone(),
141                                    context_name,
142                                    1,
143                                    op.to_string(),
144                                    false,
145                                );
146                                Some(Cow::Owned(raw_asmop))
147                            });
148                        (proc, info)
149                    }
150                    _ => (None, state.asmop.as_ref().map(|info| info.as_ref()).map(Cow::Borrowed)),
151                },
152            };
153
154            // Use the current frame's procedure context, if no other more precise context is
155            // available
156            let procedure =
157                procedure.or_else(|| self.frames.last().and_then(|f| f.procedure.clone()));
158
159            // Do we have a frame? If not, create one
160            if self.frames.is_empty() {
161                self.frames.push(CallFrame::new(procedure.clone()));
162            }
163
164            let current_frame = self.frames.last_mut().unwrap();
165
166            // Does the current frame have a procedure context/location? Use the one from this op if
167            // so
168            let procedure_context_updated =
169                current_frame.procedure.is_none() && procedure.is_some();
170            if procedure_context_updated {
171                current_frame.procedure.clone_from(&procedure);
172            }
173
174            // Push op into call frame if this is any op other than `nop` or frame setup
175            if !matches!(op, Operation::Noop) {
176                let cycle_idx = state.asmop.as_ref().map(|info| info.cycle_idx()).unwrap_or(1);
177                current_frame.push(op, cycle_idx, asmop.as_deref());
178            }
179
180            // Check if we should also update the caller frame's exec detail
181            let num_frames = self.frames.len();
182            if procedure_context_updated && num_frames > 1 {
183                let caller_frame = &mut self.frames[num_frames - 2];
184                if let Some(OpDetail::Exec { callee }) = caller_frame.context.back_mut()
185                    && callee.is_none()
186                {
187                    *callee = procedure;
188                }
189            }
190        }
191
192        None
193    }
194
195    // Get or cache procedure name/context as `Rc<str>`
196    fn cache_procedure_name(&mut self, context_name: &str) -> Rc<str> {
197        match self.contexts.get(context_name) {
198            Some(name) => Rc::clone(name),
199            None => {
200                let name = Rc::from(context_name.to_string().into_boxed_str());
201                self.contexts.insert(Rc::clone(&name));
202                name
203            }
204        }
205    }
206
207    fn handle_trace_event(
208        &mut self,
209        event: Option<TraceEvent>,
210        procedure: Option<&Rc<str>>,
211    ) -> Option<CallFrame> {
212        // Do we need to handle any frame events?
213        if let Some(event) = event {
214            match event {
215                TraceEvent::FrameStart => {
216                    // Record the fact that we exec'd a new procedure in the op context
217                    if let Some(current_frame) = self.frames.last_mut() {
218                        current_frame.push_exec(procedure.cloned());
219                    }
220                    // Push a new frame
221                    self.frames.push(CallFrame::new(procedure.cloned()));
222                }
223                TraceEvent::Unknown(code) => log::debug!("unknown trace event: {code}"),
224                TraceEvent::FrameEnd => {
225                    return self.frames.pop();
226                }
227                _ => (),
228            }
229        }
230        None
231    }
232}
233
234pub struct CallFrame {
235    procedure: Option<Rc<str>>,
236    context: VecDeque<OpDetail>,
237    display_name: std::cell::OnceCell<Rc<str>>,
238    finishing: bool,
239}
240impl CallFrame {
241    pub fn new(procedure: Option<Rc<str>>) -> Self {
242        Self {
243            procedure,
244            context: Default::default(),
245            display_name: Default::default(),
246            finishing: false,
247        }
248    }
249
250    pub fn procedure(&self, strip_prefix: &str) -> Option<Rc<str>> {
251        self.procedure.as_ref()?;
252        let name = self.display_name.get_or_init(|| {
253            let name = self.procedure.as_deref().unwrap();
254            let name = match name.split_once("::") {
255                Some((module, rest)) if module == strip_prefix => demangle(rest),
256                _ => demangle(name),
257            };
258            Rc::from(name.into_boxed_str())
259        });
260        Some(Rc::clone(name))
261    }
262
263    pub fn push_exec(&mut self, callee: Option<Rc<str>>) {
264        if self.context.len() == 5 {
265            self.context.pop_front();
266        }
267
268        self.context.push_back(OpDetail::Exec { callee });
269    }
270
271    pub fn push(&mut self, opcode: Operation, cycle_idx: u8, op: Option<&AssemblyOp>) {
272        if cycle_idx > 1 {
273            // Should we ignore this op?
274            let skip = self.context.back().map(|detail| matches!(detail, OpDetail::Full { op, .. } | OpDetail::Basic { op } if op == &opcode)).unwrap_or(false);
275            if skip {
276                return;
277            }
278        }
279
280        if self.context.len() == 5 {
281            self.context.pop_front();
282        }
283
284        match op {
285            Some(op) => {
286                let location = op.location().cloned();
287                self.context.push_back(OpDetail::Full {
288                    op: opcode,
289                    location,
290                    resolved: Default::default(),
291                });
292            }
293            None => {
294                // If this instruction does not have a location, inherit the location
295                // of the previous op in the frame, if one is present
296                if let Some(loc) = self.context.back().map(|op| op.location().cloned()) {
297                    self.context.push_back(OpDetail::Full {
298                        op: opcode,
299                        location: loc,
300                        resolved: Default::default(),
301                    });
302                } else {
303                    self.context.push_back(OpDetail::Basic { op: opcode });
304                }
305            }
306        }
307    }
308
309    pub fn last_location(&self) -> Option<&Location> {
310        match self.context.back() {
311            Some(OpDetail::Full { location, .. }) => {
312                let loc = location.as_ref();
313                if loc.is_none() {
314                    dbg!(&self.context);
315                }
316                loc
317            }
318            Some(OpDetail::Basic { .. }) => None,
319            Some(OpDetail::Exec { .. }) => {
320                let op = self.context.iter().rev().nth(1)?;
321                op.location()
322            }
323            None => None,
324        }
325    }
326
327    pub fn last_resolved(&self, source_manager: &dyn SourceManager) -> Option<&ResolvedLocation> {
328        // Search through context in reverse order to find the most recent op with a resolvable
329        // location.
330        for op in self.context.iter().rev() {
331            if let Some(resolved) = op.resolve(source_manager) {
332                return Some(resolved);
333            }
334        }
335        None
336    }
337
338    pub fn recent(&self) -> &VecDeque<OpDetail> {
339        &self.context
340    }
341
342    #[inline(always)]
343    pub fn should_break_on_exit(&self) -> bool {
344        self.finishing
345    }
346
347    #[inline(always)]
348    pub fn break_on_exit(&mut self) {
349        self.finishing = true;
350    }
351}
352
353#[derive(Debug, Clone)]
354pub enum OpDetail {
355    Full {
356        op: Operation,
357        location: Option<Location>,
358        resolved: OnceCell<Option<ResolvedLocation>>,
359    },
360    Exec {
361        callee: Option<Rc<str>>,
362    },
363    Basic {
364        op: Operation,
365    },
366}
367impl OpDetail {
368    pub fn callee(&self, strip_prefix: &str) -> Option<Box<str>> {
369        match self {
370            Self::Exec { callee: None } => Some(Box::from("<unknown>")),
371            Self::Exec {
372                callee: Some(callee),
373            } => {
374                let name = match callee.split_once("::") {
375                    Some((module, rest)) if module == strip_prefix => demangle(rest),
376                    _ => demangle(callee),
377                };
378                Some(name.into_boxed_str())
379            }
380            _ => None,
381        }
382    }
383
384    pub fn display(&self) -> String {
385        match self {
386            Self::Full { op, .. } | Self::Basic { op } => format!("{op}"),
387            Self::Exec {
388                callee: Some(callee),
389            } => format!("exec.{callee}"),
390            Self::Exec { callee: None } => "exec.<unavailable>".to_string(),
391        }
392    }
393
394    pub fn opcode(&self) -> Operation {
395        match self {
396            Self::Full { op, .. } | Self::Basic { op } => *op,
397            Self::Exec { .. } => panic!("no opcode associated with execs"),
398        }
399    }
400
401    pub fn location(&self) -> Option<&Location> {
402        match self {
403            Self::Full { location, .. } => location.as_ref(),
404            Self::Basic { .. } | Self::Exec { .. } => None,
405        }
406    }
407
408    pub fn resolve(&self, source_manager: &dyn SourceManager) -> Option<&ResolvedLocation> {
409        match self {
410            Self::Full {
411                location: Some(loc),
412                resolved,
413                ..
414            } => resolved
415                .get_or_init(|| {
416                    let path = Path::new(loc.uri().as_str());
417                    let source_file = if path.exists() {
418                        source_manager.load_file(path).ok()?
419                    } else {
420                        source_manager.get_by_uri(loc.uri())?
421                    };
422                    let span = SourceSpan::new(source_file.id(), loc.start..loc.end);
423                    let file_line_col = source_file.location(span);
424                    Some(ResolvedLocation {
425                        source_file,
426                        line: file_line_col.line.to_u32(),
427                        col: file_line_col.column.to_u32(),
428                        span,
429                    })
430                })
431                .as_ref(),
432            _ => None,
433        }
434    }
435}
436
437#[derive(Debug, Clone)]
438pub struct ResolvedLocation {
439    pub source_file: Arc<SourceFile>,
440    // TODO(fabrio): Use LineNumber and ColumnNumber instead of raw `u32`.
441    pub line: u32,
442    pub col: u32,
443    pub span: SourceSpan,
444}
445impl fmt::Display for ResolvedLocation {
446    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
447        write!(f, "{}:{}:{}", self.source_file.uri().as_str(), self.line, self.col)
448    }
449}
450
451pub struct CurrentFrame {
452    pub procedure: Option<Rc<str>>,
453    pub location: Option<ResolvedLocation>,
454}
455
456pub struct StackTrace<'a> {
457    callstack: &'a CallStack,
458    recent: &'a VecDeque<Operation>,
459    source_manager: &'a dyn SourceManager,
460    current_frame: Option<CurrentFrame>,
461}
462
463impl<'a> StackTrace<'a> {
464    pub fn new(
465        callstack: &'a CallStack,
466        recent: &'a VecDeque<Operation>,
467        source_manager: &'a dyn SourceManager,
468    ) -> Self {
469        let current_frame = callstack.current_frame().map(|frame| {
470            let location = frame.last_resolved(source_manager).cloned();
471            let procedure = frame.procedure("");
472            CurrentFrame {
473                procedure,
474                location,
475            }
476        });
477        Self {
478            callstack,
479            recent,
480            source_manager,
481            current_frame,
482        }
483    }
484
485    pub fn current_frame(&self) -> Option<&CurrentFrame> {
486        self.current_frame.as_ref()
487    }
488}
489
490impl fmt::Display for StackTrace<'_> {
491    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
492        use std::fmt::Write;
493
494        let num_frames = self.callstack.frames.len();
495
496        writeln!(f, "\nStack Trace:")?;
497
498        for (i, frame) in self.callstack.frames.iter().enumerate() {
499            let is_top = i + 1 == num_frames;
500            let name = frame.procedure("");
501            let name = name.as_deref().unwrap_or("<unknown>");
502            if is_top {
503                write!(f, " `-> {name}")?;
504            } else {
505                write!(f, " |-> {name}")?;
506            }
507            if let Some(resolved) = frame.last_resolved(self.source_manager) {
508                write!(f, " in {resolved}")?;
509            } else {
510                write!(f, " in <unavailable>")?;
511            }
512            if is_top {
513                // Print op context
514                let context_size = frame.context.len();
515                writeln!(f, ":\n\nLast {context_size} Instructions (of current frame):")?;
516                for (i, op) in frame.context.iter().enumerate() {
517                    let is_last = i + 1 == context_size;
518                    if let Some(callee) = op.callee("") {
519                        write!(f, " |   exec.{callee}")?;
520                    } else {
521                        write!(f, " |   {}", &op.opcode())?;
522                    }
523                    if is_last {
524                        writeln!(f, "\n `-> <error occured here>")?;
525                    } else {
526                        f.write_char('\n')?;
527                    }
528                }
529
530                let context_size = self.recent.len();
531                writeln!(f, "\n\nLast {context_size} Instructions (any frame):")?;
532                for (i, op) in self.recent.iter().enumerate() {
533                    let is_last = i + 1 == context_size;
534                    if is_last {
535                        writeln!(f, " |   {}", &op)?;
536                        writeln!(f, " `-> <error occured here>")?;
537                    } else {
538                        writeln!(f, " |   {}", &op)?;
539                    }
540                }
541            } else {
542                f.write_char('\n')?;
543            }
544        }
545
546        Ok(())
547    }
548}
549
550fn demangle(name: &str) -> String {
551    let mut input = name.as_bytes();
552    let mut demangled = Vec::with_capacity(input.len() * 2);
553    rustc_demangle::demangle_stream(&mut input, &mut demangled, /* include_hash= */ false)
554        .expect("failed to write demangled identifier");
555    String::from_utf8(demangled).expect("demangled identifier contains invalid utf-8")
556}