Implement a log buffer to store log messages.

Makefile

@@ -7,8 +7,16 @@ SVSM_ARGS_TEST += --no-default-features --features ${FEATURES_TEST}
 ifdef RELEASE
 TARGET_PATH=release
 CARGO_ARGS += --release
+ENABLE_CONSOLE_LOG ?= 0
 else
 TARGET_PATH=debug
+ENABLE_CONSOLE_LOG ?= 1
+endif
+
+STAGE2_ARGS =
+ifeq ($(ENABLE_CONSOLE_LOG), 1)
+SVSM_ARGS += --features enable-console-log
+STAGE2_ARGS += --features enable-console-log
 endif
 
 ifdef OFFLINE
@@ -124,7 +132,7 @@ bin/meta.bin: utils/gen_meta utils/print-meta bin
 	./utils/gen_meta $@
 
 bin/stage2.bin: bin
-	cargo build --manifest-path kernel/Cargo.toml ${CARGO_ARGS} --bin stage2
+	cargo build --manifest-path kernel/Cargo.toml ${CARGO_ARGS} ${STAGE2_ARGS} --bin stage2
 	objcopy -O binary ${STAGE2_ELF} $@
 
 bin/svsm-kernel.elf: bin

kernel/Cargo.toml

@@ -43,6 +43,7 @@ test.workspace = true
 default = []
 enable-gdb = ["dep:gdbstub", "dep:gdbstub_arch"]
 mstpm = ["dep:libmstpm"]
+enable-console-log = []
 
 [dev-dependencies]
 

kernel/src/cpu/line_buffer.rs

@@ -0,0 +1,130 @@
+// SPDX-License-Identifier: MIT OR Apache-2.0
+//
+// Copyright (c) 2022-2023 SUSE LLC
+//
+// Author: Vasant Karasulli <[email protected]>
+
+use crate::console::_print;
+use crate::cpu::percpu::this_cpu;
+use crate::log_buffer::log_buffer;
+use crate::string::FixedString;
+use crate::types::LINE_BUFFER_SIZE;
+use crate::utils::immut_after_init::{ImmutAfterInitCell, ImmutAfterInitResult};
+use core::fmt;
+use core::fmt::Write;
+
+#[derive(Debug)]
+pub struct LineBuffer {
+    buf: FixedString<LINE_BUFFER_SIZE>,
+}
+
+impl LineBuffer {
+    pub const fn new() -> Self {
+        LineBuffer {
+            buf: FixedString::new(),
+        }
+    }
+
+    pub fn write_buffer(&mut self, s: &str) {
+        for c in s.chars() {
+            self.buf.push(c);
+            if c == '\n' || self.buf.length() == LINE_BUFFER_SIZE {
+                // when buffer is full or '\n' character is encountered
+                log_buffer().write_log(&self.buf);
+                self.buf.clear();
+            }
+        }
+    }
+}
+
+impl Write for LineBuffer {
+    fn write_str(&mut self, s: &str) -> fmt::Result {
+        self.write_buffer(s);
+        Ok(())
+    }
+}
+
+impl Default for LineBuffer {
+    fn default() -> Self {
+        Self::new()
+    }
+}
+
+#[derive(Clone, Copy)]
+struct BufferLogger {
+    component: &'static str,
+}
+
+impl BufferLogger {
+    fn new(component: &'static str) -> BufferLogger {
+        BufferLogger { component }
+    }
+}
+
+impl log::Log for BufferLogger {
+    fn enabled(&self, _metadata: &log::Metadata<'_>) -> bool {
+        true
+    }
+
+    fn log(&self, record: &log::Record<'_>) {
+        let comp: &'static str = self.component;
+        let line_buf = &mut this_cpu().get_line_buffer();
+        // Log format/detail depends on the level.
+        let rec_args = record.args();
+        let lvl = record.metadata().level().as_str();
+        let target = record.metadata().target();
+        match record.metadata().level() {
+            log::Level::Error | log::Level::Warn => {
+                line_buf
+                    .write_fmt(format_args!("[{}] {}: {}\n", comp, lvl, rec_args))
+                    .unwrap();
+                #[cfg(feature = "enable-console-log")]
+                {
+                    _print(format_args!("[{}] {}: {}\n", comp, lvl, rec_args));
+                }
+            }
+
+            log::Level::Info => {
+                line_buf
+                    .write_fmt(format_args!("[{}] {}\n", comp, rec_args))
+                    .unwrap();
+                #[cfg(feature = "enable-console-log")]
+                {
+                    _print(format_args!("[{}] {}\n", comp, rec_args));
+                }
+            }
+
+            log::Level::Debug | log::Level::Trace => {
+                line_buf
+                    .write_fmt(format_args!("[{}/{}] {} {}\n", comp, target, lvl, rec_args))
+                    .unwrap();
+                #[cfg(feature = "enable-console-log")]
+                {
+                    _print(format_args!("[{}/{}] {} {}\n", comp, target, lvl, rec_args));
+                }
+            }
+        }
+    }
+
+    fn flush(&self) {}
+}
+
+static BUFFER_LOGGER: ImmutAfterInitCell<BufferLogger> = ImmutAfterInitCell::uninit();
+
+pub fn install_buffer_logger(component: &'static str) -> ImmutAfterInitResult<()> {
+    BUFFER_LOGGER.init(&BufferLogger::new(component))?;
+
+    if let Err(e) = log::set_logger(&*BUFFER_LOGGER) {
+        // Failed to install the BufferLogger, presumably because something had
+        // installed another logger before. No logs will be stored in the buffer.
+        // Print an error string.
+        _print(format_args!(
+            "[{}]: ERROR: failed to install buffer logger: {:?}",
+            component, e,
+        ));
+    }
+
+    // Log levels are to be configured via the log's library feature configuration.
+    log::set_max_level(log::LevelFilter::Trace);
+    Ok(())
+}

kernel/src/cpu/mod.rs

@@ -13,6 +13,7 @@ pub mod features;
 pub mod gdt;
 pub mod idt;
 pub mod irq_state;
+pub mod line_buffer;
 pub mod mem;
 pub mod msr;
 pub mod percpu;

kernel/src/cpu/percpu.rs

@@ -10,6 +10,7 @@ use super::gdt_mut;
 use super::tss::{X86Tss, IST_DF};
 use crate::address::{Address, PhysAddr, VirtAddr};
 use crate::cpu::idt::common::INT_INJ_VECTOR;
+use crate::cpu::line_buffer::LineBuffer;
 use crate::cpu::tss::TSS_LIMIT;
 use crate::cpu::vmsa::{init_guest_vmsa, init_svsm_vmsa};
 use crate::cpu::{IrqState, LocalApic};
@@ -313,6 +314,7 @@ pub struct PerCpu {
 
     init_stack: Cell<Option<VirtAddr>>,
     ist: IstStacks,
+    ln_buf: RefCell<LineBuffer>,
 
     /// Stack boundaries of the currently running task.
     current_stack: Cell<MemoryRegion<VirtAddr>>,
@@ -344,6 +346,7 @@ impl PerCpu {
             hv_doorbell: Cell::new(None),
             init_stack: Cell::new(None),
             ist: IstStacks::new(),
+            ln_buf: RefCell::new(LineBuffer::new()),
             current_stack: Cell::new(MemoryRegion::new(VirtAddr::null(), 0)),
         }
     }
@@ -852,6 +855,10 @@ impl PerCpu {
         tss.stacks[0] = addr;
         self.tss.set(tss);
     }
+
+    pub fn get_line_buffer(&self) -> RefMut<'_, LineBuffer> {
+        self.ln_buf.borrow_mut()
+    }
 }
 
 pub fn this_cpu() -> &'static PerCpu {

kernel/src/lib.rs

@@ -27,6 +27,8 @@ pub mod insn_decode;
 pub mod io;
 pub mod kernel_region;
 pub mod locking;
+pub mod log_buffer;
+pub mod migrate;
 pub mod mm;
 pub mod platform;
 pub mod protocols;

kernel/src/log_buffer/mod.rs

@@ -0,0 +1,163 @@
+// SPDX-License-Identifier: MIT OR Apache-2.0
+//
+// Copyright (c) 2022-2023 SUSE LLC
+//
+// Author: Vasant Karasulli <[email protected]>
+
+#[cfg(test)]
+extern crate alloc;
+use core::fmt::Debug;
+
+use crate::locking::{LockGuard, SpinLock};
+use crate::string::FixedString;
+
+use crate::types::LINE_BUFFER_SIZE;
+#[cfg(not(test))]
+use crate::types::PAGE_SIZE;
+use crate::utils::StringRingBuffer;
+
+#[cfg(test)]
+use alloc::vec;
+#[cfg(test)]
+use alloc::vec::Vec;
+
+#[cfg(not(test))]
+const BUF_SIZE: usize = PAGE_SIZE / core::mem::size_of::<char>();
+#[cfg(test)]
+const BUF_SIZE: usize = 64;
+
+#[derive(Copy, Clone, Debug)]
+pub struct LogBuffer {
+    buf: StringRingBuffer<BUF_SIZE>,
+}
+
+impl LogBuffer {
+    const fn new() -> Self {
+        Self {
+            buf: StringRingBuffer::<BUF_SIZE>::new(),
+        }
+    }
+
+    pub fn migrate(&mut self, lb: &SpinLock<LogBuffer>) {
+        self.buf = lb.lock().buf;
+    }
+
+    pub fn write_log(&mut self, s: &FixedString<LINE_BUFFER_SIZE>) {
+        self.buf.write(s.iter());
+    }
+
+    #[cfg(test)]
+    pub fn read_log(&mut self) -> Vec<u8> {
+        if let Some(str) = self.buf.read() {
+            str.as_bytes().to_vec()
+        } else {
+            vec![]
+        }
+    }
+}
+
+pub fn migrate_log_buffer(log_buf: &SpinLock<LogBuffer>) {
+    LB.lock().migrate(log_buf);
+}
+
+static LB: SpinLock<LogBuffer> = SpinLock::new(LogBuffer::new());
+pub fn log_buffer() -> LockGuard<'static, LogBuffer> {
+    LB.lock()
+}
+
+pub fn get_lb() -> &'static SpinLock<LogBuffer> {
+    &LB
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use crate::types::LINE_BUFFER_SIZE;
+
+    #[test]
+    fn test_read_write_normal() {
+        let mut fs = FixedString::<LINE_BUFFER_SIZE>::new();
+        for i in 1..=LINE_BUFFER_SIZE {
+            fs.push(char::from_u32(i as u32).unwrap());
+        }
+
+        let mut lb = LogBuffer::new();
+        lb.write_log(&fs);
+
+        let v = lb.read_log();
+        assert_eq!(v.len(), LINE_BUFFER_SIZE);
+        for i in 1..=v.len() {
+            assert_eq!(i as u8, v[i - 1]);
+        }
+    }
+
+    #[test]
+    fn test_read_write_interleaved() {
+        let mut fs = FixedString::<LINE_BUFFER_SIZE>::new();
+        for i in 1..=LINE_BUFFER_SIZE / 2 {
+            fs.push(char::from_u32(i as u32).unwrap());
+        }
+
+        let mut lb = LogBuffer::new();
+        lb.write_log(&fs);
+
+        let v = lb.read_log();
+        assert_eq!(v.len(), LINE_BUFFER_SIZE / 2);
+        for i in 1..=v.len() {
+            assert_eq!(i as u8, v[i - 1]);
+        }
+
+        fs.clear();
+        for i in LINE_BUFFER_SIZE / 2..LINE_BUFFER_SIZE {
+            fs.push(char::from_u32((i + 1) as u32).unwrap());
+        }
+
+        lb.write_log(&fs);
+
+        let v = lb.read_log();
+        assert_eq!(v.len(), LINE_BUFFER_SIZE / 2);
+        for i in 1..v.len() {
+            let val = (i + LINE_BUFFER_SIZE / 2) as u8;
+            assert_eq!(val, v[i - 1]);
+        }
+    }
+
+    #[test]
+    fn test_write_wrap_around() {
+        let mut fs = FixedString::<LINE_BUFFER_SIZE>::new();
+        for i in 1..=LINE_BUFFER_SIZE / 2 {
+            fs.push(char::from_u32(i as u32).unwrap());
+        }
+
+        let mut lb = LogBuffer::new();
+        lb.write_log(&fs);
+
+        let v = lb.read_log();
+        assert_eq!(v.len(), LINE_BUFFER_SIZE / 2);
+        for i in 1..=v.len() {
+            assert_eq!(i as u8, v[i - 1]);
+        }
+
+        fs.clear();
+        for i in 1..=LINE_BUFFER_SIZE {
+            let val = (i + LINE_BUFFER_SIZE / 2) as u32;
+            fs.push(char::from_u32(val).unwrap());
+        }
+
+        lb.write_log(&fs);
+
+        let v = lb.read_log();
+        assert_eq!(v.len(), LINE_BUFFER_SIZE);
+        for i in 1..v.len() {
+            let val = (i + LINE_BUFFER_SIZE / 2) as u8;
+            assert_eq!(val, v[i - 1]);
+        }
+    }
+
+    #[test]
+    fn test_read_empty_buffer() {
+        let mut lb = LogBuffer::new();
+        let v = lb.read_log();
+        assert_eq!(v.len(), 0);
+    }
+}