From 71ac2a84ad3ca4df3406c3a10610c04682020300 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Wed, 11 Feb 2026 23:06:09 +0000 Subject: [PATCH 01/11] Allow inspect to reprocess UEFI logs with increased log level --- .../firmware_uefi/fuzz/fuzz_diagnostics.rs | 2 +- vm/devices/firmware/firmware_uefi/src/lib.rs | 28 +++++++++++----- .../src/service/diagnostics/mod.rs | 32 +++++++++++++------ 3 files changed, 43 insertions(+), 19 deletions(-) diff --git a/vm/devices/firmware/firmware_uefi/fuzz/fuzz_diagnostics.rs b/vm/devices/firmware/firmware_uefi/fuzz/fuzz_diagnostics.rs index 5890b1304c..c270da2af4 100644 --- a/vm/devices/firmware/firmware_uefi/fuzz/fuzz_diagnostics.rs +++ b/vm/devices/firmware/firmware_uefi/fuzz/fuzz_diagnostics.rs @@ -47,7 +47,7 @@ fn do_fuzz(input: DiagnosticsInput) { // Set GPA to point somewhere in our fuzzed buffer diagnostics.set_gpa(buffer_gpa); - let _ = diagnostics.process_diagnostics(input.allow_reprocess, &gm, |_log| { + let _ = diagnostics.process_diagnostics(input.allow_reprocess, &gm, None, |_log| { // Log handler - just discard logs during fuzzing }); } diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index aa4c6571b0..c93d61f97f 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -276,7 +276,7 @@ impl UefiDevice { self.service.diagnostics.set_gpa(data) } UefiCommand::PROCESS_EFI_DIAGNOSTICS => { - self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD)) + self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD), None) } _ => tracelimit::warn_ratelimited!(addr, data, "unknown uefi write"), } @@ -288,14 +288,26 @@ impl UefiDevice { // NOTE: Today, the inspect source code will fail if we invoke like below // `inspect -u vm/uefi/process_diagnostics`. This is true, even for other // mutable paths in the inspect graph. - if v.is_some() { - self.process_diagnostics(true, None); - Result::<_, std::convert::Infallible>::Ok( - "attempted to process diagnostics through inspect".to_string(), - ) + if let Some(value) = v { + // Parse optional log level override from the input value. + // Any other value (e.g. "1") processes with the configured log level. + let log_level_override = match value { + "default" => Some(LogLevel::make_default()), + "info" => Some(LogLevel::make_info()), + "full" => Some(LogLevel::make_full()), + _ => None, + }; + self.process_diagnostics(true, None, log_level_override); + Result::<_, std::convert::Infallible>::Ok(format!( + "attempted to process diagnostics through inspect (log_level_override: {})", + match value { + "default" | "info" | "full" => value, + _ => "none", + } + )) } else { Result::<_, std::convert::Infallible>::Ok( - "Use: inspect -u 1 vm/uefi/process_diagnostics".to_string(), + "Use: inspect -u vm/uefi/process_diagnostics".to_string(), ) } }); @@ -343,7 +355,7 @@ impl PollDevice for UefiDevice { // NOTE: Do not allow reprocessing diagnostics here. // UEFI programs the watchdog's configuration, so we should assume that // this path could trigger multiple times. - self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD)); + self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD), None); } } } diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs index 9f16beac39..4f1e7c93df 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs @@ -185,11 +185,13 @@ impl DiagnosticsServices { /// # Arguments /// * `allow_reprocess` - If true, allows processing even if already processed for guest /// * `gm` - Guest memory to read diagnostics from + /// * `log_level_override` - If provided, overrides the configured log level for this processing run /// * `log_handler` - Function to handle each parsed log entry pub fn process_diagnostics( &mut self, allow_reprocess: bool, gm: &GuestMemory, + log_level_override: Option, log_handler: F, ) -> Result<(), ProcessingError> where @@ -204,8 +206,11 @@ impl DiagnosticsServices { // Mark as processed first to prevent guest spam (even on failure) self.processed = true; + // Use the override log level if provided, otherwise fall back to configured level + let effective_log_level = log_level_override.unwrap_or(self.log_level); + // Delegate to the processor module - processor::process_diagnostics_internal(self.gpa, gm, self.log_level, log_handler) + processor::process_diagnostics_internal(self.gpa, gm, effective_log_level, log_handler) } } @@ -218,15 +223,22 @@ impl UefiDevice { /// # Arguments /// * `allow_reprocess` - If true, allows processing even if already processed for guest /// * `limit` - Maximum number of logs to process per period, or `None` for no limit - pub(crate) fn process_diagnostics(&mut self, allow_reprocess: bool, limit: Option) { - if let Err(error) = - self.service - .diagnostics - .process_diagnostics(allow_reprocess, &self.gm, |log| match limit { - Some(limit) => emit_log_ratelimited(log, limit), - None => emit_log_unrestricted(log), - }) - { + /// * `log_level_override` - If provided, overrides the configured log level filter for this run + pub(crate) fn process_diagnostics( + &mut self, + allow_reprocess: bool, + limit: Option, + log_level_override: Option, + ) { + if let Err(error) = self.service.diagnostics.process_diagnostics( + allow_reprocess, + &self.gm, + log_level_override, + |log| match limit { + Some(limit) => emit_log_ratelimited(log, limit), + None => emit_log_unrestricted(log), + }, + ) { tracelimit::error_ratelimited!( error = &error as &dyn std::error::Error, "failed to process diagnostics buffer" From 42fd1c4b6b0b0dddbfd6ec439f8a627880d2848d Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Fri, 13 Feb 2026 19:23:30 +0000 Subject: [PATCH 02/11] Add capability in ohcldiag --- openhcl/ohcldiag-dev/src/main.rs | 44 +++++++++++++++++++ openvmm/openvmm_entry/src/lib.rs | 5 ++- vm/devices/firmware/firmware_uefi/src/lib.rs | 39 ++++++++++++++++ .../src/service/diagnostics/processor.rs | 4 +- 4 files changed, 88 insertions(+), 4 deletions(-) diff --git a/openhcl/ohcldiag-dev/src/main.rs b/openhcl/ohcldiag-dev/src/main.rs index 1781707532..5e96580da7 100644 --- a/openhcl/ohcldiag-dev/src/main.rs +++ b/openhcl/ohcldiag-dev/src/main.rs @@ -282,6 +282,19 @@ enum Command { #[clap(short('s'), long, default_value = "65535", value_parser = clap::value_parser!(u16).range(1..))] snaplen: u16, }, + /// Processes EFI diagnostics from guest memory and outputs the logs. + /// + /// The log level filter controls which UEFI log entries are emitted. + /// The buffer already contains all log levels; this filter selects + /// which ones to display. + EfiDiagnostics { + /// The log level filter to apply. + /// + /// Accepted values: "default" (errors+warnings), "info" (errors+warnings+info), + /// "full" (all levels). + #[clap(default_value = "full")] + log_level: EfiDiagnosticsLogLevel, + }, } #[derive(Debug, Clone, Args)] @@ -349,6 +362,26 @@ enum CrashType { UhPanic, } +#[derive(Clone, clap::ValueEnum)] +enum EfiDiagnosticsLogLevel { + /// Errors and warnings only + Default, + /// Errors, warnings, and info + Info, + /// All log levels + Full, +} + +impl EfiDiagnosticsLogLevel { + fn as_inspect_value(&self) -> &'static str { + match self { + EfiDiagnosticsLogLevel::Default => "default", + EfiDiagnosticsLogLevel::Info => "info", + EfiDiagnosticsLogLevel::Full => "full", + } + } +} + #[derive(Debug, Error)] #[error("bad environment variable, expected VAR=value")] struct BadEnvString; @@ -874,6 +907,17 @@ pub fn main() -> anyhow::Result<()> { let mut file = create_or_stderr(&output)?; file.write_all(&client.dump_saved_state().await?)?; } + Command::EfiDiagnostics { log_level } => { + let client = new_client(driver.clone(), &vm)?; + let value = client + .update("vm/uefi/efi_diagnostics_dump", log_level.as_inspect_value()) + .await + .context("failed to process EFI diagnostics")?; + match value.kind { + inspect::ValueKind::String(s) => print!("{s}"), + _ => print!("{value}"), + } + } } Ok(()) }) diff --git a/openvmm/openvmm_entry/src/lib.rs b/openvmm/openvmm_entry/src/lib.rs index a9166f11fb..ae2287b945 100644 --- a/openvmm/openvmm_entry/src/lib.rs +++ b/openvmm/openvmm_entry/src/lib.rs @@ -3257,7 +3257,10 @@ async fn run_control(driver: &DefaultDriver, mesh: &VmmMesh, opt: Options) -> an } .await; match value { - Ok(node) => println!("{:#}", node), + Ok(node) => match &node.kind { + inspect::ValueKind::String(s) => println!("{s}"), + _ => println!("{:#}", node), + }, Err(err) => println!("error: {:#}", err), } } else { diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index c93d61f97f..1378c43940 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -311,6 +311,45 @@ impl UefiDevice { ) } }); + + resp.field_mut_with("efi_diagnostics_dump", |v| { + if let Some(value) = v { + let log_level_override = match value { + "default" => Some(LogLevel::make_default()), + "info" => Some(LogLevel::make_info()), + "full" => Some(LogLevel::make_full()), + _ => None, + }; + + use std::fmt::Write; + let mut output = String::new(); + let result = self.service.diagnostics.process_diagnostics( + true, + &self.gm, + log_level_override, + |log| { + let _ = writeln!( + output, + "[{}] [{}] (ticks: {}) {}", + log.debug_level_str(), + log.phase_str(), + log.ticks(), + log.message_trimmed(), + ); + }, + ); + + Result::<_, std::convert::Infallible>::Ok(match result { + Ok(()) if output.is_empty() => "(no diagnostics entries found)".to_string(), + Ok(()) => output, + Err(error) => format!("error processing diagnostics: {error}"), + }) + } else { + Result::<_, std::convert::Infallible>::Ok( + "Use: inspect -u vm/uefi/efi_diagnostics_dump".to_string(), + ) + } + }); } } diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs index e888aeb211..dba2e60722 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs @@ -113,9 +113,7 @@ where gm.read_at(buffer_start_gpa.as_u64(), &mut buffer_data)?; // Process the buffer - LogProcessor::process_buffer(&buffer_data, log_level, log_handler)?; - - Ok(()) + LogProcessor::process_buffer(&buffer_data, log_level, log_handler) } /// Internal processor for log entries with suppression tracking From 470921b0bd63fbef6e3fb0c14fc08316e570c7e6 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Fri, 13 Feb 2026 19:27:13 +0000 Subject: [PATCH 03/11] Set it to default by default --- openhcl/ohcldiag-dev/src/main.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/openhcl/ohcldiag-dev/src/main.rs b/openhcl/ohcldiag-dev/src/main.rs index 5e96580da7..2747cebf2f 100644 --- a/openhcl/ohcldiag-dev/src/main.rs +++ b/openhcl/ohcldiag-dev/src/main.rs @@ -292,7 +292,7 @@ enum Command { /// /// Accepted values: "default" (errors+warnings), "info" (errors+warnings+info), /// "full" (all levels). - #[clap(default_value = "full")] + #[clap(default_value = "default")] log_level: EfiDiagnosticsLogLevel, }, } From 89ae12020f222583e3a4c1dace6c5b39b576a3d8 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Fri, 13 Feb 2026 19:43:32 +0000 Subject: [PATCH 04/11] Fix newlines in inspect output --- openhcl/ohcldiag-dev/src/main.rs | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/openhcl/ohcldiag-dev/src/main.rs b/openhcl/ohcldiag-dev/src/main.rs index 2747cebf2f..09ce8899f3 100644 --- a/openhcl/ohcldiag-dev/src/main.rs +++ b/openhcl/ohcldiag-dev/src/main.rs @@ -531,7 +531,10 @@ pub fn main() -> anyhow::Result<()> { }; let value = client.update(path, update).await?; - println!("{value}"); + match value.kind { + inspect::ValueKind::String(s) => println!("{s}"), + _ => println!("{value}"), + } } else { let timeout = if timeout == 0 { None @@ -589,7 +592,10 @@ pub fn main() -> anyhow::Result<()> { ); let client = new_client(driver.clone(), &vm)?; let value = client.update(path, value).await?; - println!("{value}"); + match value.kind { + inspect::ValueKind::String(s) => println!("{s}"), + _ => println!("{value}"), + } } Command::Start { env, unset, args } => { let client = new_client(driver.clone(), &vm)?; From f606a8cd3992b9af127bcad1befadf8220652114 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Thu, 19 Feb 2026 22:19:46 +0000 Subject: [PATCH 05/11] Fold two inspect nodes to one --- openhcl/ohcldiag-dev/src/main.rs | 29 +++- vm/devices/firmware/firmware_uefi/src/lib.rs | 125 +++++++++--------- .../src/service/diagnostics/mod.rs | 59 +++++++-- 3 files changed, 134 insertions(+), 79 deletions(-) diff --git a/openhcl/ohcldiag-dev/src/main.rs b/openhcl/ohcldiag-dev/src/main.rs index f1dfef9463..2d4f33902c 100644 --- a/openhcl/ohcldiag-dev/src/main.rs +++ b/openhcl/ohcldiag-dev/src/main.rs @@ -306,6 +306,9 @@ enum Command { /// "full" (all levels). #[clap(default_value = "default")] log_level: EfiDiagnosticsLogLevel, + /// The output destination. + #[clap(default_value = "stdout")] + output: EfiDiagnosticsOutput, }, } @@ -394,6 +397,23 @@ impl EfiDiagnosticsLogLevel { } } +#[derive(Clone, clap::ValueEnum)] +enum EfiDiagnosticsOutput { + /// Emit to stdout + Stdout, + /// Emit to tracing + Tracing, +} + +impl EfiDiagnosticsOutput { + fn as_inspect_value(&self) -> &'static str { + match self { + EfiDiagnosticsOutput::Stdout => "stdout", + EfiDiagnosticsOutput::Tracing => "tracing", + } + } +} + #[derive(Debug, Error)] #[error("bad environment variable, expected VAR=value")] struct BadEnvString; @@ -940,10 +960,15 @@ pub fn main() -> anyhow::Result<()> { let mut file = create_or_stderr(&output)?; file.write_all(&client.memory_profile_trace(pid).await?)?; } - Command::EfiDiagnostics { log_level } => { + Command::EfiDiagnostics { log_level, output } => { let client = new_client(driver.clone(), &vm)?; + let arg = format!( + "{},{}", + log_level.as_inspect_value(), + output.as_inspect_value() + ); let value = client - .update("vm/uefi/efi_diagnostics_dump", log_level.as_inspect_value()) + .update("vm/uefi/dump_efi_diagnostics", &arg) .await .context("failed to process EFI diagnostics")?; match value.kind { diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index 1378c43940..3f148842d4 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -276,7 +276,13 @@ impl UefiDevice { self.service.diagnostics.set_gpa(data) } UefiCommand::PROCESS_EFI_DIAGNOSTICS => { - self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD), None) + let _ = self.process_diagnostics( + false, + service::diagnostics::DiagnosticsEmitter::Tracing { + limit: Some(DEFAULT_LOGS_PER_PERIOD), + }, + None, + ); } _ => tracelimit::warn_ratelimited!(addr, data, "unknown uefi write"), } @@ -284,70 +290,55 @@ impl UefiDevice { /// Extra inspection fields for the UEFI device. fn inspect_extra(&mut self, resp: &mut inspect::Response<'_>) { - resp.field_mut_with("process_diagnostics", |v| { - // NOTE: Today, the inspect source code will fail if we invoke like below - // `inspect -u vm/uefi/process_diagnostics`. This is true, even for other - // mutable paths in the inspect graph. - if let Some(value) = v { - // Parse optional log level override from the input value. - // Any other value (e.g. "1") processes with the configured log level. - let log_level_override = match value { - "default" => Some(LogLevel::make_default()), - "info" => Some(LogLevel::make_info()), - "full" => Some(LogLevel::make_full()), - _ => None, - }; - self.process_diagnostics(true, None, log_level_override); - Result::<_, std::convert::Infallible>::Ok(format!( - "attempted to process diagnostics through inspect (log_level_override: {})", - match value { - "default" | "info" | "full" => value, - _ => "none", - } - )) - } else { - Result::<_, std::convert::Infallible>::Ok( - "Use: inspect -u vm/uefi/process_diagnostics".to_string(), - ) - } - }); - - resp.field_mut_with("efi_diagnostics_dump", |v| { - if let Some(value) = v { - let log_level_override = match value { - "default" => Some(LogLevel::make_default()), - "info" => Some(LogLevel::make_info()), - "full" => Some(LogLevel::make_full()), - _ => None, - }; - - use std::fmt::Write; - let mut output = String::new(); - let result = self.service.diagnostics.process_diagnostics( - true, - &self.gm, - log_level_override, - |log| { - let _ = writeln!( - output, - "[{}] [{}] (ticks: {}) {}", - log.debug_level_str(), - log.phase_str(), - log.ticks(), - log.message_trimmed(), - ); - }, + resp.field_mut_with("dump_efi_diagnostics", |v| { + let Some(value) = v else { + return Result::<_, std::convert::Infallible>::Ok( + "Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), ); + }; - Result::<_, std::convert::Infallible>::Ok(match result { - Ok(()) if output.is_empty() => "(no diagnostics entries found)".to_string(), - Ok(()) => output, - Err(error) => format!("error processing diagnostics: {error}"), - }) - } else { - Result::<_, std::convert::Infallible>::Ok( - "Use: inspect -u vm/uefi/efi_diagnostics_dump".to_string(), - ) + let (level_str, dest_str) = value.split_once(',').unwrap_or((value, "stdout")); + + let log_level_override = match level_str { + "default" => Some(LogLevel::make_default()), + "info" => Some(LogLevel::make_info()), + "full" => Some(LogLevel::make_full()), + _ => return Result::<_, std::convert::Infallible>::Ok( + "Invalid log level. Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), + ), + }; + + match dest_str { + "stdout" => { + let result = self.process_diagnostics( + true, + service::diagnostics::DiagnosticsEmitter::String, + log_level_override, + ); + + Result::<_, std::convert::Infallible>::Ok(match result { + Ok(Some(output)) if output.is_empty() => { + "(no diagnostics entries found)".to_string() + } + Ok(Some(output)) => output, + Err(error) => format!("error processing diagnostics: {error}"), + Ok(None) => unreachable!("String emitter should return output"), + }) + } + "tracing" => { + let _ = self.process_diagnostics( + true, + service::diagnostics::DiagnosticsEmitter::Tracing { limit: None }, + log_level_override, + ); + Result::<_, std::convert::Infallible>::Ok(format!( + "attempted to process diagnostics through inspect (log_level_override: {})", + level_str + )) + } + _ => Result::<_, std::convert::Infallible>::Ok( + "Invalid destination. Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), + ), } }); } @@ -394,7 +385,13 @@ impl PollDevice for UefiDevice { // NOTE: Do not allow reprocessing diagnostics here. // UEFI programs the watchdog's configuration, so we should assume that // this path could trigger multiple times. - self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD), None); + let _ = self.process_diagnostics( + false, + service::diagnostics::DiagnosticsEmitter::Tracing { + limit: Some(DEFAULT_LOGS_PER_PERIOD), + }, + None, + ); } } } diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs index 4f1e7c93df..a914dde6fc 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs @@ -214,36 +214,69 @@ impl DiagnosticsServices { } } +/// The output destination for diagnostics. +pub(crate) enum DiagnosticsEmitter { + /// Emit to tracing + Tracing { limit: Option }, + /// Emit to a string + String, +} + impl UefiDevice { /// Processes UEFI diagnostics from guest memory. /// - /// When a limit is provided, traces are rate-limited to avoid spam. - /// When no limit is provided, traces are unrestricted. - /// /// # Arguments /// * `allow_reprocess` - If true, allows processing even if already processed for guest - /// * `limit` - Maximum number of logs to process per period, or `None` for no limit + /// * `emitter` - The destination for the diagnostics output /// * `log_level_override` - If provided, overrides the configured log level filter for this run pub(crate) fn process_diagnostics( &mut self, allow_reprocess: bool, - limit: Option, + emitter: DiagnosticsEmitter, log_level_override: Option, - ) { + ) -> Result, ProcessingError> { + use std::fmt::Write; + let mut output = match emitter { + DiagnosticsEmitter::String => Some(String::new()), + DiagnosticsEmitter::Tracing { .. } => None, + }; + if let Err(error) = self.service.diagnostics.process_diagnostics( allow_reprocess, &self.gm, log_level_override, - |log| match limit { - Some(limit) => emit_log_ratelimited(log, limit), - None => emit_log_unrestricted(log), + |log| { + if let Some(out) = &mut output { + let _ = writeln!( + out, + "[{}] [{}] (ticks: {}) {}", + log.debug_level_str(), + log.phase_str(), + log.ticks(), + log.message_trimmed(), + ); + } else if let DiagnosticsEmitter::Tracing { limit } = emitter { + match limit { + Some(limit) => emit_log_ratelimited(log, limit), + None => emit_log_unrestricted(log), + } + } }, ) { - tracelimit::error_ratelimited!( - error = &error as &dyn std::error::Error, - "failed to process diagnostics buffer" - ); + match emitter { + DiagnosticsEmitter::Tracing { .. } => { + tracelimit::error_ratelimited!( + error = &error as &dyn std::error::Error, + "failed to process diagnostics buffer" + ); + // For tracing, we swallow the error after logging it, consistent with previous behavior + return Ok(None); + } + DiagnosticsEmitter::String => return Err(error), + } } + + Ok(output) } } From 112c080baa54f2e41ba373642e31cbe2fc8126dd Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Wed, 25 Feb 2026 22:02:07 +0000 Subject: [PATCH 06/11] Allow INFO logs with no limit during watchdog --- vm/devices/firmware/firmware_uefi/src/lib.rs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index 3f148842d4..1e576de2d5 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -385,12 +385,12 @@ impl PollDevice for UefiDevice { // NOTE: Do not allow reprocessing diagnostics here. // UEFI programs the watchdog's configuration, so we should assume that // this path could trigger multiple times. + // + // Here, we emit diagnostics to tracing with INFO level and no limit let _ = self.process_diagnostics( false, - service::diagnostics::DiagnosticsEmitter::Tracing { - limit: Some(DEFAULT_LOGS_PER_PERIOD), - }, - None, + service::diagnostics::DiagnosticsEmitter::Tracing { limit: None }, + Some(LogLevel::make_info()), ); } } From 29a3265ce872bf58b420af5ece6d1da63278f4f0 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Wed, 25 Feb 2026 22:26:19 +0000 Subject: [PATCH 07/11] Adjust format for stdout --- .../firmware/firmware_uefi/src/service/diagnostics/mod.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs index a914dde6fc..bade6618ff 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs @@ -249,10 +249,10 @@ impl UefiDevice { if let Some(out) = &mut output { let _ = writeln!( out, - "[{}] [{}] (ticks: {}) {}", + "({} ticks) [{}] [{}]: {}", + log.ticks(), log.debug_level_str(), log.phase_str(), - log.ticks(), log.message_trimmed(), ); } else if let DiagnosticsEmitter::Tracing { limit } = emitter { From d9f2fe2c6b264308e628d56c3b2944b5e99a2308 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Thu, 26 Feb 2026 19:42:38 +0000 Subject: [PATCH 08/11] Limit watchdog logs --- vm/devices/firmware/firmware_uefi/src/lib.rs | 5 ++++- .../firmware/firmware_uefi/src/service/diagnostics/mod.rs | 3 +++ 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index 1e576de2d5..67de83f2dd 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -73,6 +73,7 @@ use pal_async::local::block_on; use platform::logger::UefiLogger; use platform::nvram::VsmConfig; use service::diagnostics::DEFAULT_LOGS_PER_PERIOD; +use service::diagnostics::WATCHDOG_LOGS_PER_PERIOD; use std::convert::TryInto; use std::ops::RangeInclusive; use std::task::Context; @@ -389,7 +390,9 @@ impl PollDevice for UefiDevice { // Here, we emit diagnostics to tracing with INFO level and no limit let _ = self.process_diagnostics( false, - service::diagnostics::DiagnosticsEmitter::Tracing { limit: None }, + service::diagnostics::DiagnosticsEmitter::Tracing { + limit: Some(WATCHDOG_LOGS_PER_PERIOD), + }, Some(LogLevel::make_info()), ); } diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs index bade6618ff..5e8b17bb15 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/mod.rs @@ -34,6 +34,9 @@ mod processor; /// Default number of EfiDiagnosticsLogs emitted per period pub const DEFAULT_LOGS_PER_PERIOD: u32 = 150; +/// Number of EfiDiagnosticsLogs emitted per period for watchdog timeouts +pub const WATCHDOG_LOGS_PER_PERIOD: u32 = 2000; + /// Emit a diagnostic log entry with rate limiting. /// /// # Arguments From ab9c0f226b16715fdab27c58e0ceadee467b86d1 Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Thu, 26 Feb 2026 19:54:26 +0000 Subject: [PATCH 09/11] Rename to process diagnostics and force correct args in ohcldiag --- openhcl/ohcldiag-dev/src/main.rs | 6 +++--- vm/devices/firmware/firmware_uefi/src/lib.rs | 8 ++++---- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/openhcl/ohcldiag-dev/src/main.rs b/openhcl/ohcldiag-dev/src/main.rs index 2d4f33902c..111007e2eb 100644 --- a/openhcl/ohcldiag-dev/src/main.rs +++ b/openhcl/ohcldiag-dev/src/main.rs @@ -304,10 +304,10 @@ enum Command { /// /// Accepted values: "default" (errors+warnings), "info" (errors+warnings+info), /// "full" (all levels). - #[clap(default_value = "default")] log_level: EfiDiagnosticsLogLevel, /// The output destination. - #[clap(default_value = "stdout")] + /// + /// Accepted values: "stdout", "tracing". output: EfiDiagnosticsOutput, }, } @@ -968,7 +968,7 @@ pub fn main() -> anyhow::Result<()> { output.as_inspect_value() ); let value = client - .update("vm/uefi/dump_efi_diagnostics", &arg) + .update("vm/uefi/process_diagnostics", &arg) .await .context("failed to process EFI diagnostics")?; match value.kind { diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index 67de83f2dd..5c565e7f18 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -291,10 +291,10 @@ impl UefiDevice { /// Extra inspection fields for the UEFI device. fn inspect_extra(&mut self, resp: &mut inspect::Response<'_>) { - resp.field_mut_with("dump_efi_diagnostics", |v| { + resp.field_mut_with("process_diagnostics", |v| { let Some(value) = v else { return Result::<_, std::convert::Infallible>::Ok( - "Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), + "Use: inspect -u , vm/uefi/process_diagnostics".to_string(), ); }; @@ -305,7 +305,7 @@ impl UefiDevice { "info" => Some(LogLevel::make_info()), "full" => Some(LogLevel::make_full()), _ => return Result::<_, std::convert::Infallible>::Ok( - "Invalid log level. Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), + "Invalid log level. Use: inspect -u , vm/uefi/process_diagnostics".to_string(), ), }; @@ -338,7 +338,7 @@ impl UefiDevice { )) } _ => Result::<_, std::convert::Infallible>::Ok( - "Invalid destination. Use: inspect -u , vm/uefi/dump_efi_diagnostics".to_string(), + "Invalid destination. Use: inspect -u , vm/uefi/process_diagnostics".to_string(), ), } }); From 9b3951a956bdd3bb51ce5a0a879c0aae5c31e09a Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Fri, 27 Feb 2026 18:51:23 +0000 Subject: [PATCH 10/11] Refactor inspect_extra to be cleaner --- vm/devices/firmware/firmware_uefi/src/lib.rs | 80 ++++++++++---------- 1 file changed, 39 insertions(+), 41 deletions(-) diff --git a/vm/devices/firmware/firmware_uefi/src/lib.rs b/vm/devices/firmware/firmware_uefi/src/lib.rs index 5c565e7f18..78e5135487 100644 --- a/vm/devices/firmware/firmware_uefi/src/lib.rs +++ b/vm/devices/firmware/firmware_uefi/src/lib.rs @@ -291,56 +291,54 @@ impl UefiDevice { /// Extra inspection fields for the UEFI device. fn inspect_extra(&mut self, resp: &mut inspect::Response<'_>) { - resp.field_mut_with("process_diagnostics", |v| { - let Some(value) = v else { - return Result::<_, std::convert::Infallible>::Ok( - "Use: inspect -u , vm/uefi/process_diagnostics".to_string(), - ); - }; - - let (level_str, dest_str) = value.split_once(',').unwrap_or((value, "stdout")); - - let log_level_override = match level_str { - "default" => Some(LogLevel::make_default()), - "info" => Some(LogLevel::make_info()), - "full" => Some(LogLevel::make_full()), - _ => return Result::<_, std::convert::Infallible>::Ok( - "Invalid log level. Use: inspect -u , vm/uefi/process_diagnostics".to_string(), - ), - }; + const USAGE: &str = + "Use: inspect -u , vm/uefi/process_diagnostics"; - match dest_str { - "stdout" => { - let result = self.process_diagnostics( + resp.field_mut_with("process_diagnostics", |v| { + let output = (|| { + let value = v?; + let (level_str, dest_str) = value.split_once(',').unwrap_or((value, "stdout")); + + let log_level_override = match level_str { + "default" => Some(LogLevel::make_default()), + "info" => Some(LogLevel::make_info()), + "full" => Some(LogLevel::make_full()), + _ => return None, + }; + + Some(match dest_str { + "stdout" => match self.process_diagnostics( true, service::diagnostics::DiagnosticsEmitter::String, log_level_override, - ); - - Result::<_, std::convert::Infallible>::Ok(match result { + ) { Ok(Some(output)) if output.is_empty() => { "(no diagnostics entries found)".to_string() } Ok(Some(output)) => output, - Err(error) => format!("error processing diagnostics: {error}"), Ok(None) => unreachable!("String emitter should return output"), - }) - } - "tracing" => { - let _ = self.process_diagnostics( - true, - service::diagnostics::DiagnosticsEmitter::Tracing { limit: None }, - log_level_override, - ); - Result::<_, std::convert::Infallible>::Ok(format!( - "attempted to process diagnostics through inspect (log_level_override: {})", - level_str - )) - } - _ => Result::<_, std::convert::Infallible>::Ok( - "Invalid destination. Use: inspect -u , vm/uefi/process_diagnostics".to_string(), - ), - } + Err(error) => format!("error processing diagnostics: {error}"), + }, + "tracing" => { + match self.process_diagnostics( + true, + service::diagnostics::DiagnosticsEmitter::Tracing { limit: None }, + log_level_override, + ) { + Ok(_) => format!( + "processed diagnostics via tracing \ + (log_level_override: {level_str})" + ), + Err(error) => { + format!("error processing diagnostics: {error}") + } + } + } + _ => return None, + }) + })(); + + Result::<_, std::convert::Infallible>::Ok(output.unwrap_or_else(|| USAGE.to_string())) }); } } From d16ae8f7535dcb51faa3a9904f7190f1448c715f Mon Sep 17 00:00:00 2001 From: maheeraeron Date: Fri, 27 Feb 2026 18:54:27 +0000 Subject: [PATCH 11/11] Add entries emitted --- .../firmware_uefi/src/service/diagnostics/processor.rs | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs index dba2e60722..01979c62af 100644 --- a/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs +++ b/vm/devices/firmware/firmware_uefi/src/service/diagnostics/processor.rs @@ -124,6 +124,8 @@ struct LogProcessor { suppressed_logs: BTreeMap<&'static str, u32>, /// Number of entries processed entries_processed: usize, + /// Number of entries emitted (passed level/suppression filters) + entries_emitted: usize, /// Number of bytes read from buffer bytes_read: usize, } @@ -134,6 +136,7 @@ impl LogProcessor { accumulator: LogAccumulator::new(), suppressed_logs: BTreeMap::new(), entries_processed: 0, + entries_emitted: 0, bytes_read: 0, } } @@ -156,6 +159,7 @@ impl LogProcessor { } tracelimit::info_ratelimited!( entries_processed = self.entries_processed, + entries_emitted = self.entries_emitted, bytes_read = self.bytes_read, "processed EFI log entries" ); @@ -192,6 +196,7 @@ impl LogProcessor { if let Some(complete_log) = processor.accumulator.take() { processor.entries_processed += 1; if processor.should_emit(&complete_log, log_level) { + processor.entries_emitted += 1; log_handler(&complete_log); } } @@ -200,6 +205,7 @@ impl LogProcessor { if let Some(final_log) = processor.accumulator.clear() { processor.entries_processed += 1; if processor.should_emit(&final_log, log_level) { + processor.entries_emitted += 1; log_handler(&final_log); } }