diff --git a/src/migtd/src/bin/migtd/main.rs b/src/migtd/src/bin/migtd/main.rs index 4e711a41f..015861a2f 100644 --- a/src/migtd/src/bin/migtd/main.rs +++ b/src/migtd/src/bin/migtd/main.rs @@ -102,7 +102,7 @@ pub fn runtime_main() { { // Initialize logging with level filter. The actual log level is determined by // compile-time feature flags. - let _ = td_logger::init(log::LevelFilter::Trace); + let _ = td_logger::init(log::LevelFilter::Info); } // Create LogArea per vCPU diff --git a/src/migtd/src/migration/logging.rs b/src/migtd/src/migration/logging.rs index 941206d30..f449161d3 100644 --- a/src/migtd/src/migration/logging.rs +++ b/src/migtd/src/migration/logging.rs @@ -275,6 +275,7 @@ pub async fn enable_logarea(log_max_level: u8, request_id: u64, data: &mut Vec, loglevel: Level, request_id: u64) { + if loglevel > Level::Info { + return; + } let logarea_initialized: bool = LOGGING_INFORMATION .logarea_initialized .load(Ordering::SeqCst); @@ -642,24 +646,13 @@ impl log::Log for VmmLoggerBackend { log_max_level = u8_to_levelfilter(LOGGING_INFORMATION.maxloglevel.load(Ordering::SeqCst)); } else if provisional_logs_enabled { - // Provisional records are captured into private buffers and copied into - // the VMM-readable shared area when EnableLogArea succeeds. In release - // images cap the provisional level at Info as well, so sensitive - // Debug/Trace material cannot reach the shared area through this path. - #[cfg(debug_assertions)] - { - log_max_level = LevelFilter::Trace; - } - #[cfg(not(debug_assertions))] - { - log_max_level = LevelFilter::Info; - } + log_max_level = LevelFilter::Info; } else { log_max_level = log::max_level(); } let log_level = metadata.level(); - log_level <= log_max_level + log_level <= log_max_level.min(LevelFilter::Info) } fn log(&self, record: &Record) { @@ -706,7 +699,7 @@ static VM_LOGGER_BACKEND: VmmLoggerBackend = VmmLoggerBackend; /// Initialize the VMM logger as the global logger pub fn init_vmm_logger() -> core::result::Result<(), SetLoggerError> { - log::set_logger(&VM_LOGGER_BACKEND).map(|()| log::set_max_level(LevelFilter::Trace)) + log::set_logger(&VM_LOGGER_BACKEND).map(|()| log::set_max_level(LevelFilter::Info)) } #[cfg(test)] @@ -752,6 +745,14 @@ mod test { assert!(provisional_logs_enabled); assert!(!logarea_initialized); + for level in [Level::Info, Level::Debug, Level::Trace] { + let metadata = Metadata::builder().level(level).build(); + assert_eq!( + log::Log::enabled(&VM_LOGGER_BACKEND, &metadata), + level == Level::Info + ); + } + // Test utility functions assert_eq!(loglevel_to_u8(Level::Error), 1); assert_eq!(loglevel_to_u8(Level::Info), 3); @@ -805,6 +806,15 @@ mod test { .load(Ordering::SeqCst); assert!(!provisional_logs_enabled); assert!(logarea_initialized); + assert_eq!(log::max_level(), LevelFilter::Info); + assert_eq!(LOGGING_INFORMATION.maxloglevel.load(Ordering::SeqCst), 3); + for level in [Level::Info, Level::Debug, Level::Trace] { + let metadata = Metadata::builder().level(level).build(); + assert_eq!( + log::Log::enabled(&VM_LOGGER_BACKEND, &metadata), + level == Level::Info + ); + } let mut logareavector = LOGAREAPTR.lock(); let data_buffer = logareavector[0]; @@ -849,9 +859,16 @@ mod test { assert!(result.is_ok()); // Add a log entry + for level in [Level::Debug, Level::Trace] { + entrylog(&b"Suppressed provisional log\n".to_vec(), level, u64::MAX); + } + assert_eq!( + LOGGING_INFORMATION.logentry_id.load(Ordering::SeqCst), + initial_entry_id + ); entrylog( &"Test provisional log\n".to_string().into_bytes(), - Level::Trace, + Level::Info, u64::MAX, ); @@ -888,7 +905,7 @@ mod test { assert_eq!(log_entry_id, 1); assert_eq!(mig_request_id, u64::MAX); - assert_eq!(loglevel, loglevel_to_u8(Level::Trace)); + assert_eq!(loglevel, loglevel_to_u8(Level::Info)); assert_eq!(length, "Test provisional log\n".len() as u32); logareavector.clear(); @@ -938,9 +955,16 @@ mod test { assert!(result.is_ok()); // Add a log entry + for level in [Level::Debug, Level::Trace] { + entrylog(&b"Suppressed shared log\n".to_vec(), level, u64::MAX); + } + assert_eq!( + LOGGING_INFORMATION.logentry_id.load(Ordering::SeqCst), + initial_entry_id + ); entrylog( &"Test message\n".to_string().into_bytes(), - Level::Trace, + Level::Info, u64::MAX, ); @@ -977,7 +1001,7 @@ mod test { assert_eq!(log_entry_id, 1); assert_eq!(mig_request_id, u64::MAX); - assert_eq!(loglevel, loglevel_to_u8(Level::Trace)); + assert_eq!(loglevel, loglevel_to_u8(Level::Info)); assert_eq!(length, "Test message\n".len() as u32); logareavector.clear(); @@ -1025,7 +1049,7 @@ mod test { let provisional_msg = "Test provisional log\n"; entrylog( &provisional_msg.to_string().into_bytes(), - Level::Trace, + Level::Info, u64::MAX, ); assert_eq!(LOGGING_INFORMATION.logentry_id.load(Ordering::SeqCst), 1); @@ -1053,7 +1077,7 @@ mod test { assert_eq!(entry_log_entry_id, 1); assert_eq!(entry_mig_request_id, u64::MAX); - assert_eq!(entry_loglevel, loglevel_to_u8(Level::Trace)); + assert_eq!(entry_loglevel, loglevel_to_u8(Level::Info)); assert_eq!(entry_length, provisional_msg.len() as u32); } @@ -1096,7 +1120,7 @@ mod test { assert_eq!(first_entry_log_entry_id, 1); assert_eq!(first_entry_mig_request_id, u64::MAX); - assert_eq!(first_entry_loglevel, loglevel_to_u8(Level::Trace)); + assert_eq!(first_entry_loglevel, loglevel_to_u8(Level::Info)); assert_eq!(first_entry_length, provisional_msg.len() as u32); assert_eq!( core::str::from_utf8(&data_buffer[first_msg_start..first_msg_end]).unwrap(), diff --git a/xtask/src/build.rs b/xtask/src/build.rs index 9b9e50adf..6453fce60 100644 --- a/xtask/src/build.rs +++ b/xtask/src/build.rs @@ -77,7 +77,7 @@ pub(crate) struct BuildArgs { /// Path of the configuration file for td-shim image layout #[clap(long)] image_layout: Option, - /// Log level control in migtd, default value is `off` for release and `info` for debug + /// Log level for MigTD and dependencies, capped at `info`; defaults to `off` for release and `info` for debug #[clap(short, long)] log_level: Option, /// MMIO space layout configuration for migtd @@ -121,9 +121,7 @@ impl LogLevel { LogLevel::Off => "log/max_level_off", LogLevel::Error => "log/max_level_error", LogLevel::Warn => "log/max_level_warn", - LogLevel::Info => "log/max_level_info", - LogLevel::Debug => "log/max_level_debug", - LogLevel::Trace => "log/max_level_trace", + LogLevel::Info | LogLevel::Debug | LogLevel::Trace => "log/max_level_info", } } @@ -132,9 +130,7 @@ impl LogLevel { LogLevel::Off => "log/release_max_level_off", LogLevel::Error => "log/release_max_level_error", LogLevel::Warn => "log/release_max_level_warn", - LogLevel::Info => "log/release_max_level_info", - LogLevel::Debug => "log/release_max_level_debug", - LogLevel::Trace => "log/release_max_level_trace", + LogLevel::Info | LogLevel::Debug | LogLevel::Trace => "log/release_max_level_info", } } } @@ -464,70 +460,10 @@ impl BuildArgs { features.push_str(","); if self.debug { println!("Building debug MigTD"); - match self.log_level { - Some(loglevel) => match loglevel { - LogLevel::Off => { - println!("Building debug MigTD found loglevel=Off), overriding to Info"); - features.push_str(LogLevel::Info.debug_feature()); - } - LogLevel::Error => { - println!("Building debug MigTD found loglevel=Error"); - features.push_str(loglevel.debug_feature()); - } - LogLevel::Warn => { - println!("Building debug MigTD found loglevel=Warn"); - features.push_str(loglevel.debug_feature()); - } - LogLevel::Info => { - println!("Building debug MigTD found loglevel=Info"); - features.push_str(loglevel.debug_feature()); - } - LogLevel::Debug => { - println!("Building debug MigTD found loglevel=Debug"); - features.push_str(loglevel.debug_feature()); - } - LogLevel::Trace => { - println!("Building debug MigTD found loglevel=Trace"); - features.push_str(loglevel.debug_feature()); - } - }, - _ => { - println!("Building debug MigTD found None(loglevel)"); - } - } + features.push_str(self.log_level.unwrap_or(LogLevel::Info).debug_feature()); } else { println!("Building release MigTD"); - match self.log_level { - Some(loglevel) => match loglevel { - LogLevel::Off => { - println!("Building release MigTD found loglevel=Off), overriding to Info"); - features.push_str(LogLevel::Info.release_feature()); - } - LogLevel::Error => { - println!("Building release MigTD found loglevel=Error"); - features.push_str(loglevel.release_feature()); - } - LogLevel::Warn => { - println!("Building release MigTD found loglevel=Warn"); - features.push_str(loglevel.release_feature()); - } - LogLevel::Info => { - println!("Building release MigTD found loglevel=Info"); - features.push_str(loglevel.release_feature()); - } - LogLevel::Debug => { - println!("Building release MigTD found loglevel=Debug"); - features.push_str(loglevel.release_feature()); - } - LogLevel::Trace => { - println!("Building release MigTD found loglevel=Trace"); - features.push_str(loglevel.release_feature()); - } - }, - _ => { - println!("Building release MigTD found None(loglevel)"); - } - } + features.push_str(self.log_level.unwrap_or(LogLevel::Off).release_feature()); } features @@ -612,3 +548,56 @@ impl BuildArgs { fs::canonicalize(path).map_err(|e| e.into()) } } + +#[cfg(test)] +mod tests { + use super::BuildArgs; + use clap::Parser; + + #[derive(Parser)] + struct TestArgs { + #[clap(flatten)] + build: BuildArgs, + } + + #[test] + fn log_level_features() { + for debug in [false, true] { + for level in [ + None, + Some("off"), + Some("error"), + Some("warn"), + Some("info"), + Some("debug"), + Some("trace"), + ] { + let mut args = vec!["test"]; + if debug { + args.push("--debug"); + } + if let Some(level) = level { + args.extend(["--log-level", level]); + } + let build = TestArgs::parse_from(args).build; + let prefix = if debug { + "max_level" + } else { + "release_max_level" + }; + let expected_level = level.unwrap_or(if debug { "info" } else { "off" }); + let expected_level = match expected_level { + "debug" | "trace" => "info", + level => level, + }; + let expected = format!("log/{prefix}_{expected_level}"); + let features = build.features(); + let log_features: Vec<_> = features + .split(',') + .filter(|feature| feature.starts_with("log/")) + .collect(); + assert_eq!(log_features, vec![expected.as_str()]); + } + } + } +}