Skip to content

Commit 01e41cd

Browse files
nekevssnekevss
committed
Add MVP of virtual machine tracer
1 parent 2ebc979 commit 01e41cd

File tree

3 files changed

+180
-36
lines changed

3 files changed

+180
-36
lines changed

‎core/engine/Cargo.toml‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,9 @@ flowgraph = []
6767
# Enable Boa's VM instruction tracing.
6868
trace = ["js"]
6969

70+
# Enable Boa's VM instruction tracing printing to stdout
71+
trace-stdout = ["trace"]
72+
7073
# Enable Boa's additional ECMAScript features for web browsers.
7174
annex-b = ["boa_ast/annex-b", "boa_parser/annex-b"]
7275

‎core/engine/src/vm/mod.rs‎

Lines changed: 51 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,9 @@ use boa_gc::{Finalize, Gc, Trace, custom_trace};
1818
use shadow_stack::ShadowStack;
1919
use std::{future::Future, ops::ControlFlow, pin::Pin, task};
2020

21+
#[cfg(feature = "trace")]
22+
pub use trace::{EmptyTracer, StdoutTracer, VirtualMachineTracer};
23+
2124
#[cfg(feature = "trace")]
2225
use crate::sys::time::Instant;
2326

@@ -53,6 +56,9 @@ pub(crate) mod opcode;
5356
pub(crate) mod shadow_stack;
5457
pub(crate) mod source_info;
5558

59+
#[cfg(feature = "trace")]
60+
mod trace;
61+
5662
#[cfg(feature = "flowgraph")]
5763
pub mod flowgraph;
5864

@@ -98,6 +104,10 @@ pub struct Vm {
98104

99105
#[cfg(feature = "trace")]
100106
pub(crate) trace: bool,
107+
108+
/// A tracer registered to emit VM events
109+
#[cfg(feature = "trace")]
110+
pub(crate) tracer: Box<dyn VirtualMachineTracer>,
101111
}
102112

103113
/// The stack holds the [`JsValue`]s for the calling convention and registers.
@@ -334,6 +344,10 @@ impl Vm {
334344
shadow_stack: ShadowStack::default(),
335345
#[cfg(feature = "trace")]
336346
trace: false,
347+
#[cfg(all(feature = "trace", not(feature = "trace-stdout")))]
348+
tracer: Box::new(EmptyTracer),
349+
#[cfg(feature = "trace-stdout")]
350+
tracer: Box::new(StdoutTracer),
337351
}
338352
}
339353

@@ -581,40 +595,35 @@ impl Vm {
581595
}
582596
}
583597

584-
#[allow(clippy::print_stdout)]
585598
#[cfg(feature = "trace")]
586599
impl Context {
587-
const COLUMN_WIDTH: usize = 26;
588-
const TIME_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH / 2;
589-
const OPCODE_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH;
590-
const OPERAND_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH;
591-
const NUMBER_OF_COLUMNS: usize = 4;
600+
/// Sets the `Vm` tracer to the provided `VirtualMachineTracer` implementation
601+
pub fn set_virtual_machine_tracer(&mut self, tracer: Box<dyn VirtualMachineTracer>) {
602+
self.vm.tracer = tracer;
603+
}
592604

593605
pub(crate) fn trace_call_frame(&self) {
606+
use crate::vm::trace::{
607+
CallFrameMessage, CallFrameName, ExecutionStartMessage, VirtualMachineEvent,
608+
};
594609
let frame = self.vm.frame();
595-
let msg = if self.vm.frames.is_empty() {
596-
" VM Start ".to_string()
597-
} else {
598-
format!(
599-
" Call Frame -- {} ",
600-
frame.code_block().name().to_std_string_escaped()
601-
)
610+
let call_frame_message = CallFrameMessage {
611+
bytecode: frame.code_block.to_string(),
602612
};
613+
self.vm
614+
.tracer
615+
.emit_event(VirtualMachineEvent::CallFrameTrace(call_frame_message));
603616

604-
println!("{}", frame.code_block);
605-
println!(
606-
"{msg:-^width$}",
607-
width = Self::COLUMN_WIDTH * Self::NUMBER_OF_COLUMNS - 10
608-
);
609-
println!(
610-
"{:<TIME_COLUMN_WIDTH$} {:<OPCODE_COLUMN_WIDTH$} {:<OPERAND_COLUMN_WIDTH$} Stack\n",
611-
"Time",
612-
"Opcode",
613-
"Operands",
614-
TIME_COLUMN_WIDTH = Self::TIME_COLUMN_WIDTH,
615-
OPCODE_COLUMN_WIDTH = Self::OPCODE_COLUMN_WIDTH,
616-
OPERAND_COLUMN_WIDTH = Self::OPERAND_COLUMN_WIDTH,
617-
);
617+
let call_frame_name = if self.vm.frames.is_empty() {
618+
CallFrameName::Global
619+
} else {
620+
CallFrameName::Name(frame.code_block().name().to_std_string_escaped())
621+
};
622+
self.vm
623+
.tracer
624+
.emit_event(VirtualMachineEvent::ExecutionStart(ExecutionStartMessage {
625+
call_frame_name,
626+
}));
618627
}
619628

620629
fn trace_execute_instruction<F>(
@@ -625,6 +634,8 @@ impl Context {
625634
where
626635
F: FnOnce(&mut Context, Opcode) -> ControlFlow<CompletionRecord>,
627636
{
637+
use crate::vm::trace::{OpcodeExecutionMessage, VirtualMachineEvent};
638+
628639
let frame = self.vm.frame();
629640
let (instruction, _) = frame
630641
.code_block
@@ -647,7 +658,9 @@ impl Context {
647658
| Opcode::SuperCall
648659
| Opcode::SuperCallSpread
649660
| Opcode::SuperCallDerived => {
650-
println!();
661+
self.vm
662+
.tracer
663+
.emit_event(VirtualMachineEvent::ExecutionCallEvent);
651664
}
652665
_ => {}
653666
}
@@ -661,14 +674,16 @@ impl Context {
661674
.stack
662675
.display_trace(self.vm.frame(), self.vm.frames.len() - 1);
663676

664-
println!(
665-
"{:<TIME_COLUMN_WIDTH$} {:<OPCODE_COLUMN_WIDTH$} {operands:<OPERAND_COLUMN_WIDTH$} {stack}",
666-
format!("{}μs", duration.as_micros()),
667-
format!("{}", opcode.as_str()),
668-
TIME_COLUMN_WIDTH = Self::TIME_COLUMN_WIDTH,
669-
OPCODE_COLUMN_WIDTH = Self::OPCODE_COLUMN_WIDTH,
670-
OPERAND_COLUMN_WIDTH = Self::OPERAND_COLUMN_WIDTH,
671-
);
677+
self.vm
678+
.tracer
679+
.emit_event(VirtualMachineEvent::ExecutionTrace(
680+
OpcodeExecutionMessage {
681+
opcode: opcode.as_str(),
682+
duration,
683+
operands,
684+
stack,
685+
},
686+
));
672687

673688
result
674689
}

‎core/engine/src/vm/trace.rs‎

Lines changed: 126 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,126 @@
1+
use std::time::Duration;
2+
3+
/// The call frame name
4+
///
5+
/// This will have the name of the call frame provided or `Global` it's
6+
/// the global call frame.
7+
#[derive(Debug, Clone)]
8+
pub enum CallFrameName {
9+
Global,
10+
Name(String),
11+
}
12+
13+
/// A message that is emitted at the beginning of execution
14+
#[derive(Debug, Clone)]
15+
pub struct ExecutionStartMessage {
16+
pub call_frame_name: CallFrameName,
17+
}
18+
19+
/// A message that emits details about a call frame
20+
#[derive(Debug, Clone)]
21+
pub struct CallFrameMessage {
22+
pub bytecode: String,
23+
}
24+
25+
/// A message that emits instruction execution details about a call frame
26+
#[derive(Debug, Clone)]
27+
pub struct OpcodeExecutionMessage {
28+
pub opcode: &'static str,
29+
pub duration: Duration,
30+
pub operands: String,
31+
pub stack: String,
32+
}
33+
34+
/// The various events that are emitted from Boa's virtual machine.
35+
#[derive(Debug, Clone)]
36+
pub enum VirtualMachineEvent {
37+
/// This event is the first event triggered.
38+
///
39+
/// It emits information about the call frame.
40+
CallFrameTrace(CallFrameMessage),
41+
/// This event is triggered when the execution of a call frame is starting.
42+
ExecutionStart(ExecutionStartMessage),
43+
/// This event is triggered when executing an operation.
44+
///
45+
/// It provides information about the opcode execution
46+
ExecutionTrace(OpcodeExecutionMessage),
47+
/// This event is triggered when a opcode that calls is reached.
48+
///
49+
/// It signals that we about about to switch call frames.
50+
ExecutionCallEvent,
51+
}
52+
53+
/// A trait to define a tracer that plugs into Boa's `Vm`
54+
pub trait VirtualMachineTracer: std::fmt::Debug {
55+
/// Emits `VirtualMachineEvent`s from the virtual machine during execution
56+
fn emit_event(&self, _event: VirtualMachineEvent) {}
57+
}
58+
59+
/// A default empty virtual machine tracer that drops events submitted to it.
60+
#[derive(Debug, Clone, Copy)]
61+
pub struct EmptyTracer;
62+
63+
impl VirtualMachineTracer for EmptyTracer {}
64+
65+
/// `StdoutTracer` is a `VirtualMachineTracer` implementation that prints the events
66+
/// to stdout in a specific format.
67+
#[derive(Debug, Clone, Copy)]
68+
pub struct StdoutTracer;
69+
70+
impl StdoutTracer {
71+
const COLUMN_WIDTH: usize = 26;
72+
const TIME_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH / 2;
73+
const OPCODE_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH;
74+
const OPERAND_COLUMN_WIDTH: usize = Self::COLUMN_WIDTH;
75+
const NUMBER_OF_COLUMNS: usize = 4;
76+
}
77+
78+
#[allow(clippy::print_stdout)]
79+
impl VirtualMachineTracer for StdoutTracer {
80+
fn emit_event(&self, event: VirtualMachineEvent) {
81+
match event {
82+
VirtualMachineEvent::ExecutionStart(start_message) => {
83+
let msg = match start_message.call_frame_name {
84+
CallFrameName::Global => " VM Start ".to_string(),
85+
CallFrameName::Name(name) => {
86+
format!(" Call Frame -- {name} ")
87+
}
88+
};
89+
90+
println!(
91+
"{msg:-^width$}",
92+
width = Self::COLUMN_WIDTH * Self::NUMBER_OF_COLUMNS - 10
93+
);
94+
println!(
95+
"{:<TIME_COLUMN_WIDTH$} {:<OPCODE_COLUMN_WIDTH$} {:<OPERAND_COLUMN_WIDTH$} Stack\n",
96+
"Time",
97+
"Opcode",
98+
"Operands",
99+
TIME_COLUMN_WIDTH = Self::TIME_COLUMN_WIDTH,
100+
OPCODE_COLUMN_WIDTH = Self::OPCODE_COLUMN_WIDTH,
101+
OPERAND_COLUMN_WIDTH = Self::OPERAND_COLUMN_WIDTH,
102+
);
103+
}
104+
VirtualMachineEvent::ExecutionCallEvent => println!(),
105+
VirtualMachineEvent::CallFrameTrace(call_frame_message) => {
106+
println!("{}", call_frame_message.bytecode);
107+
}
108+
VirtualMachineEvent::ExecutionTrace(execution_message) => {
109+
let OpcodeExecutionMessage {
110+
opcode,
111+
duration,
112+
operands,
113+
stack,
114+
} = execution_message;
115+
116+
println!(
117+
"{:<TIME_COLUMN_WIDTH$} {opcode:<OPCODE_COLUMN_WIDTH$} {operands:<OPERAND_COLUMN_WIDTH$} {stack}",
118+
format!("{}μs", duration.as_micros()),
119+
TIME_COLUMN_WIDTH = Self::TIME_COLUMN_WIDTH,
120+
OPCODE_COLUMN_WIDTH = Self::OPCODE_COLUMN_WIDTH,
121+
OPERAND_COLUMN_WIDTH = Self::OPERAND_COLUMN_WIDTH,
122+
);
123+
}
124+
}
125+
}
126+
}

0 commit comments

Comments
 (0)