Add kernel log to buffer in memory (#578)

* Add LogBuffer struct

* Store logs to buffer

* Refactor macros

* Create log dir

* Add log command to print logs

* Refactor line endings

* Hide CPU frequency when zero

* Log RTC updates

src/lib.rs

@@ -31,7 +31,7 @@ pub fn init(boot_info: &'static BootInfo) {
     sys::time::init();
 
     let v = option_env!("MOROS_VERSION").unwrap_or(env!("CARGO_PKG_VERSION"));
-    log!("MOROS v{}\n", v);
+    log!("MOROS v{}", v);
 
     sys::mem::init(boot_info);
     sys::cpu::init();

src/sys/acpi.rs

@@ -18,7 +18,7 @@ pub fn shutdown() {
     let mut slp_typa = 0;
     let slp_len = 1 << 13;
 
-    log!("ACPI Shutdown\n");
+    log!("ACPI Shutdown");
     let res = unsafe { AcpiTables::search_for_rsdp_bios(MorosAcpiHandler) };
     match res {
         Ok(acpi) => {

src/sys/ata.rs

@@ -301,7 +301,7 @@ pub fn init() {
     }
 
     for drive in list() {
-        log!("ATA {}:{} {}\n", drive.bus, drive.dsk, drive);
+        log!("ATA {}:{} {}", drive.bus, drive.dsk, drive);
     }
 }
 

src/sys/clock.rs

@@ -139,7 +139,7 @@ pub fn init() {
     );
     let dt = OffsetDateTime::from_unix_timestamp(s as i64) + ns;
     let rtc = dt.format(DATE_TIME_ZONE);
-    log!("RTC {}\n", rtc);
+    log!("RTC {}", rtc);
 }
 
 #[test_case]

src/sys/cmos.rs

@@ -1,3 +1,4 @@
+use crate::sys;
 use crate::api::clock::{DATE_TIME, DATE_TIME_LEN};
 use crate::api::fs::{FileIO, IO};
 
@@ -57,10 +58,12 @@ impl RTC {
 impl FileIO for RTC {
     fn read(&mut self, buf: &mut [u8]) -> Result<usize, ()> {
         self.sync();
-        let date = Date::try_from_ymd(self.year.into(), self.month, self.day).
-            map_err(|_| ())?;
-        let date_time = date.try_with_hms(self.hour, self.minute, self.second).
-            map_err(|_| ())?;
+        let date = Date::try_from_ymd(
+            self.year.into(), self.month, self.day
+        ).map_err(|_| ())?;
+        let date_time = date.try_with_hms(
+            self.hour, self.minute, self.second
+        ).map_err(|_| ())?;
         let out = date_time.format(DATE_TIME);
         buf.copy_from_slice(out.as_bytes());
         Ok(out.len())
@@ -83,6 +86,7 @@ impl FileIO for RTC {
             return Err(());
         }
         CMOS::new().update_rtc(self);
+        sys::clock::init();
         Ok(buf.len())
     }
 

src/sys/cpu.rs

@@ -4,15 +4,17 @@ pub fn init() {
     let cpuid = CpuId::new();
 
     if let Some(vendor_info) = cpuid.get_vendor_info() {
-        log!("CPU {}\n", vendor_info);
+        log!("CPU {}", vendor_info);
     }
 
     if let Some(processor_brand_string) = cpuid.get_processor_brand_string() {
-        log!("CPU {}\n", processor_brand_string.as_str().trim());
+        log!("CPU {}", processor_brand_string.as_str().trim());
     }
 
     if let Some(info) = cpuid.get_processor_frequency_info() {
         let frequency = info.processor_base_frequency();
-        log!("CPU {} MHz\n", frequency);
+        if frequency > 0 {
+            log!("CPU {} MHz", frequency);
+        }
     }
 }

src/sys/fs/mod.rs

@@ -172,7 +172,7 @@ pub fn init() {
     for bus in 0..2 {
         for dsk in 0..2 {
             if SuperBlock::check_ata(bus, dsk) {
-                log!("MFS Superblock found in ATA {}:{}\n", bus, dsk);
+                log!("MFS Superblock found in ATA {}:{}", bus, dsk);
                 mount_ata(bus, dsk);
                 return;
             }

src/sys/log.rs

@@ -0,0 +1,61 @@
+use alloc::string::String;
+use core::fmt;
+use core::fmt::Write;
+use lazy_static::lazy_static;
+use spin::Mutex;
+use x86_64::instructions::interrupts;
+
+lazy_static! {
+    static ref LOG: Mutex<LogBuffer> = Mutex::new(LogBuffer::new());
+}
+
+const LOG_SIZE: usize = 10 << 10; // 10 KB
+
+struct LogBuffer {
+    buf: [u8; LOG_SIZE],
+    len: usize,
+}
+
+impl LogBuffer {
+    const fn new() -> Self {
+        Self {
+            buf: [0; LOG_SIZE],
+            len: 0,
+        }
+    }
+
+    fn buf(&self) -> &[u8] {
+        let n = self.len;
+        &self.buf[0..n]
+    }
+}
+
+impl core::fmt::Write for LogBuffer {
+    fn write_str(&mut self, s: &str) -> core::fmt::Result {
+        let bytes = s.as_bytes();
+        let i = self.len;
+        let n = i + bytes.len();
+
+        if n > LOG_SIZE {
+            return Err(core::fmt::Error);
+        }
+
+        self.buf[i..n].copy_from_slice(bytes);
+        self.len += bytes.len();
+
+        Ok(())
+    }
+}
+
+#[doc(hidden)]
+pub fn write_fmt(args: fmt::Arguments) {
+    interrupts::without_interrupts(||
+        LOG.lock().write_fmt(args).expect("Could not write log")
+    )
+}
+
+pub fn read() -> String {
+    let log = LOG.lock();
+    let buf = String::from_utf8_lossy(log.buf());
+    buf.into_owned()
+}

src/sys/mem.rs

@@ -24,13 +24,11 @@ pub fn init(boot_info: &'static BootInfo) {
             let end_addr = region.range.end_addr();
             memory_size += end_addr - start_addr;
             log!(
-                "MEM [{:#016X}-{:#016X}] {:?}\n",
-                start_addr,
-                end_addr - 1,
-                region.region_type
+                "MEM [{:#016X}-{:#016X}] {:?}",
+                start_addr, end_addr - 1, region.region_type
             );
         }
-        log!("MEM {} KB\n", memory_size >> 10);
+        log!("MEM {} KB", memory_size >> 10);
         MEMORY_SIZE.store(memory_size, Ordering::Relaxed);
 
         let phys_mem_offset = boot_info.physical_memory_offset;

src/sys/mod.rs

@@ -10,9 +10,9 @@ macro_rules! debug {
     ($($arg:tt)*) => ({
         let csi_color = $crate::api::console::Style::color("LightBlue");
         let csi_reset = $crate::api::console::Style::reset();
-        $crate::sys::console::print_fmt(format_args!("{}DEBUG: ", csi_color));
-        $crate::sys::console::print_fmt(format_args!($($arg)*));
-        $crate::sys::console::print_fmt(format_args!("{}\n", csi_reset));
+        $crate::sys::console::print_fmt(format_args!(
+            "{}DEBUG: {}{}\n", csi_color, format_args!($($arg)*), csi_reset
+        ));
     });
 }
 
@@ -23,11 +23,16 @@ macro_rules! log {
             let uptime = $crate::sys::clock::uptime();
             let csi_color = $crate::api::console::Style::color("LightGreen");
             let csi_reset = $crate::api::console::Style::reset();
-            $crate::sys::console::print_fmt(
-                format_args!("{}[{:.6}]{} ", csi_color, uptime, csi_reset)
-            );
-            $crate::sys::console::print_fmt(format_args!($($arg)*));
-            // TODO: Add newline
+            $crate::sys::console::print_fmt(format_args!(
+                "{}[{:.6}]{} {}\n",
+                csi_color, uptime, csi_reset, format_args!($($arg)*)
+            ));
+
+            let realtime = $crate::sys::clock::realtime();
+            $crate::sys::log::write_fmt(format_args!(
+                "[{:.6}] {}\n",
+                realtime, format_args!($($arg)*)
+            ));
         }
     });
 }
@@ -43,6 +48,7 @@ pub mod fs;
 pub mod gdt;
 pub mod idt;
 pub mod keyboard;
+pub mod log;
 pub mod mem;
 pub mod net;
 pub mod pci;

src/sys/net/mod.rs

@@ -251,7 +251,7 @@ fn find_pci_io_base(vendor_id: u16, device_id: u16) -> Option<u16> {
 pub fn init() {
     let add = |mut device: EthernetDevice, name| {
         if let Some(mac) = device.config().mac() {
-            log!("NET {} MAC {}\n", name, mac);
+            log!("NET {} MAC {}", name, mac);
 
             let config = smoltcp::iface::Config::new(mac.into());
             let iface = Interface::new(config, &mut device, time());

src/sys/pci.rs

@@ -128,12 +128,8 @@ fn add_device(bus: u8, device: u8, function: u8) {
     let config = DeviceConfig::new(bus, device, function);
     PCI_DEVICES.lock().push(config);
     log!(
-        "PCI {:04X}:{:02X}:{:02X} [{:04X}:{:04X}]\n",
-        bus,
-        device,
-        function,
-        config.vendor_id,
-        config.device_id
+        "PCI {:04X}:{:02X}:{:02X} [{:04X}:{:04X}]",
+        bus, device, function, config.vendor_id, config.device_id
     );
 }
 

src/usr/install.rs

@@ -248,6 +248,8 @@ pub fn copy_files(verbose: bool) {
         verbose,
     );
 
+    create_dir("/var/log", verbose);
+
     create_dir("/var/www", verbose);
     copy_file(
         "/var/www/index.html",

src/usr/shell.rs

@@ -381,7 +381,12 @@ fn cmd_unset(args: &[&str], config: &mut Config) -> Result<(), ExitCode> {
     Ok(())
 }
 
-fn cmd_version(_args: &[&str]) -> Result<(), ExitCode> {
+fn cmd_logs() -> Result<(), ExitCode> {
+    print!("{}", sys::log::read());
+    Ok(())
+}
+
+fn cmd_version() -> Result<(), ExitCode> {
     println!(
         "MOROS v{}",
         option_env!("MOROS_VERSION").unwrap_or(env!("CARGO_PKG_VERSION"))
@@ -539,6 +544,7 @@ fn dispatch(args: &[&str], config: &mut Config) -> Result<(), ExitCode> {
         "life"     => usr::life::main(&args),
         "lisp"     => usr::lisp::main(&args),
         "list"     => usr::list::main(&args),
+        "logs"     => cmd_logs(),
         "memory"   => usr::memory::main(&args),
         "move"     => usr::r#move::main(&args),
         "net"      => usr::net::main(&args),
@@ -553,7 +559,7 @@ fn dispatch(args: &[&str], config: &mut Config) -> Result<(), ExitCode> {
         "time"     => usr::time::main(&args),
         "unalias"  => cmd_unalias(&args, config),
         "unset"    => cmd_unset(&args, config),
-        "version"  => cmd_version(&args),
+        "version"  => cmd_version(),
         "user"     => usr::user::main(&args),
         "vga"      => usr::vga::main(&args),
         "write"    => usr::write::main(&args),