firmware_uefi: Allow inspect or ohcldiag to reprocess UEFI logs with an increased log level

openhcl/ohcldiag-dev/src/main.rs

@@ -294,6 +294,22 @@ enum Command {
         #[clap(short)]
         output: Option<PathBuf>,
     },
+    /// 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).
+        log_level: EfiDiagnosticsLogLevel,
+        /// The output destination.
+        ///
+        /// Accepted values: "stdout", "tracing".
+        output: EfiDiagnosticsOutput,
+    },
 }
 
 #[derive(Debug, Clone, Args)]
@@ -361,6 +377,43 @@ 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(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;
@@ -510,7 +563,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
@@ -568,7 +624,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)?;
@@ -901,6 +960,22 @@ 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, 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/process_diagnostics", &arg)
+                    .await
+                    .context("failed to process EFI diagnostics")?;
+                match value.kind {
+                    inspect::ValueKind::String(s) => print!("{s}"),
+                    _ => print!("{value}"),
+                }
+            }
         }
         Ok(())
     })

openvmm/openvmm_entry/src/lib.rs

@@ -3256,7 +3256,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 {

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
     });
 }

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;
@@ -276,28 +277,68 @@ impl UefiDevice {
                 self.service.diagnostics.set_gpa(data)
             }
             UefiCommand::PROCESS_EFI_DIAGNOSTICS => {
-                self.process_diagnostics(false, Some(DEFAULT_LOGS_PER_PERIOD))
+                let _ = self.process_diagnostics(
+                    false,
+                    service::diagnostics::DiagnosticsEmitter::Tracing {
+                        limit: Some(DEFAULT_LOGS_PER_PERIOD),
+                    },
+                    None,
+                );
             }
             _ => tracelimit::warn_ratelimited!(addr, data, "unknown uefi write"),
         }
     }
 
     /// Extra inspection fields for the UEFI device.
     fn inspect_extra(&mut self, resp: &mut inspect::Response<'_>) {
+        const USAGE: &str =
+            "Use: inspect -u <default|info|full>,<stdout|tracing> vm/uefi/process_diagnostics";
+
         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 v.is_some() {
-                self.process_diagnostics(true, None);
-                Result::<_, std::convert::Infallible>::Ok(
-                    "attempted to process diagnostics through inspect".to_string(),
-                )
-            } else {
-                Result::<_, std::convert::Infallible>::Ok(
-                    "Use: inspect -u 1 vm/uefi/process_diagnostics".to_string(),
-                )
-            }
+            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,
+                    ) {
+                        Ok(Some(output)) if output.is_empty() => {
+                            "(no diagnostics entries found)".to_string()
+                        }
+                        Ok(Some(output)) => output,
+                        Ok(None) => unreachable!("String emitter should return output"),
+                        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()))
         });
     }
 }
@@ -343,7 +384,15 @@ 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));
+            //
+            // Here, we emit diagnostics to tracing with INFO level and no limit
+            let _ = self.process_diagnostics(
+                false,
+                service::diagnostics::DiagnosticsEmitter::Tracing {
+                    limit: Some(WATCHDOG_LOGS_PER_PERIOD),
+                },
+                Some(LogLevel::make_info()),
+            );
         }
     }
 }

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
@@ -185,11 +188,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<F>(
         &mut self,
         allow_reprocess: bool,
         gm: &GuestMemory,
+        log_level_override: Option<LogLevel>,
         log_handler: F,
     ) -> Result<(), ProcessingError>
     where
@@ -204,34 +209,77 @@ 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)
     }
 }
 
+/// The output destination for diagnostics.
+pub(crate) enum DiagnosticsEmitter {
+    /// Emit to tracing
+    Tracing { limit: Option<u32> },
+    /// 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
-    pub(crate) fn process_diagnostics(&mut self, allow_reprocess: bool, limit: Option<u32>) {
-        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),
-                })
-        {
-            tracelimit::error_ratelimited!(
-                error = &error as &dyn std::error::Error,
-                "failed to process diagnostics buffer"
-            );
+    /// * `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,
+        emitter: DiagnosticsEmitter,
+        log_level_override: Option<LogLevel>,
+    ) -> Result<Option<String>, 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| {
+                if let Some(out) = &mut output {
+                    let _ = writeln!(
+                        out,
+                        "({} ticks) [{}] [{}]: {}",
+                        log.ticks(),
+                        log.debug_level_str(),
+                        log.phase_str(),
+                        log.message_trimmed(),
+                    );
+                } else if let DiagnosticsEmitter::Tracing { limit } = emitter {
+                    match limit {
+                        Some(limit) => emit_log_ratelimited(log, limit),
+                        None => emit_log_unrestricted(log),
+                    }
+                }
+            },
+        ) {
+            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)
     }
 }