diff --git a/Justfile b/Justfile index 07fbd6f..b6fbfdb 100644 --- a/Justfile +++ b/Justfile @@ -18,7 +18,7 @@ export HYPERLIGHT_CFLAGS := \ export CMAKE_GENERATOR := if os() == "windows" { "Ninja" } else { "" } ensure-tools: - cargo install cargo-hyperlight --locked --version 0.1.3 + cargo install cargo-hyperlight --locked --version 0.1.7 # Check if npm is installed, install automatically if missing (Linux) [private] @@ -127,6 +127,7 @@ run-examples target=default-target features="": (build target) cargo run --profile={{ if target == "debug" {"dev"} else { target } }} {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --example run_handler regex cargo run --profile={{ if target == "debug" {"dev"} else { target } }} {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F function_call_metrics," + features } }} --example metrics cargo run --profile={{ if target == "debug" {"dev"} else { target } }} {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --example metrics + cargo run --profile={{ if target == "debug" {"dev"} else { target } }} {{ if features =="" {'--features guest-call-stats,monitor-wall-clock,monitor-cpu-time'} else if features=="no-default-features" {"--no-default-features -F guest-call-stats,monitor-wall-clock,monitor-cpu-time" } else {"--no-default-features -F guest-call-stats,monitor-wall-clock,monitor-cpu-time," + features } }} --example execution_stats run-examples-tracing target=default-target features="": (build target) cargo run --profile={{ if target == "debug" {"dev"} else { target } }} {{ if features =="" {'--features function_call_metrics'} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --example tracing fmt @@ -152,10 +153,10 @@ test target=default-target features="": (build target) cd src/hyperlight-js && cargo test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} test_metrics --profile={{ if target == "debug" {"dev"} else { target } }} -- --ignored --nocapture cargo test --manifest-path=./src/hyperlight-js-runtime/Cargo.toml --test=native_cli --profile={{ if target == "debug" {"dev"} else { target } }} -# Test with monitor features enabled (wall-clock and CPU time monitors) +# Test with monitor features enabled (wall-clock, CPU time, and guest-call-stats) # Note: We exclude test_metrics as it requires process isolation and is already run by `test` recipe test-monitors target=default-target: - cd src/hyperlight-js && cargo test --features monitor-wall-clock,monitor-cpu-time --profile={{ if target == "debug" {"dev"} else { target } }} -- --include-ignored --skip test_metrics + cd src/hyperlight-js && cargo test --features monitor-wall-clock,monitor-cpu-time,guest-call-stats --profile={{ if target == "debug" {"dev"} else { target } }} -- --include-ignored --skip test_metrics test-js-host-api target=default-target features="": (build-js-host-api target features) cd src/js-host-api && npm test diff --git a/docs/execution-monitors.md b/docs/execution-monitors.md index 36b6428..adc3266 100644 --- a/docs/execution-monitors.md +++ b/docs/execution-monitors.md @@ -112,6 +112,54 @@ hyperlight-js = { version = "0.17", features = ["monitor-wall-clock", "monitor-c |---------|--------------|-------------| | `monitor-wall-clock` | (none) | Wall-clock time monitor | | `monitor-cpu-time` | `libc` (Linux), `windows-sys` (Windows) | CPU time monitor with OS-native APIs | +| `guest-call-stats` | (none) | Execution statistics (`last_call_stats()`) — see [Execution Statistics](#execution-statistics-) below | + +## Execution Statistics šŸ“Š + +When the `guest-call-stats` feature is enabled, `LoadedJSSandbox` records timing +and termination information after every `handle_event` / `handle_event_with_monitor` +call, accessible via `last_call_stats()`. + +```rust +let _ = loaded.handle_event("handler", "{}".to_string(), None)?; +if let Some(stats) = loaded.last_call_stats() { + println!("Wall clock: {:?}", stats.wall_clock); + println!("CPU time: {:?}", stats.cpu_time); // Some when monitor-cpu-time is also enabled + println!("Terminated: {:?}", stats.terminated_by); // Some("wall-clock") or Some("cpu-time") when a monitor fired +} +``` + +### `ExecutionStats` fields + +| Field | Type | Description | +|-------|------|-------------| +| `wall_clock` | `Duration` | Wall-clock elapsed time of the guest call (always available) | +| `cpu_time` | `Option` | CPU time consumed by the calling thread during the guest call. `Some` only when `monitor-cpu-time` is also enabled | +| `terminated_by` | `Option<&'static str>` | Name of the monitor that terminated execution (e.g. `"wall-clock"`, `"cpu-time"`), or `None` if the call completed normally | + +### Key behaviours + +- **Stats are per-call** — each call replaces the previous stats (not cumulative) +- **Stats are captured even on error** — if the guest is killed by a monitor, timing is still recorded +- **`None` before any call** — `last_call_stats()` returns `None` until the first `handle_event` or `handle_event_with_monitor` call +- **Feature-gated** — the entire API (struct, field, getter) disappears when `guest-call-stats` is not enabled + +### Node.js (NAPI) usage + +In the Node.js bindings, stats are always available (the feature is enabled by default in `js-host-api`): + +```javascript +await loaded.callHandler('handler', { data: 'value' }); + +const stats = loaded.lastCallStats; +if (stats) { + console.log(`Wall clock: ${stats.wallClockMs}ms`); + console.log(`CPU time: ${stats.cpuTimeMs}ms`); // null if monitor-cpu-time not enabled + console.log(`Terminated by: ${stats.terminatedBy}`); // null for normal completion +} +``` + +See the [JS Host API README](../src/js-host-api/README.md) for full API details. ## Environment Variables @@ -258,5 +306,6 @@ if result.is_err() && loaded_sandbox.poisoned() { ## See Also - [Examples README](../src/js-host-api/examples/README.md) - interrupt.js and cpu-timeout.js examples -- [JS Host API README](../src/js-host-api/README.md) - Node.js bindings with `callHandler()` +- [Rust execution_stats example](../src/hyperlight-js/examples/execution_stats/main.rs) - Demonstrates `last_call_stats()` API +- [JS Host API README](../src/js-host-api/README.md) - Node.js bindings with `callHandler()` and `lastCallStats` - [Observability](./observability.md) - Metrics including `monitor_terminations_total` diff --git a/src/hyperlight-js/Cargo.toml b/src/hyperlight-js/Cargo.toml index 9f101ba..c6dcb97 100644 --- a/src/hyperlight-js/Cargo.toml +++ b/src/hyperlight-js/Cargo.toml @@ -75,6 +75,7 @@ kvm = ["hyperlight-host/kvm"] mshv3 = ["hyperlight-host/mshv3"] print_debug = ["hyperlight-host/print_debug"] trace_guest = ["hyperlight-host/trace_guest"] +guest-call-stats = [] monitor-wall-clock = [] monitor-cpu-time = ["dep:libc", "dep:windows-sys"] @@ -111,6 +112,12 @@ name = "runtime_debugging" path = "examples/runtime_debugging/main.rs" test = false +[[example]] +name = "execution_stats" +path = "examples/execution_stats/main.rs" +required-features = ["guest-call-stats"] +test = false + [[bench]] name = "benchmarks" harness = false diff --git a/src/hyperlight-js/examples/execution_stats/main.rs b/src/hyperlight-js/examples/execution_stats/main.rs new file mode 100644 index 0000000..9a37b32 --- /dev/null +++ b/src/hyperlight-js/examples/execution_stats/main.rs @@ -0,0 +1,244 @@ +/* +Copyright 2026 The Hyperlight Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ +//! Execution Stats Example: Demonstrates guest call statistics +//! +//! This example shows how to inspect timing and termination information +//! after each guest function call using the `guest-call-stats` feature. +//! +//! Features demonstrated: +//! 1. Wall-clock timing after a normal `handle_event` call +//! 2. CPU time measurement (when `monitor-cpu-time` is enabled) +//! 3. Stats with execution monitors — including which monitor fired +//! 4. Stats update on every call (not cumulative) +//! +//! Run with: +//! cargo run --example execution_stats --features guest-call-stats,monitor-wall-clock,monitor-cpu-time +//! +//! Or via Just: +//! just run-examples + +#![allow(clippy::disallowed_macros)] + +use std::time::Duration; + +use anyhow::Result; +use hyperlight_js::{SandboxBuilder, Script}; + +fn main() -> Result<()> { + println!("šŸ“Š Execution Stats Example: Guest Call Statistics\n"); + + // ── Setup ──────────────────────────────────────────────────────── + let proto = SandboxBuilder::new().build()?; + let mut sandbox = proto.load_runtime()?; + + // A fast handler that returns immediately + let fast_handler = Script::from_content( + r#" + function handler(event) { + event.message = "Hello from the guest!"; + return event; + } + "#, + ); + + // A CPU-intensive handler that burns for a configurable duration + let slow_handler = Script::from_content( + r#" + function handler(event) { + const startTime = Date.now(); + const runtime = event.runtime || 200; + let counter = 0; + while (Date.now() - startTime < runtime) { + counter++; + } + event.counter = counter; + return event; + } + "#, + ); + + // ── Test 1: Basic wall-clock timing ────────────────────────────── + println!("šŸ“Š Test 1: Basic wall-clock timing (fast handler)"); + + sandbox.add_handler("fast", fast_handler)?; + let mut loaded = sandbox.get_loaded_sandbox()?; + + // Before any call, stats are None + assert!(loaded.last_call_stats().is_none()); + println!(" Before call: stats = None āœ…"); + + let result = loaded.handle_event("fast", r#"{"name": "World"}"#.to_string(), None)?; + println!(" Result: {result}"); + + let stats = loaded + .last_call_stats() + .expect("Stats should be populated after a call"); + println!(" ā±ļø Wall clock: {:?}", stats.wall_clock); + print_cpu_time(stats); + println!( + " šŸ Terminated by: {}", + stats.terminated_by.unwrap_or("(none — completed normally)") + ); + + // ── Test 2: CPU-intensive handler ──────────────────────────────── + println!("\nšŸ“Š Test 2: CPU-intensive handler (200ms burn)"); + + let mut sandbox = loaded.unload()?; + sandbox.clear_handlers(); + sandbox.add_handler("slow", slow_handler)?; + let mut loaded = sandbox.get_loaded_sandbox()?; + + let _ = loaded.handle_event("slow", r#"{"runtime": 200}"#.to_string(), None)?; + + let stats = loaded.last_call_stats().unwrap(); + println!(" ā±ļø Wall clock: {:?}", stats.wall_clock); + print_cpu_time(stats); + println!(" šŸ Terminated by: (none — completed normally)"); + + // ── Test 3: Stats update on each call ──────────────────────────── + println!("\nšŸ“Š Test 3: Stats update on each call (50ms then 150ms)"); + + let _ = loaded.handle_event("slow", r#"{"runtime": 50}"#.to_string(), None)?; + let stats1 = loaded.last_call_stats().unwrap().clone(); + println!(" Call 1 wall clock: {:?}", stats1.wall_clock); + + let _ = loaded.handle_event("slow", r#"{"runtime": 150}"#.to_string(), None)?; + let stats2 = loaded.last_call_stats().unwrap().clone(); + println!(" Call 2 wall clock: {:?}", stats2.wall_clock); + println!( + " Stats replaced (not cumulative): call2 > call1 = {} āœ…", + stats2.wall_clock > stats1.wall_clock + ); + + // ── Test 4: With monitors — successful completion ──────────────── + #[cfg(feature = "monitor-wall-clock")] + { + use hyperlight_js::WallClockMonitor; + + println!("\nšŸ“Š Test 4: Monitored call — completes within limit"); + + let monitor = WallClockMonitor::new(Duration::from_secs(5))?; + let _ = loaded.handle_event_with_monitor( + "slow", + r#"{"runtime": 50}"#.to_string(), + &monitor, + None, + )?; + + let stats = loaded.last_call_stats().unwrap(); + println!(" ā±ļø Wall clock: {:?}", stats.wall_clock); + print_cpu_time(stats); + println!( + " šŸ Terminated by: {} āœ…", + stats.terminated_by.unwrap_or("(none — completed normally)") + ); + } + + // ── Test 5: With monitors — timeout fires ──────────────────────── + #[cfg(feature = "monitor-wall-clock")] + { + use hyperlight_js::WallClockMonitor; + + println!("\nšŸ“Š Test 5: Monitored call — wall-clock timeout fires"); + + let snapshot = loaded.snapshot()?; + let monitor = WallClockMonitor::new(Duration::from_millis(50))?; + let result = loaded.handle_event_with_monitor( + "slow", + r#"{"runtime": 5000}"#.to_string(), + &monitor, + None, + ); + + match result { + Ok(_) => println!(" āŒ Unexpected: handler completed"), + Err(_) => { + let stats = loaded.last_call_stats().unwrap(); + println!(" ā±ļø Wall clock: {:?}", stats.wall_clock); + print_cpu_time(stats); + println!( + " šŸ’€ Terminated by: {} āœ…", + stats.terminated_by.unwrap_or("(unknown)") + ); + println!(" šŸ”’ Poisoned: {}", loaded.poisoned()); + } + } + + // Recover from poisoned state + loaded.restore(snapshot.clone())?; + println!( + " šŸ“ø Restored from snapshot — poisoned: {}", + loaded.poisoned() + ); + } + + // ── Test 6: Combined monitors — CPU monitor wins ───────────────── + #[cfg(all(feature = "monitor-wall-clock", feature = "monitor-cpu-time"))] + { + use hyperlight_js::{CpuTimeMonitor, WallClockMonitor}; + + println!("\nšŸ“Š Test 6: Combined monitors — CPU monitor fires first"); + + let snapshot = loaded.snapshot()?; + + // CPU limit is tight (30ms), wall-clock is generous (5s) + let monitor = ( + WallClockMonitor::new(Duration::from_secs(5))?, + CpuTimeMonitor::new(Duration::from_millis(30))?, + ); + let result = loaded.handle_event_with_monitor( + "slow", + r#"{"runtime": 5000}"#.to_string(), + &monitor, + None, + ); + + match result { + Ok(_) => println!(" āŒ Unexpected: handler completed"), + Err(_) => { + let stats = loaded.last_call_stats().unwrap(); + println!(" ā±ļø Wall clock: {:?}", stats.wall_clock); + print_cpu_time(stats); + println!( + " šŸ’€ Terminated by: {} āœ…", + stats.terminated_by.unwrap_or("(unknown)") + ); + } + } + + loaded.restore(snapshot.clone())?; + println!(" šŸ“ø Restored from snapshot"); + } + + println!("\nšŸŽ‰ Execution stats example complete!"); + println!("\nšŸ’” Key Points:"); + println!(" - last_call_stats() returns None before any call"); + println!(" - Stats are replaced (not accumulated) on each call"); + println!(" - wall_clock is always available"); + println!(" - cpu_time requires the monitor-cpu-time feature"); + println!(" - terminated_by shows which monitor fired (or None for normal completion)"); + println!(" - Stats are captured even when the call returns Err"); + + Ok(()) +} + +/// Helper to print CPU time, handling the feature-gated `Option`. +fn print_cpu_time(stats: &hyperlight_js::ExecutionStats) { + match stats.cpu_time { + Some(cpu) => println!(" šŸ–„ļø CPU time: {:?}", cpu), + None => println!(" šŸ–„ļø CPU time: (not available — enable monitor-cpu-time feature)"), + } +} diff --git a/src/hyperlight-js/src/lib.rs b/src/hyperlight-js/src/lib.rs index 916faba..05cb209 100644 --- a/src/hyperlight-js/src/lib.rs +++ b/src/hyperlight-js/src/lib.rs @@ -64,6 +64,9 @@ pub use hyperlight_host::sandbox::snapshot::Snapshot; pub use hyperlight_host::sandbox::SandboxConfiguration; /// Module resolution and loading functionality. pub use resolver::{FileMetadata, FileSystem, FileSystemEmbedded, ResolveError}; +/// Execution statistics from the most recent guest function call. +#[cfg(feature = "guest-call-stats")] +pub use sandbox::execution_stats::ExecutionStats; /// The monitor module — re-exports `sleep` so custom monitors don't couple to tokio directly. pub use sandbox::monitor; /// CPU time based execution monitor. diff --git a/src/hyperlight-js/src/sandbox/execution_stats.rs b/src/hyperlight-js/src/sandbox/execution_stats.rs new file mode 100644 index 0000000..506614c --- /dev/null +++ b/src/hyperlight-js/src/sandbox/execution_stats.rs @@ -0,0 +1,79 @@ +/* +Copyright 2026 The Hyperlight Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ +//! Execution statistics captured during guest function calls. +//! +//! When the `guest-call-stats` feature is enabled, every call to +//! [`handle_event`](super::loaded_js_sandbox::LoadedJSSandbox::handle_event) or +//! [`handle_event_with_monitor`](super::loaded_js_sandbox::LoadedJSSandbox::handle_event_with_monitor) +//! stores an [`ExecutionStats`] on the sandbox, retrievable via +//! [`last_call_stats()`](super::loaded_js_sandbox::LoadedJSSandbox::last_call_stats). +//! +//! # What's measured +//! +//! | Field | When populated | +//! |---|---| +//! | `wall_clock` | Always (when feature is on) | +//! | `cpu_time` | Only when `monitor-cpu-time` feature is also enabled | +//! | `terminated_by` | Only when a monitor killed the call | +//! +//! # Example +//! +//! ```text +//! let result = loaded.handle_event("handler", event, None); +//! if let Some(stats) = loaded.last_call_stats() { +//! println!("Wall clock: {:?}", stats.wall_clock); +//! if let Some(cpu) = stats.cpu_time { +//! println!("CPU time: {:?}", cpu); +//! } +//! if let Some(monitor) = stats.terminated_by { +//! println!("Terminated by: {}", monitor); +//! } +//! } +//! ``` + +use std::time::Duration; + +/// Statistics from the most recent guest function call. +/// +/// Retrieved via +/// [`LoadedJSSandbox::last_call_stats()`](super::loaded_js_sandbox::LoadedJSSandbox::last_call_stats). +/// +/// Stats are captured even when the call returns an error (e.g. monitor +/// termination, guest abort). They are overwritten on each subsequent call +/// — they are **not** cumulative. +#[derive(Debug, Clone)] +pub struct ExecutionStats { + /// Wall-clock (elapsed) time for the guest call. + /// + /// Measured with `std::time::Instant` — always available when the + /// `guest-call-stats` feature is enabled. + pub wall_clock: Duration, + + /// CPU time consumed by the guest call. + /// + /// Only populated when the `monitor-cpu-time` feature is also enabled. + /// + /// `None` if `monitor-cpu-time` is not enabled, or if the CPU time + /// handle could not be obtained for the calling thread. + pub cpu_time: Option, + + /// Name of the monitor that terminated execution, if any. + /// + /// `Some("wall-clock")` or `Some("cpu-time")` when a built-in monitor + /// killed the call. `Some()` for custom monitors. `None` when + /// the call completed (or failed) without monitor intervention. + pub terminated_by: Option<&'static str>, +} diff --git a/src/hyperlight-js/src/sandbox/loaded_js_sandbox.rs b/src/hyperlight-js/src/sandbox/loaded_js_sandbox.rs index 297aaad..43d4c10 100644 --- a/src/hyperlight-js/src/sandbox/loaded_js_sandbox.rs +++ b/src/hyperlight-js/src/sandbox/loaded_js_sandbox.rs @@ -23,6 +23,8 @@ use hyperlight_host::{MultiUseSandbox, Result}; use tokio::task::JoinHandle; use tracing::{instrument, Level}; +#[cfg(feature = "guest-call-stats")] +use super::execution_stats::ExecutionStats; use super::js_sandbox::JSSandbox; use super::metrics::{METRIC_SANDBOX_LOADS, METRIC_SANDBOX_UNLOADS}; use super::monitor::runtime::get_monitor_runtime; @@ -39,6 +41,10 @@ pub struct LoadedJSSandbox { snapshot: Arc, // metric drop guard to manage sandbox metric _metric_guard: SandboxMetricsGuard, + // Stats from the most recent handle_event / handle_event_with_monitor call. + // None before any call has been made. + #[cfg(feature = "guest-call-stats")] + last_call_stats: Option, } /// RAII guard that aborts a spawned monitor task on drop. @@ -63,6 +69,8 @@ impl LoadedJSSandbox { inner, snapshot, _metric_guard: SandboxMetricsGuard::new(), + #[cfg(feature = "guest-call-stats")] + last_call_stats: None, }) } @@ -93,7 +101,65 @@ impl LoadedJSSandbox { #[cfg(feature = "function_call_metrics")] let _metric_guard = EventHandlerMetricGuard::new(&func_name, should_gc); - self.inner.call(&func_name, (event, should_gc)) + // --- guest-call-stats: capture timing before the call --- + #[cfg(feature = "guest-call-stats")] + let wall_start = std::time::Instant::now(); + + #[cfg(all(feature = "guest-call-stats", feature = "monitor-cpu-time"))] + let cpu_start = super::monitor::cpu_time::ThreadCpuHandle::for_current_thread() + .and_then(|h| h.elapsed().map(|t| (h, t))); + + let result = self.inner.call(&func_name, (event, should_gc)); + + // --- guest-call-stats: record timing after the call --- + // CPU time is read first so the wall-clock measurement fully wraps it. + #[cfg(feature = "guest-call-stats")] + { + #[cfg(feature = "monitor-cpu-time")] + let cpu_time = cpu_start.and_then(|(handle, start_ticks)| { + handle.elapsed().map(|end_ticks| { + let delta_nanos = + handle.ticks_to_approx_nanos(end_ticks.saturating_sub(start_ticks)); + std::time::Duration::from_nanos(delta_nanos) + }) + }); + #[cfg(not(feature = "monitor-cpu-time"))] + let cpu_time: Option = None; + + let wall_clock = wall_start.elapsed(); + + self.last_call_stats = Some(ExecutionStats { + wall_clock, + cpu_time, + terminated_by: None, + }); + } + + result + } + + /// Returns the execution statistics from the most recent guest function call. + /// + /// Returns `None` before any call has been made. After each `handle_event` or + /// `handle_event_with_monitor` call, this returns the timing and termination + /// information from that call — stats are **not** cumulative. + /// + /// Stats are captured even when the call returns an error (e.g. the sandbox + /// was poisoned by a monitor timeout). + /// + /// # Example + /// + /// ```text + /// let _ = loaded.handle_event("handler", event, None); + /// if let Some(stats) = loaded.last_call_stats() { + /// println!("Wall clock: {:?}", stats.wall_clock); + /// println!("CPU time: {:?}", stats.cpu_time); + /// println!("Terminated by: {:?}", stats.terminated_by); + /// } + /// ``` + #[cfg(feature = "guest-call-stats")] + pub fn last_call_stats(&self) -> Option<&ExecutionStats> { + self.last_call_stats.as_ref() } /// Unloads the Handlers from the sandbox and returns a `JSSandbox` with the JavaScript runtime loaded. @@ -219,8 +285,9 @@ impl LoadedJSSandbox { })?; // Phase 2: Spawn the racing future on the shared runtime. - // When the first monitor fires, to_race() emits the metric and log, - // then we call kill() to terminate the guest. + // When the first monitor fires, to_race() returns the winner's name. + // We record the metric/log, store the winner name for stats, then + // call kill() to terminate the guest. // kill() is safe to call even if the guest already finished — hyperlight's // InterruptHandle checks RUNNING_BIT and clear_cancel() at the start of // the next guest call clears any stale CANCEL_BIT. @@ -229,14 +296,40 @@ impl LoadedJSSandbox { HyperlightError::Error("Monitor runtime is unavailable".to_string()) })?; + // Shared slot for the winning monitor's name. The monitor task writes + // the winner *before* calling kill(), and handle_event only returns + // *after* kill takes effect, so the read after handle_event is safe. + let terminated_by = Arc::new(std::sync::Mutex::new(None::<&'static str>)); + let terminated_by_writer = terminated_by.clone(); + let _monitor_task = MonitorTask(runtime.spawn(async move { - racing_future.await; + let winner = racing_future.await; + super::monitor::record_monitor_triggered(winner); + // Store the winner name before kill — ordering guarantee: + // handle_event returns only after kill() poisons the sandbox, + // so the caller sees the write. + if let Ok(mut guard) = terminated_by_writer.lock() { + *guard = Some(winner); + } interrupt_handle.kill(); })); // Phase 3: Execute the handler (blocking). When this returns (success // or error), _monitor_task drops and aborts the spawned monitor task. - self.handle_event(&func_name, event, gc) + let result = self.handle_event(&func_name, event, gc); + + // Phase 4: Patch terminated_by into the stats captured by handle_event. + // If the monitor fired, the winner name was written before kill(), so + // we can read it safely now. + #[cfg(feature = "guest-call-stats")] + if let Ok(guard) = terminated_by.lock() + && let Some(winner) = *guard + && let Some(stats) = &mut self.last_call_stats + { + stats.terminated_by = Some(winner); + } + + result } /// Generate a crash dump of the current state of the VM underlying this sandbox. diff --git a/src/hyperlight-js/src/sandbox/mod.rs b/src/hyperlight-js/src/sandbox/mod.rs index cb1e90c..2d6893c 100644 --- a/src/hyperlight-js/src/sandbox/mod.rs +++ b/src/hyperlight-js/src/sandbox/mod.rs @@ -15,6 +15,9 @@ limitations under the License. */ //! The `sandbox` module contains the sandbox types for the Hyperlight JavaScript runtime. use std::env; +/// Execution statistics captured after each guest function call. +#[cfg(feature = "guest-call-stats")] +pub mod execution_stats; /// Definition of a host function that can be called from guest JavaScript code. pub(crate) mod host_fn; /// A Hyperlight Sandbox with a JavaScript run time loaded but no guest code. diff --git a/src/hyperlight-js/src/sandbox/monitor/mod.rs b/src/hyperlight-js/src/sandbox/monitor/mod.rs index e76328c..e44430a 100644 --- a/src/hyperlight-js/src/sandbox/monitor/mod.rs +++ b/src/hyperlight-js/src/sandbox/monitor/mod.rs @@ -146,7 +146,7 @@ use crate::sandbox::metrics::{METRIC_MONITOR_TERMINATIONS, METRIC_MONITOR_TYPE_L /// /// Emits the `monitor_terminations_total` counter metric with the winning /// monitor's name as the `monitor_type` label, and logs a warning. -fn record_monitor_triggered(triggered_by: &'static str) { +pub(crate) fn record_monitor_triggered(triggered_by: &'static str) { metrics::counter!( METRIC_MONITOR_TERMINATIONS, METRIC_MONITOR_TYPE_LABEL => triggered_by @@ -253,22 +253,21 @@ pub trait MonitorSet: private::Sealed + Send + Sync { /// /// Each sub-monitor's `get_monitor()` is called on the **calling thread** /// so monitors can capture thread-local state (e.g., CPU clock handles). - /// The returned future completes when the first monitor fires, emitting - /// the `monitor_terminations_total` metric and a warning log with the - /// winning monitor's name. - fn to_race(&self) -> Result + Send>>>; + /// The returned future completes when the first monitor fires, returning + /// the winning monitor's name for metrics, logging, and stats. + fn to_race(&self) -> Result + Send>>>; } // Every ExecutionMonitor is automatically a MonitorSet of one. impl private::Sealed for M {} impl MonitorSet for M { - fn to_race(&self) -> Result + Send>>> { + fn to_race(&self) -> Result + Send>>> { let future = self.get_monitor()?; let name = self.name(); Ok(Box::pin(async move { future.await; - record_monitor_triggered(name); + name })) } } @@ -288,7 +287,7 @@ macro_rules! impl_monitor_set_tuple { impl<$($P: ExecutionMonitor),+> private::Sealed for ($($P,)+) {} impl<$($P: ExecutionMonitor),+> MonitorSet for ($($P,)+) { - fn to_race(&self) -> Result + Send>>> { + fn to_race(&self) -> Result + Send>>> { let ($($p,)+) = &self; // Each get_monitor() runs here on the calling thread, // preserving thread-local state (e.g. CPU clock handles). @@ -296,10 +295,9 @@ macro_rules! impl_monitor_set_tuple { Ok(Box::pin(async move { // Race all monitors — first to complete wins. - let winner = tokio::select! { + tokio::select! { $(_ = $p.0 => $p.1,)+ - }; - record_monitor_triggered(winner); + } })) } } @@ -323,7 +321,7 @@ mod wall_clock; pub use wall_clock::WallClockMonitor; #[cfg(feature = "monitor-cpu-time")] -mod cpu_time; +pub(crate) mod cpu_time; #[cfg(feature = "monitor-cpu-time")] pub use cpu_time::CpuTimeMonitor; diff --git a/src/hyperlight-js/tests/execution_stats.rs b/src/hyperlight-js/tests/execution_stats.rs new file mode 100644 index 0000000..510aa97 --- /dev/null +++ b/src/hyperlight-js/tests/execution_stats.rs @@ -0,0 +1,313 @@ +/* +Copyright 2026 The Hyperlight Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ +//! Integration tests for the `guest-call-stats` feature. +//! +//! These tests verify that `LoadedJSSandbox::last_call_stats()` returns +//! correct execution statistics after guest function calls, both with +//! and without execution monitors. + +#![cfg(feature = "guest-call-stats")] +#![allow(clippy::disallowed_macros)] + +use std::time::Duration; + +#[cfg(feature = "monitor-cpu-time")] +use hyperlight_js::CpuTimeMonitor; +#[cfg(feature = "monitor-wall-clock")] +use hyperlight_js::WallClockMonitor; +use hyperlight_js::{SandboxBuilder, Script}; + +// ── Helpers ────────────────────────────────────────────────────────── + +/// Create a sandbox with a simple handler that returns immediately. +fn create_fast_sandbox() -> hyperlight_js::LoadedJSSandbox { + let handler = Script::from_content( + r#" + function handler(event) { + event.handled = true; + return event; + } + "#, + ); + + let proto = SandboxBuilder::new().build().unwrap(); + let mut sandbox = proto.load_runtime().unwrap(); + sandbox.add_handler("handler", handler).unwrap(); + sandbox.get_loaded_sandbox().unwrap() +} + +/// Create a sandbox with a CPU-burning handler. +fn create_cpu_burning_sandbox() -> hyperlight_js::LoadedJSSandbox { + let handler = Script::from_content( + r#" + function handler(event) { + const startTime = Date.now(); + const runtime = event.runtime || 100; + let counter = 0; + while (Date.now() - startTime < runtime) { + counter++; + } + event.counter = counter; + return event; + } + "#, + ); + + let proto = SandboxBuilder::new().build().unwrap(); + let mut sandbox = proto.load_runtime().unwrap(); + sandbox.add_handler("handler", handler).unwrap(); + sandbox.get_loaded_sandbox().unwrap() +} + +// ── Basic stats tests ──────────────────────────────────────────────── + +#[test] +fn last_call_stats_is_none_before_any_call() { + let loaded = create_fast_sandbox(); + assert!( + loaded.last_call_stats().is_none(), + "Stats should be None before any call" + ); +} + +#[test] +fn handle_event_populates_wall_clock() { + let mut loaded = create_fast_sandbox(); + let event = r#"{"test": true}"#; + + let result = loaded.handle_event("handler", event.to_string(), None); + assert!(result.is_ok()); + + let stats = loaded + .last_call_stats() + .expect("Stats should be populated after a call"); + assert!( + stats.wall_clock > Duration::ZERO, + "Wall clock should be > 0, got {:?}", + stats.wall_clock + ); + assert_eq!( + stats.terminated_by, None, + "terminated_by should be None for a normal call" + ); +} + +#[test] +fn stats_update_on_each_call() { + let mut loaded = create_cpu_burning_sandbox(); + + // First call — 50ms burn + let _ = loaded.handle_event("handler", r#"{"runtime": 50}"#.to_string(), None); + let stats1 = loaded.last_call_stats().unwrap().clone(); + + // Second call — 100ms burn (should be slower) + let _ = loaded.handle_event("handler", r#"{"runtime": 100}"#.to_string(), None); + let stats2 = loaded.last_call_stats().unwrap().clone(); + + // Stats should have been replaced, not accumulated + // The second call should have a longer wall clock + assert!( + stats2.wall_clock >= Duration::from_millis(80), + "Second call wall clock ({:?}) should be >= 80ms", + stats2.wall_clock + ); + assert!( + stats2.wall_clock > stats1.wall_clock, + "Second call ({:?}) should take longer than first ({:?})", + stats2.wall_clock, + stats1.wall_clock + ); +} + +#[test] +fn stats_available_even_when_handler_errors() { + let mut loaded = create_fast_sandbox(); + + // Call a non-existent handler + let result = loaded.handle_event("nonexistent", r#"{}"#.to_string(), None); + assert!(result.is_err(), "Should fail for non-existent handler"); + + // Stats should still be available from the last successful setup + // Note: if the error happens before inner.call(), stats won't be set. + // But if inner.call() fails (runtime error), stats ARE set. + // The JSON validation passes, the call to the VM happens but fails. + // Stats are populated because the timing wraps inner.call(). + let stats = loaded.last_call_stats(); + // For a non-existent handler, inner.call() does fail, and we DO capture timing + assert!( + stats.is_some(), + "Stats should be available even after a failed call" + ); +} + +// ── CPU time tests ─────────────────────────────────────────────────── + +#[test] +#[cfg(feature = "monitor-cpu-time")] +fn handle_event_populates_cpu_time_when_feature_enabled() { + let mut loaded = create_cpu_burning_sandbox(); + let event = r#"{"runtime": 50}"#; + + let result = loaded.handle_event("handler", event.to_string(), None); + assert!(result.is_ok()); + + let stats = loaded.last_call_stats().unwrap(); + assert!( + stats.cpu_time.is_some(), + "cpu_time should be Some when monitor-cpu-time feature is enabled" + ); + let cpu_time = stats.cpu_time.unwrap(); + assert!( + cpu_time > Duration::ZERO, + "cpu_time should be > 0 for a CPU-burning handler, got {:?}", + cpu_time + ); +} + +#[test] +#[cfg(not(feature = "monitor-cpu-time"))] +fn handle_event_cpu_time_is_none_without_feature() { + let mut loaded = create_fast_sandbox(); + let event = r#"{"test": true}"#; + + let _ = loaded.handle_event("handler", event.to_string(), None); + + let stats = loaded.last_call_stats().unwrap(); + assert!( + stats.cpu_time.is_none(), + "cpu_time should be None without monitor-cpu-time feature" + ); +} + +// ── Monitor termination tests ──────────────────────────────────────── + +#[test] +#[cfg(feature = "monitor-wall-clock")] +fn wall_clock_termination_sets_terminated_by() { + let mut loaded = create_cpu_burning_sandbox(); + let monitor = WallClockMonitor::new(Duration::from_millis(50)).unwrap(); + + // Handler burns for 5 seconds — well past the 50ms timeout + let event = r#"{"runtime": 5000}"#; + let result = loaded.handle_event_with_monitor("handler", event.to_string(), &monitor, None); + + assert!(result.is_err(), "Should have been terminated by monitor"); + + let stats = loaded + .last_call_stats() + .expect("Stats should be available after monitor termination"); + assert_eq!( + stats.terminated_by, + Some("wall-clock"), + "terminated_by should be 'wall-clock'" + ); + assert!( + stats.wall_clock > Duration::ZERO, + "Wall clock should still be measured" + ); +} + +#[test] +#[cfg(feature = "monitor-cpu-time")] +fn cpu_time_termination_sets_terminated_by() { + let mut loaded = create_cpu_burning_sandbox(); + let monitor = CpuTimeMonitor::new(Duration::from_millis(50)).unwrap(); + + // Handler burns CPU for 5 seconds — well past the 50ms CPU timeout + let event = r#"{"runtime": 5000}"#; + let result = loaded.handle_event_with_monitor("handler", event.to_string(), &monitor, None); + + assert!( + result.is_err(), + "Should have been terminated by CPU monitor" + ); + + let stats = loaded + .last_call_stats() + .expect("Stats should be available after CPU monitor termination"); + assert_eq!( + stats.terminated_by, + Some("cpu-time"), + "terminated_by should be 'cpu-time'" + ); +} + +#[test] +#[cfg(feature = "monitor-wall-clock")] +fn monitor_completion_normal_has_no_terminated_by() { + let mut loaded = create_fast_sandbox(); + let monitor = WallClockMonitor::new(Duration::from_secs(5)).unwrap(); + + // Handler is fast, timeout is generous — should complete normally + let event = r#"{"test": true}"#; + let result = loaded.handle_event_with_monitor("handler", event.to_string(), &monitor, None); + + assert!(result.is_ok(), "Should complete normally"); + + let stats = loaded.last_call_stats().unwrap(); + assert_eq!( + stats.terminated_by, None, + "terminated_by should be None when monitor didn't fire" + ); +} + +#[test] +#[cfg(all(feature = "monitor-wall-clock", feature = "monitor-cpu-time"))] +fn tuple_monitor_reports_correct_winner() { + let mut loaded = create_cpu_burning_sandbox(); + + // CPU limit is very tight (30ms), wall clock is generous (5s). + // CPU monitor should win the race. + let wall = WallClockMonitor::new(Duration::from_secs(5)).unwrap(); + let cpu = CpuTimeMonitor::new(Duration::from_millis(30)).unwrap(); + let monitor = (wall, cpu); + + let event = r#"{"runtime": 5000}"#; + let result = loaded.handle_event_with_monitor("handler", event.to_string(), &monitor, None); + + assert!(result.is_err(), "Should have been terminated"); + + let stats = loaded.last_call_stats().unwrap(); + assert_eq!( + stats.terminated_by, + Some("cpu-time"), + "CPU monitor should win with tight 30ms limit vs 5s wall" + ); +} + +#[test] +#[cfg(all(feature = "monitor-wall-clock", feature = "monitor-cpu-time"))] +fn tuple_monitor_wall_clock_wins_when_tighter() { + let mut loaded = create_cpu_burning_sandbox(); + + // Wall clock is tight (50ms), CPU limit is generous (5s). + // Wall clock monitor should win the race. + let wall = WallClockMonitor::new(Duration::from_millis(50)).unwrap(); + let cpu = CpuTimeMonitor::new(Duration::from_secs(5)).unwrap(); + let monitor = (wall, cpu); + + let event = r#"{"runtime": 5000}"#; + let result = loaded.handle_event_with_monitor("handler", event.to_string(), &monitor, None); + + assert!(result.is_err(), "Should have been terminated"); + + let stats = loaded.last_call_stats().unwrap(); + assert_eq!( + stats.terminated_by, + Some("wall-clock"), + "Wall-clock monitor should win with tight 50ms limit vs 5s CPU" + ); +} diff --git a/src/js-host-api/Cargo.toml b/src/js-host-api/Cargo.toml index 9232a04..16ed8d0 100644 --- a/src/js-host-api/Cargo.toml +++ b/src/js-host-api/Cargo.toml @@ -12,7 +12,7 @@ publish = false crate-type = ["cdylib"] [dependencies] -hyperlight-js = { workspace = true, features = ["monitor-wall-clock", "monitor-cpu-time"] } +hyperlight-js = { workspace = true, features = ["monitor-wall-clock", "monitor-cpu-time", "guest-call-stats"] } napi = { version = "3.8", features = ["tokio_rt", "serde-json"] } napi-derive = "3.5" serde_json = "1" diff --git a/src/js-host-api/README.md b/src/js-host-api/README.md index d3c2079..361feb8 100644 --- a/src/js-host-api/README.md +++ b/src/js-host-api/README.md @@ -120,6 +120,7 @@ A sandbox with handlers loaded, ready to process events. **Properties:** - `interruptHandle` → `InterruptHandle` — Gets a handle to interrupt/kill handler execution (getter, not a method) - `poisoned` → `boolean` — Whether the sandbox is in a poisoned (inconsistent) state +- `lastCallStats` → `CallStats | null` — Execution statistics from the most recent `callHandler()` call (see [CallStats](#callstats-) below) ```javascript // Call a handler with event data — pass objects directly, get objects back @@ -190,6 +191,35 @@ the handler runs without any monitors. When both timeouts are set, monitors race with **OR semantics** — whichever fires first terminates execution. This is the **recommended** pattern for comprehensive protection. +### CallStats šŸ“Š + +Execution statistics from the most recent `callHandler()` call. Retrieved via the `lastCallStats` getter property. + +| Property | Type | Description | +|----------|------|-------------| +| `wallClockMs` | `number` | Wall-clock elapsed time in milliseconds | +| `cpuTimeMs` | `number \| null` | CPU time in milliseconds (`null` if `monitor-cpu-time` feature not enabled) | +| `terminatedBy` | `string \| null` | Name of the monitor that fired (e.g. `"wall-clock"`, `"cpu-time"`), or `null` for normal completion | + +```javascript +await loaded.callHandler('handler', { data: 'value' }); + +const stats = loaded.lastCallStats; +if (stats) { + console.log(`Wall clock: ${stats.wallClockMs.toFixed(1)}ms`); + if (stats.cpuTimeMs != null) { + console.log(`CPU time: ${stats.cpuTimeMs.toFixed(1)}ms`); + } + if (stats.terminatedBy) { + console.log(`Terminated by: ${stats.terminatedBy}`); + } +} +``` + +- Stats are `null` before any call +- Stats are replaced (not accumulated) on each call +- Stats are available even when the call throws (e.g. monitor timeout) + ### InterruptHandle ā±ļø Handle for interrupting/killing handler execution. Because hypervisor calls run on background threads and return Promises, you can call `kill()` from a timer, a signal handler, or any async callback while a handler is running. diff --git a/src/js-host-api/examples/README.md b/src/js-host-api/examples/README.md index b97c6c2..2b54158 100644 --- a/src/js-host-api/examples/README.md +++ b/src/js-host-api/examples/README.md @@ -198,6 +198,7 @@ node cpu-timeout.js - Uses `callHandler()` with **both** CPU + wall-clock timeout options - CPU monitor fires first for compute-bound work - Wall-clock acts as backstop for resource exhaustion attacks +- Prints `lastCallStats` after each call (wall clock, CPU time, termination reason) Expected output: ``` @@ -205,11 +206,13 @@ Expected output: šŸ“Š Test 1: Fast Handler (completes before either timeout) āœ… SUCCESS: Handler completed! + šŸ“Š Stats: wall=105.2ms, cpu=104.8ms šŸ“Š Test 2: Slow Handler (CPU monitor fires first) šŸ’€ Handler killed after ~500ms ⚔ CPU time limit: 500ms (fired first for compute-bound work) ā±ļø Wall-clock limit: 5000ms (backstop, not reached) + šŸ“Š Stats: wall=502.1ms, cpu=501.3ms, terminated_by=cpu-time āœ… SUCCESS: Timeout enforced correctly! ``` @@ -263,6 +266,14 @@ async function main() { // Manual kill interruptHandle.kill(); + + // Check execution stats after any callHandler() call + const stats = loadedSandbox.lastCallStats; + if (stats) { + console.log(`Wall clock: ${stats.wallClockMs}ms`); + console.log(`CPU time: ${stats.cpuTimeMs}ms`); // null if not available + console.log(`Terminated by: ${stats.terminatedBy}`); // null for normal completion + } } main(); ``` diff --git a/src/js-host-api/examples/cpu-timeout.js b/src/js-host-api/examples/cpu-timeout.js index b2029d2..ef3a440 100644 --- a/src/js-host-api/examples/cpu-timeout.js +++ b/src/js-host-api/examples/cpu-timeout.js @@ -47,6 +47,7 @@ async function main() { ); console.log(` āœ… SUCCESS: Handler completed!`); console.log(` šŸ“Š Counter: ${result.counter.toLocaleString()}`); + printCallStats(loaded); console.log(` šŸ”’ Poisoned: ${loaded.poisoned}\n`); } catch (err) { console.log(` āŒ Unexpected timeout: ${err.message}\n`); @@ -99,6 +100,7 @@ async function main() { console.log(` šŸ’€ Handler killed after ~${elapsed}ms`); console.log(` ⚔ CPU time limit: 500ms (fired first for compute-bound work)`); console.log(` ā±ļø Wall-clock limit: 5000ms (backstop, not reached)`); + printCallStats(loaded); console.log(` šŸ”’ Poisoned: ${loaded.poisoned} (sandbox is in inconsistent state)`); console.log(` āœ… SUCCESS: Timeout enforced correctly!\n`); @@ -131,3 +133,15 @@ main().catch((error) => { console.error('\nStack trace:', error.stack); process.exit(1); }); + +/// Print last call stats from the loaded sandbox. +function printCallStats(loaded) { + const stats = loaded.lastCallStats; + if (stats) { + console.log( + ` šŸ“Š Stats: wall=${stats.wallClockMs.toFixed(1)}ms` + + (stats.cpuTimeMs != null ? `, cpu=${stats.cpuTimeMs.toFixed(1)}ms` : '') + + (stats.terminatedBy ? `, terminated_by=${stats.terminatedBy}` : '') + ); + } +} diff --git a/src/js-host-api/lib.d.ts b/src/js-host-api/lib.d.ts new file mode 100644 index 0000000..3c8dc91 --- /dev/null +++ b/src/js-host-api/lib.d.ts @@ -0,0 +1,2 @@ +export = native; +import native = require("./index.js"); diff --git a/src/js-host-api/src/lib.rs b/src/js-host-api/src/lib.rs index 8c4caa9..fc9d12c 100644 --- a/src/js-host-api/src/lib.rs +++ b/src/js-host-api/src/lib.rs @@ -18,8 +18,8 @@ use std::sync::{Arc, Mutex}; use std::time::Duration; use hyperlight_js::{ - CpuTimeMonitor, HyperlightError, InterruptHandle, JSSandbox, LoadedJSSandbox, ProtoJSSandbox, - SandboxBuilder, Script, Snapshot, WallClockMonitor, + CpuTimeMonitor, ExecutionStats, HyperlightError, InterruptHandle, JSSandbox, LoadedJSSandbox, + ProtoJSSandbox, SandboxBuilder, Script, Snapshot, WallClockMonitor, }; use napi::bindgen_prelude::{JsValuesTupleIntoVec, Promise, ToNapiValue}; use napi::sys::{napi_env, napi_value}; @@ -788,6 +788,7 @@ impl JSSandboxWrapper { inner: Arc::new(Mutex::new(Some(loaded_sandbox))), interrupt, poisoned_flag, + last_call_stats: Arc::new(Mutex::new(None)), }) } @@ -839,6 +840,15 @@ pub struct LoadedJSSandboxWrapper { /// (where we already hold the lock), read via `Ordering::Acquire` in the /// getter. See the module-level architecture comment for the full rationale. poisoned_flag: Arc, + + /// Execution statistics from the most recent `callHandler()` call. + /// + /// Updated inside the `spawn_blocking` closure while we still hold the + /// inner lock. Read by the `lastCallStats` getter after `callHandler()` + /// resolves. Unlike `poisoned_flag`, this uses a `Mutex` because it + /// stores a struct — but contention is negligible since it's only + /// accessed after the call completes. + last_call_stats: Arc>>, } #[napi] @@ -907,6 +917,7 @@ impl LoadedJSSandboxWrapper { let inner = self.inner.clone(); let poisoned_flag = self.poisoned_flag.clone(); + let last_call_stats_store = self.last_call_stats.clone(); let gc = options.gc; let wall_clock_timeout_ms = options.wall_clock_timeout_ms; let cpu_timeout_ms = options.cpu_timeout_ms; @@ -965,6 +976,12 @@ impl LoadedJSSandboxWrapper { // Update poisoned flag while we hold the lock — keeps the getter // lock-free so it never blocks the Node.js event loop. poisoned_flag.store(sandbox.poisoned(), Ordering::Release); + + // Copy execution stats while we still hold the lock. + if let Ok(mut stats_guard) = last_call_stats_store.lock() { + *stats_guard = sandbox.last_call_stats().map(CallStats::from); + } + result }) .await @@ -1045,6 +1062,35 @@ impl LoadedJSSandboxWrapper { self.poisoned_flag.load(Ordering::Acquire) } + /// Execution statistics from the most recent `callHandler()` call. + /// + /// Returns `null` before any call has been made. After each call, + /// this returns timing and termination information — stats are + /// **not** cumulative. + /// + /// Stats are captured even when `callHandler()` throws (e.g. the + /// sandbox was poisoned by a monitor timeout). + /// + /// ```js + /// await loaded.callHandler('compute', data, { + /// wallClockTimeoutMs: 5000, + /// cpuTimeoutMs: 500, + /// }); + /// const stats = loaded.lastCallStats; + /// if (stats) { + /// console.log(`Wall: ${stats.wallClockMs}ms`); + /// if (stats.cpuTimeMs != null) console.log(`CPU: ${stats.cpuTimeMs}ms`); + /// if (stats.terminatedBy) console.log(`Killed by: ${stats.terminatedBy}`); + /// } + /// ``` + #[napi(getter)] + pub fn last_call_stats(&self) -> Option { + self.last_call_stats + .lock() + .ok() + .and_then(|guard| guard.clone()) + } + /// Capture the current sandbox state as a snapshot. /// /// Take a snapshot **before** risky operations so you can recover @@ -1176,3 +1222,44 @@ impl InterruptHandleWrapper { self.inner.kill(); } } + +// ── CallStats ──────────────────────────────────────────────────────── + +/// Execution statistics from a guest function call. +/// +/// Retrieved via `loaded.lastCallStats` after calling `callHandler()`. +/// Stats are captured even when the call throws (e.g. monitor timeout). +/// +/// ```js +/// try { +/// await loaded.callHandler('compute', data, { cpuTimeoutMs: 500 }); +/// } catch (e) { /* monitor fired */ } +/// const stats = loaded.lastCallStats; +/// console.log(stats); +/// // { wallClockMs: 502.3, cpuTimeMs: 499.8, terminatedBy: 'cpu-time' } +/// ``` +#[napi(object)] +#[derive(Debug, Clone)] +pub struct CallStats { + /// Wall-clock (elapsed) time in milliseconds. Always present. + pub wall_clock_ms: f64, + + /// CPU time in milliseconds. Only present when the `monitor-cpu-time` + /// feature is enabled and the CPU clock handle was successfully obtained. + pub cpu_time_ms: Option, + + /// Name of the monitor that terminated execution, if any. + /// e.g. `"wall-clock"`, `"cpu-time"`, or a custom monitor name. + /// `null` when the call completed (or failed) without monitor intervention. + pub terminated_by: Option, +} + +impl From<&ExecutionStats> for CallStats { + fn from(stats: &ExecutionStats) -> Self { + Self { + wall_clock_ms: stats.wall_clock.as_secs_f64() * 1000.0, + cpu_time_ms: stats.cpu_time.map(|d| d.as_secs_f64() * 1000.0), + terminated_by: stats.terminated_by.map(|s| s.to_string()), + } + } +}