From ceca3237c1d6f9eb2a3901d9299fadf5e5fa17a0 Mon Sep 17 00:00:00 2001 From: August Date: Fri, 26 Sep 2025 23:29:46 -0400 Subject: [PATCH] Changes to logging --- output.txt | 53 ++++++++++++++ src/kernel/arch/x86_64/paging.rs | 11 +-- src/kernel/boot/modules.rs | 16 +++++ src/kernel/log.rs | 28 ++++---- src/kernel/main.rs | 114 +++++-------------------------- src/kernel/memory.rs | 75 ++++++++++++++++++++ 6 files changed, 184 insertions(+), 113 deletions(-) create mode 100644 output.txt diff --git a/output.txt b/output.txt new file mode 100644 index 0000000..4a18bab --- /dev/null +++ b/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 diff --git a/src/kernel/arch/x86_64/paging.rs b/src/kernel/arch/x86_64/paging.rs index b8add20..94fbe8c 100644 --- a/src/kernel/arch/x86_64/paging.rs +++ b/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,11 +27,12 @@ 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) { log_trace!("Page Table Level 4 Entry: 0x{:X}", entry.addr()); } } -} \ No newline at end of file +} diff --git a/src/kernel/boot/modules.rs b/src/kernel/boot/modules.rs index acd42b9..02b4c4d 100644 --- a/src/kernel/boot/modules.rs +++ b/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? diff --git a/src/kernel/log.rs b/src/kernel/log.rs index 9c2c70c..094fe46 100644 --- a/src/kernel/log.rs +++ b/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) { - self.inner.lock().log(level, msg); + pub fn log(&self, level: LogLevel, msg: &str, file: &'static str, line: u32, column: u32) { + self.inner.lock().log(level, msg, file, line, column); } pub fn add_subscriber(&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 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::Info => "INFO", + LogLevel::Warning => "WARN ", + LogLevel::Info => "INFO ", LogLevel::Trace => "TRACE", } .into() diff --git a/src/kernel/main.rs b/src/kernel/main.rs index 0999d55..afbcc41 100644 --- a/src/kernel/main.rs +++ b/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!("Boot: Enabled features: {}", FEATURE_FLAGS.to_string()); + log_info!("Booting gila version {}", kernel_version_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_trace!("MP: {} CPUs found", resp.cpus().len()); + log_info!("Multiprocessing response received"); + log_trace!("{} CPUs found", resp.cpus().len()); } } - if !MODULE_RESPONSE.modules().is_empty() { - 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}") - } + boot::modules::log_modules(); - // 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!("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"); - } + memory::log_memory(); arch::x86_64::paging::get_mappings(); diff --git a/src/kernel/memory.rs b/src/kernel/memory.rs index 461c4cd..c1d74e5 100644 --- a/src/kernel/memory.rs +++ b/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();