Changes to logging

output.txt

@@ -0,0 +1,53 @@
+[TRACE] \e[1;37msrc/kernel/main.rs:66,9\e[0m - Configured kernel logging devices
+[INFO] \e[1;37msrc/kernel/main.rs:68,5\e[0m - Kernel cmdline: -loglevel=Trace -logdev=display,serial -initramfs=/boot/initramfs.tar.lzma
+[INFO] \e[1;37msrc/kernel/main.rs:74,5\e[0m - Kernel file path: /boot/kernel
+[INFO] \e[1;37msrc/kernel/main.rs:78,5\e[0m - Booting gila version 0.3.1-x86_64-debug
+[INFO] \e[1;37msrc/kernel/main.rs:79,5\e[0m - Enabled features: Acpi | Dtb | Compression | Uefi
+[INFO] \e[1;37msrc/kernel/main.rs:82,23\e[0m - Firmware type: x86 BIOS
+[INFO] \e[1;37msrc/kernel/main.rs:95,5\e[0m - Trans rights!
+[WARN] \e[1;37msrc/kernel/device/devtree.rs:18,13\e[0m - Device: Did not get DTB pointer
+[INFO] \e[1;37msrc/kernel/device/acpi.rs:18,13\e[0m - Device: Got RSDP pointer
+[INFO] \e[1;37msrc/kernel/main.rs:101,9\e[0m - Framebuffer response received
+[TRACE] \e[1;37msrc/kernel/main.rs:102,9\e[0m - Framebuffer dimensions: 1280x800, 32 bits per pixel
+[INFO] \e[1;37msrc/kernel/main.rs:116,13\e[0m - Multiprocessing response received
+[TRACE] \e[1;37msrc/kernel/main.rs:117,13\e[0m - 1 CPUs found
+[TRACE] \e[1;37msrc/kernel/main.rs:129,9\e[0m - Kernel modules list:
+		/boot/initramfs.tar.lzma
+[INFO] \e[1;37msrc/kernel/main.rs:136,5\e[0m - Memory map received
+[TRACE] \e[1;37msrc/kernel/main.rs:186,9\e[0m - Memory map:
+		0x51000 bytes @ 0x1000: bootloader (reclaimable)
+		0x4D000 bytes @ 0x52000: usable
+		0x400 bytes @ 0x9FC00: reserved
+		0x10000 bytes @ 0xF0000: reserved
+		0x7AC2000 bytes @ 0x100000: usable
+		0x1000 bytes @ 0x7BC2000: executable & modules
+		0x1000 bytes @ 0x7BC3000: bootloader (reclaimable)
+		0x1000 bytes @ 0x7BC4000: usable
+		0x1000 bytes @ 0x7BC5000: bootloader (reclaimable)
+		0x1000 bytes @ 0x7BC6000: usable
+		0xE000 bytes @ 0x7BC7000: bootloader (reclaimable)
+		0x34000 bytes @ 0x7BD5000: executable & modules
+		0x346000 bytes @ 0x7C09000: bootloader (reclaimable)
+		0x15000 bytes @ 0x7F4F000: usable
+		0x7C000 bytes @ 0x7F64000: bootloader (reclaimable)
+		0x20000 bytes @ 0x7FE0000: reserved
+		0x3E8000 bytes @ 0xFD000000: framebuffer
+		0x40000 bytes @ 0xFFFC0000: reserved
+		0x300000000 bytes @ 0xFD00000000: reserved
+[INFO] \e[1;37msrc/kernel/main.rs:188,9\e[0m - Boot: Memory report:
+            	Free: 0x7B26000
+            	Available: 0x423000
+            	Usable: 0x7F49000
+            	Hardware: 0x3E8000
+            	Unusable: 0x3000A5400
+            	Total: 0x3083D6400
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:11,5\e[0m - HHDM offset: 0xFFFF800000000000
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:13,5\e[0m - Paging: true
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:14,5\e[0m - Protection: true
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:15,5\e[0m - Physical Address Extensions: true
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:19,5\e[0m - Page Size Extensions: false
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:20,5\e[0m - Paging mode: Four-Level
+[INFO] \e[1;37msrc/kernel/arch/x86_64/paging.rs:28,5\e[0m - CR3 Value: 0b0000000000000000000000000000000000000111111110000010000000000000
+[TRACE] \e[1;37msrc/kernel/arch/x86_64/paging.rs:34,13\e[0m - Page Table Level 4 Entry: 0x7F7D000
+[TRACE] \e[1;37msrc/kernel/arch/x86_64/paging.rs:34,13\e[0m - Page Table Level 4 Entry: 0x7F81000
+[CRIT] \e[1;37msrc/kernel/panic.rs:13,5\e[0m - Panic in src/kernel/main.rs:204:5: Bailing

src/kernel/arch/x86_64/paging.rs

@@ -1,11 +1,11 @@
 #![allow(dead_code)]
 
-use crate::{log_info, log_trace, LogLevel, LOGGER, format};
-use crate::memory::HHDM_RESPONSE;
 use crate::arch;
+use crate::memory::HHDM_RESPONSE;
+use crate::{LOGGER, LogLevel, format, log_info, log_trace};
 use intbits::Bits;
-use x86_64::structures::paging::page_table::PageTable;
 use x86_64::structures::paging::PageTableFlags;
+use x86_64::structures::paging::page_table::PageTable;
 
 pub fn get_mappings() {
     log_info!("HHDM offset: 0x{:X}", HHDM_RESPONSE.offset());
@@ -27,7 +27,8 @@ pub fn get_mappings() {
     );
     log_info!("CR3 Value: 0b{:064b}", arch::asm::read_cr3());
     // Physical address of Page Map Level 4 Table
-    let pml4_ptr: *const PageTable = ((arch::asm::read_cr3().bits(12..=63) << 12) + HHDM_RESPONSE.offset()) as *const PageTable;
+    let pml4_ptr: *const PageTable =
+        ((arch::asm::read_cr3().bits(12..=63) << 12) + HHDM_RESPONSE.offset()) as *const PageTable;
     let pagemap_lvl4 = unsafe { &*pml4_ptr };
     for entry in pagemap_lvl4.iter() {
         if entry.flags().contains(PageTableFlags::PRESENT) {

src/kernel/boot/modules.rs

@@ -1,6 +1,9 @@
 // Copyright (c) 2025 shibedrill
 // SPDX-License-Identifier: GPL-3.0-or-later
 
+use crate::format;
+use crate::memory::alloc::string::String;
+use crate::{LOGGER, LogLevel, log_trace};
 use lazy_static::lazy_static;
 use limine::{
     request::{ExecutableFileRequest, ModuleRequest},
@@ -21,4 +24,17 @@ lazy_static! {
         .expect("Bootloader did not return kernel modules");
 }
 
+pub fn log_modules() {
+    if !MODULE_RESPONSE.modules().is_empty() {
+        let mut log_msg: String = String::from("Kernel modules list:\n");
+        for module in MODULE_RESPONSE.modules() {
+            log_msg.push_str(&format!(
+                "\t{}",
+                String::from_utf8_lossy(module.path().to_bytes())
+            ));
+        }
+        log_trace!("{log_msg}")
+    }
+}
+
 // TODO: make initramfs a lazy static somehow?

src/kernel/log.rs

@@ -13,14 +13,14 @@ use spin::Mutex;
 #[macro_export]
 macro_rules! log_info {
     ($($arg:tt)*) => {
-        LOGGER.log(LogLevel::Info, &format!($($arg)*))
+        LOGGER.log(LogLevel::Info, &format!($($arg)*), file!(), line!(), column!())
     };
 }
 
 #[macro_export]
 macro_rules! log_trace {
     ($($arg:tt)*) => {
-        LOGGER.log(LogLevel::Trace, &format!($($arg)*))
+        LOGGER.log(LogLevel::Trace, &format!($($arg)*), file!(), line!(), column!())
     };
 }
 
@@ -28,7 +28,7 @@ macro_rules! log_trace {
 #[allow(unused_macros)]
 macro_rules! log_warning {
     ($($arg:tt)*) => {
-        LOGGER.log(LogLevel::Warning, &format!($($arg)*))
+        LOGGER.log(LogLevel::Warning, &format!($($arg)*), file!(), line!(), column!())
     };
 }
 
@@ -36,7 +36,7 @@ macro_rules! log_warning {
 #[allow(unused_macros)]
 macro_rules! log_error {
     ($($arg:tt)*) => {
-        LOGGER.log(LogLevel::Error, &format!($($arg)*))
+        LOGGER.log(LogLevel::Error, &format!($($arg)*), file!(), line!(), column!())
     };
 }
 
@@ -44,7 +44,7 @@ macro_rules! log_error {
 #[allow(unused_macros)]
 macro_rules! log_critical {
     ($($arg:tt)*) => {
-        LOGGER.log(LogLevel::Critical, &format!($($arg)*))
+        LOGGER.log(LogLevel::Critical, &format!($($arg)*), file!(), line!(), column!())
     };
 }
 
@@ -53,8 +53,8 @@ pub struct Logger {
 }
 
 impl Logger {
-    pub fn log(&self, level: LogLevel, msg: &str) {
+    pub fn log(&self, level: LogLevel, msg: &str, file: &'static str, line: u32, column: u32) {
-        self.inner.lock().log(level, msg);
+        self.inner.lock().log(level, msg, file, line, column);
     }
     pub fn add_subscriber<T: LogSubscriber + Send + Sync + 'static>(&self, sub: T) {
         self.inner
@@ -99,7 +99,7 @@ impl LoggerInner {
 
     // Calling log will sequentially acquire lock on all logging subscribers
     // to write to them with a formatted log message.
-    pub fn log(&self, level: LogLevel, msg: &str) {
+    pub fn log(&self, level: LogLevel, msg: &str, file: &'static str, line: u32, column: u32) {
         // Nobody is EVER allowed to call log with the Disabled log level. It is a placeholder.
         if level == LogLevel::Disabled {
             // Nothing
@@ -107,7 +107,11 @@ impl LoggerInner {
             let level_string = String::from(level);
             for sub in &self.subscriber {
                 let mut message = String::new();
-                writeln!(&mut message, "{level_string}: \t{msg}").unwrap();
+                writeln!(
+                    &mut message,
+                    "[{level_string}] {file}:{line},{column} - {msg}"
+                )
+                .unwrap();
                 sub.lock().write(&message);
             }
         }
@@ -158,10 +162,10 @@ impl From<LogLevel> for String {
     fn from(from: LogLevel) -> String {
         match from {
             LogLevel::Disabled => "Disabled",
-            LogLevel::Critical => "CRIT",
+            LogLevel::Critical => "CRIT ",
             LogLevel::Error => "ERROR",
-            LogLevel::Warning => "WARN",
+            LogLevel::Warning => "WARN ",
-            LogLevel::Info => "INFO",
+            LogLevel::Info => "INFO ",
             LogLevel::Trace => "TRACE",
         }
         .into()

src/kernel/main.rs

@@ -23,15 +23,14 @@ mod util;
 #[cfg(target_arch = "x86_64")]
 use arch::x86_64::serial::Serialport;
 
-use boot::{modules::*, params, *};
+use boot::{BASE_REVISION, params, *};
 use constants::*;
 use limine::firmware_type::FirmwareType;
 use log::*;
 use memory::alloc::{format, string::*, vec};
-use memory::MEMMAP_REQUEST;
+
 use params::*;
 
-use limine::memory_map::EntryType;
 #[allow(unused_imports)]
 use lzma_rs::lzma_decompress;
 
@@ -63,24 +62,24 @@ unsafe extern "C" fn main() -> ! {
             #[cfg(target_arch = "x86_64")]
             LOGGER.add_subscriber(Serialport::new(0x3f8));
         }
-        log_trace!("Boot: Configured kernel logging devices");
+        log_trace!("Configured kernel logging devices");
     }
     log_info!(
-        "Boot: Kernel cmdline: {}",
+        "Kernel cmdline: {}",
         String::from_utf8_lossy(
             limine::file::File::string(EXECUTABLE_FILE_RESPONSE.file()).to_bytes()
         )
     );
     log_info!(
-        "Boot: Kernel file path: {}",
+        "Kernel file path: {}",
         String::from_utf8_lossy(EXECUTABLE_FILE_RESPONSE.file().path().to_bytes())
     );
-    log_info!("Boot: Booting gila version {}", kernel_version_string());
+    log_info!("Booting gila version {}", kernel_version_string());
-    log_info!("Boot: Enabled features: {}", FEATURE_FLAGS.to_string());
+    log_info!("Enabled features: {}", FEATURE_FLAGS.to_string());
 
     match boot::FIRMWARE_TYPE_REQUEST.get_response() {
         Some(resp) => log_info!(
-            "Boot: Firmware type: {}",
+            "Firmware type: {}",
             match resp.firmware_type() {
                 FirmwareType::SBI => "SBI",
                 FirmwareType::UEFI_32 => "UEFI (32-bit)",
@@ -89,115 +88,38 @@ unsafe extern "C" fn main() -> ! {
                 _ => "Unknown",
             }
         ),
-        None => log_warning!("Boot: Firmware type: No response"),
+        None => log_warning!("Firmware type: No response"),
     }
 
-    log_info!("Boot: Trans rights!");
+    log_info!("Trans rights!");
 
     device::init_statics();
 
     if let Some(framebuffer_response) = FRAMEBUFFER_REQUEST.get_response() {
         let fb = framebuffer_response.framebuffers().next().unwrap();
-        log_info!("Boot: Framebuffer response received");
+        log_info!("Framebuffer response received");
         log_trace!(
-            "Boot: Framebuffer dimensions: {}x{}, {} bits per pixel",
+            "Framebuffer dimensions: {}x{}, {} bits per pixel",
             fb.width(),
             fb.height(),
             fb.bpp()
         );
     } else {
-        log_info!("Boot: Framebuffer response absent, graphics disabled",);
+        log_info!("Framebuffer response absent, graphics disabled",);
     }
 
     let smp_response = MP_REQUEST.get_response();
     match smp_response {
-        None => log_info!("MP: Multiprocessing response not received"),
+        None => log_info!("Multiprocessing response not received"),
         Some(resp) => {
-            log_info!("MP: Multiprocessing response received");
+            log_info!("Multiprocessing response received");
-            log_trace!("MP: {} CPUs found", resp.cpus().len());
+            log_trace!("{} CPUs found", resp.cpus().len());
         }
     }
 
-    if !MODULE_RESPONSE.modules().is_empty() {
+    boot::modules::log_modules();
-        let mut log_msg: String = String::from("Boot: Kernel modules list:\n");
-        for module in MODULE_RESPONSE.modules() {
-            log_msg.push_str(&format!(
-                "\t\t{}",
-                String::from_utf8_lossy(module.path().to_bytes())
-            ));
-        }
-        log_trace!("{log_msg}")
-    }
 
-    // Panic if this is absent. It's needed to set up the GDT and paging
+    memory::log_memory();
-    let mmap_response = MEMMAP_REQUEST
-        .get_response()
-        .expect("Bootloader did not supply memory map");
-    log_info!("Boot: Memory map received");
-    if !mmap_response.entries().is_empty() {
-        let mut log_msg: String = String::from("Boot: Memory map:");
-        let mut usable: u64 = 0;
-        let mut reclaimable: u64 = 0;
-        let mut hardware: u64 = 0;
-        let mut unusable: u64 = 0;
-        for entry in mmap_response.entries() {
-            log_msg.push_str(&format!(
-                "\n\t\t0x{:X} bytes @ 0x{:X}: {}",
-                entry.length,
-                entry.base,
-                match entry.entry_type {
-                    EntryType::ACPI_NVS => {
-                        hardware += entry.length;
-                        "ACPI (reserved)"
-                    }
-                    EntryType::ACPI_RECLAIMABLE => {
-                        reclaimable += entry.length;
-                        "ACPI (reclaimable)"
-                    }
-                    EntryType::BAD_MEMORY => {
-                        unusable += entry.length;
-                        "damaged/unusable"
-                    }
-                    EntryType::BOOTLOADER_RECLAIMABLE => {
-                        reclaimable += entry.length;
-                        "bootloader (reclaimable)"
-                    }
-                    #[allow(unreachable_patterns, deprecated)]
-                    EntryType::EXECUTABLE_AND_MODULES | EntryType::KERNEL_AND_MODULES => {
-                        unusable += entry.length;
-                        "executable & modules"
-                    }
-                    EntryType::FRAMEBUFFER => {
-                        hardware += entry.length;
-                        "framebuffer"
-                    }
-                    EntryType::RESERVED => {
-                        unusable += entry.length;
-                        "reserved"
-                    }
-                    EntryType::USABLE => {
-                        usable += entry.length;
-                        "usable"
-                    }
-                    _ => "unidentified",
-                }
-            ));
-        }
-        log_trace!("{log_msg}");
-        let total = usable + reclaimable + hardware + unusable;
-        log_info!(
-            "Boot: Memory report:
-            \tFree: 0x{usable:X}
-            \tAvailable: 0x{reclaimable:X}
-            \tUsable: 0x{:X}
-            \tHardware: 0x{hardware:X}
-            \tUnusable: 0x{unusable:X}
-            \tTotal: 0x{total:X}",
-            usable + reclaimable,
-        );
-    } else {
-        panic!("Memory map contains no entries");
-    }
 
     arch::x86_64::paging::get_mappings();
 

src/kernel/memory.rs

@@ -1,8 +1,11 @@
 // Copyright (c) 2025 shibedrill
 // SPDX-License-Identifier: GPL-3.0-or-later
 
+use crate::{LOGGER, LogLevel, format, log_info, log_trace};
+use alloc::string::String;
 use lazy_static::lazy_static;
 use limine::{
+    memory_map::EntryType,
     request::{ExecutableAddressRequest, HhdmRequest, MemoryMapRequest, PagingModeRequest},
     response::HhdmResponse,
 };
@@ -11,6 +14,78 @@ use talc::*;
 
 pub extern crate alloc;
 
+pub fn log_memory() {
+    // Panic if this is absent. It's needed to set up the GDT and paging
+    let mmap_response = MEMMAP_REQUEST
+        .get_response()
+        .expect("Bootloader did not supply memory map");
+    log_info!("Memory map received");
+    if !mmap_response.entries().is_empty() {
+        let mut log_msg: String = String::from("Memory map:");
+        let mut usable: u64 = 0;
+        let mut reclaimable: u64 = 0;
+        let mut hardware: u64 = 0;
+        let mut unusable: u64 = 0;
+        for entry in mmap_response.entries() {
+            log_msg.push_str(&format!(
+                "\n\t0x{:X} bytes @ 0x{:X}: {}",
+                entry.length,
+                entry.base,
+                match entry.entry_type {
+                    EntryType::ACPI_NVS => {
+                        hardware += entry.length;
+                        "ACPI (reserved)"
+                    }
+                    EntryType::ACPI_RECLAIMABLE => {
+                        reclaimable += entry.length;
+                        "ACPI (reclaimable)"
+                    }
+                    EntryType::BAD_MEMORY => {
+                        unusable += entry.length;
+                        "damaged/unusable"
+                    }
+                    EntryType::BOOTLOADER_RECLAIMABLE => {
+                        reclaimable += entry.length;
+                        "bootloader (reclaimable)"
+                    }
+                    #[allow(unreachable_patterns, deprecated)]
+                    EntryType::EXECUTABLE_AND_MODULES | EntryType::KERNEL_AND_MODULES => {
+                        unusable += entry.length;
+                        "executable & modules"
+                    }
+                    EntryType::FRAMEBUFFER => {
+                        hardware += entry.length;
+                        "framebuffer"
+                    }
+                    EntryType::RESERVED => {
+                        unusable += entry.length;
+                        "reserved"
+                    }
+                    EntryType::USABLE => {
+                        usable += entry.length;
+                        "usable"
+                    }
+                    _ => "unidentified",
+                }
+            ));
+        }
+        log_trace!("{log_msg}");
+        let total = usable + reclaimable + hardware + unusable;
+        log_info!(
+            "Boot: Memory report:
+        Free: 0x{usable:X}
+        Available: 0x{reclaimable:X}
+        Usable: 0x{:X}
+        Hardware: 0x{hardware:X}
+        Unusable: 0x{unusable:X}
+        Total: 0x{total:X}",
+            usable + reclaimable,
+        );
+    } else {
+        panic!("Memory map contains no entries");
+    }
+}
+
 #[used]
 #[unsafe(link_section = ".requests")]
 pub static PAGING_REQUEST: PagingModeRequest = limine::request::PagingModeRequest::new();