orinium_browser/engine/js/
trace.rs

1//! JavaScript execution tracing for the DevTools pane.
2//!
3//! The runtime records a bounded stream of execution events (script
4//! evaluations, event dispatch, timers, microtasks, network settlement and
5//! `console` output). Events are drained after each JS task by the processor
6//! and rendered by the browser's DevTools UI (`resource:///devtools/`).
7//!
8//! Tracing is intentionally coarse: it operates at the engine boundary, where
9//! the runtime hands control to page JavaScript. Recording an event never
10//! changes execution and is skipped entirely while tracing is disabled.
11
12use std::any::Any;
13use std::collections::{HashSet, VecDeque};
14use std::rc::Rc;
15use std::time::Instant;
16
17use pixi_byte::value::jsvalue::JsValueKind;
18use pixi_byte::vm::VM;
19use pixi_byte::{JSEngine, JSResult, JSValue};
20
21use super::JsHost;
22
23/// Default number of events kept in the JS thread's ring buffer.
24const CAPACITY: usize = 512;
25
26/// The kind of JavaScript execution event.
27#[derive(Debug, Clone, Copy, PartialEq, Eq)]
28pub enum JsTraceKind {
29    /// A classic script (or an inline handler compiled on demand).
30    Script,
31    /// DOM/window event dispatch.
32    Event,
33    /// A timer callback.
34    Timer,
35    /// Promise/`fetch` settlement.
36    Fetch,
37    /// Microtask checkpoint.
38    Microtask,
39    /// `console.*` output.
40    Console,
41}
42
43impl JsTraceKind {
44    /// Lowercase stable name used in the DevTools JSON envelope.
45    pub fn as_str(self) -> &'static str {
46        match self {
47            Self::Script => "script",
48            Self::Event => "event",
49            Self::Timer => "timer",
50            Self::Fetch => "fetch",
51            Self::Microtask => "microtask",
52            Self::Console => "console",
53        }
54    }
55}
56
57/// A single traced JavaScript execution event.
58#[derive(Debug, Clone)]
59pub struct JsTraceEvent {
60    /// Monotonic event number, reset when the trace is cleared.
61    pub seq: u64,
62    /// Milliseconds since the trace started (or was last cleared).
63    pub at_ms: f64,
64    /// Event category.
65    pub kind: JsTraceKind,
66    /// Short label, e.g. `DOMContentLoaded` or `setTimeout`.
67    pub label: String,
68    /// Human-readable detail: listener counts, URLs, console text, …
69    pub detail: String,
70    /// Execution time in microseconds (0 for instantaneous events).
71    pub duration_us: u64,
72    /// Error message when the event failed.
73    pub error: Option<String>,
74    /// JavaScript call stack (innermost first) captured at the event.
75    pub stack: Vec<String>,
76    /// Bounded source preview for scripts and inline handlers.
77    pub source: Option<String>,
78    /// True when source is the most recently evaluated script, used for
79    /// callbacks whose VM frame does not retain source text.
80    pub source_is_fallback: bool,
81    /// Local variables captured when this event terminated with an error.
82    pub variables: Vec<(String, String)>,
83    /// Bytecode program counter captured at a terminal runtime error.
84    pub program_counter: Option<usize>,
85}
86
87/// A batch of trace events drained after one JS task.
88#[derive(Debug, Clone, Default)]
89pub struct JsTraceBatch {
90    /// Whether tracing was enabled while the task ran.
91    pub enabled: bool,
92    /// Events recorded since the trace was cleared.
93    pub total: u64,
94    /// Events evicted from the ring buffer before being drained.
95    pub dropped: u64,
96    /// Events recorded during this task.
97    pub events: Vec<JsTraceEvent>,
98    /// JavaScript operations currently in progress on the JS thread.
99    pub active: Vec<JsActiveTrace>,
100}
101
102/// An in-progress traced operation.
103pub(crate) struct JsTraceSpan {
104    pub(crate) active_id: Option<usize>,
105    pub(crate) started: Instant,
106    pub(crate) kind: JsTraceKind,
107    pub(crate) label: String,
108    pub(crate) detail: String,
109    pub(crate) source: Option<String>,
110}
111
112/// Snapshot of a JavaScript operation currently in progress.
113#[derive(Debug, Clone)]
114pub struct JsActiveTrace {
115    pub kind: JsTraceKind,
116    pub label: String,
117    pub detail: String,
118    pub elapsed_ms: f64,
119    pub stack: Vec<String>,
120    pub source: Option<String>,
121}
122
123struct ActiveSpanEntry {
124    id: usize,
125    started: Instant,
126    kind: JsTraceKind,
127    label: String,
128    detail: String,
129    source: Option<String>,
130}
131
132/// Bounded event stream owned by [`JsHost`].
133pub(crate) struct JsTraceSession {
134    enabled: bool,
135    start: Instant,
136    events: VecDeque<JsTraceEvent>,
137    next_seq: u64,
138    next_active_id: usize,
139    total: u64,
140    dropped: u64,
141    latest_source: Option<String>,
142    active_spans: Vec<ActiveSpanEntry>,
143}
144
145impl JsTraceSession {
146    pub(crate) fn new() -> Self {
147        Self {
148            enabled: default_enabled(),
149            start: Instant::now(),
150            events: VecDeque::with_capacity(CAPACITY),
151            next_seq: 1,
152            next_active_id: 1,
153            total: 0,
154            dropped: 0,
155            latest_source: None,
156            active_spans: Vec::new(),
157        }
158    }
159
160    pub(crate) fn enabled(&self) -> bool {
161        self.enabled
162    }
163
164    fn set_enabled(&mut self, enabled: bool) {
165        self.enabled = enabled;
166    }
167
168    fn clear(&mut self) {
169        self.events.clear();
170        self.active_spans.clear();
171        self.start = Instant::now();
172        self.next_seq = 1;
173        self.total = 0;
174        self.dropped = 0;
175        self.latest_source = None;
176    }
177
178    fn begin_active(
179        &mut self,
180        kind: JsTraceKind,
181        label: String,
182        detail: String,
183        source: Option<String>,
184    ) -> Option<usize> {
185        if !self.enabled {
186            return None;
187        }
188        let id = self.next_active_id;
189        self.next_active_id += 1;
190        if let Some(source) = source.as_ref() {
191            self.latest_source = Some(source.clone());
192        }
193        self.active_spans.push(ActiveSpanEntry {
194            id,
195            started: Instant::now(),
196            kind,
197            label,
198            detail,
199            source,
200        });
201        Some(id)
202    }
203
204    fn end_active(&mut self, id: Option<usize>) {
205        let Some(id) = id else {
206            return;
207        };
208        if let Some(index) = self.active_spans.iter().rposition(|span| span.id == id) {
209            self.active_spans.remove(index);
210        }
211    }
212
213    fn snapshot_active(&self, vm: &VM) -> Vec<JsActiveTrace> {
214        if !self.enabled || self.active_spans.is_empty() {
215            return Vec::new();
216        }
217        let stack = stack_from_vm(vm);
218        self.active_spans
219            .iter()
220            .rev()
221            .map(|span| JsActiveTrace {
222                kind: span.kind,
223                label: span.label.clone(),
224                detail: span.detail.clone(),
225                elapsed_ms: span.started.elapsed().as_secs_f64() * 1000.0,
226                stack: stack.clone(),
227                source: span.source.clone().or_else(|| self.latest_source.clone()),
228            })
229            .collect()
230    }
231
232    #[allow(clippy::too_many_arguments)]
233    fn record(
234        &mut self,
235        kind: JsTraceKind,
236        label: String,
237        detail: String,
238        duration_us: u64,
239        error: Option<String>,
240        stack: Vec<String>,
241        source: Option<String>,
242        variables: Vec<(String, String)>,
243        program_counter: Option<usize>,
244    ) {
245        if !self.enabled {
246            return;
247        }
248        self.total += 1;
249        if let Some(source) = source.as_ref() {
250            self.latest_source = Some(source.clone());
251        }
252        // Event and timer callbacks usually do not carry their own source
253        // text. Attach the latest evaluated script to failures for inspection.
254        let source_is_fallback =
255            source.is_none() && error.is_some() && self.latest_source.is_some();
256        let source = source.or_else(|| error.as_ref().and(self.latest_source.clone()));
257        if self.events.len() == CAPACITY {
258            self.events.pop_front();
259            self.dropped += 1;
260        }
261        let seq = self.next_seq;
262        self.next_seq += 1;
263        self.events.push_back(JsTraceEvent {
264            seq,
265            at_ms: self.start.elapsed().as_secs_f64() * 1000.0,
266            kind,
267            label,
268            detail,
269            duration_us,
270            error,
271            stack,
272            source,
273            source_is_fallback,
274            variables,
275            program_counter,
276        });
277    }
278
279    fn take_batch(&mut self, vm: &VM) -> JsTraceBatch {
280        JsTraceBatch {
281            enabled: self.enabled,
282            total: self.total,
283            dropped: self.dropped,
284            events: self.events.drain(..).collect(),
285            active: self.snapshot_active(vm),
286        }
287    }
288}
289
290/// Whether tracing starts enabled for a fresh runtime.
291///
292/// The event buffer is bounded, so recording starts before document scripts in
293/// every build. Opening DevTools after navigation can then inspect startup.
294pub fn default_enabled() -> bool {
295    true
296}
297
298/// Installs an internal hook used by lowered async `catch` blocks to retain
299/// errors that page code would otherwise swallow.
300pub(crate) fn install_caught_exception_hook(engine: &mut JSEngine) {
301    engine.global_mut().borrow_mut().set(
302        "__orinium_trace_caught_error".to_string(),
303        JSValue::from_native_function(trace_caught_exception),
304    );
305}
306
307fn trace_caught_exception(vm: &mut VM, args: Vec<JSValue>) -> JSResult<JSValue> {
308    let error = args
309        .get(1)
310        .cloned()
311        .unwrap_or_else(JSValue::undefined)
312        .to_console_string();
313    let catch_name = args
314        .get(2)
315        .map(JSValue::to_console_string)
316        .unwrap_or_else(|| "error".to_string());
317    let stack = stack_from_vm(vm);
318    record(
319        vm,
320        JsTraceKind::Event,
321        "caught async exception".to_string(),
322        error.clone(),
323        0,
324        Some(error.clone()),
325        stack,
326        None,
327        vec![(catch_name, error)],
328        None,
329    );
330    Ok(JSValue::undefined())
331}
332
333/// Captures the current JavaScript call stack, innermost function first.
334pub(crate) fn stack_from_vm(vm: &VM) -> Vec<String> {
335    vm.frames
336        .iter()
337        .rev()
338        .take(24)
339        .map(|frame| {
340            frame
341                .function_name
342                .as_ref()
343                .map(|name| name.as_str())
344                .unwrap_or_else(|| "<anonymous>".to_string())
345        })
346        .collect()
347}
348
349/// Records a trace event if tracing is enabled.
350#[allow(clippy::too_many_arguments)]
351pub(crate) fn record(
352    vm: &VM,
353    kind: JsTraceKind,
354    label: String,
355    detail: String,
356    duration_us: u64,
357    error: Option<String>,
358    stack: Vec<String>,
359    source: Option<String>,
360    variables: Vec<(String, String)>,
361    program_counter: Option<usize>,
362) {
363    with_session_mut(vm, |session| {
364        session.record(
365            kind,
366            label,
367            detail,
368            duration_us,
369            error,
370            stack,
371            source,
372            variables,
373            program_counter,
374        )
375    });
376}
377
378/// Records a `console.*` call, including the stack that produced it.
379pub(crate) fn record_console(vm: &VM, level: log::Level, message: &str) {
380    let label = match level {
381        log::Level::Error => "console.error",
382        log::Level::Warn => "console.warn",
383        log::Level::Info => "console.log",
384        log::Level::Debug => "console.debug",
385        log::Level::Trace => "console.trace",
386    };
387    let stack = stack_from_vm(vm);
388    record(
389        vm,
390        JsTraceKind::Console,
391        label.to_string(),
392        message.to_string(),
393        0,
394        None,
395        stack,
396        None,
397        Vec::new(),
398        None,
399    );
400}
401
402/// Formats JavaScript values for the DevTools console without invoking getters.
403pub(crate) fn format_console_value(value: &JSValue) -> String {
404    format_console_value_inner(value, 0, &mut HashSet::new(), false)
405}
406
407fn format_console_value_inner(
408    value: &JSValue,
409    depth: usize,
410    seen: &mut HashSet<usize>,
411    quote_strings: bool,
412) -> String {
413    match value.kind() {
414        JsValueKind::String if quote_strings => {
415            serde_json::to_string(value.as_string().unwrap_or("")).unwrap_or_default()
416        }
417        JsValueKind::Object => {
418            let Some(object) = value.as_object() else {
419                return value.to_console_string();
420            };
421            let identity = Rc::as_ptr(&object) as usize;
422            if !seen.insert(identity) {
423                return "[Circular]".to_string();
424            }
425            if depth >= 4 {
426                seen.remove(&identity);
427                return "[Object]".to_string();
428            }
429            let (is_array, keys, length) = {
430                let object = object.borrow();
431                (
432                    object.is_array(),
433                    object.keys(),
434                    object.get("length").to_number().max(0.0) as usize,
435                )
436            };
437            let rendered = if is_array {
438                let values = (0..length.min(40))
439                    .map(|index| {
440                        let item = object.borrow().get_index(index);
441                        format_console_value_inner(&item, depth + 1, seen, true)
442                    })
443                    .collect::<Vec<_>>();
444                let mut values = values;
445                if length > 40 {
446                    values.push(format!("… {} more", length - 40));
447                }
448                format!("[{}]", values.join(", "))
449            } else {
450                let mut properties = keys
451                    .into_iter()
452                    .take(40)
453                    .map(|key| {
454                        let item = object.borrow().get(&key);
455                        format!(
456                            "{}: {}",
457                            serde_json::to_string(&key).unwrap_or_default(),
458                            format_console_value_inner(&item, depth + 1, seen, true)
459                        )
460                    })
461                    .collect::<Vec<_>>();
462                if object.borrow().keys().len() > 40 {
463                    properties.push("… more properties".to_string());
464                }
465                format!("{{{}}}", properties.join(", "))
466            };
467            seen.remove(&identity);
468            rendered
469        }
470        _ => value.to_console_string(),
471    }
472}
473
474/// Returns whether tracing is currently enabled.
475pub(crate) fn is_enabled(vm: &VM) -> bool {
476    let Some(host) = vm.host.as_ref() else {
477        return false;
478    };
479    let Ok(host_ref) = host.try_borrow() else {
480        return false;
481    };
482    let Some(js_host) = (&*host_ref as &dyn Any).downcast_ref::<JsHost>() else {
483        return false;
484    };
485    js_host.trace.enabled()
486}
487
488/// Enables or disables tracing on the JS thread.
489pub(crate) fn set_enabled(vm: &VM, enabled: bool) {
490    with_session_mut(vm, |session| session.set_enabled(enabled));
491}
492
493/// Clears the buffered trace and resets its counters.
494pub(crate) fn clear(vm: &VM) {
495    with_session_mut(vm, JsTraceSession::clear);
496}
497
498/// Drains the buffered events into a batch for the browser thread.
499pub(crate) fn take_batch(vm: &VM) -> JsTraceBatch {
500    let Some(host) = vm.host.as_ref() else {
501        return JsTraceBatch::default();
502    };
503    let Ok(mut host_ref) = host.try_borrow_mut() else {
504        return JsTraceBatch::default();
505    };
506    let Some(js_host) = (&mut *host_ref as &mut dyn Any).downcast_mut::<JsHost>() else {
507        return JsTraceBatch::default();
508    };
509    js_host.trace.take_batch(vm)
510}
511
512pub(crate) fn begin_active(
513    vm: &VM,
514    kind: JsTraceKind,
515    label: String,
516    detail: String,
517    source: Option<String>,
518) -> Option<usize> {
519    let host = vm.host.as_ref()?;
520    let mut host_ref = host.try_borrow_mut().ok()?;
521    let js_host = (&mut *host_ref as &mut dyn Any).downcast_mut::<JsHost>()?;
522    js_host.trace.begin_active(kind, label, detail, source)
523}
524
525pub(crate) fn end_active(vm: &VM, id: Option<usize>) {
526    let Some(host) = vm.host.as_ref() else {
527        return;
528    };
529    let Ok(mut host_ref) = host.try_borrow_mut() else {
530        return;
531    };
532    if let Some(js_host) = (&mut *host_ref as &mut dyn Any).downcast_mut::<JsHost>() {
533        js_host.trace.end_active(id);
534    }
535}
536
537fn with_session_mut(vm: &VM, f: impl FnOnce(&mut JsTraceSession)) {
538    let Some(host) = vm.host.as_ref() else {
539        return;
540    };
541    // Trace calls can be reentrant (a console call while another native holds
542    // the host). Skipping an event is preferable to panicking.
543    let Ok(mut host_ref) = host.try_borrow_mut() else {
544        return;
545    };
546    if let Some(js_host) = (&mut *host_ref as &mut dyn Any).downcast_mut::<JsHost>() {
547        f(&mut js_host.trace);
548    }
549}
550
551/// Short single-line preview of a script source.
552pub(crate) fn source_summary(source: &str) -> String {
553    let line = source
554        .lines()
555        .map(str::trim)
556        .find(|line| !line.is_empty())
557        .unwrap_or("");
558    truncate_chars(line, 100)
559}
560
561/// Bounded multi-line source excerpt retained for DevTools inspection.
562pub(crate) fn source_preview(source: &str) -> String {
563    truncate_chars(source.trim(), 240)
564}
565
566fn truncate_chars(text: &str, limit: usize) -> String {
567    let mut out = String::new();
568    for (index, ch) in text.chars().enumerate() {
569        if index == limit {
570            out.push('…');
571            break;
572        }
573        out.push(ch);
574    }
575    out
576}
577
578#[cfg(test)]
579mod tests {
580    use super::*;
581
582    #[test]
583    fn session_keeps_only_the_newest_events() {
584        let mut session = JsTraceSession::new();
585        session.set_enabled(true);
586        for index in 0..(CAPACITY + 3) {
587            session.record(
588                JsTraceKind::Script,
589                format!("script-{index}"),
590                String::new(),
591                0,
592                None,
593                Vec::new(),
594                None,
595                Vec::new(),
596                None,
597            );
598        }
599        let batch = session.take_batch(&VM::new());
600        assert_eq!(batch.total as usize, CAPACITY + 3);
601        assert_eq!(batch.dropped, 3);
602        assert_eq!(batch.events.len(), CAPACITY);
603        assert_eq!(batch.events[0].label, "script-3");
604    }
605
606    #[test]
607    fn disabled_session_records_nothing_and_clear_resets_counters() {
608        let mut session = JsTraceSession::new();
609        session.set_enabled(false);
610        session.record(
611            JsTraceKind::Script,
612            "ignored".to_string(),
613            String::new(),
614            0,
615            None,
616            Vec::new(),
617            None,
618            Vec::new(),
619            None,
620        );
621        assert!(session.take_batch(&VM::new()).events.is_empty());
622
623        session.set_enabled(true);
624        session.record(
625            JsTraceKind::Event,
626            "click".to_string(),
627            String::new(),
628            0,
629            None,
630            Vec::new(),
631            None,
632            Vec::new(),
633            None,
634        );
635        session.clear();
636        let batch = session.take_batch(&VM::new());
637        assert_eq!(batch.total, 0);
638        assert!(batch.events.is_empty());
639        assert!(batch.active.is_empty());
640    }
641
642    #[test]
643    fn source_previews_are_bounded_and_char_safe() {
644        let summary = source_summary("\n\n  const answer = 42;  \n");
645        assert_eq!(summary, "const answer = 42;");
646        let preview = source_preview(&"あ".repeat(300));
647        assert_eq!(preview.chars().count(), 241);
648    }
649}
orinium_browser/engine/js/trace.rs

orinium_browser/engine/js/
trace.rs
