Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 4 additions & 3 deletions Justfile
Original file line number Diff line number Diff line change
Expand Up @@ -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]
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand Down
51 changes: 50 additions & 1 deletion docs/execution-monitors.md
Original file line number Diff line number Diff line change
Expand Up @@ -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<Duration>` | 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

Expand Down Expand Up @@ -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`
7 changes: 7 additions & 0 deletions src/hyperlight-js/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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"]

Expand Down Expand Up @@ -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
244 changes: 244 additions & 0 deletions src/hyperlight-js/examples/execution_stats/main.rs
Original file line number Diff line number Diff line change
@@ -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)"),
}
}
3 changes: 3 additions & 0 deletions src/hyperlight-js/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
Loading