From f4ceb0057eadd26eeda10d843a8b7c37d7d2ea8c Mon Sep 17 00:00:00 2001 From: liquidev Date: Mon, 2 Sep 2024 21:35:52 +0200 Subject: [PATCH] add a bunch of logging to haku, including vm-trace for tracing what the VM does --- crates/haku/Cargo.toml | 4 ++++ crates/haku/src/parser.rs | 10 ++++++++-- crates/haku/src/vm.rs | 26 +++++++++++++++++++++----- crates/rkgk/Cargo.toml | 1 + 4 files changed, 34 insertions(+), 7 deletions(-) diff --git a/crates/haku/Cargo.toml b/crates/haku/Cargo.toml index 883aff6..6c71582 100644 --- a/crates/haku/Cargo.toml +++ b/crates/haku/Cargo.toml @@ -6,3 +6,7 @@ edition = "2021" [dependencies] log.workspace = true tiny-skia = { version = "0.11.4", default-features = false, features = ["no-std-float"] } + +[features] +default = [] +vm-trace = [] diff --git a/crates/haku/src/parser.rs b/crates/haku/src/parser.rs index 3dce27a..ae5511c 100644 --- a/crates/haku/src/parser.rs +++ b/crates/haku/src/parser.rs @@ -1,6 +1,7 @@ use core::{cell::Cell, error::Error, fmt}; use alloc::vec::Vec; +use log::{error, info}; use crate::{ ast::{Ast, NodeAllocError, NodeId, NodeKind}, @@ -157,6 +158,7 @@ impl<'a> Parser<'a> { pub fn into_ast(self, ast: &mut Ast) -> Result<(NodeId, Vec), IntoAstError> { // If events are at capacity, that means the pool was exhausted and we return an error. if self.events.len() == self.events.capacity() { + error!("parser is at capacity"); return Err(IntoAstError::TooManyEvents); } @@ -171,13 +173,16 @@ impl<'a> Parser<'a> { } // Remove the last Close to keep a single node on the stack. - assert!(matches!( + if !matches!( events.pop(), Some(Event { kind: EventKind::Close, .. }) - )); + ) { + error!("parser should have produced a Close event, but didn't"); + return Err(IntoAstError::UnbalancedEvents); + } for event in events { match event.kind { @@ -209,6 +214,7 @@ impl<'a> Parser<'a> { if stack.len() != 1 { // This means we had too many events emitted and they are no longer balanced. + error!("parser produced an unbalanced amount of events"); return Err(IntoAstError::UnbalancedEvents); } // assert_eq!(token, self.tokens.len()); diff --git a/crates/haku/src/vm.rs b/crates/haku/src/vm.rs index 0d6bd01..3bb96f9 100644 --- a/crates/haku/src/vm.rs +++ b/crates/haku/src/vm.rs @@ -5,7 +5,6 @@ use core::{ }; use alloc::{string::String, vec::Vec}; -use log::info; use crate::{ bytecode::{self, Defs, Opcode, CAPTURE_CAPTURE, CAPTURE_LOCAL}, @@ -13,6 +12,15 @@ use crate::{ value::{BytecodeLoc, Closure, FunctionName, List, Ref, RefId, Rgba, Value, Vec4}, }; +macro_rules! vmtrace { + ($($args:expr),* $(,)?) => { + #[cfg(feature = "vm-trace")] + { + log::info!($($args),*); + } + } +} + pub struct VmLimits { pub stack_capacity: usize, pub call_stack_capacity: usize, @@ -129,6 +137,7 @@ impl Vm { )); } self.stack.push(value); + vmtrace!("push {:?}", self.stack); Ok(()) } @@ -147,9 +156,12 @@ impl Vm { } fn pop(&mut self) -> Result { - self.stack + let value = self + .stack .pop() - .ok_or_else(|| self.create_exception("corrupted bytecode (value stack underflow)")) + .ok_or_else(|| self.create_exception("corrupted bytecode (value stack underflow)"))?; + vmtrace!("pop {:?} -> {:?}", self.stack, value); + Ok(value) } fn push_call(&mut self, frame: CallFrame) -> Result<(), Exception> { @@ -198,7 +210,9 @@ impl Vm { .checked_sub(1) .ok_or_else(|| self.create_exception("code ran for too long"))?; + let pc2 = pc; let opcode = chunk.read_opcode(&mut pc)?; + vmtrace!("{pc2:2} {opcode:?}"); match opcode { Opcode::Nil => self.push(Value::Nil)?, Opcode::False => self.push(Value::False)?, @@ -301,7 +315,7 @@ impl Vm { }) } - let id = self.create_ref(Ref::Closure(Closure { + let closure = Closure { start: BytecodeLoc { chunk_id, offset: body as u16, @@ -310,7 +324,9 @@ impl Vm { param_count, local_count, captures, - }))?; + }; + vmtrace!("{closure:?}"); + let id = self.create_ref(Ref::Closure(closure))?; self.push(Value::Ref(id))?; } diff --git a/crates/rkgk/Cargo.toml b/crates/rkgk/Cargo.toml index 651aac8..e9b3192 100644 --- a/crates/rkgk/Cargo.toml +++ b/crates/rkgk/Cargo.toml @@ -35,3 +35,4 @@ webp = "0.3.0" [features] default = [] memory-profiling = ["dep:tracy-client"] +haku-vm-trace = ["haku/vm-trace"]