diff --git a/CHANGELOG.md b/CHANGELOG.md index 6fd145a77..eb06394a4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/). ### Fixed * Fix symbol resolution in guest core dumps for sandboxes created from snapshots by @ludfjig in https://github.com/hyperlight-dev/hyperlight/pull/1618 * Reject malformed OCI snapshot metadata and non-regular artifact files during load. +* `MultiUseSandbox::from_snapshot` now honours the guest log level set via `SandboxConfiguration::set_max_guest_log_level` instead of ignoring it and falling back to `RUST_LOG` by @sethryanrollins in https://github.com/hyperlight-dev/hyperlight/pull/1699 ## [v0.16.0] - 2026-06-26 diff --git a/Justfile b/Justfile index f69d88c41..5bb7aea8b 100644 --- a/Justfile +++ b/Justfile @@ -241,6 +241,7 @@ test-loom: test-isolated target=default-target features="" : {{ cargo-cmd }} test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} -p hyperlight-host --lib -- sandbox::uninitialized::tests::test_log_trace --exact --ignored {{ cargo-cmd }} test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} -p hyperlight-host --lib -- sandbox::outb::tests::test_log_outb_log --exact --ignored + {{ cargo-cmd }} test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} -p hyperlight-host --lib -- sandbox::initialized_multi_use::tests::from_snapshot::max_guest_log_level_is_honored_from_snapshot --exact --ignored {{ cargo-cmd }} test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} -p hyperlight-host --test integration_test -- log_message --exact --ignored @# CPU vendor check, gated to known CI runner hardware {{ cargo-cmd }} test {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F " + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} -p hyperlight-host --lib -- sandbox::snapshot::file::config::tests::cpu_vendor_current_is_recognized --exact --ignored @@ -525,6 +526,7 @@ coverage-run hypervisor="kvm": ensure-cargo-llvm-cov # isolated tests (require running separately due to global state) cargo +nightly test -p hyperlight-host --lib -- sandbox::uninitialized::tests::test_log_trace --exact --ignored cargo +nightly test -p hyperlight-host --lib -- sandbox::outb::tests::test_log_outb_log --exact --ignored + cargo +nightly test -p hyperlight-host --lib -- sandbox::initialized_multi_use::tests::from_snapshot::max_guest_log_level_is_honored_from_snapshot --exact --ignored cargo +nightly test -p hyperlight-host --test integration_test -- log_message --exact --ignored cargo +nightly test -p hyperlight-host --no-default-features -F function_call_metrics,{{ if hypervisor == "mshv3" { "mshv3" } else { "kvm" } }} --lib -- metrics::tests::test_metrics_are_emitted --exact diff --git a/src/hyperlight_host/src/sandbox/config.rs b/src/hyperlight_host/src/sandbox/config.rs index e7216a8a7..cec262675 100644 --- a/src/hyperlight_host/src/sandbox/config.rs +++ b/src/hyperlight_host/src/sandbox/config.rs @@ -17,9 +17,11 @@ limitations under the License. use std::cmp::max; use std::time::Duration; +use hyperlight_common::log_level::GuestLogFilter; #[cfg(target_os = "linux")] use libc::c_int; use tracing::{Span, instrument}; +use tracing_core::LevelFilter; /// Used for passing debug configuration to a sandbox #[cfg(gdb)] @@ -86,6 +88,13 @@ pub struct SandboxConfiguration { interrupt_vcpu_sigrtmin_offset: u8, /// How much writable memory to offer the guest scratch_size: usize, + /// The maximum log level enabled for guest code execution. + /// + /// If unset, the level is determined from the `RUST_LOG` environment + /// variable, defaulting to [`LevelFilter::ERROR`] when no level is found. + /// Stored as the guest ABI's numeric log-filter value, with `u64::MAX` + /// representing an unset value, to keep this `#[repr(C)]` struct FFI-safe. + max_guest_log_level: u64, /// Declared guest MSRs, stored inline to keep this type `Copy`. #[cfg(target_arch = "x86_64")] guest_msrs: [u32; Self::MAX_GUEST_MSRS], @@ -116,6 +125,7 @@ impl SandboxConfiguration { /// own range, so 16 is the portable limit across backends. #[cfg(target_arch = "x86_64")] pub const MAX_GUEST_MSRS: usize = 16; + const MAX_GUEST_LOG_LEVEL_UNSET: u64 = u64::MAX; #[allow(clippy::too_many_arguments)] /// Create a new configuration for a sandbox with the given sizes. @@ -135,6 +145,7 @@ impl SandboxConfiguration { output_data_size: max(output_data_size, Self::MIN_OUTPUT_SIZE), heap_size_override: heap_size_override.unwrap_or(0), scratch_size, + max_guest_log_level: Self::MAX_GUEST_LOG_LEVEL_UNSET, interrupt_retry_delay, interrupt_vcpu_sigrtmin_offset, #[cfg(gdb)] @@ -299,6 +310,27 @@ impl SandboxConfiguration { self.scratch_size = scratch_size; } + /// Sets the maximum log level for guest code execution. + /// + /// If not set, the level is determined from the `RUST_LOG` environment + /// variable, defaulting to [`LevelFilter::ERROR`] when no level is found. + #[instrument(skip_all, parent = Span::current(), level= "Trace")] + pub fn set_max_guest_log_level(&mut self, log_level: LevelFilter) { + self.max_guest_log_level = GuestLogFilter::from(log_level).into(); + } + + pub(crate) fn get_max_guest_log_level(&self) -> Option { + if self.max_guest_log_level == Self::MAX_GUEST_LOG_LEVEL_UNSET { + None + } else { + Some( + GuestLogFilter::try_from(self.max_guest_log_level) + .expect("SandboxConfiguration stores a valid guest log filter") + .into(), + ) + } + } + #[cfg(crashdump)] #[instrument(skip_all, parent = Span::current(), level= "Trace")] pub(crate) fn get_guest_core_dump(&self) -> bool { @@ -345,7 +377,29 @@ impl Default for SandboxConfiguration { #[cfg(test)] mod tests { - use super::{GuestMsrError, SandboxConfiguration}; + use tracing_core::LevelFilter; + + #[cfg(target_arch = "x86_64")] + use super::GuestMsrError; + use super::SandboxConfiguration; + + #[test] + fn max_guest_log_level_defaults_to_none_and_round_trips_all_levels() { + let mut cfg = SandboxConfiguration::default(); + assert_eq!(cfg.get_max_guest_log_level(), None); + + for level in [ + LevelFilter::OFF, + LevelFilter::ERROR, + LevelFilter::WARN, + LevelFilter::INFO, + LevelFilter::DEBUG, + LevelFilter::TRACE, + ] { + cfg.set_max_guest_log_level(level); + assert_eq!(cfg.get_max_guest_log_level(), Some(level)); + } + } #[test] #[cfg(target_arch = "x86_64")] diff --git a/src/hyperlight_host/src/sandbox/initialized_multi_use.rs b/src/hyperlight_host/src/sandbox/initialized_multi_use.rs index f43e57d39..6e3e2625d 100644 --- a/src/hyperlight_host/src/sandbox/initialized_multi_use.rs +++ b/src/hyperlight_host/src/sandbox/initialized_multi_use.rs @@ -164,6 +164,14 @@ impl MultiUseSandbox { /// [`SandboxConfiguration::guest_msrs`](crate::sandbox::SandboxConfiguration::guest_msrs)), /// or the load fails with an MSR mismatch. /// + /// [`SandboxConfiguration::set_max_guest_log_level`](crate::sandbox::SandboxConfiguration::set_max_guest_log_level) + /// sets the maximum log level passed to the guest. This only takes effect + /// for snapshots that still need their guest entrypoint run + /// (`NextAction::Initialise`). For a snapshot taken from an + /// already-initialized guest, the level was baked into the captured memory + /// when the guest first ran, so a configured value has no effect and a + /// warning is logged. + /// /// # Examples /// /// From a snapshot taken on another sandbox: @@ -236,6 +244,7 @@ impl MultiUseSandbox { config.set_output_data_size(snapshot.layout().output_data_size()); config.set_heap_size(snapshot.layout().heap_size() as u64); config.set_scratch_size(snapshot.layout().get_scratch_size()); + let max_guest_log_level = config.get_max_guest_log_level(); let load_info = snapshot.load_info(); let mgr = crate::mem::mgr::SandboxMemoryManager::from_snapshot(&snapshot)?; @@ -282,13 +291,28 @@ impl MultiUseSandbox { #[cfg(gdb)] let dbg_mem_access_hdl = Arc::new(Mutex::new(hshm.clone())); + // `max_guest_log_level` is consumed by `initialise` when it runs the + // guest entrypoint, which only happens for a preinitialised + // (`NextAction::Initialise`) snapshot. A `Call` snapshot already ran + // its entrypoint and baked the log level into the captured memory, so + // warn instead of silently ignoring the configured value. + if max_guest_log_level.is_some() + && matches!(snapshot.next_action(), super::snapshot::NextAction::Call(_)) + { + tracing::warn!( + "max_guest_log_level was configured for from_snapshot, but the snapshot is \ + an already-initialized (Call) snapshot; the log level is baked into the \ + snapshot's memory and the configured value has no effect" + ); + } + // noop for NextAction::Call vm.initialise( peb_addr, seed, &mut hshm, &host_funcs, - None, + max_guest_log_level, #[cfg(gdb)] dbg_mem_access_hdl, ) @@ -4082,6 +4106,81 @@ mod tests { assert_eq!(sbox.call::("GetStatic", ()).unwrap(), 0); } + /// `max_guest_log_level` configured through the + /// `SandboxConfiguration` passed to `from_snapshot` is honored for a + /// pre-init (`NextAction::Initialise`) snapshot: the guest runs its + /// entrypoint with the configured filter, so a higher level lets more + /// guest log messages through than a lower one. Before this was + /// plumbed, `from_snapshot` always passed `None` (falling back to + /// `RUST_LOG`), so both counts below would be equal. + /// + /// Ignored because it installs a process-global `log` logger; run + /// in isolation via the `test-isolated` Justfile recipe. + #[test] + #[ignore] + fn max_guest_log_level_is_honored_from_snapshot() { + use hyperlight_common::log_level::GuestLogFilter; + use hyperlight_testing::logger::{LOGGER, Logger}; + use tracing_core::LevelFilter; + + Logger::initialize_test_logger(); + LOGGER.set_max_level(log::LevelFilter::Trace); + + // Build a fresh pre-init sandbox with the given guest log level, + // emit one guest log message at each level, and count how many + // reached the host (guest logs carry target "hyperlight_guest"). + let count_guest_logs = |max_level: LevelFilter| -> usize { + let snap = Snapshot::from_env( + GuestBinary::FilePath(simple_guest_as_string().unwrap()), + SandboxConfiguration::default(), + ) + .unwrap(); + let mut config = SandboxConfiguration::default(); + config.set_max_guest_log_level(max_level); + let mut sbox = MultiUseSandbox::from_snapshot( + Arc::new(snap), + HostFunctions::default(), + Some(config), + ) + .unwrap(); + + // Drop any log records emitted while the guest initialised. + LOGGER.clear_log_calls(); + + for level in [ + LevelFilter::TRACE, + LevelFilter::DEBUG, + LevelFilter::INFO, + LevelFilter::WARN, + LevelFilter::ERROR, + ] { + let encoded: u64 = GuestLogFilter::from(level).into(); + sbox.call::<()>("LogMessage", ("hello".to_string(), encoded as i32)) + .unwrap(); + } + + let count = (0..LOGGER.num_log_calls()) + .filter_map(|i| LOGGER.get_log_call(i)) + .filter(|c| c.target == "hyperlight_guest") + .count(); + LOGGER.clear_log_calls(); + count + }; + + let trace_count = count_guest_logs(LevelFilter::TRACE); + let error_count = count_guest_logs(LevelFilter::ERROR); + + assert!( + error_count >= 1, + "an ERROR-level guest log must reach the host, got {error_count}" + ); + assert!( + trace_count > error_count, + "TRACE must let more guest logs through than ERROR (trace={trace_count}, \ + error={error_count}); equal counts mean max_guest_log_level was ignored" + ); + } + /// Two sandboxes built from clones of one `Arc` can /// each `restore` back to it, and stay memory-isolated from /// each other in between. diff --git a/src/hyperlight_host/src/sandbox/uninitialized.rs b/src/hyperlight_host/src/sandbox/uninitialized.rs index 015db0acd..517a07ac7 100644 --- a/src/hyperlight_host/src/sandbox/uninitialized.rs +++ b/src/hyperlight_host/src/sandbox/uninitialized.rs @@ -70,7 +70,6 @@ pub struct UninitializedSandbox { pub(crate) host_funcs: Arc>, /// The memory manager for the sandbox. pub(crate) mgr: SandboxMemoryManager, - pub(crate) max_guest_log_level: Option, pub(crate) config: SandboxConfiguration, #[cfg(any(crashdump, gdb))] pub(crate) rt_cfg: SandboxRuntimeConfig, @@ -222,7 +221,6 @@ impl UninitializedSandbox { let sandbox = Self { host_funcs, mgr: mem_mgr_wrapper, - max_guest_log_level: None, config: sandbox_cfg, #[cfg(any(crashdump, gdb))] rt_cfg, @@ -355,9 +353,9 @@ impl UninitializedSandbox { /// Sets the maximum log level for guest code execution. /// /// If not set, the log level is determined by the `RUST_LOG` environment variable, - /// defaulting to [`LevelFilter::Error`] if unset. + /// defaulting to [`LevelFilter::ERROR`] if unset. pub fn set_max_guest_log_level(&mut self, log_level: LevelFilter) { - self.max_guest_log_level = Some(log_level); + self.config.set_max_guest_log_level(log_level); } /// Registers a host function that the guest can call. diff --git a/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs b/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs index 09e2761e3..d76415a81 100644 --- a/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs +++ b/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs @@ -37,6 +37,7 @@ use crate::{MultiUseSandbox, Result, UninitializedSandbox}; #[instrument(err(Debug), skip_all, parent = Span::current(), level = "Trace")] pub(super) fn evolve_impl_multi_use(u_sbox: UninitializedSandbox) -> Result { + let max_guest_log_level = u_sbox.config.get_max_guest_log_level(); let (mut hshm, gshm) = u_sbox.mgr.build()?; // Get the host page size. Narrowed to u32 because the guest ABI @@ -100,7 +101,7 @@ pub(super) fn evolve_impl_multi_use(u_sbox: UninitializedSandbox) -> Result