From 1607f5d9ccb9954ba487d3758b1fac1259b0f312 Mon Sep 17 00:00:00 2001 From: Philipp Schuster Date: Wed, 22 May 2024 18:53:43 +0200 Subject: [PATCH] uefi/helpers: logger logs to debugcon device This modifies the logger so that it also prints to the debugcon device in QEMU respectively the debug-console device in cloud-hypervisor [0]. By default, this device is at I/O port 0xe9. This only works on x86. The major benefit is that one can get log output from the logger set up by uefi::helpers::init even after boot services has been exited. Now the memory map can be logged, for example. When the integration test runs, the output txt file is put into the root directory of the project. Also everyone else developing UEFI apps using uefi-rs and running them in QEMU or cloud-hypervisor (on x86) benefits. [0]: https://phip1611.de/blog/how-to-use-qemus-debugcon-feature/ --- .gitignore | 3 ++ uefi-test-runner/src/main.rs | 17 +++++++++-- uefi/CHANGELOG.md | 7 +++-- uefi/Cargo.toml | 10 ++++++- uefi/src/helpers/logger.rs | 55 ++++++++++++++++++++++++++++++------ uefi/src/helpers/mod.rs | 8 ++++-- xtask/src/qemu.rs | 4 +++ 7 files changed, 89 insertions(+), 15 deletions(-) diff --git a/.gitignore b/.gitignore index 1d263f4af..39bd96a03 100644 --- a/.gitignore +++ b/.gitignore @@ -3,3 +3,6 @@ # Files generated by mdBook. /book/book/ + +# Integration test output by QEMU. +integration-test-debugcon.log diff --git a/uefi-test-runner/src/main.rs b/uefi-test-runner/src/main.rs index b3a3e7ad4..39baced14 100644 --- a/uefi-test-runner/src/main.rs +++ b/uefi-test-runner/src/main.rs @@ -196,10 +196,23 @@ fn shutdown(mut st: SystemTable) -> ! { // 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")] { diff --git a/uefi/CHANGELOG.md b/uefi/CHANGELOG.md index 671cf33c7..866baf204 100644 --- a/uefi/CHANGELOG.md +++ b/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`. diff --git a/uefi/Cargo.toml b/uefi/Cargo.toml index fdb2e64fb..22c45c4bc 100644 --- a/uefi/Cargo.toml +++ b/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 diff --git a/uefi/src/helpers/logger.rs b/uefi/src/helpers/logger.rs index 31e65c3a3..b8d8cfa41 100644 --- a/uefi/src/helpers/logger.rs +++ b/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: +#[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(""), + record.line().unwrap_or(0), + ); + } } fn flush(&self) { diff --git a/uefi/src/helpers/mod.rs b/uefi/src/helpers/mod.rs index f8aa20761..a10d61e12 100644 --- a/uefi/src/helpers/mod.rs +++ b/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 { /// 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) -> Result<()> { if system_table_opt().is_some() { // Avoid double initialization. diff --git a/xtask/src/qemu.rs b/xtask/src/qemu.rs index 94386862e..d0ac4cd60 100644 --- a/xtask/src/qemu.rs +++ b/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