From 5a6117b5ae56a2eed4a6b9d30f0a547d1f0fa5ab Mon Sep 17 00:00:00 2001 From: bjorn3 <17426603+bjorn3@users.noreply.github.com> Date: Sat, 13 Sep 2025 12:23:25 +0200 Subject: [PATCH] Replace the log crate with a custom logging system This avoids the need to explicitly set a logger early during boot, which reduces the amount of moving parts that could go wrong slightly. And it cuts the kernel image size by 13kb. --- Cargo.lock | 7 --- Cargo.toml | 1 - src/acpi/gtdt.rs | 6 +-- src/acpi/hpet.rs | 2 +- src/acpi/madt/arch/aarch64.rs | 12 ++--- src/acpi/madt/arch/other.rs | 2 +- src/acpi/mod.rs | 6 +-- src/acpi/spcr.rs | 15 +++---- src/arch/aarch64/device/generic_timer.rs | 1 - src/arch/aarch64/device/irqchip/gic.rs | 1 - src/arch/aarch64/device/irqchip/gicv3.rs | 4 +- .../aarch64/device/irqchip/irq_bcm2835.rs | 1 - .../aarch64/device/irqchip/irq_bcm2836.rs | 1 - src/arch/aarch64/device/irqchip/mod.rs | 6 +-- src/arch/aarch64/device/rtc.rs | 6 +-- src/arch/aarch64/device/serial.rs | 7 +-- src/arch/aarch64/interrupt/exception.rs | 2 +- src/arch/aarch64/start.rs | 9 +--- src/arch/riscv64/device/irqchip/mod.rs | 2 +- src/arch/riscv64/device/irqchip/plic.rs | 1 - src/arch/riscv64/device/serial.rs | 7 +-- src/arch/riscv64/interrupt/exception.rs | 5 +-- src/arch/riscv64/start.rs | 7 --- src/arch/x86_64/alternative.rs | 16 +++---- src/arch/x86_shared/device/hpet.rs | 4 +- src/arch/x86_shared/device/local_apic.rs | 4 +- src/arch/x86_shared/device/mod.rs | 12 ++--- src/arch/x86_shared/device/tsc.rs | 4 +- src/arch/x86_shared/interrupt/irq.rs | 2 +- src/arch/x86_shared/start.rs | 7 --- src/arch/x86_shared/stop.rs | 12 ++--- src/context/memory.rs | 42 ++++++++---------- src/context/signal.rs | 8 ++-- src/debugger.rs | 6 +-- src/dtb/irqchip.rs | 1 - src/dtb/mod.rs | 7 ++- src/log.rs | 35 +-------------- src/macros.rs | 39 ++++++++++++++++ src/main.rs | 1 - src/memory/mod.rs | 28 ++++++------ src/percpu.rs | 2 +- src/profiling.rs | 4 +- src/scheme/acpi.rs | 6 +-- src/scheme/debug.rs | 2 +- src/scheme/dtb.rs | 2 +- src/scheme/irq.rs | 4 +- src/scheme/memory.rs | 5 +-- src/scheme/proc.rs | 4 +- src/scheme/root.rs | 4 +- src/scheme/user.rs | 15 +++---- src/startup/memory.rs | 44 +++++++------------ src/syscall/fs.rs | 5 +-- src/syscall/process.rs | 2 +- 53 files changed, 186 insertions(+), 252 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 77c73faf22..5609b27518 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -131,7 +131,6 @@ dependencies = [ "hashbrown 0.14.5", "indexmap", "linked_list_allocator 0.9.1", - "log", "raw-cpuid", "redox-path", "redox_syscall", @@ -175,12 +174,6 @@ dependencies = [ "scopeguard", ] -[[package]] -name = "log" -version = "0.4.27" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "13dc2df351e3202783a1fe0d44375f7295ffb4049267b0f3018346dc122a1d94" - [[package]] name = "memchr" version = "2.7.5" diff --git a/Cargo.toml b/Cargo.toml index ccd24bd731..0de9d62b1a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -14,7 +14,6 @@ bitflags = "2" bitfield = "0.13.2" hashbrown = { version = "0.14.3", default-features = false, features = ["ahash", "inline-more"] } linked_list_allocator = "0.9.0" -log = "0.4" redox-path = "0.2.0" redox_syscall = { git = "https://gitlab.redox-os.org/redox-os/syscall.git", branch = "master", default-features = false } slab_allocator = { path = "slab_allocator", optional = true } diff --git a/src/acpi/gtdt.rs b/src/acpi/gtdt.rs index 753658da39..04674c9b4b 100644 --- a/src/acpi/gtdt.rs +++ b/src/acpi/gtdt.rs @@ -38,17 +38,17 @@ impl Gtdt { match Gtdt::new(gtdt_sdt[0]) { Some(gtdt) => gtdt, None => { - log::warn!("Failed to parse GTDT"); + warn!("Failed to parse GTDT"); return; } } } else { - log::warn!("Unable to find GTDT"); + warn!("Unable to find GTDT"); return; }; let gsiv = gtdt.non_secure_el1_timer_gsiv; - log::info!("generic_timer gsiv = {}", gsiv); + info!("generic_timer gsiv = {}", gsiv); let mut timer = GenericTimer::new(); timer.init(); register_irq(gsiv, Box::new(timer)); diff --git a/src/acpi/hpet.rs b/src/acpi/hpet.rs index 59f9fc86e5..2e0db8e391 100644 --- a/src/acpi/hpet.rs +++ b/src/acpi/hpet.rs @@ -47,7 +47,7 @@ impl Hpet { unsafe { s.map() }; Some(s) } else { - log::warn!( + warn!( "HPET has unsupported address space {}", s.base_address.address_space ); diff --git a/src/acpi/madt/arch/aarch64.rs b/src/acpi/madt/arch/aarch64.rs index dc460b08a5..ecf0bd3666 100644 --- a/src/acpi/madt/arch/aarch64.rs +++ b/src/acpi/madt/arch/aarch64.rs @@ -21,7 +21,7 @@ pub(super) fn init(madt: Madt) { } MadtEntry::Gicd(gicd) => { if gicd_opt.is_some() { - log::warn!("Only one GICD should be present on a system, ignoring this one"); + warn!("Only one GICD should be present on a system, ignoring this one"); } else { gicd_opt = Some(gicd); } @@ -30,7 +30,7 @@ pub(super) fn init(madt: Madt) { } } let Some(gicd) = gicd_opt else { - log::warn!("No GICD found"); + warn!("No GICD found"); return; }; let mut gic_dist_if = GicDistIf::default(); @@ -39,7 +39,7 @@ pub(super) fn init(madt: Madt) { let virt = map_device_memory(phys, PAGE_SIZE); gic_dist_if.init(virt.data()); }; - log::info!("{:#x?}", gic_dist_if); + info!("{:#x?}", gic_dist_if); match gicd.gic_version { 1 | 2 => { for gicc in giccs { @@ -49,7 +49,7 @@ pub(super) fn init(madt: Madt) { let virt = map_device_memory(phys, PAGE_SIZE); gic_cpu_if.init(virt.data()) }; - log::info!("{:#x?}", gic_cpu_if); + info!("{:#x?}", gic_cpu_if); let gic = GenericInterruptController { gic_dist_if, gic_cpu_if, @@ -70,7 +70,7 @@ pub(super) fn init(madt: Madt) { for gicc in giccs { let mut gic_cpu_if = GicV3CpuIf; unsafe { gic_cpu_if.init() }; - log::info!("{:#x?}", gic_cpu_if); + info!("{:#x?}", gic_cpu_if); let gic = GicV3 { gic_dist_if, gic_cpu_if, @@ -90,7 +90,7 @@ pub(super) fn init(madt: Madt) { } } _ => { - log::warn!("unsupported GIC version {}", gicd.gic_version); + warn!("unsupported GIC version {}", gicd.gic_version); } } unsafe { IRQ_CHIP.init(None) }; diff --git a/src/acpi/madt/arch/other.rs b/src/acpi/madt/arch/other.rs index cf9440be33..09a4a2df14 100644 --- a/src/acpi/madt/arch/other.rs +++ b/src/acpi/madt/arch/other.rs @@ -5,5 +5,5 @@ pub(super) fn init(madt: Madt) { println!(" {:#x?}", madt_entry); } - log::warn!("MADT not yet handled on this platform"); + warn!("MADT not yet handled on this platform"); } diff --git a/src/acpi/mod.rs b/src/acpi/mod.rs index ae43c5a39c..f65916758b 100644 --- a/src/acpi/mod.rs +++ b/src/acpi/mod.rs @@ -6,8 +6,6 @@ use alloc::{boxed::Box, string::String, vec::Vec}; use hashbrown::HashMap; use spin::{Once, RwLock}; -use log::info; - use crate::{ memory::KernelMapper, paging::{PageFlags, PhysicalAddress, RmmA, RmmArch}, @@ -123,7 +121,7 @@ pub unsafe fn init(already_supplied_rsdp: Option<*const u8>) { }); if !initialized { - log::error!("RXSDT_ENUM already initialized"); + error!("RXSDT_ENUM already initialized"); } rsdt @@ -136,7 +134,7 @@ pub unsafe fn init(already_supplied_rsdp: Option<*const u8>) { RxsdtEnum::Xsdt(xsdt) }); if !initialized { - log::error!("RXSDT_ENUM already initialized"); + error!("RXSDT_ENUM already initialized"); } xsdt diff --git a/src/acpi/spcr.rs b/src/acpi/spcr.rs index be59441e2b..cad4a90a69 100644 --- a/src/acpi/spcr.rs +++ b/src/acpi/spcr.rs @@ -47,12 +47,12 @@ impl Spcr { match Spcr::new(spcr_sdt[0]) { Some(spcr) => spcr, None => { - log::warn!("Failed to parse SPCR"); + warn!("Failed to parse SPCR"); return; } } } else { - log::warn!("Unable to find SPCR"); + warn!("Unable to find SPCR"); return; }; @@ -80,7 +80,7 @@ impl Spcr { let serial_port = uart_pl011::SerialPort::new(virt.data(), false); *COM1.lock() = SerialKind::Pl011(serial_port) } else { - log::warn!( + warn!( "SPCR unsuppoted address for PL011 {:#x?}", spcr.base_address ); @@ -88,10 +88,9 @@ impl Spcr { } //TODO: support more types! unsupported => { - log::warn!( + warn!( "SPCR revision {} unsupported interface type {}", - spcr.header.revision, - unsupported + spcr.header.revision, unsupported ); } } @@ -99,11 +98,11 @@ impl Spcr { match spcr.interface_type { //TODO: support more types! unsupported => { - log::warn!("SPCR revision 1 unsupported interface type {}", unsupported); + warn!("SPCR revision 1 unsupported interface type {}", unsupported); } } } else { - log::warn!("SPCR unsupported revision {}", spcr.header.revision); + warn!("SPCR unsupported revision {}", spcr.header.revision); } let mut serial_port = COM1.lock(); if serial_was_empty && !matches!(*serial_port, SerialKind::NotPresent) { diff --git a/src/arch/aarch64/device/generic_timer.rs b/src/arch/aarch64/device/generic_timer.rs index eb145f1d7b..1cfd63ce62 100644 --- a/src/arch/aarch64/device/generic_timer.rs +++ b/src/arch/aarch64/device/generic_timer.rs @@ -1,5 +1,4 @@ use alloc::boxed::Box; -use log::{debug, error, info}; use super::ic_for_chip; use crate::{ diff --git a/src/arch/aarch64/device/irqchip/gic.rs b/src/arch/aarch64/device/irqchip/gic.rs index 22f4d24686..f4dd47c748 100644 --- a/src/arch/aarch64/device/irqchip/gic.rs +++ b/src/arch/aarch64/device/irqchip/gic.rs @@ -5,7 +5,6 @@ use crate::dtb::{ }; use core::ptr::{read_volatile, write_volatile}; use fdt::{node::FdtNode, Fdt}; -use log::info; use syscall::{ error::{Error, EINVAL}, Result, diff --git a/src/arch/aarch64/device/irqchip/gicv3.rs b/src/arch/aarch64/device/irqchip/gicv3.rs index a4ec2ad62b..7a1837c861 100644 --- a/src/arch/aarch64/device/irqchip/gicv3.rs +++ b/src/arch/aarch64/device/irqchip/gicv3.rs @@ -88,7 +88,7 @@ impl InterruptController for GicV3 { if let Some(fdt) = fdt_opt { self.parse(fdt)?; } - log::info!("{:X?}", self); + info!("{:X?}", self); unsafe { self.gic_cpu_if.init(); @@ -109,7 +109,7 @@ impl InterruptController for GicV3 { i += 1; } - log::info!("gic irq_range = ({}, {})", idx, idx + cnt); + info!("gic irq_range = ({}, {})", idx, idx + cnt); self.irq_range = (idx, idx + cnt); *irq_idx = idx + cnt; Ok(()) diff --git a/src/arch/aarch64/device/irqchip/irq_bcm2835.rs b/src/arch/aarch64/device/irqchip/irq_bcm2835.rs index 067b897d8a..2efdcab25a 100644 --- a/src/arch/aarch64/device/irqchip/irq_bcm2835.rs +++ b/src/arch/aarch64/device/irqchip/irq_bcm2835.rs @@ -1,6 +1,5 @@ use core::ptr::{read_volatile, write_volatile}; use fdt::{node::FdtNode, Fdt}; -use log::{debug, error, info}; use super::InterruptController; use crate::dtb::{ diff --git a/src/arch/aarch64/device/irqchip/irq_bcm2836.rs b/src/arch/aarch64/device/irqchip/irq_bcm2836.rs index a3e9357fca..3c5afcd150 100644 --- a/src/arch/aarch64/device/irqchip/irq_bcm2836.rs +++ b/src/arch/aarch64/device/irqchip/irq_bcm2836.rs @@ -12,7 +12,6 @@ use core::{ sync::atomic::Ordering, }; use fdt::{node::FdtNode, Fdt}; -use log::{debug, info}; use syscall::{ error::{Error, EINVAL}, Result, diff --git a/src/arch/aarch64/device/irqchip/mod.rs b/src/arch/aarch64/device/irqchip/mod.rs index 05f890d094..442569e61b 100644 --- a/src/arch/aarch64/device/irqchip/mod.rs +++ b/src/arch/aarch64/device/irqchip/mod.rs @@ -18,7 +18,7 @@ pub(crate) fn new_irqchip(ic_str: &str) -> Option> } else if ic_str.contains("brcm,bcm2836-armctrl-ic") { Some(Box::new(irq_bcm2835::Bcm2835ArmInterruptController::new())) } else { - log::warn!("no driver for interrupt controller {:?}", ic_str); + warn!("no driver for interrupt controller {:?}", ic_str); //TODO: return None and handle it properly Some(Box::new(null::Null)) } @@ -26,7 +26,7 @@ pub(crate) fn new_irqchip(ic_str: &str) -> Option> pub(crate) fn ic_for_chip(fdt: &Fdt, node: &FdtNode) -> Option { if let Some(_) = node.property("interrupts-extended") { - log::error!("multi-parented device not supported"); + error!("multi-parented device not supported"); None } else if let Some(irqc_phandle) = node .property("interrupt-parent") @@ -35,7 +35,7 @@ pub(crate) fn ic_for_chip(fdt: &Fdt, node: &FdtNode) -> Option { { unsafe { IRQ_CHIP.phandle_to_ic_idx(irqc_phandle as u32) } } else { - log::error!("no irq parent found"); + error!("no irq parent found"); None } } diff --git a/src/arch/aarch64/device/rtc.rs b/src/arch/aarch64/device/rtc.rs index f4cb849891..df1f334963 100644 --- a/src/arch/aarch64/device/rtc.rs +++ b/src/arch/aarch64/device/rtc.rs @@ -12,15 +12,15 @@ pub unsafe fn init(fdt: &fdt::Fdt) { { Some(phys) => { let mut rtc = Pl031rtc { phys }; - log::info!("PL031 RTC at {:#x}", rtc.phys); + info!("PL031 RTC at {:#x}", rtc.phys); *time::START.lock() = (rtc.time() as u128) * time::NANOS_PER_SEC; } None => { - log::warn!("No PL031 RTC registers"); + warn!("No PL031 RTC registers"); } } } else { - log::warn!("No PL031 RTC found"); + warn!("No PL031 RTC found"); } } diff --git a/src/arch/aarch64/device/serial.rs b/src/arch/aarch64/device/serial.rs index 6a2a9bf094..ff4087474b 100644 --- a/src/arch/aarch64/device/serial.rs +++ b/src/arch/aarch64/device/serial.rs @@ -11,7 +11,6 @@ use crate::{ interrupt::irq::trigger, }; use fdt::Fdt; -use log::{error, info}; use syscall::Mmio; pub static COM1: Mutex = Mutex::new(SerialKind::NotPresent); @@ -58,11 +57,9 @@ pub unsafe fn init_early(dtb: &Fdt) { info!("UART {:?} at {:#X} size {:#X}", compatible, virt, size); } None => { - log::warn!( + warn!( "UART {:?} at {:#X} size {:#X}: no driver found", - compatible, - virt, - size + compatible, virt, size ); } } diff --git a/src/arch/aarch64/interrupt/exception.rs b/src/arch/aarch64/interrupt/exception.rs index 04accdbfec..da42e5c910 100644 --- a/src/arch/aarch64/interrupt/exception.rs +++ b/src/arch/aarch64/interrupt/exception.rs @@ -197,7 +197,7 @@ exception_stack!(synchronous_exception_at_el0, |stack| { ty => { if !pf_inner(stack, ty as u8, "sync_exc_el0") { - log::error!( + error!( "FATAL: Not an SVC induced synchronous exception (ty={:b})", ty ); diff --git a/src/arch/aarch64/start.rs b/src/arch/aarch64/start.rs index 92d0a8303e..d087139922 100644 --- a/src/arch/aarch64/start.rs +++ b/src/arch/aarch64/start.rs @@ -6,7 +6,6 @@ use core::slice; use core::sync::atomic::{AtomicBool, AtomicU32, AtomicUsize, Ordering}; use fdt::Fdt; -use log::info; use crate::{ allocator, @@ -105,12 +104,6 @@ pub unsafe extern "C" fn kstart(args_ptr: *const KernelArgs) -> ! { device::serial::init_early(dtb); } - // Initialize logger - crate::log::init_logger(|r| { - println!("{}:{} -- {}", r.target(), r.level(), r.args()); - }); - log::set_max_level(::log::LevelFilter::Debug); - info!("Redox OS starting..."); info!( "Kernel: {:X}:{:X}", @@ -205,7 +198,7 @@ pub unsafe extern "C" fn kstart(args_ptr: *const KernelArgs) -> ! { } Err(err) => { dtb::init(None); - log::warn!("failed to parse DTB: {}", err); + warn!("failed to parse DTB: {}", err); #[cfg(feature = "acpi")] { diff --git a/src/arch/riscv64/device/irqchip/mod.rs b/src/arch/riscv64/device/irqchip/mod.rs index 310e42875d..c32874dd51 100644 --- a/src/arch/riscv64/device/irqchip/mod.rs +++ b/src/arch/riscv64/device/irqchip/mod.rs @@ -17,7 +17,7 @@ pub fn new_irqchip(ic_str: &str) -> Option> { } else if ic_str.contains("riscv,plic0") || ic_str.contains("sifive,plic-1.0.0") { Some(Box::new(plic::Plic::new())) } else { - log::warn!("no driver for interrupt controller {:?}", ic_str); + warn!("no driver for interrupt controller {:?}", ic_str); None } } diff --git a/src/arch/riscv64/device/irqchip/plic.rs b/src/arch/riscv64/device/irqchip/plic.rs index 242e392a8b..67886b991a 100644 --- a/src/arch/riscv64/device/irqchip/plic.rs +++ b/src/arch/riscv64/device/irqchip/plic.rs @@ -7,7 +7,6 @@ use crate::{ }; use core::{mem, num::NonZero, sync::atomic::Ordering}; use fdt::Fdt; -use log::{error, info}; use syscall::{Error, Io, Mmio, EINVAL}; #[repr(packed(4))] diff --git a/src/arch/riscv64/device/serial.rs b/src/arch/riscv64/device/serial.rs index 918b4411ed..ca84a3257b 100644 --- a/src/arch/riscv64/device/serial.rs +++ b/src/arch/riscv64/device/serial.rs @@ -1,6 +1,5 @@ use alloc::boxed::Box; use fdt::Fdt; -use log::info; use spin::Mutex; use syscall::Mmio; @@ -59,11 +58,9 @@ pub unsafe fn init_early(dtb: &Fdt) { info!("UART {:?} at {:#X} size {:#X}", compatible, virt, size); } None => { - log::warn!( + warn!( "UART {:?} at {:#X} size {:#X}: no driver found", - compatible, - virt, - size + compatible, virt, size ); } } diff --git a/src/arch/riscv64/interrupt/exception.rs b/src/arch/riscv64/interrupt/exception.rs index 3d8fe1836a..916b1dc000 100644 --- a/src/arch/riscv64/interrupt/exception.rs +++ b/src/arch/riscv64/interrupt/exception.rs @@ -1,6 +1,5 @@ use ::syscall::Exception; use core::{arch::global_asm, sync::atomic::Ordering}; -use log::{error, info}; use rmm::VirtualAddress; use crate::{ @@ -97,7 +96,7 @@ unsafe fn exception_handler_inner(regs: &mut InterruptStack) { options(nostack) ); - //log::info!("Exception handler incoming: sepc={:x} scause={:x} sstatus={:x}", regs.iret.sepc, scause, sstatus); + //info!("Exception handler incoming: sepc={:x} scause={:x} sstatus={:x}", regs.iret.sepc, scause, sstatus); let user_mode = sstatus & (1 << 8) == 0; @@ -109,7 +108,7 @@ unsafe fn exception_handler_inner(regs: &mut InterruptStack) { } else { handle_system_exception(scause, regs); } - //log::info!("Exception handler outgoing"); + //info!("Exception handler outgoing"); } } diff --git a/src/arch/riscv64/start.rs b/src/arch/riscv64/start.rs index ce90c2d312..74dfa46472 100644 --- a/src/arch/riscv64/start.rs +++ b/src/arch/riscv64/start.rs @@ -4,7 +4,6 @@ use core::{ sync::atomic::{AtomicU32, AtomicUsize, Ordering}, }; use fdt::Fdt; -use log::info; use crate::{ allocator, @@ -105,12 +104,6 @@ pub unsafe extern "C" fn kstart(args_ptr: *const KernelArgs) -> ! { init_early(dtb); } - // Initialize logger - crate::log::init_logger(|r| { - println!("{}:{} -- {}", r.target(), r.level(), r.args()); - }); - ::log::set_max_level(::log::LevelFilter::Debug); - info!("Redox OS starting..."); info!( "Kernel: {:X}:{:X}", diff --git a/src/arch/x86_64/alternative.rs b/src/arch/x86_64/alternative.rs index e552c7585c..7d73a1c606 100644 --- a/src/arch/x86_64/alternative.rs +++ b/src/arch/x86_64/alternative.rs @@ -108,14 +108,14 @@ pub unsafe fn early_init(bsp: bool) { .expect("CPUID said AVX was supported but there's no state info"); if state.size() as usize != 16 * core::mem::size_of::() { - log::warn!("Unusual AVX state size {}", state.size()); + warn!("Unusual AVX state size {}", state.size()); } state.offset() }), xsave_size: ext_state_info.xsave_area_size_enabled_features(), }; - log::debug!("XSAVE: {:?}", info); + debug!("XSAVE: {:?}", info); xsave::XSAVE_INFO.call_once(|| info); } else { @@ -147,7 +147,7 @@ unsafe fn overwrite(relocs: &[AltReloc], enable: KcpuFeatures) { return; } - log::info!("self-modifying features: {:?}", enable); + info!("self-modifying features: {:?}", enable); let mut mapper = KernelMapper::lock(); for reloc in relocs.iter().copied() { @@ -178,7 +178,7 @@ unsafe fn overwrite(relocs: &[AltReloc], enable: KcpuFeatures) { let code = core::slice::from_raw_parts_mut(reloc.code_start, reloc.padded_len); - log::trace!( + trace!( "feature {} current {:x?} altcode {:x?}", name, code, @@ -216,16 +216,16 @@ unsafe fn overwrite(relocs: &[AltReloc], enable: KcpuFeatures) { ]; if feature_is_enabled { - log::trace!("feature {} origcode {:x?}", name, code); + trace!("feature {} origcode {:x?}", name, code); let (dst, dst_nops) = code.split_at_mut(altcode.len()); dst.copy_from_slice(altcode); for chunk in dst_nops.chunks_mut(NOPS_TABLE.len()) { chunk.copy_from_slice(NOPS_TABLE[chunk.len() - 1]); } - log::trace!("feature {} new {:x?} altcode {:x?}", name, code, altcode); + trace!("feature {} new {:x?} altcode {:x?}", name, code, altcode); } else { - log::trace!("feature !{} origcode {:x?}", name, code); + trace!("feature !{} origcode {:x?}", name, code); let (_, padded) = code.split_at_mut(reloc.origcode_len); // Not strictly necessary, but reduces the number of instructions using longer nop @@ -234,7 +234,7 @@ unsafe fn overwrite(relocs: &[AltReloc], enable: KcpuFeatures) { chunk.copy_from_slice(NOPS_TABLE[chunk.len() - 1]); } - log::trace!("feature !{} new {:x?}", name, code); + trace!("feature !{} new {:x?}", name, code); } for page in dst_pages.pages() { diff --git a/src/arch/x86_shared/device/hpet.rs b/src/arch/x86_shared/device/hpet.rs index 1e36f5b4e4..5d96b7b770 100644 --- a/src/arch/x86_shared/device/hpet.rs +++ b/src/arch/x86_shared/device/hpet.rs @@ -39,7 +39,7 @@ pub unsafe fn init(hpet: &mut Hpet) -> bool { let capability = hpet.read_u64(CAPABILITY_OFFSET); if capability & LEG_RT_CAP == 0 { - log::warn!("HPET missing capability LEG_RT_CAP"); + warn!("HPET missing capability LEG_RT_CAP"); return false; } @@ -48,7 +48,7 @@ pub unsafe fn init(hpet: &mut Hpet) -> bool { let t0_capabilities = hpet.read_u64(T0_CONFIG_CAPABILITY_OFFSET); if t0_capabilities & PER_INT_CAP == 0 { - log::warn!("HPET T0 missing capability PER_INT_CAP"); + warn!("HPET T0 missing capability PER_INT_CAP"); return false; } diff --git a/src/arch/x86_shared/device/local_apic.rs b/src/arch/x86_shared/device/local_apic.rs index 0f3dd17338..f395f8a1b1 100644 --- a/src/arch/x86_shared/device/local_apic.rs +++ b/src/arch/x86_shared/device/local_apic.rs @@ -73,7 +73,7 @@ impl LocalApic { .map_or(false, |feature_info| feature_info.has_x2apic()); if !self.x2 { - log::info!("Detected xAPIC at {:#x}", physaddr.data()); + info!("Detected xAPIC at {:#x}", physaddr.data()); if let Some((_entry, _, flush)) = mapper.unmap_phys(virtaddr, true) { // Unmap xAPIC page if already mapped flush.flush(); @@ -83,7 +83,7 @@ impl LocalApic { .expect("failed to map local APIC memory") .flush(); } else { - log::info!("Detected x2APIC"); + info!("Detected x2APIC"); } self.init_ap(); diff --git a/src/arch/x86_shared/device/mod.rs b/src/arch/x86_shared/device/mod.rs index a4cb445ce1..3bf824b0ce 100644 --- a/src/arch/x86_shared/device/mod.rs +++ b/src/arch/x86_shared/device/mod.rs @@ -37,7 +37,7 @@ unsafe fn init_hpet() -> bool { Some(ref mut hpet) => { if cfg!(target_arch = "x86") { //TODO: fix HPET on i686 - log::warn!("HPET found but implemented on i686"); + warn!("HPET found but implemented on i686"); return false; } hpet::init(hpet) @@ -54,21 +54,21 @@ unsafe fn init_hpet() -> bool { pub unsafe fn init_noncore() { unsafe { - log::info!("Initializing system timer"); + info!("Initializing system timer"); #[cfg(feature = "x86_kvm_pv")] if tsc::init() { - log::info!("TSC used as system clock source"); + info!("TSC used as system clock source"); } if init_hpet() { - log::info!("HPET used as system timer"); + info!("HPET used as system timer"); } else { pit::init(); - log::info!("PIT used as system timer"); + info!("PIT used as system timer"); } - log::info!("Finished initializing devices"); + info!("Finished initializing devices"); } } diff --git a/src/arch/x86_shared/device/tsc.rs b/src/arch/x86_shared/device/tsc.rs index 4b9886e2df..efe8a5b7eb 100644 --- a/src/arch/x86_shared/device/tsc.rs +++ b/src/arch/x86_shared/device/tsc.rs @@ -86,7 +86,7 @@ pub fn monotonic_absolute() -> Option { let prev = inf.prev.replace(time); if prev > time { // TODO - log::error!("TSC wraparound ({prev} > {time})"); + error!("TSC wraparound ({prev} > {time})"); return None; } assert!(prev <= time); @@ -111,7 +111,7 @@ pub fn get_kvm_support() -> &'static Option { let supp_feats = KvmFeatureBits::from_bits_retain(res.eax); - log::info!("Detected KVM paravirtualization support, features {supp_feats:?}"); + info!("Detected KVM paravirtualization support, features {supp_feats:?}"); Some(KvmSupport { max_leaf, diff --git a/src/arch/x86_shared/interrupt/irq.rs b/src/arch/x86_shared/interrupt/irq.rs index 0db58e1330..f69172885b 100644 --- a/src/arch/x86_shared/interrupt/irq.rs +++ b/src/arch/x86_shared/interrupt/irq.rs @@ -306,7 +306,7 @@ interrupt!(aux_timer, || { }); interrupt!(lapic_error, || { - log::error!("Local apic internal error: ESR={:#0x}", unsafe { + error!("Local apic internal error: ESR={:#0x}", unsafe { local_apic::the_local_apic().esr() }); unsafe { lapic_eoi() }; diff --git a/src/arch/x86_shared/start.rs b/src/arch/x86_shared/start.rs index d240967767..516f4dedf7 100644 --- a/src/arch/x86_shared/start.rs +++ b/src/arch/x86_shared/start.rs @@ -8,8 +8,6 @@ use core::{ sync::atomic::{AtomicBool, AtomicU32, AtomicUsize, Ordering}, }; -use log::info; - #[cfg(feature = "acpi")] use crate::acpi; @@ -95,11 +93,6 @@ pub unsafe extern "C" fn kstart(args_ptr: *const KernelArgs) -> ! { #[cfg(feature = "system76_ec_debug")] device::system76_ec::init(); - // Initialize logger - crate::log::init_logger(|r| { - println!("{}:{} -- {}", r.target(), r.level(), r.args()); - }); - info!("Redox OS starting..."); info!( "Kernel: {:X}:{:X}", diff --git a/src/arch/x86_shared/stop.rs b/src/arch/x86_shared/stop.rs index 6b6b1cb106..e02972bab4 100644 --- a/src/arch/x86_shared/stop.rs +++ b/src/arch/x86_shared/stop.rs @@ -5,7 +5,7 @@ use crate::syscall::io::{Io, Pio}; pub unsafe fn kreset() -> ! { unsafe { - log::info!("kreset"); + info!("kreset"); // 8042 reset { @@ -57,15 +57,15 @@ pub unsafe fn emergency_reset() -> ! { #[cfg(feature = "acpi")] fn userspace_acpi_shutdown() { - log::info!("Notifying any potential ACPI driver"); + info!("Notifying any potential ACPI driver"); // Tell whatever driver that handles ACPI, that it should enter the S5 state (i.e. // shutdown). if !acpi::register_kstop() { // There was no context to switch to. - log::info!("No ACPI driver was alive to handle shutdown."); + info!("No ACPI driver was alive to handle shutdown."); return; } - log::info!("Waiting one second for ACPI driver to run the shutdown sequence."); + info!("Waiting one second for ACPI driver to run the shutdown sequence."); let initial = time::monotonic(); // Since this driver is a userspace process, and we do not use any magic like directly @@ -80,7 +80,7 @@ fn userspace_acpi_shutdown() { let current = time::monotonic(); if current - initial > time::NANOS_PER_SEC { - log::info!("Timeout reached, thus falling back to other shutdown methods."); + info!("Timeout reached, thus falling back to other shutdown methods."); return; } } @@ -88,7 +88,7 @@ fn userspace_acpi_shutdown() { pub unsafe fn kstop() -> ! { unsafe { - log::info!("Running kstop()"); + info!("Running kstop()"); #[cfg(feature = "acpi")] userspace_acpi_shutdown(); diff --git a/src/context/memory.rs b/src/context/memory.rs index 33089957a8..1d1f507d1e 100644 --- a/src/context/memory.rs +++ b/src/context/memory.rs @@ -263,13 +263,13 @@ impl AddrSpaceWrapper { .grants .remove(grant_span.base) .expect("grant cannot magically disappear while we hold the lock!"); - //log::info!("Mprotecting {:#?} to {:#?} in {:#?}", grant, flags, grant_span); + //info!("Mprotecting {:#?} to {:#?} in {:#?}", grant, flags, grant_span); let intersection = grant_span.intersection(requested_span); let (before, mut grant, after) = grant .extract(intersection) .expect("failed to extract grant"); - //log::info!("Sliced into\n\n{:#?}\n\n{:#?}\n\n{:#?}", before, grant, after); + //info!("Sliced into\n\n{:#?}\n\n{:#?}\n\n{:#?}", before, grant, after); if let Some(before) = before { guard.grants.insert(before); @@ -295,7 +295,7 @@ impl AddrSpaceWrapper { // think), execute-only memory is also supported. grant.remap(mapper, &mut flusher, new_flags); - //log::info!("Mprotect grant became {:#?}", grant); + //info!("Mprotect grant became {:#?}", grant); guard.grants.insert(grant); } Ok(()) @@ -1175,7 +1175,7 @@ impl Grant { for i in 0..span.count { if let Some(info) = get_page_info(phys.next_by(i)) { - log::warn!("Driver tried to physmap the allocator-frame {phys:?} (info {info:?})!"); + warn!("Driver tried to physmap the allocator-frame {phys:?} (info {info:?})!"); return Err(Error::new(EPERM)); } } @@ -1211,7 +1211,7 @@ impl Grant { flusher: &mut Flusher, ) -> Result { if !span.count.is_power_of_two() { - log::warn!("Attempted non-power-of-two zeroed_phys_contiguous allocation, rounding up to next power of two."); + warn!("Attempted non-power-of-two zeroed_phys_contiguous allocation, rounding up to next power of two."); } let alloc_order = span.count.next_power_of_two().trailing_zeros(); @@ -1503,23 +1503,17 @@ impl Grant { let prev_span = prev_span.replace(grant_span); if prev_span.is_none() && src_grant_base > src_base { - log::warn!( + warn!( "Grant too far away, prev_span {:?} src_base {:?} grant base {:?} grant {:#?}", - prev_span, - src_base, - src_grant_base, - src_grant + prev_span, src_base, src_grant_base, src_grant ); return Err(Error::new(EINVAL)); } else if let Some(prev) = prev_span && prev.end() != src_grant_base { - log::warn!( + warn!( "Hole between grants, prev_span {:?} src_base {:?} grant base {:?} grant {:#?}", - prev_span, - src_base, - src_grant_base, - src_grant + prev_span, src_base, src_grant_base, src_grant ); return Err(Error::new(EINVAL)); } @@ -1538,12 +1532,12 @@ impl Grant { } let Some(last_span) = prev_span else { - log::warn!("Called Grant::borrow, but no grants were there!"); + warn!("Called Grant::borrow, but no grants were there!"); return Err(Error::new(EINVAL)); }; if last_span.end() < src_span.end() { - log::warn!("Requested end page too far away from last grant"); + warn!("Requested end page too far away from last grant"); return Err(Error::new(EINVAL)); } if eager { @@ -1828,7 +1822,7 @@ impl Grant { continue; }; flush.ignore(); - //log::info!("Remapped page {:?} (frame {:?})", page, Frame::containing(mapper.translate(page.start_address()).unwrap().0)); + //info!("Remapped page {:?} (frame {:?})", page, Frame::containing(mapper.translate(page.start_address()).unwrap().0)); flusher.queue( Frame::containing(phys), None, @@ -2380,7 +2374,7 @@ pub unsafe fn copy_frame_to_frame_directly(dst: Frame, src: Frame) { pub fn try_correcting_page_tables(faulting_page: Page, access: AccessMode) -> Result<(), PfError> { let Ok(addr_space_lock) = AddrSpace::current() else { - log::debug!("User page fault without address space being set."); + debug!("User page fault without address space being set."); return Err(PfError::Segv); }; @@ -2402,7 +2396,7 @@ fn correct_inner<'l>( let mut flusher = Flusher::with_cpu_set(&mut addr_space.used_by, &addr_space_lock.tlb_ack); let Some((grant_base, grant_info)) = addr_space.grants.contains(faulting_page) else { - log::debug!("Lacks grant"); + debug!("Lacks grant"); return Err(PfError::Segv); }; @@ -2414,11 +2408,11 @@ fn correct_inner<'l>( AccessMode::Read => (), AccessMode::Write if !grant_flags.has_write() => { - log::debug!("Write, but grant was not PROT_WRITE."); + debug!("Write, but grant was not PROT_WRITE."); return Err(PfError::Segv); } AccessMode::InstrFetch if !grant_flags.has_execute() => { - log::debug!("Instuction fetch, but grant was not PROT_EXEC."); + debug!("Instuction fetch, but grant was not PROT_EXEC."); return Err(PfError::Segv); } @@ -2596,7 +2590,7 @@ fn correct_inner<'l>( let mut guard = RwLockUpgradableGuard::upgrade(guard); // TODO: Should this be called? - log::warn!("Mapped zero page since grant didn't exist"); + warn!("Mapped zero page since grant didn't exist"); map_zeroed( &mut guard.table.utable, src_page, @@ -2649,7 +2643,7 @@ fn correct_inner<'l>( addr_space = &mut *addr_space_guard; flusher = Flusher::with_cpu_set(&mut addr_space.used_by, &addr_space_lock.tlb_ack); - log::info!("Got frame {:?} from external fmap", frame); + info!("Got frame {:?} from external fmap", frame); frame } diff --git a/src/context/signal.rs b/src/context/signal.rs index 91c4646295..0a0494984d 100644 --- a/src/context/signal.rs +++ b/src/context/signal.rs @@ -24,7 +24,7 @@ pub fn signal_handler() { // TODO: thumbs_down let Some((thread_ctl, proc_ctl, st)) = context.sigcontrol() else { // Discard signal if sigcontrol is unset. - log::trace!("no sigcontrol, returning"); + trace!("no sigcontrol, returning"); return; }; if thread_ctl.currently_pending_unblocked(proc_ctl) == 0 { @@ -42,7 +42,7 @@ pub fn signal_handler() { if control_flags.contains(SigcontrolFlags::INHIBIT_DELIVERY) { // Signals are inhibited to protect critical sections inside libc, but this code will run // every time the context is switched to. - log::trace!("Inhibiting delivery, returning"); + trace!("Inhibiting delivery, returning"); return; } @@ -50,7 +50,7 @@ pub fn signal_handler() { let Some(regs) = context.regs_mut() else { // TODO: is this even reachable? - log::trace!("No registers, returning"); + trace!("No registers, returning"); return; }; @@ -78,7 +78,7 @@ pub fn excp_handler(excp: syscall::Exception) { let Some(eh) = context.sig.as_ref().and_then(|s| s.excp_handler) else { // TODO: Let procmgr print this? - log::info!( + info!( "UNHANDLED EXCEPTION, CPU {}, PID {}, NAME {}, CONTEXT {current:p}", crate::cpu_id(), context.pid, diff --git a/src/debugger.rs b/src/debugger.rs index 75ec5df490..4ec8bf5f04 100644 --- a/src/debugger.rs +++ b/src/debugger.rs @@ -243,7 +243,7 @@ unsafe fn check_page_table_consistency( { Some(g) => g, None => { - log::error!( + error!( "ADDRESS {:p} LACKING GRANT BUT MAPPED TO {:#0x} FLAGS {:?}!", address.data() as *const u8, physaddr.data(), @@ -257,7 +257,7 @@ unsafe fn check_page_table_consistency( if grant.flags().write(false).data() & !EXCLUDE != flags.write(false).data() & !EXCLUDE { - log::error!( + error!( "FLAG MISMATCH: {:?} != {:?}, address {:p} in grant at {:?}", grant.flags(), flags, @@ -302,7 +302,7 @@ unsafe fn check_page_table_consistency( let _entry = match addr_space.table.utable.translate(page.start_address()) { Some(e) => e, None => { - log::error!("GRANT AT {:?} LACKING MAPPING AT PAGE {:p}", span, page.start_address().data() as *const u8); + error!("GRANT AT {:?} LACKING MAPPING AT PAGE {:p}", span, page.start_address().data() as *const u8); continue; } }; diff --git a/src/dtb/irqchip.rs b/src/dtb/irqchip.rs index 3b1d099fcf..23d3b44dad 100644 --- a/src/dtb/irqchip.rs +++ b/src/dtb/irqchip.rs @@ -3,7 +3,6 @@ use crate::{arch::device::irqchip::new_irqchip, cpu_set::LogicalCpuId, scheme::i use alloc::{boxed::Box, vec::Vec}; use byteorder::{ByteOrder, BE}; use fdt::{node::NodeProperty, Fdt}; -use log::{debug, error}; use syscall::{Error, Result, EINVAL}; pub trait InterruptHandler { diff --git a/src/dtb/mod.rs b/src/dtb/mod.rs index 0bd1de0905..f740980fe3 100644 --- a/src/dtb/mod.rs +++ b/src/dtb/mod.rs @@ -12,7 +12,6 @@ use fdt::{ standard_nodes::MemoryRegion, Fdt, }; -use log::debug; use spin::once::Once; pub static DTB_BINARY: Once> = Once::new(); @@ -105,15 +104,15 @@ pub fn register_dev_memory_ranges(dt: &Fdt) { } let Some(soc_node) = dt.find_node("/soc") else { - log::warn!("failed to find /soc in devicetree"); + warn!("failed to find /soc in devicetree"); return; }; let Some(reg) = soc_node.ranges() else { - log::warn!("devicetree /soc has no ranges"); + warn!("devicetree /soc has no ranges"); return; }; for chunk in reg { - log::debug!( + debug!( "dev mem 0x{:08x} 0x{:08x} 0x{:08x} 0x{:08x}", chunk.child_bus_address_hi, chunk.child_bus_address, diff --git a/src/log.rs b/src/log.rs index b774759320..b3b4dcf9f4 100644 --- a/src/log.rs +++ b/src/log.rs @@ -1,6 +1,6 @@ use alloc::collections::VecDeque; use core::fmt; -use spin::{Mutex, MutexGuard, Once}; +use spin::{Mutex, MutexGuard}; use crate::devices::graphical_debug::{DebugDisplay, DEBUG_DISPLAY}; @@ -37,39 +37,6 @@ impl Log { } } -struct RedoxLogger { - log_func: fn(&log::Record), -} - -impl ::log::Log for RedoxLogger { - fn enabled(&self, _: &log::Metadata<'_>) -> bool { - false - } - fn log(&self, record: &log::Record<'_>) { - (self.log_func)(record) - } - fn flush(&self) {} -} - -pub fn init_logger(log_func: fn(&log::Record)) { - let mut called = false; - let logger = LOGGER.call_once(|| { - ::log::set_max_level(::log::LevelFilter::Info); - called = true; - - RedoxLogger { log_func } - }); - if !called { - log::error!("Tried to reinitialize the logger, which is not possible. Ignoring.") - } - match ::log::set_logger(logger) { - Ok(_) => log::info!("Logger initialized."), - Err(e) => println!("Logger setup failed! error: {}", e), - } -} - -static LOGGER: Once = Once::new(); - pub struct Writer<'a> { log: MutexGuard<'a, Option>, display: MutexGuard<'a, Option>, diff --git a/src/macros.rs b/src/macros.rs index 63a0629297..2f81a3cb13 100644 --- a/src/macros.rs +++ b/src/macros.rs @@ -15,3 +15,42 @@ macro_rules! println { let _ = writeln!($crate::log::Writer::new(), $($arg)*); }); } + +#[macro_export] +macro_rules! error { + ($($arg:tt)*) => { + println!("{}:ERROR -- {}", core::module_path!(), format_args!($($arg)*)); + }; +} + +#[macro_export] +macro_rules! warn { + ($($arg:tt)*) => { + println!("{}:WARN -- {}", core::module_path!(), format_args!($($arg)*)); + }; +} + +#[macro_export] +macro_rules! info { + ($($arg:tt)*) => { + println!("{}:INFO -- {}", core::module_path!(), format_args!($($arg)*)); + }; +} + +#[macro_export] +macro_rules! debug { + ($($arg:tt)*) => { + if cfg!(any(target_arch = "aarch64", target_arch = "riscv64")) { + println!("{}:DEBUG -- {}", core::module_path!(), format_args!($($arg)*)); + } + }; +} + +#[macro_export] +macro_rules! trace { + ($($arg:tt)*) => { + if false { + println!("{}:TRACE -- {}", core::module_path!(), format_args!($($arg)*)); + } + }; +} diff --git a/src/main.rs b/src/main.rs index 9eb8cc8a56..dcdf71255e 100644 --- a/src/main.rs +++ b/src/main.rs @@ -117,7 +117,6 @@ mod externs; /// Logging mod log; -use ::log::info; use alloc::sync::Arc; use spinning_top::RwSpinlock; diff --git a/src/memory/mod.rs b/src/memory/mod.rs index 8a3f4065a2..a5d2dbd6a5 100644 --- a/src/memory/mod.rs +++ b/src/memory/mod.rs @@ -88,7 +88,7 @@ pub fn allocate_p2frame_complex( .as_free() .expect("freelist frames must not be marked used!"); let next_free = info.next(); - //log::info!("FREE {frame:?} ORDER {frame_order} NEXT_FREE {next_free:?}"); + //info!("FREE {frame:?} ORDER {frame_order} NEXT_FREE {next_free:?}"); debug_assert_eq!( next_free.order(), @@ -111,13 +111,13 @@ pub fn allocate_p2frame_complex( freelist.for_orders[frame_order as usize] = next_free.frame(); // TODO: Is this LIFO cache optimal? - //log::info!("MIN{min_order}FRAMEORD{frame_order}"); + //info!("MIN{min_order}FRAMEORD{frame_order}"); for order in (min_order..frame_order).rev() { - //log::info!("SPLIT ORDER {order}"); + //info!("SPLIT ORDER {order}"); let order_page_count = 1 << order; let hi = frame.next_by(order_page_count); - //log::info!("SPLIT INTO {frame:?}:{hi:?} ORDER {order}"); + //info!("SPLIT INTO {frame:?}:{hi:?} ORDER {order}"); debug_assert_eq!(freelist.for_orders[order as usize], None); @@ -185,7 +185,7 @@ pub unsafe fn deallocate_p2frame(orig_frame: Frame, order: u32) { !(sib_info.next().order() > merge_order), "sibling page has unaligned order or contains current page" ); - //log::info!("MERGED {lo:?} WITH {hi:?} ORDER {order}"); + //info!("MERGED {lo:?} WITH {hi:?} ORDER {order}"); if let Some(sib_prev) = sib_info.prev().frame() { get_free_alloc_page_info(sib_prev).set_next(sib_info.next()); @@ -216,7 +216,7 @@ pub unsafe fn deallocate_p2frame(orig_frame: Frame, order: u32) { debug_assert!(new_head.is_aligned_to_order(largest_order)); if let Some(old_head) = freelist.for_orders[largest_order as usize].replace(new_head) { - //log::info!("HEAD {:p} FREED {:p} BARRIER {:p}", get_page_info(old_head).unwrap(), get_page_info(frame).unwrap(), unsafe { ALLOCATOR_DATA.abs_off as *const u8 }); + //info!("HEAD {:p} FREED {:p} BARRIER {:p}", get_page_info(old_head).unwrap(), get_page_info(frame).unwrap(), unsafe { ALLOCATOR_DATA.abs_off as *const u8 }); let old_head_info = get_free_alloc_page_info(old_head); let new_head_info = get_free_alloc_page_info(new_head); @@ -225,7 +225,7 @@ pub unsafe fn deallocate_p2frame(orig_frame: Frame, order: u32) { old_head_info.set_prev(P2Frame::new(Some(new_head), largest_order)); } - //log::info!("FREED {frame:?}+2^{order}"); + //info!("FREED {frame:?}+2^{order}"); freelist.used_frames -= 1 << order; } @@ -625,7 +625,7 @@ fn init_sections(mut allocator: BumpAllocator) { if frame.base() >= allocator.abs_offset() { break 'sections; } - //log::info!("MARKING {frame:?} AS USED"); + //info!("MARKING {frame:?} AS USED"); page_info .refcount .store(RC_USED_NOT_FREE, Ordering::Relaxed); @@ -687,13 +687,13 @@ fn init_sections(mut allocator: BumpAllocator) { frames[0].next.store(order as usize, Ordering::Relaxed); // The first section page is not aligned to the next order size. - //log::info!("ORDER {order}: FIRST {base:?}"); + //info!("ORDER {order}: FIRST {base:?}"); append_page(base, &frames[0], order); base = base.next_by(pages_for_current_order); frames = &frames[pages_for_current_order..]; } else { - //log::info!("ORDER {order}: FIRST SKIP"); + //info!("ORDER {order}: FIRST SKIP"); } if !frames.is_empty() @@ -707,12 +707,12 @@ fn init_sections(mut allocator: BumpAllocator) { frames[off].next.store(order as usize, Ordering::Relaxed); - //log::info!("ORDER {order}: LAST {final_page:?}"); + //info!("ORDER {order}: LAST {final_page:?}"); append_page(final_page, &frames[off], order); frames = &frames[..off]; } else { - //log::info!("ORDER {order}: LAST SKIP"); + //info!("ORDER {order}: LAST SKIP"); } if frames.is_empty() { @@ -730,7 +730,7 @@ fn init_sections(mut allocator: BumpAllocator) { } } - //log::info!("SECTION from {:?}, {} pages, array at {:p}", section.base, section.frames.len(), section.frames); + //info!("SECTION from {:?}, {} pages, array at {:p}", section.base, section.frames.len(), section.frames); } for (order, tuple_opt) in last_pages.iter().enumerate() { let Some((frame, info)) = tuple_opt else { @@ -745,7 +745,7 @@ fn init_sections(mut allocator: BumpAllocator) { FREELIST.lock().for_orders = first_pages.map(|pair| pair.map(|(frame, _)| frame)); //debug_freelist(); - log::info!("Initial freelist consistent"); + info!("Initial freelist consistent"); } #[cold] diff --git a/src/percpu.rs b/src/percpu.rs index f35376fb3c..a7c834867f 100644 --- a/src/percpu.rs +++ b/src/percpu.rs @@ -85,7 +85,7 @@ pub fn shootdown_tlb_ipi(target: Option) { .load(Ordering::Acquire) .as_ref() }) else { - log::warn!("Trying to TLB shootdown a CPU that doesn't exist or isn't initialized."); + warn!("Trying to TLB shootdown a CPU that doesn't exist or isn't initialized."); return; }; while percpublock diff --git a/src/profiling.rs b/src/profiling.rs index 5d07943b1c..5d80918322 100644 --- a/src/profiling.rs +++ b/src/profiling.rs @@ -102,11 +102,11 @@ pub fn serio_command(index: usize, data: u8) { if PROFILE_TOGGLEABLE { if index == 0 && data == 30 { // "a" key in QEMU - log::info!("Enabling profiling"); + info!("Enabling profiling"); IS_PROFILING.store(true, Ordering::SeqCst); } else if index == 0 && data == 48 { // "b" key - log::info!("Disabling profiling"); + info!("Disabling profiling"); IS_PROFILING.store(false, Ordering::SeqCst); } } diff --git a/src/scheme/acpi.rs b/src/scheme/acpi.rs index 3122a0305a..7c09c88fdd 100644 --- a/src/scheme/acpi.rs +++ b/src/scheme/acpi.rs @@ -70,7 +70,7 @@ pub fn register_kstop() -> bool { } if waiters_awoken == 0 { - log::error!("No userspace ACPI handler was notified when trying to shutdown. This is bad."); + error!("No userspace ACPI handler was notified when trying to shutdown. This is bad."); // Let the kernel shutdown without ACPI. return false; } @@ -94,7 +94,7 @@ impl AcpiScheme { Some(RxsdtEnum::Rsdt(rsdt)) => rsdt.as_slice(), Some(RxsdtEnum::Xsdt(xsdt)) => xsdt.as_slice(), None => { - log::warn!("expected RXSDT_ENUM to be initialized before AcpiScheme, is ACPI available?"); + warn!("expected RXSDT_ENUM to be initialized before AcpiScheme, is ACPI available?"); &[] } }; @@ -103,7 +103,7 @@ impl AcpiScheme { }); if !data_init { - log::error!("AcpiScheme::init called multiple times"); + error!("AcpiScheme::init called multiple times"); } } } diff --git a/src/scheme/debug.rs b/src/scheme/debug.rs index ae03c17eb8..d0cefa6c72 100644 --- a/src/scheme/debug.rs +++ b/src/scheme/debug.rs @@ -154,7 +154,7 @@ impl KernelScheme for DebugScheme { b'1' => true, _ => return Err(Error::new(EINVAL)), }; - log::info!("Wrote {is_profiling} to IS_PROFILING"); + info!("Wrote {is_profiling} to IS_PROFILING"); crate::profiling::IS_PROFILING.store(is_profiling, Ordering::Relaxed); return Ok(1); diff --git a/src/scheme/dtb.rs b/src/scheme/dtb.rs index 759108827f..b2c400ce48 100644 --- a/src/scheme/dtb.rs +++ b/src/scheme/dtb.rs @@ -49,7 +49,7 @@ impl DtbScheme { }); if !data_init { - log::error!("DtbScheme::new called multiple times"); + error!("DtbScheme::new called multiple times"); } } } diff --git a/src/scheme/irq.rs b/src/scheme/irq.rs index d2e3938130..20cbd1d332 100644 --- a/src/scheme/irq.rs +++ b/src/scheme/irq.rs @@ -105,7 +105,7 @@ impl IrqScheme { }) .collect::>(), None => { - log::warn!("no MADT found, defaulting to 1 CPU"); + warn!("no MADT found, defaulting to 1 CPU"); vec![0] } } @@ -180,7 +180,7 @@ impl IrqScheme { let irq_number = IRQ_CHIP .irq_xlate(ic_idx, addr.as_slice()) .or(Err(Error::new(ENOENT)))?; - log::debug!("open_phandle_irq virq={}", irq_number); + debug!("open_phandle_irq virq={}", irq_number); if flags & O_STAT == 0 { if is_reserved(LogicalCpuId::new(0), irq_number as u8) { return Err(Error::new(EEXIST)); diff --git a/src/scheme/memory.rs b/src/scheme/memory.rs index f2374884b0..e0bf73399d 100644 --- a/src/scheme/memory.rs +++ b/src/scheme/memory.rs @@ -128,10 +128,9 @@ impl MemoryScheme { } if size % PAGE_SIZE != 0 { - log::warn!( + warn!( "physmap size {} is not multiple of PAGE_SIZE {}", - size, - PAGE_SIZE + size, PAGE_SIZE ); return Err(Error::new(EINVAL)); } diff --git a/src/scheme/proc.rs b/src/scheme/proc.rs index 726bba96f3..64a3938055 100644 --- a/src/scheme/proc.rs +++ b/src/scheme/proc.rs @@ -1089,7 +1089,7 @@ impl ContextHandle { } ContextVerb::ForceKill => { if context::is_current(&context) { - //log::trace!("FORCEKILL SELF {} {}", context.read().debug_id, context.read().pid); + //trace!("FORCEKILL SELF {} {}", context.read().debug_id, context.read().pid); // The following functionality simplifies the cleanup step when detached threads // terminate. @@ -1115,7 +1115,7 @@ impl ContextHandle { crate::syscall::exit_this_context(None); } else { let mut ctxt = context.write(); - //log::trace!("FORCEKILL NONSELF={} {}, SELF={}", ctxt.debug_id, ctxt.pid, context::current().read().debug_id); + //trace!("FORCEKILL NONSELF={} {}, SELF={}", ctxt.debug_id, ctxt.pid, context::current().read().debug_id); ctxt.status = context::Status::Runnable; ctxt.being_sigkilled = true; Ok(mem::size_of::()) diff --git a/src/scheme/root.rs b/src/scheme/root.rs index 8dd4dbc467..e69667edd9 100644 --- a/src/scheme/root.rs +++ b/src/scheme/root.rs @@ -78,10 +78,10 @@ impl KernelScheme for RootScheme { let new_close = flags & O_EXLOCK == O_EXLOCK; if !v2 { - //log::warn!("Context {} opened a v1 scheme", context::current().read().name); + //warn!("Context {} opened a v1 scheme", context::current().read().name); } if !new_close { - /*log::warn!( + /*warn!( "Context {} opened a non-async-close scheme", context::current().read().name );*/ diff --git a/src/scheme/user.rs b/src/scheme/user.rs index 054a1e4dc5..478f0329d7 100644 --- a/src/scheme/user.rs +++ b/src/scheme/user.rs @@ -127,7 +127,7 @@ impl ParsedCqe { flags: EventFlags::from_bits_truncate(packet.c), }, _ => { - log::warn!( + warn!( "Unknown scheme -> kernel message {} from {}", packet.a, context::current().read().name @@ -908,7 +908,7 @@ impl UserInner { required_page_count: usize, flags: MapFlags, ) -> Result<()> { - log::info!("REQUEST FMAP"); + info!("REQUEST FMAP"); let tag = self.next_id()?; { @@ -1008,12 +1008,9 @@ impl UserInner { base_addr, page_count, } => { - log::info!( + info!( "PROVIDE_MAP {:x} {:x} {:?} {:x}", - tag, - offset, - base_addr, - page_count + tag, offset, base_addr, page_count ); if offset % PAGE_SIZE as u64 != 0 { @@ -1259,7 +1256,7 @@ impl UserInner { let base_page_opt = match response { Response::Regular(code, _) => (!mapping_is_lazy).then_some(Error::demux(code)?), Response::Fd(_) => { - log::debug!("Scheme incorrectly returned an fd for fmap."); + debug!("Scheme incorrectly returned an fd for fmap."); return Err(Error::new(EIO)); } @@ -1382,7 +1379,7 @@ impl UserInner { if metadata.is_empty() { return Err(Error::new(EINVAL)); } - log::debug!( + debug!( "call_fdread: payload: {} metadata: {}", payload.len(), metadata.len() diff --git a/src/startup/memory.rs b/src/startup/memory.rs index b987365580..e2f51876c3 100644 --- a/src/startup/memory.rs +++ b/src/startup/memory.rs @@ -146,7 +146,7 @@ fn align_down(x: usize) -> usize { pub fn register_memory_region(base: usize, size: usize, kind: BootloaderMemoryKind) { if kind != Null && size != 0 { - log::debug!("Registering {:?} memory {:X} size {:X}", kind, base, size); + debug!("Registering {:?} memory {:X} size {:X}", kind, base, size); unsafe { (*MEMORY_MAP.get()).register(base, size, kind) } } } @@ -171,12 +171,9 @@ unsafe fn add_memory(areas: &mut [MemoryArea], area_i: &mut usize, mut area: Mem unsafe { for reservation in (*MEMORY_MAP.get()).non_free() { if area.end > reservation.start && area.end <= reservation.end { - log::info!( + info!( "Memory {:X}:{:X} overlaps with reservation {:X}:{:X}", - area.start, - area.end, - reservation.start, - reservation.end + area.start, area.end, reservation.start, reservation.end ); area.end = reservation.start; } @@ -185,12 +182,9 @@ unsafe fn add_memory(areas: &mut [MemoryArea], area_i: &mut usize, mut area: Mem } if area.start >= reservation.start && area.start < reservation.end { - log::info!( + info!( "Memory {:X}:{:X} overlaps with reservation {:X}:{:X}", - area.start, - area.end, - reservation.start, - reservation.end + area.start, area.end, reservation.start, reservation.end ); area.start = reservation.end; } @@ -199,12 +193,9 @@ unsafe fn add_memory(areas: &mut [MemoryArea], area_i: &mut usize, mut area: Mem } if area.start <= reservation.start && area.end > reservation.start { - log::info!( + info!( "Memory {:X}:{:X} contains reservation {:X}:{:X}", - area.start, - area.end, - reservation.start, - reservation.end + area.start, area.end, reservation.start, reservation.end ); debug_assert!(area.start < reservation.start && reservation.end < area.end, "Should've contained reservation entirely: memory block {:X}:{:X} reservation {:X}:{:X}", @@ -251,14 +242,9 @@ unsafe fn add_memory(areas: &mut [MemoryArea], area_i: &mut usize, mut area: Mem kind: BootloaderMemoryKind::Free, }; if let Some(union) = area.combine(&other) { - log::debug!( + debug!( "{:X}:{:X} overlaps with area {:X}:{:X}, combining into {:X}:{:X}", - area.start, - area.end, - other.start, - other.end, - union.start, - union.end + area.start, area.end, other.start, other.end, union.start, union.end ); area = union; *area_i -= 1; // delete the original memory chunk @@ -379,11 +365,11 @@ unsafe fn map_memory(areas: &[MemoryArea], mut bump_allocator: &mut Bum } } - log::debug!("Table: {:X}", mapper.table().phys().data()); + debug!("Table: {:X}", mapper.table().phys().data()); for i in 0..A::PAGE_ENTRIES { if let Some(entry) = mapper.table().entry(i) { if entry.present() { - log::debug!("{}: {:X}", i, entry.data()); + debug!("{}: {:X}", i, entry.data()); } } } @@ -406,7 +392,7 @@ pub unsafe fn init(low_limit: Option, high_limit: Option) { // Copy initial memory map, and page align it for area in (*MEMORY_MAP.get()).free() { - log::debug!("{:X}:{:X}", area.start, area.end); + debug!("{:X}:{:X}", area.start, area.end); if let Some(area) = area.intersect(&physmem_limit) { add_memory(areas, &mut area_i, area); @@ -423,12 +409,12 @@ pub unsafe fn init(low_limit: Option, high_limit: Option) { let mut size = 0; for area in areas.iter() { if area.size > 0 { - log::debug!("{:X?}", area); + debug!("{:X?}", area); size += area.size; } } - log::info!("Memory: {} MB", (size + (MEGABYTE - 1)) / MEGABYTE); + info!("Memory: {} MB", (size + (MEGABYTE - 1)) / MEGABYTE); // Create a basic allocator for the first pages let mut bump_allocator = BumpAllocator::::new(areas, 0); @@ -437,7 +423,7 @@ pub unsafe fn init(low_limit: Option, high_limit: Option) { // Create the physical memory map let offset = bump_allocator.offset(); - log::info!( + info!( "Permanently used: {} KB", (offset + (KILOBYTE - 1)) / KILOBYTE ); diff --git a/src/syscall/fs.rs b/src/syscall/fs.rs index 7bda154f40..57b6f9b3ce 100644 --- a/src/syscall/fs.rs +++ b/src/syscall/fs.rs @@ -648,10 +648,9 @@ pub fn funmap(virtual_address: usize, length: usize) -> Result { let length_aligned = length.next_multiple_of(PAGE_SIZE); if length != length_aligned { - log::warn!( + warn!( "funmap passed length {:#x} instead of {:#x}", - length, - length_aligned + length, length_aligned ); } diff --git a/src/syscall/process.rs b/src/syscall/process.rs index 9dd7bc927e..ca4f3ea54f 100644 --- a/src/syscall/process.rs +++ b/src/syscall/process.rs @@ -121,7 +121,7 @@ pub unsafe fn usermode_bootstrap(bootstrap: &Bootstrap) { .expect("failed to copy memory to bootstrap"); let bootstrap_entry = u64::from_le_bytes(bootstrap_slice[0x1a..0x22].try_into().unwrap()); - log::info!("Bootstrap entry point: {:X}", bootstrap_entry); + info!("Bootstrap entry point: {:X}", bootstrap_entry); assert_ne!(bootstrap_entry, 0); println!("\n");