From 8801c1fa0a37e36459f57caa2f57c657fda09463 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 22:23:42 +0000 Subject: [PATCH 1/7] Initial plan From cb4f261219df9233ef82f1048e3551398da7f091 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 22:37:07 +0000 Subject: [PATCH 2/7] Replace log crate with tracing crate in dependencies and code Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- src/hyperlight_common/Cargo.toml | 3 +-- src/hyperlight_component_util/Cargo.toml | 2 +- src/hyperlight_component_util/src/emit.rs | 10 +++++----- src/hyperlight_component_util/src/guest.rs | 2 +- src/hyperlight_component_util/src/hl.rs | 8 ++++---- src/hyperlight_component_util/src/host.rs | 4 ++-- src/hyperlight_component_util/src/rtypes.rs | 14 +++++++------- src/hyperlight_component_util/src/util.rs | 2 +- src/hyperlight_guest_bin/Cargo.toml | 1 - src/hyperlight_guest_capi/Cargo.toml | 2 +- src/hyperlight_host/Cargo.toml | 1 - .../src/hypervisor/hyperlight_vm.rs | 2 +- src/hyperlight_host/src/hypervisor/mod.rs | 4 ++-- src/hyperlight_host/src/lib.rs | 2 +- src/hyperlight_host/src/sandbox/outb.rs | 11 ++++++----- src/hyperlight_host/src/sandbox/uninitialized.rs | 10 +++++----- src/hyperlight_host/tests/integration_test.rs | 2 +- src/hyperlight_testing/Cargo.toml | 1 - src/hyperlight_testing/src/logger.rs | 2 +- src/hyperlight_testing/src/simplelogger.rs | 2 +- src/tests/rust_guests/simpleguest/Cargo.toml | 1 - src/tests/rust_guests/simpleguest/src/main.rs | 4 ++-- 22 files changed, 43 insertions(+), 47 deletions(-) diff --git a/src/hyperlight_common/Cargo.toml b/src/hyperlight_common/Cargo.toml index a10a991d6..e07ba4a2e 100644 --- a/src/hyperlight_common/Cargo.toml +++ b/src/hyperlight_common/Cargo.toml @@ -17,7 +17,6 @@ workspace = true [dependencies] flatbuffers = { version = "25.9.23", default-features = false } anyhow = { version = "1.0.100", default-features = false } -log = "0.4.29" tracing = { version = "0.1.43", optional = true } arbitrary = {version = "1.4.2", optional = true, features = ["derive"]} spin = "0.10.0" @@ -29,7 +28,7 @@ tracing = ["dep:tracing"] fuzzing = ["dep:arbitrary"] trace_guest = [] mem_profile = [] -std = ["thiserror/std", "log/std", "tracing/std"] +std = ["thiserror/std", "tracing/std"] [lib] bench = false # see https://bheisler.github.io/criterion.rs/book/faq.html#cargo-bench-gives-unrecognized-option-errors-for-valid-command-line-options diff --git a/src/hyperlight_component_util/Cargo.toml b/src/hyperlight_component_util/Cargo.toml index 1292ca527..2206a73d3 100644 --- a/src/hyperlight_component_util/Cargo.toml +++ b/src/hyperlight_component_util/Cargo.toml @@ -21,4 +21,4 @@ proc-macro2 = { version = "1.0.103" } syn = { version = "2.0.111" } itertools = { version = "0.14.0" } prettyplease = { version = "0.2.37" } -log = { version = "0.4" } \ No newline at end of file +tracing = { version = "0.1.43" } \ No newline at end of file diff --git a/src/hyperlight_component_util/src/emit.rs b/src/hyperlight_component_util/src/emit.rs index 1b3545813..d6c67cdf7 100644 --- a/src/hyperlight_component_util/src/emit.rs +++ b/src/hyperlight_component_util/src/emit.rs @@ -416,7 +416,7 @@ impl<'a, 'b> State<'a, 'b> { let Some(ref mut cnvs) = self.cur_needs_vars else { return; }; - log::debug!("debug varref: recording {:?} for var {:?}", cnvs.iter(), un); + tracing::debug!("debug varref: recording {:?} for var {:?}", cnvs.iter(), un); self.vars_needs_vars[un].extend(cnvs.iter()); } /// Get a list of all the variables needed by a var, given its absolute @@ -426,7 +426,7 @@ impl<'a, 'b> State<'a, 'b> { if self.vars_needs_vars.len() < un + 1 { return BTreeSet::new(); }; - log::debug!( + tracing::debug!( "debug varref: looking up {:?} for var {:?}", self.vars_needs_vars[un].iter(), un @@ -559,7 +559,7 @@ impl<'a, 'b> State<'a, 'b> { Defined::Handleable(Handleable::Var(tv)) => match tv { Tyvar::Bound(n) => { let bv = &self.bound_vars[self.var_offset + (*n as usize)]; - log::debug!("checking an origin {:?} {:?}", bv.origin, self.origin); + tracing::debug!("checking an origin {:?} {:?}", bv.origin, self.origin); if bv.origin.matches(self.origin.iter()) { Some((*n, bv.bound.clone())) } else { @@ -588,7 +588,7 @@ impl<'a, 'b> State<'a, 'b> { /// /// Precondition: all named traits/modules must exist pub fn resolve_trait_immut(&self, absolute: bool, path: &[Ident]) -> &Trait { - log::debug!("resolving trait {:?} {:?}", absolute, path); + tracing::debug!("resolving trait {:?} {:?}", absolute, path); let mut m = if absolute { &*self.root_mod } else { @@ -611,7 +611,7 @@ impl<'a, 'b> State<'a, 'b> { .enumerate() .for_each(|(i, vs)| { *vs = vs.iter().map(|v| v + n).collect(); - log::debug!("updated {:?} to {:?}", i, *vs); + tracing::debug!("updated {:?} to {:?}", i, *vs); }); for _ in 0..n { self.vars_needs_vars.push_front(BTreeSet::new()); diff --git a/src/hyperlight_component_util/src/guest.rs b/src/hyperlight_component_util/src/guest.rs index 09e909034..27469cbec 100644 --- a/src/hyperlight_component_util/src/guest.rs +++ b/src/hyperlight_component_util/src/guest.rs @@ -344,7 +344,7 @@ fn emit_component<'a, 'b, 'c>( /// - functions when given a type that implements the `Guest` trait pub fn emit_toplevel<'a, 'b, 'c>(s: &'c mut State<'a, 'b>, n: &str, ct: &'c Component<'b>) { s.is_impl = true; - log::debug!("\n\n=== starting guest emit ===\n"); + tracing::debug!("\n\n=== starting guest emit ===\n"); let wn = split_wit_name(n); let ns = wn.namespace_path(); diff --git a/src/hyperlight_component_util/src/hl.rs b/src/hyperlight_component_util/src/hl.rs index d58eb7aaf..5b7211cf3 100644 --- a/src/hyperlight_component_util/src/hl.rs +++ b/src/hyperlight_component_util/src/hl.rs @@ -298,7 +298,7 @@ pub fn emit_hl_unmarshal_value(s: &mut State, id: Ident, vt: &Value) -> TokenStr } Value::Own(ht) => { let vi = resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (1) {:?} {:?}", ht, vi); + tracing::debug!("resolved ht to r (1) {:?} {:?}", ht, vi); if s.is_guest { let rid = format_ident!("HostResource{}", vi); if s.is_wasmtime_guest { @@ -326,7 +326,7 @@ pub fn emit_hl_unmarshal_value(s: &mut State, id: Ident, vt: &Value) -> TokenStr } Value::Borrow(ht) => { let vi = resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (2) {:?} {:?}", ht, vi); + tracing::debug!("resolved ht to r (2) {:?} {:?}", ht, vi); if s.is_guest { let rid = format_ident!("HostResource{}", vi); if s.is_wasmtime_guest { @@ -624,7 +624,7 @@ pub fn emit_hl_marshal_value(s: &mut State, id: Ident, vt: &Value) -> TokenStrea } Value::Own(ht) => { let vi = resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (3) {:?} {:?}", ht, vi); + tracing::debug!("resolved ht to r (3) {:?} {:?}", ht, vi); if s.is_guest { let call = if s.is_wasmtime_guest { quote! { () } @@ -645,7 +645,7 @@ pub fn emit_hl_marshal_value(s: &mut State, id: Ident, vt: &Value) -> TokenStrea } Value::Borrow(ht) => { let vi = resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (6) {:?} {:?}", ht, vi); + tracing::debug!("resolved ht to r (6) {:?} {:?}", ht, vi); if s.is_guest { let call = if s.is_wasmtime_guest { quote! { () } diff --git a/src/hyperlight_component_util/src/host.rs b/src/hyperlight_component_util/src/host.rs index 0f6bca65b..79b682332 100644 --- a/src/hyperlight_component_util/src/host.rs +++ b/src/hyperlight_component_util/src/host.rs @@ -202,7 +202,7 @@ fn emit_import_extern_decl<'a, 'b, 'c>( ExternDesc::CoreModule(_) => panic!("core module (im/ex)ports are not supported"), ExternDesc::Func(ft) => { let hln = emit_fn_hl_name(s, ed.kebab_name); - log::debug!("providing host function {}", hln); + tracing::debug!("providing host function {}", hln); let (pds, pus) = ft .params .iter() @@ -382,7 +382,7 @@ fn emit_component<'a, 'b, 'c>(s: &'c mut State<'a, 'b>, wn: WitName, ct: &'c Com /// See [`emit_component`] pub fn emit_toplevel<'a, 'b, 'c>(s: &'c mut State<'a, 'b>, n: &str, ct: &'c Component<'b>) { s.is_impl = true; - log::debug!("\n\n=== starting host emit ===\n"); + tracing::debug!("\n\n=== starting host emit ===\n"); let wn = split_wit_name(n); emit_component(s, wn, ct) } diff --git a/src/hyperlight_component_util/src/rtypes.rs b/src/hyperlight_component_util/src/rtypes.rs index 18665db31..427344dae 100644 --- a/src/hyperlight_component_util/src/rtypes.rs +++ b/src/hyperlight_component_util/src/rtypes.rs @@ -164,7 +164,7 @@ fn try_find_local_var_id( return Some(emit_resource_ref(s, n, path)); } } - log::debug!("path is {:?}\n", path); + tracing::debug!("path is {:?}\n", path); let mut path = path.iter().rev(); let name = kebab_to_type(path.next().unwrap().name()); let owner = path.next(); @@ -216,7 +216,7 @@ pub fn emit_var_ref_value(s: &mut State, tv: &Tyvar) -> TokenStream { /// the bound variable being referenced /// - `is_value`: whether this is a value (e.g. constructor) or type context. pub fn emit_var_ref_noff(s: &mut State, n: u32, is_value: bool) -> TokenStream { - log::debug!("var_ref {:?} {:?}", &s.bound_vars[n as usize], s.origin); + tracing::debug!("var_ref {:?} {:?}", &s.bound_vars[n as usize], s.origin); // if the variable was defined locally, try to reference it directly let id = try_find_local_var_id(s, n); let id = match id { @@ -317,7 +317,7 @@ pub fn emit_value(s: &mut State, vt: &Value) -> TokenStream { wrap(emit_var_ref(s, tv)) } else { let n = crate::hl::resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (4) {:?} {:?}", ht, n); + tracing::debug!("resolved ht to r (4) {:?} {:?}", ht, n); let id = format_ident!("HostResource{}", n); wrap(quote! { #id }) } @@ -339,7 +339,7 @@ pub fn emit_value(s: &mut State, vt: &Value) -> TokenStream { wrap(emit_var_ref(s, tv)) } else { let n = crate::hl::resolve_handleable_to_resource(s, ht); - log::debug!("resolved ht to r (5) {:?} {:?}", ht, n); + tracing::debug!("resolved ht to r (5) {:?} {:?}", ht, n); let id = format_ident!("HostResource{}", n); wrap(quote! { #id }) } @@ -619,7 +619,7 @@ fn emit_extern_decl<'a, 'b, 'c>( s: &'c mut State<'a, 'b>, ed: &'c ExternDecl<'b>, ) -> TokenStream { - log::debug!(" emitting decl {:?}", ed.kebab_name); + tracing::debug!(" emitting decl {:?}", ed.kebab_name); match &ed.desc { ExternDesc::CoreModule(_) => panic!("core module (im/ex)ports are not supported"), ExternDesc::Func(ft) => { @@ -749,7 +749,7 @@ fn emit_extern_decl<'a, 'b, 'c>( /// Emit (via mutating `s`) a Rust trait declaration corresponding to /// this instance type fn emit_instance<'a, 'b, 'c>(s: &'c mut State<'a, 'b>, wn: WitName, it: &'c Instance<'b>) { - log::debug!("emitting instance {:?}", wn); + tracing::debug!("emitting instance {:?}", wn); let mut s = s.with_cursor(wn.namespace_idents()); let name = kebab_to_type(wn.name); @@ -801,7 +801,7 @@ fn emit_instance<'a, 'b, 'c>(s: &'c mut State<'a, 'b>, wn: WitName, it: &'c Inst } drop(sv); - log::debug!("after exports, ncur_needs_vars is {:?}", needs_vars); + tracing::debug!("after exports, ncur_needs_vars is {:?}", needs_vars); for v in needs_vars { let id = s.noff_var_id(v); s.cur_trait().tvs.insert(id, (Some(v), TokenStream::new())); diff --git a/src/hyperlight_component_util/src/util.rs b/src/hyperlight_component_util/src/util.rs index c068721d8..8e1960a30 100644 --- a/src/hyperlight_component_util/src/util.rs +++ b/src/hyperlight_component_util/src/util.rs @@ -47,7 +47,7 @@ pub fn read_wit_type_from_file R>( let ExternDesc::Component(ct) = &export.desc else { panic!("malformed component type container: does not contain component type"); }; - log::debug!("hcm: considering component type {:?}", ct); + tracing::debug!("hcm: considering component type {:?}", ct); cb(export.kebab_name.to_string(), ct) } diff --git a/src/hyperlight_guest_bin/Cargo.toml b/src/hyperlight_guest_bin/Cargo.toml index 056e636e6..353ac3c02 100644 --- a/src/hyperlight_guest_bin/Cargo.toml +++ b/src/hyperlight_guest_bin/Cargo.toml @@ -27,7 +27,6 @@ hyperlight-common = { workspace = true, default-features = false } hyperlight-guest-tracing = { workspace = true, default-features = false } hyperlight-guest-macro = { workspace = true, default-features = false, optional = true } buddy_system_allocator = "0.11.0" -log = { version = "0.4", default-features = false } linkme = { version = "0.3.35", optional = true } spin = "0.10.0" flatbuffers = { version = "25.2.10", default-features = false } diff --git a/src/hyperlight_guest_capi/Cargo.toml b/src/hyperlight_guest_capi/Cargo.toml index 5727fbdf2..60d239c85 100644 --- a/src/hyperlight_guest_capi/Cargo.toml +++ b/src/hyperlight_guest_capi/Cargo.toml @@ -17,7 +17,7 @@ hyperlight-guest-bin = { workspace = true, default-features = true } hyperlight-common = { workspace = true, default-features = false } flatbuffers = { version = "25.2.10", default-features = false } -log = { version = "0.4", default-features = false } +tracing = { version = "0.1.43", default-features = false } [build-dependencies] cbindgen = "0.29.2" diff --git a/src/hyperlight_host/Cargo.toml b/src/hyperlight_host/Cargo.toml index 8cd0ef944..8e014255a 100644 --- a/src/hyperlight_host/Cargo.toml +++ b/src/hyperlight_host/Cargo.toml @@ -34,7 +34,6 @@ blake3 = "1.8.2" page_size = "0.6.0" termcolor = "1.2.0" bitflags = "2.10.0" -log = "0.4.29" opentelemetry = { version = "0.31.0", optional = true } tracing = { version = "0.1.43", features = ["log"] } tracing-log = "0.2.0" diff --git a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs index 7fdd83b8f..673789a6e 100644 --- a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs +++ b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs @@ -25,7 +25,7 @@ use std::sync::atomic::AtomicU8; use std::sync::atomic::AtomicU64; use std::sync::{Arc, Mutex}; -use log::LevelFilter; +use tracing::level_filters::LevelFilter; use tracing::{Span, instrument}; #[cfg(feature = "trace_guest")] use tracing_opentelemetry::OpenTelemetrySpanExt; diff --git a/src/hyperlight_host/src/hypervisor/mod.rs b/src/hyperlight_host/src/hypervisor/mod.rs index 5cdd74b48..6d9015237 100644 --- a/src/hyperlight_host/src/hypervisor/mod.rs +++ b/src/hyperlight_host/src/hypervisor/mod.rs @@ -14,7 +14,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -use log::LevelFilter; +use tracing::level_filters::LevelFilter; use crate::Result; use crate::hypervisor::regs::{CommonFpu, CommonRegisters, CommonSpecialRegisters}; @@ -628,7 +628,7 @@ pub(crate) mod tests { let seed = 12345u64; // Random seed let page_size = 4096u32; // Standard page size let host_funcs = Arc::new(Mutex::new(FunctionRegistry::default())); - let guest_max_log_level = Some(log::LevelFilter::Error); + let guest_max_log_level = Some(tracing::level_filters::LevelFilter::ERROR); #[cfg(gdb)] let dbg_mem_access_fn = Arc::new(Mutex::new(mem_mgr.clone())); diff --git a/src/hyperlight_host/src/lib.rs b/src/hyperlight_host/src/lib.rs index 5f034dc79..d74ecbe6e 100644 --- a/src/hyperlight_host/src/lib.rs +++ b/src/hyperlight_host/src/lib.rs @@ -145,7 +145,7 @@ static LOG_ONCE: Once = Once::new(); #[cfg(feature = "build-metadata")] pub(crate) fn log_build_details() { - use log::info; + use tracing::info; LOG_ONCE.call_once(|| { info!("Package name: {}", built_info::PKG_NAME); info!("Package version: {}", built_info::PKG_VERSION); diff --git a/src/hyperlight_host/src/sandbox/outb.rs b/src/hyperlight_host/src/sandbox/outb.rs index 087162a4a..8dffd560c 100644 --- a/src/hyperlight_host/src/sandbox/outb.rs +++ b/src/hyperlight_host/src/sandbox/outb.rs @@ -20,9 +20,10 @@ use hyperlight_common::flatbuffer_wrappers::function_types::{FunctionCallResult, use hyperlight_common::flatbuffer_wrappers::guest_error::{ErrorCode, GuestError}; use hyperlight_common::flatbuffer_wrappers::guest_log_data::GuestLogData; use hyperlight_common::outb::{Exception, OutBAction}; -use log::{Level, Record}; use tracing::{Span, instrument}; -use tracing_log::format_trace; +use tracing_log::{LogTracer, format_trace, log}; + +use log::{Level, Record}; use super::host_funcs::FunctionRegistry; #[cfg(feature = "mem_profile")] @@ -197,7 +198,7 @@ pub(crate) fn handle_outb( mod tests { use hyperlight_common::flatbuffer_wrappers::guest_log_level::LogLevel; use hyperlight_testing::logger::{LOGGER, Logger}; - use log::Level; + use tracing_log::log::{Level, LevelFilter}; use tracing_core::callsite::rebuild_interest_cache; use super::outb_log; @@ -224,7 +225,7 @@ mod tests { #[ignore] fn test_log_outb_log() { Logger::initialize_test_logger(); - LOGGER.set_max_level(log::LevelFilter::Off); + LOGGER.set_max_level(LevelFilter::Off); let sandbox_cfg = SandboxConfiguration::default(); @@ -271,7 +272,7 @@ mod tests { } { // now, test logging - LOGGER.set_max_level(log::LevelFilter::Trace); + LOGGER.set_max_level(LevelFilter::Trace); let mut mgr = new_mgr(); LOGGER.clear_log_calls(); diff --git a/src/hyperlight_host/src/sandbox/uninitialized.rs b/src/hyperlight_host/src/sandbox/uninitialized.rs index cd7077062..72466badc 100644 --- a/src/hyperlight_host/src/sandbox/uninitialized.rs +++ b/src/hyperlight_host/src/sandbox/uninitialized.rs @@ -19,7 +19,7 @@ use std::option::Option; use std::path::Path; use std::sync::{Arc, Mutex}; -use log::LevelFilter; +use tracing::level_filters::LevelFilter; use tracing::{Span, instrument}; use super::host_funcs::{FunctionRegistry, default_writer_func}; @@ -906,12 +906,12 @@ mod tests { use std::path::PathBuf; use hyperlight_testing::logger::{LOGGER as TEST_LOGGER, Logger as TestLogger}; - use log::Level; + use tracing_log::log::Level; use tracing_core::callsite::rebuild_interest_cache; { TestLogger::initialize_test_logger(); - TEST_LOGGER.set_max_level(log::LevelFilter::Trace); + TEST_LOGGER.set_max_level(tracing_log::log::LevelFilter::Trace); // This makes sure that the metadata interest cache is rebuilt so that // the log records are emitted for the trace records @@ -983,7 +983,7 @@ mod tests { { // test to ensure an invalid binary logs & traces properly TEST_LOGGER.clear_log_calls(); - TEST_LOGGER.set_max_level(log::LevelFilter::Info); + TEST_LOGGER.set_max_level(tracing_log::log::LevelFilter::Info); let mut valid_binary_path = PathBuf::from(env!("CARGO_MANIFEST_DIR")); valid_binary_path.push("src"); @@ -1022,7 +1022,7 @@ mod tests { } { TEST_LOGGER.clear_log_calls(); - TEST_LOGGER.set_max_level(log::LevelFilter::Error); + TEST_LOGGER.set_max_level(tracing_log::log::LevelFilter::Error); let sbox = { let res = UninitializedSandbox::new( diff --git a/src/hyperlight_host/tests/integration_test.rs b/src/hyperlight_host/tests/integration_test.rs index c5e2d2a8a..4c4b3b714 100644 --- a/src/hyperlight_host/tests/integration_test.rs +++ b/src/hyperlight_host/tests/integration_test.rs @@ -25,7 +25,7 @@ use hyperlight_host::sandbox::SandboxConfiguration; use hyperlight_host::{GuestBinary, HyperlightError, MultiUseSandbox, UninitializedSandbox}; use hyperlight_testing::simplelogger::{LOGGER, SimpleLogger}; use hyperlight_testing::{c_simple_guest_as_string, simple_guest_as_string}; -use log::LevelFilter; +use tracing::level_filters::LevelFilter; pub mod common; // pub to disable dead_code warning use crate::common::{new_uninit, new_uninit_c, new_uninit_rust}; diff --git a/src/hyperlight_testing/Cargo.toml b/src/hyperlight_testing/Cargo.toml index 4334cb084..ad936fb59 100644 --- a/src/hyperlight_testing/Cargo.toml +++ b/src/hyperlight_testing/Cargo.toml @@ -4,7 +4,6 @@ edition = "2021" [dependencies] anyhow = "1.0.100" -log = "0.4" once_cell = "1.21" tracing = { version = "0.1.43", features = ["log"] } tracing-log = "0.2.0" diff --git a/src/hyperlight_testing/src/logger.rs b/src/hyperlight_testing/src/logger.rs index 31a15069c..7cf505092 100644 --- a/src/hyperlight_testing/src/logger.rs +++ b/src/hyperlight_testing/src/logger.rs @@ -18,7 +18,7 @@ use std::cell::RefCell; use std::sync::Once; use std::thread::current; -use log::{Level, LevelFilter, Log, Metadata, Record, set_logger, set_max_level}; +use tracing_log::log::{Level, LevelFilter, Log, Metadata, Record, set_logger, set_max_level}; use once_cell::sync::Lazy; use tracing_log::LogTracer; diff --git a/src/hyperlight_testing/src/simplelogger.rs b/src/hyperlight_testing/src/simplelogger.rs index 83642d425..b93731c17 100644 --- a/src/hyperlight_testing/src/simplelogger.rs +++ b/src/hyperlight_testing/src/simplelogger.rs @@ -21,7 +21,7 @@ limitations under the License. use std::sync::Once; use std::thread::current; -use log::{Level, Log, Metadata, Record, set_logger, set_max_level}; +use tracing_log::log::{Level, Log, Metadata, Record, set_logger, set_max_level}; pub static LOGGER: SimpleLogger = SimpleLogger {}; static INITLOGGER: Once = Once::new(); diff --git a/src/tests/rust_guests/simpleguest/Cargo.toml b/src/tests/rust_guests/simpleguest/Cargo.toml index 5edff7ff5..2d97da5f0 100644 --- a/src/tests/rust_guests/simpleguest/Cargo.toml +++ b/src/tests/rust_guests/simpleguest/Cargo.toml @@ -8,7 +8,6 @@ hyperlight-guest = { path = "../../../hyperlight_guest" } hyperlight-guest-bin = { path = "../../../hyperlight_guest_bin" } hyperlight-common = { path = "../../../hyperlight_common", default-features = false } hyperlight-guest-tracing = { path = "../../../hyperlight_guest_tracing" } -log = {version = "0.4", default-features = false } tracing = { version = "0.1.41", default-features = false, features = ["log", "attributes"] } [features] diff --git a/src/tests/rust_guests/simpleguest/src/main.rs b/src/tests/rust_guests/simpleguest/src/main.rs index 1cef4a858..dd877bff3 100644 --- a/src/tests/rust_guests/simpleguest/src/main.rs +++ b/src/tests/rust_guests/simpleguest/src/main.rs @@ -440,7 +440,7 @@ fn test_write_raw_ptr(offset: i64) -> String { let page_guard_start = min_stack_addr - PAGE_SIZE; let addr = { let abs = u64::try_from(offset.abs()) - .map_err(|_| error!("Invalid offset")) + .map_err(|_| tracing::error!("Invalid offset")) .unwrap(); if offset.is_negative() { page_guard_start - abs @@ -564,7 +564,7 @@ fn read_from_user_memory(num: u64, expected: Vec) -> Result> { // verify that the user memory contains the expected data if bytes != expected { - error!("User memory does not contain the expected data"); + tracing::error!("User memory does not contain the expected data"); return Err(HyperlightGuestError::new( ErrorCode::GuestError, "User memory does not contain the expected data".to_string(), From a43a330a31b17dfefe360f65194e695f756219c0 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 22:48:56 +0000 Subject: [PATCH 3/7] Fix compilation errors after log to tracing migration Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- Cargo.lock | 8 ++------ .../flatbuffer_wrappers/guest_log_level.rs | 12 +++++++++++- .../src/hypervisor/hyperlight_vm.rs | 19 ++++++++++++++++++- .../src/hypervisor/hyperv_linux.rs | 2 +- src/hyperlight_host/src/hypervisor/kvm.rs | 10 +++++----- src/hyperlight_host/src/hypervisor/mod.rs | 17 ++++++++++++----- src/hyperlight_host/src/lib.rs | 12 ++++++------ src/hyperlight_host/src/sandbox/outb.rs | 16 ++++++++++++++-- src/hyperlight_testing/src/logger.rs | 4 ++-- src/hyperlight_testing/src/simplelogger.rs | 4 ++-- 10 files changed, 73 insertions(+), 31 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 966d257ef..586567335 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1387,7 +1387,6 @@ dependencies = [ "anyhow", "arbitrary", "flatbuffers", - "log", "spin 0.10.0", "thiserror 2.0.17", "tracing", @@ -1412,11 +1411,11 @@ name = "hyperlight-component-util" version = "0.12.0" dependencies = [ "itertools 0.14.0", - "log", "prettyplease", "proc-macro2", "quote", "syn", + "tracing", "wasmparser", ] @@ -1456,7 +1455,6 @@ dependencies = [ "hyperlight-guest-macro", "hyperlight-guest-tracing", "linkme", - "log", "spin 0.10.0", "tracing", ] @@ -1511,7 +1509,6 @@ dependencies = [ "kvm-ioctls", "lazy_static", "libc", - "log", "metrics", "metrics-exporter-prometheus", "metrics-util", @@ -1557,7 +1554,6 @@ name = "hyperlight-testing" version = "0.0.0" dependencies = [ "anyhow", - "log", "once_cell", "serde", "serde_json", @@ -1576,7 +1572,7 @@ dependencies = [ "hyperlight-common", "hyperlight-guest", "hyperlight-guest-bin", - "log", + "tracing", ] [[package]] diff --git a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs index deec57070..45017bf78 100644 --- a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs +++ b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs @@ -15,12 +15,22 @@ limitations under the License. */ use anyhow::{Error, Result, bail}; -use log::Level; #[cfg(feature = "tracing")] use tracing::{Span, instrument}; use crate::flatbuffers::hyperlight::generated::LogLevel as FbLogLevel; +// Define a minimal Level enum for conversions. +// This mirrors log::Level/tracing::Level but is no_std compatible. +#[derive(Copy, Clone, Eq, PartialEq, Debug)] +pub enum Level { + Trace, + Debug, + Info, + Warn, + Error, +} + #[repr(u8)] #[derive(Copy, Clone, Eq, PartialEq, Debug)] pub enum LogLevel { diff --git a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs index 673789a6e..e9edd9957 100644 --- a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs +++ b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs @@ -30,6 +30,23 @@ use tracing::{Span, instrument}; #[cfg(feature = "trace_guest")] use tracing_opentelemetry::OpenTelemetrySpanExt; +// Helper function to convert LevelFilter to u64 for guest +fn level_filter_to_u64(filter: LevelFilter) -> u64 { + // Map LevelFilter to numeric values matching the guest expectations + // OFF = 5, ERROR = 4, WARN = 3, INFO = 2, DEBUG = 1, TRACE = 0 + if filter >= LevelFilter::ERROR { + 4 + } else if filter >= LevelFilter::WARN { + 3 + } else if filter >= LevelFilter::INFO { + 2 + } else if filter >= LevelFilter::DEBUG { + 1 + } else { + 0 + } +} + #[cfg(gdb)] use super::gdb::{DebugCommChannel, DebugMsg, DebugResponse, DebuggableVm, VcpuStopReason, arch}; use super::regs::{CommonFpu, CommonRegisters}; @@ -229,7 +246,7 @@ impl HyperlightVm { self.page_size = page_size as usize; let guest_max_log_level: u64 = match guest_max_log_level { - Some(level) => level as u64, + Some(level) => level_filter_to_u64(level), None => get_max_log_level().into(), }; diff --git a/src/hyperlight_host/src/hypervisor/hyperv_linux.rs b/src/hyperlight_host/src/hypervisor/hyperv_linux.rs index 8c6feb351..2eb553214 100644 --- a/src/hyperlight_host/src/hypervisor/hyperv_linux.rs +++ b/src/hyperlight_host/src/hypervisor/hyperv_linux.rs @@ -44,7 +44,7 @@ pub(crate) fn is_hypervisor_present() -> bool { match Mshv::new() { Ok(_) => true, Err(_) => { - log::info!("MSHV is not available on this system"); + tracing::info!("MSHV is not available on this system"); false } } diff --git a/src/hyperlight_host/src/hypervisor/kvm.rs b/src/hyperlight_host/src/hypervisor/kvm.rs index 037b60fc1..be2177f59 100644 --- a/src/hyperlight_host/src/hypervisor/kvm.rs +++ b/src/hyperlight_host/src/hypervisor/kvm.rs @@ -37,16 +37,16 @@ pub(crate) fn is_hypervisor_present() -> bool { match api_version { version if version == 12 && kvm.check_extension(UserMemory) => true, 12 => { - log::info!("KVM does not have KVM_CAP_USER_MEMORY capability"); + tracing::info!("KVM does not have KVM_CAP_USER_MEMORY capability"); false } version => { - log::info!("KVM GET_API_VERSION returned {}, expected 12", version); + tracing::info!("KVM GET_API_VERSION returned {}, expected 12", version); false } } } else { - log::info!("KVM is not available on this system"); + tracing::info!("KVM is not available on this system"); false } } @@ -190,7 +190,7 @@ impl DebuggableVm for KvmVm { fn set_debug(&mut self, enable: bool) -> Result<()> { use kvm_bindings::{KVM_GUESTDBG_ENABLE, KVM_GUESTDBG_USE_HW_BP, KVM_GUESTDBG_USE_SW_BP}; - log::info!("Setting debug to {}", enable); + tracing::info!("Setting debug to {}", enable); if enable { self.debug_regs.control |= KVM_GUESTDBG_ENABLE | KVM_GUESTDBG_USE_HW_BP | KVM_GUESTDBG_USE_SW_BP; @@ -205,7 +205,7 @@ impl DebuggableVm for KvmVm { fn set_single_step(&mut self, enable: bool) -> Result<()> { use kvm_bindings::KVM_GUESTDBG_SINGLESTEP; - log::info!("Setting single step to {}", enable); + tracing::info!("Setting single step to {}", enable); if enable { self.debug_regs.control |= KVM_GUESTDBG_SINGLESTEP; } else { diff --git a/src/hyperlight_host/src/hypervisor/mod.rs b/src/hyperlight_host/src/hypervisor/mod.rs index 6d9015237..e1d616935 100644 --- a/src/hyperlight_host/src/hypervisor/mod.rs +++ b/src/hyperlight_host/src/hypervisor/mod.rs @@ -14,7 +14,6 @@ See the License for the specific language governing permissions and limitations under the License. */ -use tracing::level_filters::LevelFilter; use crate::Result; use crate::hypervisor::regs::{CommonFpu, CommonRegisters, CommonSpecialRegisters}; @@ -53,7 +52,6 @@ pub(crate) mod crashdump; pub(crate) mod hyperlight_vm; use std::fmt::Debug; -use std::str::FromStr; #[cfg(any(kvm, mshv3))] use std::sync::atomic::{AtomicBool, AtomicU8, AtomicU64, Ordering}; #[cfg(target_os = "windows")] @@ -169,10 +167,19 @@ fn get_max_log_level() -> u32 { val.split(',').find(|s| !s.contains("=")).unwrap_or("") }; - log::info!("Determined guest log level: {}", level); + tracing::info!("Determined guest log level: {}", level); // Convert the log level string to a LevelFilter // If no value is found, default to Error - LevelFilter::from_str(level).unwrap_or(LevelFilter::Error) as u32 + // tracing::LevelFilter doesn't implement FromStr or as u32, so we need to convert via string matching + let level_filter = match level.to_lowercase().as_str() { + "trace" => 0u32, + "debug" => 1u32, + "info" => 2u32, + "warn" => 3u32, + "error" => 4u32, + _ => 4u32, // Default to Error + }; + level_filter } /// A trait for platform-specific interrupt handle implementation details @@ -299,7 +306,7 @@ impl LinuxInterruptHandle { break; } - log::info!("Sending signal to kill vcpu thread..."); + tracing::info!("Sending signal to kill vcpu thread..."); sent_signal = true; // Acquire ordering to synchronize with the Release store in set_tid() // This ensures we see the correct tid value for the currently running vcpu diff --git a/src/hyperlight_host/src/lib.rs b/src/hyperlight_host/src/lib.rs index d74ecbe6e..62695a19b 100644 --- a/src/hyperlight_host/src/lib.rs +++ b/src/hyperlight_host/src/lib.rs @@ -109,33 +109,33 @@ macro_rules! log_then_return { None => std::format!($msg), }; let __err = $crate::HyperlightError::Error(__err_msg); - log::error!("{}", __err); + tracing::error!("{}", __err); return Err(__err); }}; ($err:expr $(,)?) => { - log::error!("{}", $err); + tracing::error!("{}", $err); return Err($err); }; ($err:stmt $(,)?) => { - log::error!("{}", $err); + tracing::error!("{}", $err); return Err($err); }; ($fmtstr:expr, $($arg:tt)*) => { let __err_msg = std::format!($fmtstr, $($arg)*); let __err = $crate::error::HyperlightError::Error(__err_msg); - log::error!("{}", __err); + tracing::error!("{}", __err); return Err(__err); }; } -/// Same as log::debug!, but will additionally print to stdout if the print_debug feature is enabled +/// Same as tracing::debug!, but will additionally print to stdout if the print_debug feature is enabled #[macro_export] macro_rules! debug { ($($arg:tt)+) => { #[cfg(print_debug)] println!($($arg)+); - log::debug!($($arg)+); + tracing::debug!($($arg)+); } } diff --git a/src/hyperlight_host/src/sandbox/outb.rs b/src/hyperlight_host/src/sandbox/outb.rs index 8dffd560c..84e4839c1 100644 --- a/src/hyperlight_host/src/sandbox/outb.rs +++ b/src/hyperlight_host/src/sandbox/outb.rs @@ -19,12 +19,24 @@ use std::sync::{Arc, Mutex}; use hyperlight_common::flatbuffer_wrappers::function_types::{FunctionCallResult, ParameterValue}; use hyperlight_common::flatbuffer_wrappers::guest_error::{ErrorCode, GuestError}; use hyperlight_common::flatbuffer_wrappers::guest_log_data::GuestLogData; +use hyperlight_common::flatbuffer_wrappers::guest_log_level::Level as GuestLevel; use hyperlight_common::outb::{Exception, OutBAction}; use tracing::{Span, instrument}; -use tracing_log::{LogTracer, format_trace, log}; +use tracing_log::{format_trace, log}; use log::{Level, Record}; +// Convert from guest Level to log Level +fn guest_level_to_log_level(guest_level: GuestLevel) -> Level { + match guest_level { + GuestLevel::Trace => Level::Trace, + GuestLevel::Debug => Level::Debug, + GuestLevel::Info => Level::Info, + GuestLevel::Warn => Level::Warn, + GuestLevel::Error => Level::Error, + } +} + use super::host_funcs::FunctionRegistry; #[cfg(feature = "mem_profile")] use crate::hypervisor::regs::CommonRegisters; @@ -45,7 +57,7 @@ pub(super) fn outb_log(mgr: &mut SandboxMemoryManager) -> Resu let log_data: GuestLogData = mgr.read_guest_log_data()?; - let record_level: Level = (&log_data.level).into(); + let record_level: Level = guest_level_to_log_level((&log_data.level).into()); // Work out if we need to log or trace // this API is marked as follows but it is the easiest way to work out if we should trace or log diff --git a/src/hyperlight_testing/src/logger.rs b/src/hyperlight_testing/src/logger.rs index 7cf505092..e80046cc2 100644 --- a/src/hyperlight_testing/src/logger.rs +++ b/src/hyperlight_testing/src/logger.rs @@ -46,14 +46,14 @@ impl Logger { pub fn initialize_test_logger() { INITLOGGER.call_once(|| { set_logger(&LOGGER).unwrap(); - set_max_level(log::LevelFilter::Trace); + set_max_level(LevelFilter::Trace); }); } pub fn initialize_log_tracer() { INITLOGGER.call_once(|| { set_logger(&*LOG_TRACER).unwrap(); - set_max_level(log::LevelFilter::Trace); + set_max_level(LevelFilter::Trace); }); } diff --git a/src/hyperlight_testing/src/simplelogger.rs b/src/hyperlight_testing/src/simplelogger.rs index b93731c17..d8dcf2ffa 100644 --- a/src/hyperlight_testing/src/simplelogger.rs +++ b/src/hyperlight_testing/src/simplelogger.rs @@ -44,7 +44,7 @@ impl SimpleLogger { pub fn initialize_test_logger() { INITLOGGER.call_once(|| { set_logger(&LOGGER).unwrap(); - set_max_level(log::LevelFilter::Trace); + set_max_level(tracing_log::log::LevelFilter::Trace); }); } @@ -86,7 +86,7 @@ impl Log for SimpleLogger { if metadata.target() == "hyperlight_guest" { NUMBER_OF_ENABLED_CALLS += 1; } - metadata.target() == "hyperlight_guest" && metadata.level() <= log::max_level() + metadata.target() == "hyperlight_guest" && metadata.level() <= tracing_log::log::max_level() } } fn log(&self, record: &Record) { From 2f8187e704f1ec0046a9e62bfa9ac892cceb33b0 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 22:59:26 +0000 Subject: [PATCH 4/7] Add log dependency back for guest environments and fix conversions Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- Cargo.lock | 1 + .../src/flatbuffer_wrappers/guest_log_level.rs | 18 ++++++++++++++++++ src/hyperlight_guest_bin/Cargo.toml | 1 + src/tests/rust_guests/simpleguest/Cargo.lock | 1 - src/tests/rust_guests/simpleguest/Cargo.toml | 1 + 5 files changed, 21 insertions(+), 1 deletion(-) diff --git a/Cargo.lock b/Cargo.lock index 586567335..630eab2a7 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1455,6 +1455,7 @@ dependencies = [ "hyperlight-guest-macro", "hyperlight-guest-tracing", "linkme", + "log", "spin 0.10.0", "tracing", ] diff --git a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs index 45017bf78..4c0675210 100644 --- a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs +++ b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs @@ -18,6 +18,9 @@ use anyhow::{Error, Result, bail}; #[cfg(feature = "tracing")] use tracing::{Span, instrument}; +#[cfg(feature = "std")] +extern crate log; + use crate::flatbuffers::hyperlight::generated::LogLevel as FbLogLevel; // Define a minimal Level enum for conversions. @@ -122,3 +125,18 @@ impl From for LogLevel { } } } + +// Conversion from log::Level (which guest logger uses) to LogLevel +// Only available when std feature is enabled (for guest environments) +#[cfg(feature = "std")] +impl From for LogLevel { + fn from(val: log::Level) -> LogLevel { + match val { + log::Level::Trace => LogLevel::Trace, + log::Level::Debug => LogLevel::Debug, + log::Level::Info => LogLevel::Information, + log::Level::Warn => LogLevel::Warning, + log::Level::Error => LogLevel::Error, + } + } +} diff --git a/src/hyperlight_guest_bin/Cargo.toml b/src/hyperlight_guest_bin/Cargo.toml index 353ac3c02..056e636e6 100644 --- a/src/hyperlight_guest_bin/Cargo.toml +++ b/src/hyperlight_guest_bin/Cargo.toml @@ -27,6 +27,7 @@ hyperlight-common = { workspace = true, default-features = false } hyperlight-guest-tracing = { workspace = true, default-features = false } hyperlight-guest-macro = { workspace = true, default-features = false, optional = true } buddy_system_allocator = "0.11.0" +log = { version = "0.4", default-features = false } linkme = { version = "0.3.35", optional = true } spin = "0.10.0" flatbuffers = { version = "25.2.10", default-features = false } diff --git a/src/tests/rust_guests/simpleguest/Cargo.lock b/src/tests/rust_guests/simpleguest/Cargo.lock index 032791dab..d210ee675 100644 --- a/src/tests/rust_guests/simpleguest/Cargo.lock +++ b/src/tests/rust_guests/simpleguest/Cargo.lock @@ -78,7 +78,6 @@ version = "0.12.0" dependencies = [ "anyhow", "flatbuffers", - "log", "spin 0.10.0", "thiserror", ] diff --git a/src/tests/rust_guests/simpleguest/Cargo.toml b/src/tests/rust_guests/simpleguest/Cargo.toml index 2d97da5f0..5edff7ff5 100644 --- a/src/tests/rust_guests/simpleguest/Cargo.toml +++ b/src/tests/rust_guests/simpleguest/Cargo.toml @@ -8,6 +8,7 @@ hyperlight-guest = { path = "../../../hyperlight_guest" } hyperlight-guest-bin = { path = "../../../hyperlight_guest_bin" } hyperlight-common = { path = "../../../hyperlight_common", default-features = false } hyperlight-guest-tracing = { path = "../../../hyperlight_guest_tracing" } +log = {version = "0.4", default-features = false } tracing = { version = "0.1.41", default-features = false, features = ["log", "attributes"] } [features] From 25393e4e2499cefd0493da2035e78384d53fa703 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 23:08:22 +0000 Subject: [PATCH 5/7] Add log dependency to hyperlight_common for guest compatibility Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- Cargo.lock | 2 ++ src/hyperlight_common/Cargo.toml | 3 ++- .../src/flatbuffer_wrappers/guest_log_level.rs | 5 ----- src/hyperlight_guest_capi/Cargo.toml | 1 + src/tests/rust_guests/simpleguest/Cargo.lock | 1 + src/tests/rust_guests/witguest/Cargo.lock | 11 ++++++++++- 6 files changed, 16 insertions(+), 7 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 630eab2a7..1f0ec6b38 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1387,6 +1387,7 @@ dependencies = [ "anyhow", "arbitrary", "flatbuffers", + "log", "spin 0.10.0", "thiserror 2.0.17", "tracing", @@ -1573,6 +1574,7 @@ dependencies = [ "hyperlight-common", "hyperlight-guest", "hyperlight-guest-bin", + "log", "tracing", ] diff --git a/src/hyperlight_common/Cargo.toml b/src/hyperlight_common/Cargo.toml index e07ba4a2e..ce7c929dd 100644 --- a/src/hyperlight_common/Cargo.toml +++ b/src/hyperlight_common/Cargo.toml @@ -21,6 +21,7 @@ tracing = { version = "0.1.43", optional = true } arbitrary = {version = "1.4.2", optional = true, features = ["derive"]} spin = "0.10.0" thiserror = { version = "2.0.16", default-features = false } +log = { version = "0.4.29", default-features = false } [features] default = ["tracing"] @@ -28,7 +29,7 @@ tracing = ["dep:tracing"] fuzzing = ["dep:arbitrary"] trace_guest = [] mem_profile = [] -std = ["thiserror/std", "tracing/std"] +std = ["thiserror/std", "tracing/std", "log/std"] [lib] bench = false # see https://bheisler.github.io/criterion.rs/book/faq.html#cargo-bench-gives-unrecognized-option-errors-for-valid-command-line-options diff --git a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs index 4c0675210..edfb26a6d 100644 --- a/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs +++ b/src/hyperlight_common/src/flatbuffer_wrappers/guest_log_level.rs @@ -18,9 +18,6 @@ use anyhow::{Error, Result, bail}; #[cfg(feature = "tracing")] use tracing::{Span, instrument}; -#[cfg(feature = "std")] -extern crate log; - use crate::flatbuffers::hyperlight::generated::LogLevel as FbLogLevel; // Define a minimal Level enum for conversions. @@ -127,8 +124,6 @@ impl From for LogLevel { } // Conversion from log::Level (which guest logger uses) to LogLevel -// Only available when std feature is enabled (for guest environments) -#[cfg(feature = "std")] impl From for LogLevel { fn from(val: log::Level) -> LogLevel { match val { diff --git a/src/hyperlight_guest_capi/Cargo.toml b/src/hyperlight_guest_capi/Cargo.toml index 60d239c85..e6700589b 100644 --- a/src/hyperlight_guest_capi/Cargo.toml +++ b/src/hyperlight_guest_capi/Cargo.toml @@ -17,6 +17,7 @@ hyperlight-guest-bin = { workspace = true, default-features = true } hyperlight-common = { workspace = true, default-features = false } flatbuffers = { version = "25.2.10", default-features = false } +log = { version = "0.4", default-features = false } tracing = { version = "0.1.43", default-features = false } [build-dependencies] diff --git a/src/tests/rust_guests/simpleguest/Cargo.lock b/src/tests/rust_guests/simpleguest/Cargo.lock index d210ee675..032791dab 100644 --- a/src/tests/rust_guests/simpleguest/Cargo.lock +++ b/src/tests/rust_guests/simpleguest/Cargo.lock @@ -78,6 +78,7 @@ version = "0.12.0" dependencies = [ "anyhow", "flatbuffers", + "log", "spin 0.10.0", "thiserror", ] diff --git a/src/tests/rust_guests/witguest/Cargo.lock b/src/tests/rust_guests/witguest/Cargo.lock index 7933a0903..8e3d6d67b 100644 --- a/src/tests/rust_guests/witguest/Cargo.lock +++ b/src/tests/rust_guests/witguest/Cargo.lock @@ -212,11 +212,11 @@ name = "hyperlight-component-util" version = "0.12.0" dependencies = [ "itertools", - "log", "prettyplease", "proc-macro2", "quote", "syn", + "tracing", "wasmparser", ] @@ -370,6 +370,12 @@ version = "2.7.5" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "32a282da65faaf38286cf3be983213fcf1d2e2a58700e808f83f4ea9a4804bc0" +[[package]] +name = "once_cell" +version = "1.21.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42f5e15c9953c5e4ccceeb2e7382a716482c34515315f7b03532b8b4e8393d2d" + [[package]] name = "once_cell_polyfill" version = "1.70.1" @@ -643,6 +649,9 @@ name = "tracing-core" version = "0.1.35" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7a04e24fab5c89c6a36eb8558c9656f30d81de51dfa4d3b45f26b21d61fa0a6c" +dependencies = [ + "once_cell", +] [[package]] name = "unicode-ident" From ddb80db25400c19cb4e3b5b50bdd4cf3f6210ff0 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 16 Dec 2025 23:10:48 +0000 Subject: [PATCH 6/7] Fix test compilation error in outb.rs Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- src/hyperlight_host/src/sandbox/outb.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/hyperlight_host/src/sandbox/outb.rs b/src/hyperlight_host/src/sandbox/outb.rs index 84e4839c1..fac1b458e 100644 --- a/src/hyperlight_host/src/sandbox/outb.rs +++ b/src/hyperlight_host/src/sandbox/outb.rs @@ -213,7 +213,7 @@ mod tests { use tracing_log::log::{Level, LevelFilter}; use tracing_core::callsite::rebuild_interest_cache; - use super::outb_log; + use super::{outb_log, guest_level_to_log_level}; use crate::mem::layout::SandboxMemoryLayout; use crate::mem::mgr::SandboxMemoryManager; use crate::mem::shared_mem::SharedMemory; @@ -317,7 +317,7 @@ mod tests { outb_log(&mut mgr).unwrap(); LOGGER.test_log_records(|log_calls| { - let expected_level: Level = (&level).into(); + let expected_level: Level = guest_level_to_log_level((&level).into()); assert!( log_calls From 8fe82c4bf41e74a69d43fd3f7105b39171b1b4bc Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Thu, 18 Dec 2025 00:05:57 +0000 Subject: [PATCH 7/7] Replace remaining log macros with tracing equivalents in host code Co-authored-by: jsturtevant <648372+jsturtevant@users.noreply.github.com> --- .../src/hypervisor/crashdump.rs | 8 +- .../src/hypervisor/gdb/arch.rs | 2 +- .../src/hypervisor/gdb/event_loop.rs | 22 ++--- src/hyperlight_host/src/hypervisor/gdb/mod.rs | 24 ++--- .../src/hypervisor/gdb/x86_64_target.rs | 90 +++++++++---------- .../src/hypervisor/hyperlight_vm.rs | 32 +++---- .../src/hypervisor/hyperv_windows.rs | 4 +- src/hyperlight_host/src/hypervisor/mod.rs | 8 +- .../src/sandbox/trace/context.rs | 8 +- .../src/sandbox/trace/mem_profile.rs | 2 +- .../src/sandbox/uninitialized_evolve.rs | 2 +- src/hyperlight_host/tests/integration_test.rs | 31 ++++--- 12 files changed, 121 insertions(+), 112 deletions(-) diff --git a/src/hyperlight_host/src/hypervisor/crashdump.rs b/src/hyperlight_host/src/hypervisor/crashdump.rs index a5f7c19fc..171d6caa5 100644 --- a/src/hyperlight_host/src/hypervisor/crashdump.rs +++ b/src/hyperlight_host/src/hypervisor/crashdump.rs @@ -285,10 +285,10 @@ pub(crate) fn generate_crashdump(hv: &HyperlightVm) -> Result<()> { if let Ok(nbytes) = checked_core_dump(ctx, create_dump_file) { if nbytes > 0 { println!("Core dump created successfully: {}", file_path); - log::error!("Core dump file: {}", file_path); + tracing::error!("Core dump file: {}", file_path); } } else { - log::error!("Failed to create core dump file"); + tracing::error!("Failed to create core dump file"); } Ok(()) @@ -321,7 +321,7 @@ fn core_dump_file_path(dump_dir: Option) -> String { if std::path::Path::new(&dump_dir).exists() { std::path::PathBuf::from(dump_dir) } else { - log::warn!( + tracing::warn!( "Directory \"{}\" does not exist, falling back to temp directory", dump_dir ); @@ -356,7 +356,7 @@ fn checked_core_dump( // If the HV returned a context it means we can create a core dump // This is the case when the sandbox has been configured at runtime to allow core dumps if let Some(ctx) = ctx { - log::info!("Creating core dump file..."); + tracing::info!("Creating core dump file..."); // Set up data sources for the core dump let guest_view = GuestView::new(&ctx); diff --git a/src/hyperlight_host/src/hypervisor/gdb/arch.rs b/src/hyperlight_host/src/hypervisor/gdb/arch.rs index 05f221e46..dc6f4fcf6 100644 --- a/src/hyperlight_host/src/hypervisor/gdb/arch.rs +++ b/src/hyperlight_host/src/hypervisor/gdb/arch.rs @@ -85,7 +85,7 @@ pub(crate) fn vcpu_stop_reason( } // Log an error and provide internal debugging info - log::error!( + tracing::error!( r"The vCPU exited because of an unknown reason: rip: {:?} dr6: {:?} diff --git a/src/hyperlight_host/src/hypervisor/gdb/event_loop.rs b/src/hyperlight_host/src/hypervisor/gdb/event_loop.rs index 69dec3407..bc7c9fd14 100644 --- a/src/hyperlight_host/src/hypervisor/gdb/event_loop.rs +++ b/src/hyperlight_host/src/hypervisor/gdb/event_loop.rs @@ -54,7 +54,7 @@ impl run_blocking::BlockingEventLoop for GdbBlockingEventLoop { loop { match target.try_recv() { Ok(DebugResponse::VcpuStopped(stop_reason)) => { - log::debug!("VcpuStopped with reason {:?}", stop_reason); + tracing::debug!("VcpuStopped with reason {:?}", stop_reason); // Resume execution if unknown reason for stop let stop_response = match stop_reason { @@ -73,7 +73,7 @@ impl run_blocking::BlockingEventLoop for GdbBlockingEventLoop { signal: Signal(signals::SIGSEGV as u8), }, VcpuStopReason::Unknown => { - log::warn!("Unknown stop reason received"); + tracing::warn!("Unknown stop reason received"); // Marking as a SwBreak so the gdb inspect where/why it stopped BaseStopReason::SwBreak(()) @@ -83,7 +83,7 @@ impl run_blocking::BlockingEventLoop for GdbBlockingEventLoop { return Ok(run_blocking::Event::TargetStopped(stop_response)); } Ok(msg) => { - log::error!("Unexpected message received {:?}", msg); + tracing::error!("Unexpected message received {:?}", msg); } Err(crossbeam_channel::TryRecvError::Empty) => (), Err(crossbeam_channel::TryRecvError::Disconnected) => { @@ -112,13 +112,13 @@ impl run_blocking::BlockingEventLoop for GdbBlockingEventLoop { fn on_interrupt( target: &mut Self::Target, ) -> Result, ::Error> { - log::info!("Received interrupt from GDB client - sending signal to target thread"); + tracing::info!("Received interrupt from GDB client - sending signal to target thread"); // Send a signal to the target thread to interrupt it let res = target.interrupt_vcpu(); if !res { - log::error!("Failed to send signal to target thread"); + tracing::error!("Failed to send signal to target thread"); return Err(GdbTargetError::SendSignalError); } @@ -133,21 +133,21 @@ pub(crate) fn event_loop_thread( match debugger.run_blocking::(target) { Ok(disconnect_reason) => match disconnect_reason { DisconnectReason::Disconnect => { - log::info!("Gdb client disconnected"); + tracing::info!("Gdb client disconnected"); if let Err(e) = target.disable_debug() { - log::error!("Cannot disable debugging: {:?}", e); + tracing::error!("Cannot disable debugging: {:?}", e); } } DisconnectReason::TargetExited(_) => { - log::info!("Guest finalized execution and disconnected"); + tracing::info!("Guest finalized execution and disconnected"); } DisconnectReason::TargetTerminated(sig) => { - log::info!("Gdb target terminated with signal {}", sig) + tracing::info!("Gdb target terminated with signal {}", sig) } - DisconnectReason::Kill => log::info!("Gdb sent a kill command"), + DisconnectReason::Kill => tracing::info!("Gdb sent a kill command"), }, Err(e) => { - log::error!("fatal error encountered: {e:?}"); + tracing::error!("fatal error encountered: {e:?}"); } } } diff --git a/src/hyperlight_host/src/hypervisor/gdb/mod.rs b/src/hyperlight_host/src/hypervisor/gdb/mod.rs index cb866d511..7170be8e7 100644 --- a/src/hyperlight_host/src/hypervisor/gdb/mod.rs +++ b/src/hyperlight_host/src/hypervisor/gdb/mod.rs @@ -100,7 +100,7 @@ impl DebugMemoryAccess { let mem_offset = (gpa as usize) .checked_sub(SandboxMemoryLayout::BASE_ADDRESS) .ok_or_else(|| { - log::warn!( + tracing::warn!( "gpa={:#X} causes subtract with underflow: \"gpa - BASE_ADDRESS={:#X}-{:#X}\"", gpa, gpa, @@ -113,11 +113,11 @@ impl DebugMemoryAccess { let mut region_found = false; for reg in self.guest_mmap_regions.iter() { if reg.guest_region.contains(&mem_offset) { - log::debug!("Found mapped region containing {:X}: {:#?}", gpa, reg); + tracing::debug!("Found mapped region containing {:X}: {:#?}", gpa, reg); // Region found - calculate the offset within the region let region_offset = mem_offset.checked_sub(reg.guest_region.start).ok_or_else(|| { - log::warn!( + tracing::warn!( "Cannot calculate offset in memory region: mem_offset={:#X}, base={:#X}", mem_offset, reg.guest_region.start, @@ -136,7 +136,7 @@ impl DebugMemoryAccess { } if !region_found { - log::debug!( + tracing::debug!( "No mapped region found containing {:X}. Trying shared memory ...", gpa ); @@ -165,7 +165,7 @@ impl DebugMemoryAccess { let mem_offset = (gpa as usize) .checked_sub(SandboxMemoryLayout::BASE_ADDRESS) .ok_or_else(|| { - log::warn!( + tracing::warn!( "gpa={:#X} causes subtract with underflow: \"gpa - BASE_ADDRESS={:#X}-{:#X}\"", gpa, gpa, @@ -178,11 +178,11 @@ impl DebugMemoryAccess { let mut region_found = false; for reg in self.guest_mmap_regions.iter() { if reg.guest_region.contains(&mem_offset) { - log::debug!("Found mapped region containing {:X}: {:#?}", gpa, reg); + tracing::debug!("Found mapped region containing {:X}: {:#?}", gpa, reg); // Region found - calculate the offset within the region let region_offset = mem_offset.checked_sub(reg.guest_region.start).ok_or_else(|| { - log::warn!( + tracing::warn!( "Cannot calculate offset in memory region: mem_offset={:#X}, base={:#X}", mem_offset, reg.guest_region.start, @@ -204,7 +204,7 @@ impl DebugMemoryAccess { } if !region_found { - log::debug!( + tracing::debug!( "No mapped region found containing {:X}. Trying shared memory at offset {:X} ...", gpa, mem_offset @@ -344,14 +344,14 @@ pub(crate) fn create_gdb_thread( let (gdb_conn, hyp_conn) = DebugCommChannel::unbounded(); let socket = format!("localhost:{}", port); - log::info!("Listening on {:?}", socket); + tracing::info!("Listening on {:?}", socket); let listener = TcpListener::bind(socket)?; - log::info!("Starting GDB thread"); + tracing::info!("Starting GDB thread"); let _handle = thread::Builder::new() .name("GDB handler".to_string()) .spawn(move || -> Result<(), GdbTargetError> { - log::info!("Waiting for GDB connection ... "); + tracing::info!("Waiting for GDB connection ... "); let (conn, _) = listener.accept()?; let conn: Box> = Box::new(conn); @@ -362,7 +362,7 @@ pub(crate) fn create_gdb_thread( // Waits for vCPU to stop at entrypoint breakpoint let msg = target.recv()?; if let DebugResponse::InterruptHandle(handle) = msg { - log::info!("Received interrupt handle: {:?}", handle); + tracing::info!("Received interrupt handle: {:?}", handle); target.set_interrupt_handle(handle); } else { return Err(GdbTargetError::UnexpectedMessage); diff --git a/src/hyperlight_host/src/hypervisor/gdb/x86_64_target.rs b/src/hyperlight_host/src/hypervisor/gdb/x86_64_target.rs index 7ba38fc48..f5950039b 100644 --- a/src/hyperlight_host/src/hypervisor/gdb/x86_64_target.rs +++ b/src/hyperlight_host/src/hypervisor/gdb/x86_64_target.rs @@ -77,18 +77,18 @@ impl HyperlightSandboxTarget { /// Sends an event to the Hypervisor that tells it to resume vCPU execution /// Note: The method waits for a confirmation message pub(crate) fn resume_vcpu(&mut self) -> Result<(), GdbTargetError> { - log::info!("Resume vCPU execution"); + tracing::info!("Resume vCPU execution"); match self.send_command(DebugMsg::Continue)? { DebugResponse::Continue => Ok(()), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Ok(()) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(GdbTargetError::UnexpectedMessage) } } @@ -103,16 +103,16 @@ impl HyperlightSandboxTarget { /// and continue executing /// Note: The method waits for a confirmation message pub(crate) fn disable_debug(&mut self) -> Result<(), GdbTargetError> { - log::info!("Disable debugging and resume execution"); + tracing::info!("Disable debugging and resume execution"); match self.send_command(DebugMsg::DisableDebug)? { DebugResponse::DisableDebug => Ok(()), DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(GdbTargetError::UnexpectedError) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(GdbTargetError::UnexpectedMessage) } } @@ -123,7 +123,7 @@ impl HyperlightSandboxTarget { if let Some(handle) = &self.interrupt_handle { handle.kill_from_debugger() } else { - log::warn!("No interrupt handle set, cannot interrupt vCPU"); + tracing::warn!("No interrupt handle set, cannot interrupt vCPU"); false } @@ -156,7 +156,7 @@ impl SingleThreadBase for HyperlightSandboxTarget { gva: ::Usize, data: &mut [u8], ) -> TargetResult { - log::debug!("Read addr: {:X} len: {:X}", gva, data.len()); + tracing::debug!("Read addr: {:X} len: {:X}", gva, data.len()); match self.send_command(DebugMsg::ReadAddr(gva, data.len()))? { DebugResponse::ReadAddr(v) => { @@ -165,11 +165,11 @@ impl SingleThreadBase for HyperlightSandboxTarget { Ok(v.len()) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -180,23 +180,23 @@ impl SingleThreadBase for HyperlightSandboxTarget { gva: ::Usize, data: &[u8], ) -> TargetResult<(), Self> { - log::debug!("Write addr: {:X} len: {:X}", gva, data.len()); + tracing::debug!("Write addr: {:X} len: {:X}", gva, data.len()); let v = Vec::from(data); match self.send_command(DebugMsg::WriteAddr(gva, v))? { DebugResponse::WriteAddr => Ok(()), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Ok(()) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -206,7 +206,7 @@ impl SingleThreadBase for HyperlightSandboxTarget { &mut self, regs: &mut ::Registers, ) -> TargetResult<(), Self> { - log::debug!("Read regs"); + tracing::debug!("Read regs"); match self.send_command(DebugMsg::ReadRegisters)? { DebugResponse::ReadRegisters(boxed_regs) => { @@ -236,12 +236,12 @@ impl SingleThreadBase for HyperlightSandboxTarget { Ok(()) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -251,7 +251,7 @@ impl SingleThreadBase for HyperlightSandboxTarget { &mut self, regs: &::Registers, ) -> TargetResult<(), Self> { - log::debug!("Write regs"); + tracing::debug!("Write regs"); let common_regs = CommonRegisters { rax: regs.regs[0], @@ -291,17 +291,17 @@ impl SingleThreadBase for HyperlightSandboxTarget { ))))? { DebugResponse::WriteRegisters => Ok(()), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Ok(()) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -314,7 +314,7 @@ impl SingleThreadBase for HyperlightSandboxTarget { impl SectionOffsets for HyperlightSandboxTarget { fn get_section_offsets(&mut self) -> Result::Usize>, Self::Error> { - log::debug!("Get section offsets"); + tracing::debug!("Get section offsets"); match self.send_command(DebugMsg::GetCodeSectionOffset)? { DebugResponse::GetCodeSectionOffset(text) => Ok(Offsets::Segments { @@ -322,11 +322,11 @@ impl SectionOffsets for HyperlightSandboxTarget { data_seg: None, }), DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(GdbTargetError::UnexpectedError) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(GdbTargetError::UnexpectedMessage) } } @@ -348,22 +348,22 @@ impl HwBreakpoint for HyperlightSandboxTarget { addr: ::Usize, _kind: ::BreakpointKind, ) -> TargetResult { - log::debug!("Add hw breakpoint at address {:X}", addr); + tracing::debug!("Add hw breakpoint at address {:X}", addr); match self.send_command(DebugMsg::AddHwBreakpoint(addr))? { DebugResponse::AddHwBreakpoint(rsp) => Ok(rsp), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Err(TargetError::NonFatal) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -374,22 +374,22 @@ impl HwBreakpoint for HyperlightSandboxTarget { addr: ::Usize, _kind: ::BreakpointKind, ) -> TargetResult { - log::debug!("Remove hw breakpoint at address {:X}", addr); + tracing::debug!("Remove hw breakpoint at address {:X}", addr); match self.send_command(DebugMsg::RemoveHwBreakpoint(addr))? { DebugResponse::RemoveHwBreakpoint(rsp) => Ok(rsp), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Err(TargetError::NonFatal) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -402,22 +402,22 @@ impl SwBreakpoint for HyperlightSandboxTarget { addr: ::Usize, _kind: ::BreakpointKind, ) -> TargetResult { - log::debug!("Add sw breakpoint at address {:X}", addr); + tracing::debug!("Add sw breakpoint at address {:X}", addr); match self.send_command(DebugMsg::AddSwBreakpoint(addr))? { DebugResponse::AddSwBreakpoint(rsp) => Ok(rsp), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Err(TargetError::NonFatal) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -428,22 +428,22 @@ impl SwBreakpoint for HyperlightSandboxTarget { addr: ::Usize, _kind: ::BreakpointKind, ) -> TargetResult { - log::debug!("Remove sw breakpoint at address {:X}", addr); + tracing::debug!("Remove sw breakpoint at address {:X}", addr); match self.send_command(DebugMsg::RemoveSwBreakpoint(addr))? { DebugResponse::RemoveSwBreakpoint(rsp) => Ok(rsp), DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Err(TargetError::NonFatal) } DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(TargetError::NonFatal) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(TargetError::Fatal(GdbTargetError::UnexpectedMessage)) } } @@ -454,7 +454,7 @@ impl SingleThreadResume for HyperlightSandboxTarget { /// Resumes the execution of the vCPU /// Note: We do not handle signals passed to this method fn resume(&mut self, _signal: Option) -> Result<(), Self::Error> { - log::debug!("Resume"); + tracing::debug!("Resume"); self.resume_vcpu() } fn support_single_step(&mut self) -> Option> { @@ -466,21 +466,21 @@ impl SingleThreadSingleStep for HyperlightSandboxTarget { /// Steps the vCPU execution by /// Note: We do not handle signals passed to this method fn step(&mut self, _signal: Option) -> Result<(), Self::Error> { - log::debug!("Step"); + tracing::debug!("Step"); match self.send_command(DebugMsg::Step)? { DebugResponse::Step => Ok(()), DebugResponse::ErrorOccurred => { - log::error!("Error occurred"); + tracing::error!("Error occurred"); Err(GdbTargetError::UnexpectedError) } DebugResponse::NotAllowed => { - log::error!("Action not allowed at this time, crash might have occurred"); + tracing::error!("Action not allowed at this time, crash might have occurred"); // This is a consequence of the target crashing or being in an invalid state // we cannot continue execution, but we can still read registers and memory Ok(()) } msg => { - log::error!("Unexpected message received: {:?}", msg); + tracing::error!("Unexpected message received: {:?}", msg); Err(GdbTargetError::UnexpectedMessage) } } diff --git a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs index e9edd9957..a6853a13c 100644 --- a/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs +++ b/src/hyperlight_host/src/hypervisor/hyperlight_vm.rs @@ -416,7 +416,7 @@ impl HyperlightVm { if let Err(e) = tc.handle_trace(®s, mem_mgr) { // If no trace data is available, we just log a message and continue // Is this the right thing to do? - log::debug!("Error handling guest trace: {:?}", e); + tracing::debug!("Error handling guest trace: {:?}", e); } } result @@ -632,7 +632,7 @@ impl HyperlightVm { })?; loop { - log::debug!("Debug wait for event to resume vCPU"); + tracing::debug!("Debug wait for event to resume vCPU"); // Wait for a message from gdb let req = self.recv_dbg_msg()?; @@ -671,7 +671,7 @@ impl HyperlightVm { DebugResponse::ErrorOccurred } Err(e) => { - log::error!("Error processing debug request: {:?}", e); + tracing::error!("Error processing debug request: {:?}", e); return Err(e); } } @@ -707,7 +707,7 @@ impl HyperlightVm { })?; loop { - log::debug!("Debug wait for event to resume vCPU"); + tracing::debug!("Debug wait for event to resume vCPU"); // Wait for a message from gdb let req = self.recv_dbg_msg()?; @@ -860,7 +860,7 @@ mod debug { self.vm .add_hw_breakpoint(addr) .map_err(|e| { - log::error!("Failed to add hw breakpoint: {:?}", e); + tracing::error!("Failed to add hw breakpoint: {:?}", e); e }) @@ -869,7 +869,7 @@ mod debug { DebugMsg::AddSwBreakpoint(addr) => Ok(DebugResponse::AddSwBreakpoint( self.add_sw_breakpoint(addr, mem_access) .map_err(|e| { - log::error!("Failed to add sw breakpoint: {:?}", e); + tracing::error!("Failed to add sw breakpoint: {:?}", e); e }) @@ -877,7 +877,7 @@ mod debug { )), DebugMsg::Continue => { self.vm.set_single_step(false).map_err(|e| { - log::error!("Failed to continue execution: {:?}", e); + tracing::error!("Failed to continue execution: {:?}", e); e })?; @@ -886,7 +886,7 @@ mod debug { } DebugMsg::DisableDebug => { self.vm.set_debug(false).map_err(|e| { - log::error!("Failed to disable debugging: {:?}", e); + tracing::error!("Failed to disable debugging: {:?}", e); e })?; @@ -908,7 +908,7 @@ mod debug { let mut data = vec![0u8; len]; self.read_addrs(addr, &mut data, mem_access).map_err(|e| { - log::error!("Failed to read from address: {:?}", e); + tracing::error!("Failed to read from address: {:?}", e); e })?; @@ -924,7 +924,7 @@ mod debug { self.vm .remove_hw_breakpoint(addr) .map_err(|e| { - log::error!("Failed to remove hw breakpoint: {:?}", e); + tracing::error!("Failed to remove hw breakpoint: {:?}", e); e }) @@ -933,7 +933,7 @@ mod debug { DebugMsg::RemoveSwBreakpoint(addr) => Ok(DebugResponse::RemoveSwBreakpoint( self.remove_sw_breakpoint(addr, mem_access) .map_err(|e| { - log::error!("Failed to remove sw breakpoint: {:?}", e); + tracing::error!("Failed to remove sw breakpoint: {:?}", e); e }) @@ -941,7 +941,7 @@ mod debug { )), DebugMsg::Step => { self.vm.set_single_step(true).map_err(|e| { - log::error!("Failed to enable step instruction: {:?}", e); + tracing::error!("Failed to enable step instruction: {:?}", e); e })?; @@ -950,7 +950,7 @@ mod debug { } DebugMsg::WriteAddr(addr, data) => { self.write_addrs(addr, &data, mem_access).map_err(|e| { - log::error!("Failed to write to address: {:?}", e); + tracing::error!("Failed to write to address: {:?}", e); e })?; @@ -985,7 +985,7 @@ mod debug { } pub(crate) fn send_dbg_msg(&mut self, cmd: DebugResponse) -> Result<()> { - log::debug!("Sending {:?}", cmd); + tracing::debug!("Sending {:?}", cmd); let gdb_conn = self .gdb_conn @@ -1007,7 +1007,7 @@ mod debug { mem_access: &DebugMemoryAccess, ) -> crate::Result<()> { let data_len = data.len(); - log::debug!("Read addr: {:X} len: {:X}", gva, data_len); + tracing::debug!("Read addr: {:X} len: {:X}", gva, data_len); while !data.is_empty() { let gpa = self.vm.translate_gva(gva)?; @@ -1035,7 +1035,7 @@ mod debug { mem_access: &DebugMemoryAccess, ) -> crate::Result<()> { let data_len = data.len(); - log::debug!("Write addr: {:X} len: {:X}", gva, data_len); + tracing::debug!("Write addr: {:X} len: {:X}", gva, data_len); while !data.is_empty() { let gpa = self.vm.translate_gva(gva)?; diff --git a/src/hyperlight_host/src/hypervisor/hyperv_windows.rs b/src/hyperlight_host/src/hypervisor/hyperv_windows.rs index cc6876a5b..fe1afb810 100644 --- a/src/hyperlight_host/src/hypervisor/hyperv_windows.rs +++ b/src/hyperlight_host/src/hypervisor/hyperv_windows.rs @@ -52,7 +52,7 @@ pub(crate) fn is_hypervisor_present() -> bool { } { Ok(_) => unsafe { capability.HypervisorPresent.as_bool() }, Err(_) => { - log::info!("Windows Hypervisor Platform is not available on this system"); + tracing::info!("Windows Hypervisor Platform is not available on this system"); false } } @@ -675,7 +675,7 @@ impl Drop for WhpVm { // (HyperlightVm::drop() runs before its fields are dropped, so // set_dropped() completes before this Drop impl runs.) if let Err(e) = unsafe { WHvDeletePartition(self.partition) } { - log::error!("Failed to delete partition: {}", e); + tracing::error!("Failed to delete partition: {}", e); } } } diff --git a/src/hyperlight_host/src/hypervisor/mod.rs b/src/hyperlight_host/src/hypervisor/mod.rs index e1d616935..cb76ae589 100644 --- a/src/hyperlight_host/src/hypervisor/mod.rs +++ b/src/hyperlight_host/src/hypervisor/mod.rs @@ -512,7 +512,7 @@ impl InterruptHandleImpl for WindowsInterruptHandle { guard.dropped = true; } Err(e) => { - log::error!("Failed to acquire partition_state write lock: {}", e); + tracing::error!("Failed to acquire partition_state write lock: {}", e); } } } @@ -540,7 +540,7 @@ impl InterruptHandle for WindowsInterruptHandle { let guard = match self.partition_state.read() { Ok(guard) => guard, Err(e) => { - log::error!("Failed to acquire partition_state read lock: {}", e); + tracing::error!("Failed to acquire partition_state read lock: {}", e); return false; } }; @@ -568,7 +568,7 @@ impl InterruptHandle for WindowsInterruptHandle { let guard = match self.partition_state.read() { Ok(guard) => guard, Err(e) => { - log::error!("Failed to acquire partition_state read lock: {}", e); + tracing::error!("Failed to acquire partition_state read lock: {}", e); return false; } }; @@ -585,7 +585,7 @@ impl InterruptHandle for WindowsInterruptHandle { match self.partition_state.read() { Ok(guard) => guard.dropped, Err(e) => { - log::error!("Failed to acquire partition_state read lock: {}", e); + tracing::error!("Failed to acquire partition_state read lock: {}", e); true // Assume dropped if we can't acquire lock } } diff --git a/src/hyperlight_host/src/sandbox/trace/context.rs b/src/hyperlight_host/src/sandbox/trace/context.rs index c885a1732..9f0e996e8 100644 --- a/src/hyperlight_host/src/sandbox/trace/context.rs +++ b/src/hyperlight_host/src/sandbox/trace/context.rs @@ -130,7 +130,7 @@ impl TraceContext { if !hyperlight_guest_tracing::invariant_tsc::has_invariant_tsc() { // If the platform does not support invariant TSC, warn the user. // On Azure nested virtualization, the TSC invariant bit is not correctly reported, this is a known issue. - log::warn!( + tracing::warn!( "Invariant TSC is not supported on this platform, trace timestamps may be inaccurate" ); } @@ -170,7 +170,7 @@ impl TraceContext { // This is a fallback mechanism to ensure that we can still calculate, however it // should be noted that this may lead to inaccuracies in the TSC frequency. // The start time should be already set before running the guest for each sandbox. - log::error!( + tracing::error!( "Guest start TSC and time are not set. Calculating TSC frequency will use current time and TSC." ); ( @@ -186,7 +186,7 @@ impl TraceContext { let elapsed = end_time.duration_since(start_time).as_secs_f64(); let tsc_freq = ((end - start) as f64 / elapsed) as u64; - log::info!("Calculated TSC frequency: {} Hz", tsc_freq); + tracing::info!("Calculated TSC frequency: {} Hz", tsc_freq); self.tsc_freq = Some(tsc_freq); Ok(()) @@ -400,7 +400,7 @@ impl Drop for TraceContext { fn drop(&mut self) { for (k, mut v) in self.guest_spans.drain() { v.end(); - log::debug!("Dropped guest span with id {}", k); + tracing::debug!("Dropped guest span with id {}", k); } while let Some(entered) = self.host_spans.pop() { entered.exit(); diff --git a/src/hyperlight_host/src/sandbox/trace/mem_profile.rs b/src/hyperlight_host/src/sandbox/trace/mem_profile.rs index f181b0a7e..c4ac05f00 100644 --- a/src/hyperlight_host/src/sandbox/trace/mem_profile.rs +++ b/src/hyperlight_host/src/sandbox/trace/mem_profile.rs @@ -62,7 +62,7 @@ impl MemTraceInfo { path.push(uuid::Uuid::new_v4().to_string()); path.set_extension("trace"); - log::info!("Creating trace file at: {}", path.display()); + tracing::info!("Creating trace file at: {}", path.display()); println!("Creating trace file at: {}", path.display()); let hash = unwind_module.hash(); diff --git a/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs b/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs index 87870b3a2..ba2ada67d 100644 --- a/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs +++ b/src/hyperlight_host/src/sandbox/uninitialized_evolve.rs @@ -153,7 +153,7 @@ pub(crate) fn set_up_hypervisor_partition( match gdb_conn { Ok(gdb_conn) => Some(gdb_conn), Err(e) => { - log::error!("Could not create gdb connection: {:#}", e); + tracing::error!("Could not create gdb connection: {:#}", e); None } diff --git a/src/hyperlight_host/tests/integration_test.rs b/src/hyperlight_host/tests/integration_test.rs index 4c4b3b714..0788ab512 100644 --- a/src/hyperlight_host/tests/integration_test.rs +++ b/src/hyperlight_host/tests/integration_test.rs @@ -742,12 +742,12 @@ fn log_message() { }; let tests = vec![ - (LevelFilter::Trace, 5 + num_fixed_trace_log), - (LevelFilter::Debug, 4), - (LevelFilter::Info, 3), - (LevelFilter::Warn, 2), - (LevelFilter::Error, 1), - (LevelFilter::Off, 0), + (LevelFilter::TRACE, 5 + num_fixed_trace_log), + (LevelFilter::DEBUG, 4), + (LevelFilter::INFO, 3), + (LevelFilter::WARN, 2), + (LevelFilter::ERROR, 1), + (LevelFilter::OFF, 0), ]; // init @@ -785,10 +785,19 @@ fn log_message() { assert_eq!(1, LOGGER.num_log_calls()); } -fn log_test_messages(levelfilter: Option) { +fn log_test_messages(levelfilter: Option) { LOGGER.clear_log_calls(); assert_eq!(0, LOGGER.num_log_calls()); - for level in log::LevelFilter::iter() { + let all_level_filters: Vec<(LevelFilter, i32)> = vec![ + (LevelFilter::OFF, 6), + (LevelFilter::ERROR, 4), + (LevelFilter::WARN, 3), + (LevelFilter::INFO, 2), + (LevelFilter::DEBUG, 1), + (LevelFilter::TRACE, 0), + ]; + + for (level, level_i32) in all_level_filters { let mut sbox = new_uninit().unwrap(); if let Some(levelfilter) = levelfilter { sbox.set_max_guest_log_level(levelfilter); @@ -796,9 +805,9 @@ fn log_test_messages(levelfilter: Option) { let mut sbox1 = sbox.evolve().unwrap(); - let message = format!("Hello from log_message level {}", level as i32); + let message = format!("Hello from log_message level {}", level_i32); sbox1 - .call::<()>("LogMessage", (message.to_string(), level as i32)) + .call::<()>("LogMessage", (message.to_string(), level_i32)) .unwrap(); } } @@ -914,7 +923,7 @@ fn interrupt_random_kill_stress_test() { use std::sync::atomic::AtomicUsize; use hyperlight_host::sandbox::snapshot::Snapshot; - use log::{error, trace}; + use tracing::{error, trace}; const POOL_SIZE: usize = 100; const NUM_THREADS: usize = 100;