Merge pull request #1172 from phip1611/debugcon

uefi/helpers: logger logs to debugcon device

Author: nicholasbishop

.gitignore

@@ -3,3 +3,6 @@
 
 # Files generated by mdBook.
 /book/book/
+
+# Integration test output by QEMU.
+integration-test-debugcon.log

uefi-test-runner/src/main.rs

@@ -196,10 +196,23 @@ fn shutdown(mut st: SystemTable<Boot>) -> ! {
     // type of regression this prevents.
     info!("LOGGING_STILL_WORKING_RIGHT_BEFORE_EBS");
 
-    info!("Testing complete, shutting down...");
+    info!("Testing complete, exiting boot services...");
 
     // Exit boot services as a proof that it works :)
-    let (st, _iter) = st.exit_boot_services(MemoryType::LOADER_DATA);
+    let (st, mmap) = st.exit_boot_services(MemoryType::LOADER_DATA);
+
+    info!("Memory Map:");
+    for desc in mmap.entries() {
+        info!(
+            "start=0x{:016x} size=0x{:016x} type={:?}, attr={:?}",
+            desc.phys_start,
+            desc.page_count * 4096,
+            desc.ty,
+            desc.att
+        );
+    }
+
+    info!("Shutting down...");
 
     #[cfg(target_arch = "x86_64")]
     {

uefi/CHANGELOG.md

@@ -3,6 +3,11 @@
 ## Added
 - Added `RuntimeServices::update_capsule`.
 - Added `RuntimeServices::query_capsule_capabilities`.
+- The logger from `uefi::helpers` now also logs to the [debugcon](https://phip1611.de/blog/how-to-use-qemus-debugcon-feature/)
+  device (QEMU) respectively the debug-console (cloud-hypervisor). This only
+  works on x86. It is activated by default (only on x86) and can be deactivated
+  by removing the `log-debugcon` cargo feature. The major benefit is that one
+  can get log messages even after one exited the boot services.
 
 ## Removed
 - Removed the `panic-on-logger-errors` feature of the `uefi` crate. Logger
@@ -13,8 +18,6 @@
 
 ## Added
 - Added `ResetNotification` protocol.
-
-## Added
 - Added `Timestamp` protocol.
 - Added `UnalignedSlice::as_ptr`.
 - Added common derives for `Event` and `Handle`.

uefi/Cargo.toml

@@ -13,6 +13,7 @@ repository.workspace = true
 rust-version.workspace = true
 
 [features]
+default = [ "log-debugcon" ]
 alloc = []
 
 # Generic gate to code that uses unstable features of Rust. You usually need a nightly toolchain.
@@ -22,7 +23,14 @@ unstable = []
 logger = []
 global_allocator = []
 panic_handler = []
-qemu = ["dep:qemu-exit", "panic_handler"] # panic_handler: logical, not technical dependency
+# Some convenience when running inside QEMU.
+# - dependency log-debugcon: logical, not technical
+# - dependency panic_handler: logical, not technical 
+qemu = ["dep:qemu-exit", "panic_handler", "log-debugcon"]
+# Whether the internal logger from the helpers module should also log to
+# the debugcon device (QEMU) and debug-console (cloud-hypervisor). Only works
+# on x86.
+log-debugcon = []
 
 [dependencies]
 bitflags.workspace = true

uefi/src/helpers/logger.rs

@@ -12,9 +12,8 @@
 //! The last part also means that some Unicode characters might not be
 //! supported by the UEFI console. Don't expect emoji output support.
 
-use crate::proto::console::text::Output;
-
 use crate::prelude::{Boot, SystemTable};
+use crate::proto::console::text::Output;
 use core::fmt::{self, Write};
 use core::ptr;
 use core::sync::atomic::{AtomicPtr, Ordering};
@@ -43,6 +42,31 @@ pub fn disable() {
     LOGGER.disable();
 }
 
+/// Writer to the QEMU debugcon device and the debug-console of
+/// cloud-hypervisor.
+///
+/// More info: <https://phip1611.de/blog/how-to-use-qemus-debugcon-feature/>
+#[cfg(any(target_arch = "x86", target_arch = "x86_64"))]
+#[derive(Copy, Clone, Debug)]
+struct DebugconWriter;
+
+#[cfg(any(target_arch = "x86", target_arch = "x86_64"))]
+impl DebugconWriter {
+    const IO_PORT: u16 = 0xe9;
+}
+
+#[cfg(any(target_arch = "x86", target_arch = "x86_64"))]
+impl core::fmt::Write for DebugconWriter {
+    fn write_str(&mut self, s: &str) -> fmt::Result {
+        for &byte in s.as_bytes() {
+            unsafe {
+                core::arch::asm!("outb %al, %dx", in("al") byte, in("dx") DebugconWriter::IO_PORT, options(att_syntax))
+            };
+        }
+        Ok(())
+    }
+}
+
 /// Logging implementation which writes to a UEFI output stream.
 ///
 /// If this logger is used as a global logger, you must disable it using the
@@ -99,15 +123,13 @@ impl Logger {
 
 impl log::Log for Logger {
     fn enabled(&self, _metadata: &log::Metadata) -> bool {
-        !self.output().is_null()
+        // We decide in `log` already if something is printed. We do not
+        // need micro optimizations here.
+        true
     }
 
     fn log(&self, record: &log::Record) {
-        let output = self.output();
-
-        if !output.is_null() {
-            let writer = unsafe { &mut *output };
-
+        if let Some(writer) = unsafe { self.output().as_mut() } {
             // Ignore all errors. Since we're in the logger implementation we
             // can't log the error. We also don't want to panic, since logging
             // is generally not critical functionality.
@@ -119,6 +141,23 @@ impl log::Log for Logger {
                 record.line().unwrap_or(0),
             );
         }
+
+        #[cfg(all(
+            any(target_arch = "x86", target_arch = "x86_64"),
+            feature = "log-debugcon"
+        ))]
+        {
+            // Ignore all errors. Since we're in the logger implementation we
+            // can't log the error. We also don't want to panic, since logging
+            // is generally not critical functionality.
+            let _ = DecoratedLog::write(
+                &mut DebugconWriter,
+                record.level(),
+                record.args(),
+                record.file().unwrap_or("<unknown file>"),
+                record.line().unwrap_or(0),
+            );
+        }
     }
 
     fn flush(&self) {

uefi/src/helpers/mod.rs

@@ -4,7 +4,10 @@
 //!
 //! For now, this includes:
 //! - using [`uefi::allocator::Allocator`] as global allocator (feature `global_allocator`)
-//! - an implementation of  [`log::Log`] (feature `logger`)
+//! - an implementation of  [`log::Log`] (feature `logger`) which logs to
+//!   the stdout text protocol of UEFI (as long as boot services were not
+//!   excited) and to the [debugcon device](https://phip1611.de/blog/how-to-use-qemus-debugcon-feature/)
+//!   (only on x86)  (feature `log-debugcon`).
 //! - [`print!`][print_macro] and [`println!`][println_macro] macros defaulting
 //!   to the uefi boot service stdout stream
 //! - default panic handler (feature `panic_handler`)
@@ -73,7 +76,8 @@ pub fn system_table() -> SystemTable<Boot> {
 /// memory allocation capabilities.
 ///
 /// **PLEASE NOTE** that these helpers are meant for the pre exit boot service
-/// epoch.
+/// epoch. Limited functionality might work after exiting them, such as logging
+/// to the debugcon device.
 pub fn init(st: &mut SystemTable<Boot>) -> Result<()> {
     if system_table_opt().is_some() {
         // Avoid double initialization.

xtask/src/qemu.rs

@@ -484,6 +484,10 @@ pub fn run_qemu(arch: UefiArch, opt: &QemuOpt) -> Result<()> {
 
     cmd.args(["-device", "virtio-rng-pci"]);
 
+    if arch == UefiArch::IA32 || arch == UefiArch::X86_64 {
+        cmd.args(["-debugcon", "file:./integration-test-debugcon.log"]);
+    }
+
     // Set the boot menu timeout to zero. On aarch64 in particular this speeds
     // up the boot a lot. Note that we have to enable the menu here even though
     // we are skipping right past it, otherwise `splash-time` is ignored in