diff --git a/Kernel/ACPI/ACPIDynamicParser.cpp b/Kernel/ACPI/ACPIDynamicParser.cpp index c46031956a7..ab369337a0a 100644 --- a/Kernel/ACPI/ACPIDynamicParser.cpp +++ b/Kernel/ACPI/ACPIDynamicParser.cpp @@ -47,13 +47,13 @@ namespace ACPI { , StaticParser() { - kprintf("ACPI: Dynamic Parsing Enabled, Can parse AML\n"); + klog() << "ACPI: Dynamic Parsing Enabled, Can parse AML"; } DynamicParser::DynamicParser(PhysicalAddress rsdp) : IRQHandler(9) , StaticParser(rsdp) { - kprintf("ACPI: Dynamic Parsing Enabled, Can parse AML\n"); + klog() << "ACPI: Dynamic Parsing Enabled, Can parse AML"; } void DynamicParser::handle_irq(RegisterState&) diff --git a/Kernel/ACPI/ACPIParser.cpp b/Kernel/ACPI/ACPIParser.cpp index bfbf3eaf165..cd8d8bc150e 100644 --- a/Kernel/ACPI/ACPIParser.cpp +++ b/Kernel/ACPI/ACPIParser.cpp @@ -51,49 +51,49 @@ namespace ACPI { Parser::Parser(bool usable) { if (usable) { - kprintf("ACPI: Setting up a functional parser\n"); + klog() << "ACPI: Setting up a functional parser"; } else { - kprintf("ACPI: Limited Initialization. Vital functions are disabled by a request\n"); + klog() << "ACPI: Limited Initialization. Vital functions are disabled by a request"; } s_acpi_parser = this; } PhysicalAddress Parser::find_table(const char*) { - kprintf("ACPI: Requested to search for a table, Abort!\n"); + klog() << "ACPI: Requested to search for a table, Abort!"; return {}; } void Parser::do_acpi_reboot() { - kprintf("ACPI: Cannot invoke reboot!\n"); + klog() << "ACPI: Cannot invoke reboot!"; ASSERT_NOT_REACHED(); } void Parser::do_acpi_shutdown() { - kprintf("ACPI: Cannot invoke shutdown!\n"); + klog() << "ACPI: Cannot invoke shutdown!"; ASSERT_NOT_REACHED(); } void Parser::enable_aml_interpretation() { - kprintf("ACPI: No AML Interpretation Allowed\n"); + klog() << "ACPI: No AML Interpretation Allowed"; ASSERT_NOT_REACHED(); } void Parser::enable_aml_interpretation(File&) { - kprintf("ACPI: No AML Interpretation Allowed\n"); + klog() << "ACPI: No AML Interpretation Allowed"; ASSERT_NOT_REACHED(); } void Parser::enable_aml_interpretation(u8*, u32) { - kprintf("ACPI: No AML Interpretation Allowed\n"); + klog() << "ACPI: No AML Interpretation Allowed"; ASSERT_NOT_REACHED(); } void Parser::disable_aml_interpretation() { - kprintf("ACPI Limited: No AML Interpretation Allowed\n"); + klog() << "ACPI Limited: No AML Interpretation Allowed"; ASSERT_NOT_REACHED(); } bool Parser::is_operable() diff --git a/Kernel/ACPI/ACPIStaticParser.cpp b/Kernel/ACPI/ACPIStaticParser.cpp index 21e1272d365..d97f321fa46 100644 --- a/Kernel/ACPI/ACPIStaticParser.cpp +++ b/Kernel/ACPI/ACPIStaticParser.cpp @@ -88,8 +88,8 @@ namespace ACPI { void StaticParser::init_fadt() { - kprintf("ACPI: Initializing Fixed ACPI data\n"); - kprintf("ACPI: Searching for the Fixed ACPI Data Table\n"); + klog() << "ACPI: Initializing Fixed ACPI data"; + klog() << "ACPI: Searching for the Fixed ACPI Data Table"; m_fadt = find_table("FACP"); ASSERT(!m_fadt.is_null()); @@ -99,7 +99,7 @@ namespace ACPI { #ifdef ACPI_DEBUG dbg() << "ACPI: FADT @ V " << sdt << ", P " << (void*)fadt.as_ptr(); #endif - kprintf("ACPI: Fixed ACPI data, Revision %u, Length %u bytes\n", sdt->revision, sdt->length); + klog() << "ACPI: Fixed ACPI data, Revision " << sdt->revision << ", Length " << sdt->length << " bytes"; } void StaticParser::do_acpi_reboot() @@ -111,10 +111,10 @@ namespace ACPI { auto region = MM.allocate_kernel_region(m_fadt.page_base(), (PAGE_SIZE * 2), "ACPI Static Parser", Region::Access::Read); auto* fadt = (const Structures::FADT*)region->vaddr().offset(m_fadt.offset_in_page().get()).as_ptr(); if (fadt->h.revision >= 2) { - kprintf("ACPI: Reboot, Sending value 0%x to Port 0x%x\n", fadt->reset_value, fadt->reset_reg.address); + klog() << "ACPI: Reboot, Sending value 0x" << String::format("%x", fadt->reset_value) << " to Port 0x" << String::format("%x", fadt->reset_reg.address); IO::out8(fadt->reset_reg.address, fadt->reset_value); } else { - kprintf("ACPI: Reboot, Not supported!\n"); + klog() << "ACPI: Reboot, Not supported!"; } ASSERT_NOT_REACHED(); /// If rebooting didn't work, halt. @@ -122,7 +122,7 @@ namespace ACPI { void StaticParser::do_acpi_shutdown() { - kprintf("ACPI: Shutdown is not supported with the current configuration, Abort!\n"); + klog() << "ACPI: Shutdown is not supported with the current configuration, Abort!"; ASSERT_NOT_REACHED(); } @@ -159,12 +159,12 @@ namespace ACPI { auto main_sdt_region = MM.allocate_kernel_region(m_main_system_description_table.page_base(), PAGE_ROUND_UP(length) + PAGE_SIZE, "ACPI Static Parser Initialization", Region::Access::Read, false, true); auto* sdt = (volatile Structures::SDTHeader*)main_sdt_region->vaddr().offset(m_main_system_description_table.offset_in_page().get()).as_ptr(); - kprintf("ACPI: Main Description Table valid? 0x%x\n", StaticParsing::validate_table(const_cast(*sdt), length)); + klog() << "ACPI: Main Description Table valid? " << StaticParsing::validate_table(const_cast(*sdt), length); if (m_xsdt_supported) { volatile auto* xsdt = (volatile Structures::XSDT*)sdt; - kprintf("ACPI: Using XSDT, Enumerating tables @ P 0x%x\n", m_main_system_description_table.get()); - kprintf("ACPI: XSDT Revision %d, Total length - %u\n", revision, length); + klog() << "ACPI: Using XSDT, Enumerating tables @ P " << String::format("%p", m_main_system_description_table.get()); + klog() << "ACPI: XSDT Revision " << revision << ", Total length - " << length; #ifdef ACPI_DEBUG dbg() << "ACPI: XSDT pointer @ V " << xsdt; #endif @@ -176,8 +176,8 @@ namespace ACPI { } } else { volatile auto* rsdt = (volatile Structures::RSDT*)sdt; - kprintf("ACPI: Using RSDT, Enumerating tables @ P 0x%x\n", m_main_system_description_table.get()); - kprintf("ACPI: RSDT Revision %d, Total length - %u\n", revision, length); + klog() << "ACPI: Using RSDT, Enumerating tables @ P " << String::format("%p", m_main_system_description_table.get()); + klog() << "ACPI: RSDT Revision " << revision << ", Total length - " << length; #ifdef ACPI_DEBUG dbg() << "ACPI: RSDT pointer @ V " << rsdt; #endif @@ -215,12 +215,12 @@ namespace ACPI { , m_rsdp(StaticParsing::search_rsdp()) { if (!m_rsdp.is_null()) { - kprintf("ACPI: Using RSDP @ P 0x%x\n", m_rsdp); + klog() << "ACPI: Using RSDP @ P " << String::format("%p", m_rsdp); m_operable = true; locate_static_data(); } else { m_operable = false; - kprintf("ACPI: Disabled, due to RSDP being absent\n"); + klog() << "ACPI: Disabled, due to RSDP being absent"; } } @@ -228,7 +228,7 @@ namespace ACPI { : Parser(true) , m_rsdp(rsdp) { - kprintf("ACPI: Using RSDP @ Px%x\n", rsdp.get()); + klog() << "ACPI: Using RSDP @ P " << String::format("%p", rsdp.get()); m_operable = true; locate_static_data(); } @@ -279,7 +279,7 @@ namespace ACPI { PhysicalAddress rsdp; auto region = MM.allocate_kernel_region(PhysicalAddress(0), PAGE_SIZE, "ACPI RSDP Searching", Region::Access::Read); u16 ebda_seg = (u16) * ((uint16_t*)((region->vaddr().get() & PAGE_MASK) + 0x40e)); - kprintf("ACPI: Probing EBDA, Segment 0x%x\n", ebda_seg); + klog() << "ACPI: Probing EBDA, Segment 0x" << String::format("%x", ebda_seg); rsdp = search_rsdp_in_ebda(ebda_seg); if (!rsdp.is_null()) diff --git a/Kernel/ACPI/DMIDecoder.cpp b/Kernel/ACPI/DMIDecoder.cpp index dc747941740..6db8b73ef68 100644 --- a/Kernel/ACPI/DMIDecoder.cpp +++ b/Kernel/ACPI/DMIDecoder.cpp @@ -62,7 +62,7 @@ void DMIDecoder::initialize_untrusted() void DMIDecoder::set_64_bit_entry_initialization_values(PhysicalAddress entry) { - kprintf("DMIDecoder: SMBIOS 64bit Entry point @ P 0x%x\n", m_entry64bit_point.get()); + klog() << "DMIDecoder: SMBIOS 64bit Entry point @ P " << String::format("%p", m_entry64bit_point.get()); m_use_64bit_entry = true; auto region = MM.allocate_kernel_region(entry.page_base(), PAGE_ROUND_UP(SMBIOS_SEARCH_AREA_SIZE), "DMI Decoder 64 bit Initialization", Region::Access::Read, false, false); @@ -74,7 +74,7 @@ void DMIDecoder::set_64_bit_entry_initialization_values(PhysicalAddress entry) void DMIDecoder::set_32_bit_entry_initialization_values(PhysicalAddress entry) { - kprintf("DMIDecoder: SMBIOS 32bit Entry point @ P 0x%x\n", m_entry32bit_point.get()); + klog() << "DMIDecoder: SMBIOS 32bit Entry point @ P " << String::format("%p", m_entry32bit_point.get()); m_use_64bit_entry = false; auto region = MM.allocate_kernel_region(entry.page_base(), PAGE_ROUND_UP(SMBIOS_SEARCH_AREA_SIZE), "DMI Decoder 32 bit Initialization", Region::Access::Read, false, false); @@ -90,18 +90,18 @@ void DMIDecoder::initialize_parser() if (m_entry32bit_point.is_null() && m_entry64bit_point.is_null()) { m_operable = false; - kprintf("DMI Decoder is disabled. Cannot find SMBIOS tables.\n"); + klog() << "DMI Decoder is disabled. Cannot find SMBIOS tables."; return; } m_operable = true; - kprintf("DMI Decoder is enabled\n"); + klog() << "DMI Decoder is enabled"; if (!m_entry64bit_point.is_null()) { set_64_bit_entry_initialization_values(m_entry64bit_point); } else if (!m_entry32bit_point.is_null()) { set_32_bit_entry_initialization_values(m_entry32bit_point); } - kprintf("DMIDecoder: Data table @ P 0x%x\n", m_structure_table.get()); + klog() << "DMIDecoder: Data table @ P " << String::format("%p", m_structure_table.get()); enumerate_smbios_tables(); } @@ -125,10 +125,10 @@ void DMIDecoder::enumerate_smbios_tables() #endif structures_count++; if (v_table_ptr->type == (u8)SMBIOS::TableType::EndOfTable) { - kprintf("DMIDecoder: Detected table with type 127, End of SMBIOS data.\n"); + klog() << "DMIDecoder: Detected table with type 127, End of SMBIOS data."; break; } - kprintf("DMIDecoder: Detected table with type %d\n", v_table_ptr->type); + klog() << "DMIDecoder: Detected table with type " << v_table_ptr->type; m_smbios_tables.append(p_table); table_length -= v_table_ptr->length; @@ -205,7 +205,7 @@ DMIDecoder::DMIDecoder(bool trusted) , m_untrusted(!trusted) { if (!trusted) { - kprintf("DMI Decoder initialized as untrusted due to user request.\n"); + klog() << "DMI Decoder initialized as untrusted due to user request."; } initialize_parser(); } @@ -249,7 +249,7 @@ PhysicalAddress DMIDecoder::find_entry32bit_point() Vector& DMIDecoder::get_physical_memory_areas() { // FIXME: Implement it... - kprintf("DMIDecoder::get_physical_memory_areas() is not implemented.\n"); + klog() << "DMIDecoder::get_physical_memory_areas() is not implemented."; ASSERT_NOT_REACHED(); } bool DMIDecoder::is_reliable() @@ -264,7 +264,7 @@ u64 DMIDecoder::get_bios_characteristics() auto* bios_info = (SMBIOS::BIOSInfo*)get_smbios_physical_table_by_type(0).as_ptr(); ASSERT(bios_info != nullptr); - kprintf("DMIDecoder: BIOS info @ P 0x%x\n", bios_info); + klog() << "DMIDecoder: BIOS info @ P " << String::format("%p", bios_info); return bios_info->bios_characteristics; } @@ -272,7 +272,7 @@ char* DMIDecoder::get_smbios_string(PhysicalAddress, u8) { // FIXME: Implement it... // FIXME: Make sure we have some mapping here so we don't rely on existing identity mapping... - kprintf("DMIDecoder::get_smbios_string() is not implemented.\n"); + klog() << "DMIDecoder::get_smbios_string() is not implemented."; ASSERT_NOT_REACHED(); return nullptr; } diff --git a/Kernel/ACPI/MultiProcessorParser.cpp b/Kernel/ACPI/MultiProcessorParser.cpp index af0713a27b9..eb00b90de7d 100644 --- a/Kernel/ACPI/MultiProcessorParser.cpp +++ b/Kernel/ACPI/MultiProcessorParser.cpp @@ -48,11 +48,11 @@ MultiProcessorParser::MultiProcessorParser() , m_operable((m_floating_pointer != (uintptr_t) nullptr)) { if (m_floating_pointer != (uintptr_t) nullptr) { - kprintf("MultiProcessor: Floating Pointer Structure @ P 0x%x\n", m_floating_pointer); + klog() << "MultiProcessor: Floating Pointer Structure @ P " << String::format("%p", m_floating_pointer); parse_floating_pointer_data(); parse_configuration_table(); } else { - kprintf("MultiProcessor: Can't Locate Floating Pointer Structure, disabled.\n"); + klog() << "MultiProcessor: Can't Locate Floating Pointer Structure, disabled."; } } @@ -128,7 +128,7 @@ uintptr_t MultiProcessorParser::search_floating_pointer() uintptr_t mp_floating_pointer = (uintptr_t) nullptr; auto region = MM.allocate_kernel_region(PhysicalAddress(0), PAGE_SIZE, "MultiProcessor Parser Floating Pointer Structure Finding", Region::Access::Read); u16 ebda_seg = (u16) * ((uint16_t*)((region->vaddr().get() & PAGE_MASK) + 0x40e)); - kprintf("MultiProcessor: Probing EBDA, Segment 0x%x\n", ebda_seg); + klog() << "MultiProcessor: Probing EBDA, Segment 0x" << String::format("%x", ebda_seg); mp_floating_pointer = search_floating_pointer_in_ebda(ebda_seg); if (mp_floating_pointer != (uintptr_t) nullptr) @@ -195,12 +195,7 @@ Vector> MultiProcessorParser::get_pci_inter for (auto id : pci_bus_ids) { if (id == v_entry_ptr->source_bus_id) { - kprintf("Interrupts: Bus %d, Polarity 0x%x, Trigger Mode 0x%x, INT %x, IOAPIC %d, IOAPIC INTIN %d\n", v_entry_ptr->source_bus_id, - v_entry_ptr->polarity, - v_entry_ptr->trigger_mode, - v_entry_ptr->source_bus_irq, - v_entry_ptr->destination_ioapic_id, - v_entry_ptr->destination_ioapic_intin_pin); + klog() << "Interrupts: Bus " << v_entry_ptr->source_bus_id << ", Polarity " << v_entry_ptr->polarity << ", Trigger Mode " << v_entry_ptr->trigger_mode << ", INT " << v_entry_ptr->source_bus_irq << ", IOAPIC " << v_entry_ptr->destination_ioapic_id << ", IOAPIC INTIN " << v_entry_ptr->destination_ioapic_intin_pin; overrides.append(adopt(*new PCIInterruptOverrideMetadata( v_entry_ptr->source_bus_id, v_entry_ptr->polarity, @@ -213,14 +208,7 @@ Vector> MultiProcessorParser::get_pci_inter } for (auto override_metadata : overrides) { - kprintf("Interrupts: Bus %d, Polarity 0x%x, PCI Device %d, Trigger Mode 0x%x, INT %x, IOAPIC %d, IOAPIC INTIN %d\n", - override_metadata->bus(), - override_metadata->polarity(), - override_metadata->pci_device_number(), - override_metadata->trigger_mode(), - override_metadata->pci_interrupt_pin(), - override_metadata->ioapic_id(), - override_metadata->ioapic_interrupt_pin()); + klog() << "Interrupts: Bus " << override_metadata->bus() << ", Polarity " << override_metadata->polarity() << ", PCI Device " << override_metadata->pci_device_number() << ", Trigger Mode " << override_metadata->trigger_mode() << ", INT " << override_metadata->pci_interrupt_pin() << ", IOAPIC " << override_metadata->ioapic_id() << ", IOAPIC INTIN " << override_metadata->ioapic_interrupt_pin(); } return overrides; } diff --git a/Kernel/Arch/i386/CPU.cpp b/Kernel/Arch/i386/CPU.cpp index 639b4f1c893..c8cb0cd41b6 100644 --- a/Kernel/Arch/i386/CPU.cpp +++ b/Kernel/Arch/i386/CPU.cpp @@ -25,6 +25,7 @@ */ #include +#include #include #include #include @@ -140,13 +141,12 @@ static void dump(const RegisterState& regs) esp = regs.userspace_esp; } - kprintf("exception code: %04x (isr: %04x)\n", regs.exception_code, regs.isr_number); - kprintf(" pc=%04x:%08x flags=%04x\n", (u16)regs.cs, regs.eip, (u16)regs.eflags); - kprintf(" stk=%04x:%08x\n", ss, esp); - kprintf(" ds=%04x es=%04x fs=%04x gs=%04x\n", (u16)regs.ds, (u16)regs.es, (u16)regs.fs, (u16)regs.gs); - kprintf("eax=%08x ebx=%08x ecx=%08x edx=%08x\n", regs.eax, regs.ebx, regs.ecx, regs.edx); - kprintf("ebp=%08x esp=%08x esi=%08x edi=%08x\n", regs.ebp, esp, regs.esi, regs.edi); - + klog() << "exception code: " << String::format("%04x", regs.exception_code) << " (isr: " << String::format("%04x", regs.isr_number); + klog() << " pc=" << String::format("%04x", (u16)regs.cs) << ":" << String::format("%08x", regs.eip) << " flags=" << String::format("%04x", (u16)regs.eflags); + klog() << " stk=" << String::format("%04x", ss) << ":" << String::format("%08x", esp); + klog() << " ds=" << String::format("%04x", (u16)regs.ds) << " es=" << String::format("%04x", (u16)regs.es) << " fs=" << String::format("%04x", (u16)regs.fs) << " gs=" << String::format("%04x", (u16)regs.gs); + klog() << "eax=" << String::format("%08x", regs.eax) << " ebx=" << String::format("%08x", regs.ebx) << " ecx=" << String::format("%08x", regs.ecx) << " edx=" << String::format("%08x", regs.edx); + klog() << "ebp=" << String::format("%08x", regs.ebp) << " esp=" << String::format("%08x", regs.esp) << " esi=" << String::format("%08x", regs.esi) << " edi=" << String::format("%08x", regs.edi); u32 cr0; asm("movl %%cr0, %%eax" : "=a"(cr0)); @@ -157,27 +157,19 @@ static void dump(const RegisterState& regs) u32 cr4; asm("movl %%cr4, %%eax" : "=a"(cr4)); - kprintf("cr0=%08x cr2=%08x cr3=%08x cr4=%08x\n", cr0, cr2, cr3, cr4); + klog() << "cr0=" << String::format("%08x", cr0) << " cr2=" << String::format("%08x", cr2) << " cr3=" << String::format("%08x", cr3) << " cr4=" << String::format("%08x", cr4); if (Process::current && Process::current->validate_read((void*)regs.eip, 8)) { SmapDisabler disabler; u8* codeptr = (u8*)regs.eip; - kprintf("code: %02x %02x %02x %02x %02x %02x %02x %02x\n", - codeptr[0], - codeptr[1], - codeptr[2], - codeptr[3], - codeptr[4], - codeptr[5], - codeptr[6], - codeptr[7]); + klog() << "code: " << String::format("%02x", codeptr[0]) << " " << String::format("%02x", codeptr[1]) << " " << String::format("%02x", codeptr[2]) << " " << String::format("%02x", codeptr[3]) << " " << String::format("%02x", codeptr[4]) << " " << String::format("%02x", codeptr[5]) << " " << String::format("%02x", codeptr[6]) << " " << String::format("%02x", codeptr[7]); } } void handle_crash(RegisterState& regs, const char* description, int signal) { if (!Process::current) { - kprintf("%s with !current\n", description); + klog() << description << " with !current"; hang(); } @@ -185,16 +177,11 @@ void handle_crash(RegisterState& regs, const char* description, int signal) // make sure we switch back to the right page tables. MM.enter_process_paging_scope(*Process::current); - kprintf("\033[31;1mCRASH: %s. %s: %s(%u)\033[0m\n", - description, - Process::current->is_ring0() ? "Kernel" : "Process", - Process::current->name().characters(), - Process::current->pid()); - + klog() << "CRASH: " << description << ". " << (Process::current->is_ring0() ? "Kernel" : "Process") << ": " << Process::current->name().characters() << "(" << Process::current->pid() << ")"; dump(regs); if (Process::current->is_ring0()) { - kprintf("Oh shit, we've crashed in ring 0 :(\n"); + klog() << "Oh shit, we've crashed in ring 0 :("; dump_backtrace(); hang(); } @@ -272,15 +259,7 @@ void page_fault_handler(RegisterState regs) return; } - kprintf("\033[31;1m%s(%u:%u) Unrecoverable page fault, %s%s%s address %p\033[0m\n", - Process::current->name().characters(), - Process::current->pid(), - Thread::current->tid(), - regs.exception_code & PageFaultFlags::ReservedBitViolation ? "reserved bit violation / " : "", - regs.exception_code & PageFaultFlags::InstructionFetch ? "instruction fetch / " : "", - regs.exception_code & PageFaultFlags::Write ? "write to" : "read from", - fault_address); - + klog() << "tid - (" << Thread::current->tid() << ") Unrecoverable page fault, " << (regs.exception_code & PageFaultFlags::ReservedBitViolation ? "reserved bit violation / " : "") << ":" << (regs.exception_code & PageFaultFlags::InstructionFetch ? "instruction fetch / " : "") << ":" << (regs.exception_code & PageFaultFlags::Write ? "write to" : "read from") << " address " << String::format("%p", fault_address); u32 malloc_scrub_pattern = explode_byte(MALLOC_SCRUB_BYTE); u32 free_scrub_pattern = explode_byte(FREE_SCRUB_BYTE); u32 kmalloc_scrub_pattern = explode_byte(KMALLOC_SCRUB_BYTE); @@ -288,19 +267,19 @@ void page_fault_handler(RegisterState regs) u32 slab_alloc_scrub_pattern = explode_byte(SLAB_ALLOC_SCRUB_BYTE); u32 slab_dealloc_scrub_pattern = explode_byte(SLAB_DEALLOC_SCRUB_BYTE); if ((fault_address & 0xffff0000) == (malloc_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be uninitialized malloc() memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be uninitialized malloc() memory"; } else if ((fault_address & 0xffff0000) == (free_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be recently free()'d memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be recently free()'d memory"; } else if ((fault_address & 0xffff0000) == (kmalloc_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be uninitialized kmalloc() memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be uninitialized kmalloc() memory"; } else if ((fault_address & 0xffff0000) == (kfree_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be recently kfree()'d memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be recently kfree()'d memory"; } else if ((fault_address & 0xffff0000) == (slab_alloc_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be uninitialized slab_alloc() memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be uninitialized slab_alloc() memory"; } else if ((fault_address & 0xffff0000) == (slab_dealloc_scrub_pattern & 0xffff0000)) { - kprintf("\033[33;1mNote: Address %p looks like it may be recently slab_dealloc()'d memory\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like it may be recently slab_dealloc()'d memory"; } else if (fault_address < 4096) { - kprintf("\033[33;1mNote: Address %p looks like a possible nullptr dereference\033[0m\n", fault_address); + klog() << "Note: Address " << String::format("%p", fault_address) << " looks like a possible nullptr dereference"; } handle_crash(regs, "Page Fault", SIGSEGV); @@ -313,21 +292,21 @@ void page_fault_handler(RegisterState regs) } } -#define EH(i, msg) \ - static void _exception##i() \ - { \ - kprintf(msg "\n"); \ - u32 cr0, cr2, cr3, cr4; \ - asm("movl %%cr0, %%eax" \ - : "=a"(cr0)); \ - asm("movl %%cr2, %%eax" \ - : "=a"(cr2)); \ - asm("movl %%cr3, %%eax" \ - : "=a"(cr3)); \ - asm("movl %%cr4, %%eax" \ - : "=a"(cr4)); \ - kprintf("CR0=%x CR2=%x CR3=%x CR4=%x\n", cr0, cr2, cr3, cr4); \ - hang(); \ +#define EH(i, msg) \ + static void _exception##i() \ + { \ + klog() << msg; \ + u32 cr0, cr2, cr3, cr4; \ + asm("movl %%cr0, %%eax" \ + : "=a"(cr0)); \ + asm("movl %%cr2, %%eax" \ + : "=a"(cr2)); \ + asm("movl %%cr3, %%eax" \ + : "=a"(cr3)); \ + asm("movl %%cr4, %%eax" \ + : "=a"(cr4)); \ + klog() << "CR0=" << String::format("%x", cr0) << " CR2=" << String::format("%x", cr2) << " CR3=" << String::format("%x", cr3) << " CR4=" << String::format("%x", cr4); \ + hang(); \ } EH(1, "Debug exception") @@ -409,7 +388,7 @@ void gdt_init() static void unimp_trap() { - kprintf("Unhandled IRQ."); + klog() << "Unhandled IRQ."; hang(); } @@ -735,7 +714,7 @@ void cpu_setup() if (g_cpu_supports_sse) { sse_init(); - kprintf("x86: SSE support enabled\n"); + klog() << "x86: SSE support enabled"; } asm volatile( @@ -743,7 +722,7 @@ void cpu_setup() "orl $0x00010000, %%eax\n" "movl %%eax, %%cr0\n" :: : "%eax", "memory"); - kprintf("x86: WP support enabled\n"); + klog() << "x86: WP support enabled"; if (g_cpu_supports_pge) { // Turn on CR4.PGE so the CPU will respect the G bit in page tables. @@ -751,9 +730,9 @@ void cpu_setup() "mov %cr4, %eax\n" "orl $0x80, %eax\n" "mov %eax, %cr4\n"); - kprintf("x86: PGE support enabled\n"); + klog() << "x86: PGE support enabled"; } else { - kprintf("x86: PGE support not detected\n"); + klog() << "x86: PGE support not detected"; } if (g_cpu_supports_nx) { @@ -763,9 +742,9 @@ void cpu_setup() "rdmsr\n" "orl $0x800, %eax\n" "wrmsr\n"); - kprintf("x86: NX support enabled\n"); + klog() << "x86: NX support enabled"; } else { - kprintf("x86: NX support not detected\n"); + klog() << "x86: NX support not detected"; } if (g_cpu_supports_smep) { @@ -774,21 +753,21 @@ void cpu_setup() "mov %cr4, %eax\n" "orl $0x100000, %eax\n" "mov %eax, %cr4\n"); - kprintf("x86: SMEP support enabled\n"); + klog() << "x86: SMEP support enabled"; } else { - kprintf("x86: SMEP support not detected\n"); + klog() << "x86: SMEP support not detected"; } if (g_cpu_supports_smap) { // Turn on CR4.SMAP - kprintf("x86: Enabling SMAP\n"); + klog() << "x86: Enabling SMAP"; asm volatile( "mov %cr4, %eax\n" "orl $0x200000, %eax\n" "mov %eax, %cr4\n"); - kprintf("x86: SMAP support enabled\n"); + klog() << "x86: SMAP support enabled"; } else { - kprintf("x86: SMAP support not detected\n"); + klog() << "x86: SMAP support not detected"; } if (g_cpu_supports_umip) { @@ -796,7 +775,7 @@ void cpu_setup() "mov %cr4, %eax\n" "orl $0x800, %eax\n" "mov %eax, %cr4\n"); - kprintf("x86: UMIP support enabled\n"); + klog() << "x86: UMIP support enabled"; } if (g_cpu_supports_tsc) { @@ -804,13 +783,13 @@ void cpu_setup() "mov %cr4, %eax\n" "orl $0x4, %eax\n" "mov %eax, %cr4\n"); - kprintf("x86: RDTSC support restricted\n"); + klog() << "x86: RDTSC support restricted"; } if (g_cpu_supports_rdrand) { - kprintf("x86: Using RDRAND for good randomness\n"); + klog() << "x86: Using RDRAND for good randomness"; } else { - kprintf("x86: No RDRAND support detected. Randomness will be shitty\n"); + klog() << "x86: No RDRAND support detected. Randomness will be shitty"; } } @@ -834,7 +813,8 @@ void write_cr3(u32 cr3) void __assertion_failed(const char* msg, const char* file, unsigned line, const char* func) { asm volatile("cli"); - kprintf("ASSERTION FAILED: %s\n%s:%u in %s\n", msg, file, line, func); + klog() << "ASSERTION FAILED: " << msg << "\n" + << file << ":" << line << " in " << func; // Switch back to the current process's page tables if there are any. // Otherwise stack walking will be a disaster. diff --git a/Kernel/Devices/BXVGADevice.cpp b/Kernel/Devices/BXVGADevice.cpp index 807456b21eb..5ace534de33 100644 --- a/Kernel/Devices/BXVGADevice.cpp +++ b/Kernel/Devices/BXVGADevice.cpp @@ -160,7 +160,7 @@ u32 BXVGADevice::find_framebuffer_address() PCI::enumerate_all([&framebuffer_address](const PCI::Address& address, PCI::ID id) { if (id == bochs_vga_id || id == virtualbox_vga_id) { framebuffer_address = PCI::get_BAR0(address) & 0xfffffff0; - kprintf("BXVGA: framebuffer @ P%x\n", framebuffer_address); + klog() << "BXVGA: framebuffer @ P " << String::format("%p", framebuffer_address); } }); return framebuffer_address; diff --git a/Kernel/Devices/DiskPartition.cpp b/Kernel/Devices/DiskPartition.cpp index bf0d6e43189..ac6504dad9b 100644 --- a/Kernel/Devices/DiskPartition.cpp +++ b/Kernel/Devices/DiskPartition.cpp @@ -50,7 +50,7 @@ DiskPartition::~DiskPartition() bool DiskPartition::read_blocks(unsigned index, u16 count, u8* out) { #ifdef OFFD_DEBUG - kprintf("DiskPartition::read_blocks %u (really: %u) count=%u\n", index, m_block_offset + index, count); + klog() << "DiskPartition::read_blocks " << index << " (really: " << (m_block_offset + index) << ") count=" << count; #endif return m_device->read_blocks(m_block_offset + index, count, out); @@ -59,7 +59,7 @@ bool DiskPartition::read_blocks(unsigned index, u16 count, u8* out) bool DiskPartition::write_blocks(unsigned index, u16 count, const u8* data) { #ifdef OFFD_DEBUG - kprintf("DiskPartition::write_blocks %u (really: %u) count=%u\n", index, m_block_offset + index, count); + klog() << "DiskPartition::write_blocks " << index << " (really: " << (m_block_offset + index) << ") count=" << count; #endif return m_device->write_blocks(m_block_offset + index, count, data); diff --git a/Kernel/Devices/EBRPartitionTable.cpp b/Kernel/Devices/EBRPartitionTable.cpp index fa672f222d5..d10d3bfa85d 100644 --- a/Kernel/Devices/EBRPartitionTable.cpp +++ b/Kernel/Devices/EBRPartitionTable.cpp @@ -69,11 +69,11 @@ bool EBRPartitionTable::initialize() m_ebr_container_id = index_of_ebr_container() + 1; #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::initialize: MBR_signature=%#x\n", header.mbr_signature); + klog() << "EBRPartitionTable::initialize: MBR_signature=0x" << String::format("%x", header.mbr_signature); #endif if (header.mbr_signature != MBR_SIGNATURE) { - kprintf("EBRPartitionTable::initialize: bad MBR signature %#x\n", header.mbr_signature); + klog() << "EBRPartitionTable::initialize: bad MBR signature 0x" << String::format("%x", header.mbr_signature); return false; } @@ -94,7 +94,7 @@ bool EBRPartitionTable::initialize() m_ebr_chained_extensions_count = index; - kprintf("EBRPartitionTable::initialize: Extended partitions count - %d\n", m_ebr_chained_extensions_count); + klog() << "EBRPartitionTable::initialize: Extended partitions count - " << m_ebr_chained_extensions_count; return true; } @@ -105,19 +105,19 @@ RefPtr EBRPartitionTable::get_non_extended_partition(unsigned ind auto& entry = header.entry[index - 1]; #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: status=%#x offset=%#x\n", entry.status, entry.offset); + klog() << "EBRPartitionTable::partition: status=0x" << String::format("%x", entry.status) << " offset=0x" << String::format("%x", entry.offset); #endif if (entry.offset == 0x00) { #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: missing partition requested index=%d\n", index); + klog() << "EBRPartitionTable::partition: missing partition requested index=" << index; #endif return nullptr; } #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: found partition index=%d type=%x\n", index, entry.type); + klog() << "EBRPartitionTable::partition: found partition index=" << index << " type=" << String::format("%x", entry.type); #endif return DiskPartition::create(m_device, entry.offset, (entry.offset + entry.length)); @@ -130,12 +130,12 @@ RefPtr EBRPartitionTable::get_extended_partition(unsigned index) auto& header = this->header(); #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: relative index %d\n", relative_index); + klog() << "EBRPartitionTable::partition: relative index " << relative_index; #endif auto& ebr_entry = header.entry[m_ebr_container_id - 1]; #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: Extended partition, offset 0x%x, type %x\n", ebr_entry.offset, ebr_entry.type); + klog() << "EBRPartitionTable::partition: Extended partition, offset 0x" << String::format("%x", ebr_entry.offset) << ", type " << String::format("%x", ebr_entry.type); #endif if (!m_device->read_block(ebr_entry.offset, m_cached_ebr_header)) { @@ -144,8 +144,8 @@ RefPtr EBRPartitionTable::get_extended_partition(unsigned index) size_t i = 0; while (i < relative_index) { #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: logical partition, relative offset 0x%x, type %x\n", ebr_extension().entry.offset, ebr_extension().entry.type); - kprintf("EBRPartitionTable::partition: next logical partition, relative offset 0x%x, type %x\n", ebr_extension().next_chained_ebr_extension.offset, ebr_extension().next_chained_ebr_extension.type); + klog() << "EBRPartitionTable::partition: logical partition, relative offset 0x" << String::format("%x", ebr_extension().entry.offset) << ", type " << String::format("%x", ebr_extension().entry.type); + klog() << "EBRPartitionTable::partition: next logical partition, relative offset 0x" << String::format("%x", ebr_extension().next_chained_ebr_extension.offset) << ", type " << String::format("%x", ebr_extension().next_chained_ebr_extension.type); #endif if (ebr_extension().next_chained_ebr_extension.offset == 0 && ebr_extension().next_chained_ebr_extension.type == 0) { break; @@ -158,19 +158,19 @@ RefPtr EBRPartitionTable::get_extended_partition(unsigned index) } #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: status=%#x offset=%#x\n", ebr_extension().entry.status, ebr_extension().entry.offset + ebr_entry.offset); + klog() << "EBRPartitionTable::partition: status=" << String::format("%x", ebr_extension().entry.status) << " offset=" << String::format("%x", ebr_extension().entry.offset + ebr_entry.offset); #endif if (ebr_extension().entry.offset == 0x00) { #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: missing partition requested index=%d\n", index); + klog() << "EBRPartitionTable::partition: missing partition requested index=" << index; #endif return nullptr; } #ifdef EBR_DEBUG - kprintf("EBRPartitionTable::partition: found partition index=%d type=%x\n", index, ebr_extension().entry.type); + klog() << "EBRPartitionTable::partition: found partition index=" << index << " type=" << String::format("%x", ebr_extension().entry.type); #endif return DiskPartition::create(m_device, ebr_extension().entry.offset + ebr_entry.offset, (ebr_extension().entry.offset + ebr_entry.offset + ebr_extension().entry.length)); @@ -187,7 +187,7 @@ RefPtr EBRPartitionTable::partition(unsigned index) auto& header = this->header(); if (header.mbr_signature != MBR_SIGNATURE) { - kprintf("EBRPartitionTable::initialize: bad MBR signature - not initalized? %#x\n", header.mbr_signature); + klog() << "EBRPartitionTable::initialize: bad MBR signature - not initalized? 0x" << String::format("%x", header.mbr_signature); return nullptr; } if (index_is_extended_partition(index)) diff --git a/Kernel/Devices/FloppyDiskDevice.cpp b/Kernel/Devices/FloppyDiskDevice.cpp index 9be38585305..dfe1f8cdaa9 100644 --- a/Kernel/Devices/FloppyDiskDevice.cpp +++ b/Kernel/Devices/FloppyDiskDevice.cpp @@ -134,7 +134,7 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) { LOCKER(m_lock); // Acquire lock #ifdef FLOPPY_DEBUG - kprintf("fdc: read_sectors_with_dma lba = %d count = %d\n", lba, count); + klog() << "fdc: read_sectors_with_dma lba = " << lba << " count = " << count; #endif motor_enable(is_slave()); // Should I bother casting this?! @@ -142,7 +142,7 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) recalibrate(); if (!seek(lba)) { - kprintf("fdc: failed to seek to lba = %d!\n", lba); + klog() << "fdc: failed to seek to lba = " << lba << "!"; return false; } @@ -168,7 +168,7 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) u16 sector = lba2sector(lba); #ifdef FLOPPY_DEBUG - kprintf("fdc: addr = 0x%x c = %d h = %d s = %d\n", lba * BYTES_PER_SECTOR, cylinder, head, sector); + klog() << "fdc: addr = 0x" << String::format("%x", lba * BYTES_PER_SECTOR) << " c = " << cylinder << " h = " << head << " s = " << sector; #endif // Intel recommends 3 attempts for a read/write @@ -194,13 +194,13 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) // the command executed correctly u8 cmd_st0 = read_byte(); if ((cmd_st0 & 0xc0) != 0) { - kprintf("fdc: read failed with error code (st0) 0x%x\n", cmd_st0 >> 6); + klog() << "fdc: read failed with error code (st0) 0x" << String::format("%x", cmd_st0 >> 6); return false; } u8 cmd_st1 = read_byte(); if (cmd_st1 != 0) { - kprintf("fdc: read failed with error code (st1) 0x%x\n", cmd_st1); + klog() << "fdc: read failed with error code (st1) 0x" << String::format("%x", cmd_st1); return false; } @@ -212,7 +212,7 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) if (cyl != cylinder) { #ifdef FLOPPY_DEBUG - kprintf("fdc: cyl != cylinder (cyl = %d cylinder = %d)! Retrying...\n", cyl, cylinder); + klog() << "fdc: cyl != cylinder (cyl = " << cyl << " cylinder = " << cylinder << ")! Retrying..."; #endif continue; } @@ -230,7 +230,7 @@ bool FloppyDiskDevice::read_sectors_with_dma(u16 lba, u16 count, u8* outbuf) } #ifdef FLOPPY_DEBUG - kprintf("fdc: out of read attempts (check your hardware maybe!?)\n"); + klog() << "fdc: out of read attempts (check your hardware maybe!?)"; #endif return false; } @@ -239,7 +239,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu { LOCKER(m_lock); // Acquire lock #ifdef FLOPPY_DEBUG - kprintf("fdc: write_sectors_with_dma lba = %d count = %d\n", lba, count); + klog() << "fdc: write_sectors_with_dma lba = " << lba << " count = " << count; #endif motor_enable(is_slave() ? 1 : 0); // Should I bother casting this?! @@ -247,7 +247,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu recalibrate(); // Recalibrate the drive if (!seek(lba)) { - kprintf("fdc: failed to seek to lba = %d!\n", lba); + klog() << "fdc: failed to seek to lba = " << lba << "!"; return false; } @@ -269,7 +269,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu u16 sector = lba2sector(lba); #ifdef FLOPPY_DEBUG - kprintf("fdc: addr = 0x%x c = %d h = %d s = %d\n", lba * BYTES_PER_SECTOR, cylinder, head, sector); + klog() << "fdc: addr = 0x" << String::format("%x", lba * BYTES_PER_SECTOR) << " c = " << cylinder << " h = " << head << " s = " << sector; #endif for (int i = 0; i < 3; i++) { @@ -292,13 +292,13 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu // Flush FIFO u8 cmd_st0 = read_byte(); if ((cmd_st0 & 0xc0) != 0) { - kprintf("fdc: write failed! Error code 0x%x\n", cmd_st0 >> 6); + klog() << "fdc: write failed! Error code 0x" << String::format("%x", cmd_st0 >> 6); return false; } u8 cmd_st1 = read_byte(); if (cmd_st1 != 0) { - kprintf("fdc: write failed with error code (st1) 0x%x\n", cmd_st1); + klog() << "fdc: write failed with error code (st1) 0x" << String::format("%x", cmd_st1); return false; } @@ -310,7 +310,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu if (cyl != cylinder) { #ifdef FLOPPY_DEBUG - kprintf("fdc: cyl != cylinder (cyl = %d cylinder = %d)! Retrying...\n", cyl, cylinder); + klog() << "fdc: cyl != cylinder (cyl = " << cyl << " cylinder = " << cylinder << ")! Retrying..."; #endif continue; } @@ -328,7 +328,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu } #ifdef FLOPPY_DEBUG - kprintf("fdc: out of read attempts (check your hardware maybe!?)\n"); + klog() << "fdc: out of read attempts (check your hardware maybe!?)"; #endif return false; } @@ -336,7 +336,7 @@ bool FloppyDiskDevice::write_sectors_with_dma(u16 lba, u16 count, const u8* inbu bool FloppyDiskDevice::wait_for_irq() { #ifdef FLOPPY_DEBUG - kprintf("fdc: Waiting for interrupt...\n"); + klog() << "fdc: Waiting for interrupt..."; #endif while (!m_interrupted) { @@ -353,7 +353,7 @@ void FloppyDiskDevice::handle_irq(RegisterState&) m_interrupted = true; #ifdef FLOPPY_DEBUG - kprintf("fdc: Received IRQ!\n"); + klog() << "fdc: Received IRQ!"; #endif } @@ -367,7 +367,7 @@ void FloppyDiskDevice::send_byte(u8 value) const } #ifdef FLOPPY_DEBUG - kprintf("fdc: FIFO write timed out!\n"); + klog() << "fdc: FIFO write timed out!"; #endif } @@ -381,7 +381,7 @@ void FloppyDiskDevice::send_byte(FloppyCommand value) const } #ifdef FLOPPY_DEBUG - kprintf("fdc: FIFO write timed out!\n"); + klog() << "fdc: FIFO write timed out!"; #endif } @@ -394,7 +394,7 @@ u8 FloppyDiskDevice::read_byte() const } #ifdef FLOPPY_DEBUG - kprintf("fdc: FIFO read timed out!\n"); + klog() << "fdc: FIFO read timed out!"; #endif return 0xff; @@ -429,7 +429,7 @@ bool FloppyDiskDevice::is_busy() const bool FloppyDiskDevice::recalibrate() { #ifdef FLOPPY_DEBUG - kprintf("fdc: recalibrating drive...\n"); + klog() << "fdc: recalibrating drive..."; #endif u8 slave = is_slave(); @@ -451,7 +451,7 @@ bool FloppyDiskDevice::recalibrate() } #ifdef FLOPPY_DEBUG - kprintf("fdc: failed to calibrate drive (check your hardware!)\n"); + klog() << "fdc: failed to calibrate drive (check your hardware!)"; #endif return false; } @@ -465,7 +465,7 @@ bool FloppyDiskDevice::seek(u16 lba) // First, we need to enable the correct drive motor motor_enable(slave); #ifdef FLOPPY_DEBUG - kprintf("fdc: seeking to cylinder %d on side %d on drive %d\n", cylinder, head, slave); + klog() << "fdc: seeking to cylinder " << cylinder << " on side " << head << " on drive " << slave; #endif // Try at most 5 times to seek to the desired cylinder @@ -482,7 +482,7 @@ bool FloppyDiskDevice::seek(u16 lba) if ((st0 >> 5) != 1 || pcn != cylinder || (st0 & 0x01)) { #ifdef FLOPPY_DEBUG - kprintf("fdc: failed to seek to cylinder %d on attempt %d!\n", cylinder, attempt); + klog() << "fdc: failed to seek to cylinder " << cylinder << " on attempt " << attempt << "!"; #endif continue; } @@ -490,7 +490,7 @@ bool FloppyDiskDevice::seek(u16 lba) return true; } - kprintf("fdc: failed to seek after 3 attempts! Aborting...\n"); + klog() << "fdc: failed to seek after 3 attempts! Aborting..."; return false; } @@ -498,7 +498,7 @@ bool FloppyDiskDevice::seek(u16 lba) void FloppyDiskDevice::initialize() { #ifdef FLOPPY_DEBUG - kprintf("fdc: m_io_base = 0x%x IRQn = %d\n", m_io_base_addr, IRQ_FLOPPY_DRIVE); + klog() << "fdc: m_io_base = 0x" << String::format("%x", m_io_base_addr) << " IRQn = " << IRQ_FLOPPY_DRIVE; #endif enable_irq(); @@ -506,7 +506,7 @@ void FloppyDiskDevice::initialize() // Get the version of the Floppy Disk Controller send_byte(FloppyCommand::Version); m_controller_version = read_byte(); - kprintf("fdc: Version = 0x%x\n", m_controller_version); + klog() << "fdc: Version = 0x" << String::format("%x", m_controller_version); // Reset write_dor(0); @@ -523,7 +523,7 @@ void FloppyDiskDevice::initialize() u8 sr0 = read_byte(); u8 trk = read_byte(); - kprintf("sr0 = 0x%x, cyl = 0x%x\n", sr0, trk); + klog() << "sr0 = 0x" << String::format("%x", sr0) << ", cyl = 0x" << String::format("%x", trk); } // This is hardcoded for a 3.5" floppy disk drive @@ -534,7 +534,7 @@ void FloppyDiskDevice::initialize() // Allocate a buffer page for us to read into. This only needs to be one sector in size. m_dma_buffer_page = MM.allocate_supervisor_physical_page(); #ifdef FLOPPY_DEBUG - kprintf("fdc: allocated supervisor page at paddr 0x%x\n", m_dma_buffer_page->paddr()); + klog() << "fdc: allocated supervisor page at paddr 0x", String::format("%x", m_dma_buffer_page->paddr()); #endif // Now, let's initialise channel 2 of the DMA controller! @@ -557,7 +557,7 @@ void FloppyDiskDevice::initialize() IO::out8(0xA, 0x2); // Unmask Channel 2 #ifdef FLOPPY_DEBUG - kprintf("fdc: fd%d initialised succesfully!\n", is_slave() ? 1 : 0); + klog() << "fdc: fd" << (is_slave() ? 1 : 0) << " initialised succesfully!"; #endif } diff --git a/Kernel/Devices/GPTPartitionTable.cpp b/Kernel/Devices/GPTPartitionTable.cpp index 12a2698240c..f0701701edc 100644 --- a/Kernel/Devices/GPTPartitionTable.cpp +++ b/Kernel/Devices/GPTPartitionTable.cpp @@ -54,11 +54,11 @@ bool GPTPartitionTable::initialize() auto& header = this->header(); #ifdef GPT_DEBUG - kprintf("GPTPartitionTable::initialize: gpt_signature=%#x%x\n", header.sig[1], header.sig[0]); + klog() << "GPTPartitionTable::initialize: gpt_signature=0x" << String::format("%x", header.sig[1]) << String::format("%x", header.sig[0]); #endif if (header.sig[0] != GPT_SIGNATURE && header.sig[1] != GPT_SIGNATURE2) { - kprintf("GPTPartitionTable::initialize: bad GPT signature %#x%x\n", header.sig[1], header.sig[0]); + klog() << "GPTPartitionTable::initialize: bad GPT signature 0x" << String::format("%x", header.sig[1]) << String::format("%x", header.sig[0]); return false; } @@ -73,7 +73,7 @@ RefPtr GPTPartitionTable::partition(unsigned index) unsigned lba = header.partition_array_start_lba + (((index - 1) * header.partition_entry_size) / BytesPerSector); if (header.sig[0] != GPT_SIGNATURE) { - kprintf("GPTPartitionTable::initialize: bad gpt signature - not initalized? %#x\n", header.sig); + klog() << "GPTPartitionTable::initialize: bad gpt signature - not initalized? 0x" << String::format("%x", header.sig); return nullptr; } @@ -84,20 +84,20 @@ RefPtr GPTPartitionTable::partition(unsigned index) GPTPartitionEntry& entry = entries[((index - 1) % entries_per_sector)]; #ifdef GPT_DEBUG - kprintf("GPTPartitionTable::partition %d\n", index); - kprintf("GPTPartitionTable - offset = %d%d\n", entry.first_lba[1], entry.first_lba[0]); + klog() << "GPTPartitionTable::partition " << index; + klog() << "GPTPartitionTable - offset = " << entry.first_lba[1] << entry.first_lba[0]; #endif if (entry.first_lba[0] == 0x00) { #ifdef GPT_DEBUG - kprintf("GPTPartitionTable::partition: missing partition requested index=%d\n", index); + klog() << "GPTPartitionTable::partition: missing partition requested index=" << index; #endif return nullptr; } #ifdef GPT_DEBUG - kprintf("GPTPartitionTable::partition: found partition index=%d type=%x-%x-%x-%x\n", index, entry.partition_guid[3], entry.partition_guid[2], entry.partition_guid[1], entry.partition_guid[0]); + klog() << "GPTPartitionTable::partition: found partition index=" << index << " type=" << String::format("%x", entry.partition_guid[3]) << "-" << String::format("%x", entry.partition_guid[2]) << "-" << String::format("%x", entry.partition_guid[1]) << "-" << String::format("%x", entry.partition_guid[0]); #endif return DiskPartition::create(m_device, entry.first_lba[0], entry.last_lba[0]); } diff --git a/Kernel/Devices/MBRPartitionTable.cpp b/Kernel/Devices/MBRPartitionTable.cpp index ea8e1e62310..bd9baa38a65 100644 --- a/Kernel/Devices/MBRPartitionTable.cpp +++ b/Kernel/Devices/MBRPartitionTable.cpp @@ -54,11 +54,11 @@ bool MBRPartitionTable::initialize() auto& header = this->header(); #ifdef MBR_DEBUG - kprintf("MBRPartitionTable::initialize: mbr_signature=%#x\n", header.mbr_signature); + klog() << "MBRPartitionTable::initialize: mbr_signature=0x" << String::format("%x", header.mbr_signature); #endif if (header.mbr_signature != MBR_SIGNATURE) { - kprintf("MBRPartitionTable::initialize: bad mbr signature %#x\n", header.mbr_signature); + klog() << "MBRPartitionTable::initialize: bad mbr signature 0x" << String::format("%x", header.mbr_signature); return false; } @@ -87,24 +87,24 @@ RefPtr MBRPartitionTable::partition(unsigned index) auto& entry = header.entry[index - 1]; if (header.mbr_signature != MBR_SIGNATURE) { - kprintf("MBRPartitionTable::initialize: bad mbr signature - not initalized? %#x\n", header.mbr_signature); + klog() << "MBRPartitionTable::initialize: bad mbr signature - not initalized? 0x" << String::format("%x", header.mbr_signature); return nullptr; } #ifdef MBR_DEBUG - kprintf("MBRPartitionTable::partition: status=%#x offset=%#x\n", entry.status, entry.offset); + klog() << "MBRPartitionTable::partition: status=0x" << String::format("%x", entry.status) << " offset=0x" << String::format("%x", entry.offset); #endif if (entry.offset == 0x00) { #ifdef MBR_DEBUG - kprintf("MBRPartitionTable::partition: missing partition requested index=%d\n", index); + klog() << "MBRPartitionTable::partition: missing partition requested index=" << index; #endif return nullptr; } #ifdef MBR_DEBUG - kprintf("MBRPartitionTable::partition: found partition index=%d type=%x\n", index, entry.type); + klog() << "MBRPartitionTable::partition: found partition index=" << index << " type=" << String::format("%x", entry.type); #endif return DiskPartition::create(m_device, entry.offset, (entry.offset + entry.length)); diff --git a/Kernel/Devices/PATAChannel.cpp b/Kernel/Devices/PATAChannel.cpp index 771c0b3ba87..2ddf05212a3 100644 --- a/Kernel/Devices/PATAChannel.cpp +++ b/Kernel/Devices/PATAChannel.cpp @@ -261,7 +261,7 @@ bool PATAChannel::ata_read_sectors_with_dma(u32 lba, u16 count, u8* outbuf, bool { LOCKER(s_lock()); #ifdef PATA_DEBUG - dbg() << Process::current->name().characters() << "(" << Process::current->pid() << "): PATAChannel::ata_read_sectors_with_dma (" << lba << " x" << count << ") -> " << outbuf; + dbg() << "PATAChannel::ata_read_sectors_with_dma (" << lba << " x" << count << ") -> " << outbuf; #endif prdt().offset = m_dma_buffer_page->paddr(); @@ -332,7 +332,7 @@ bool PATAChannel::ata_write_sectors_with_dma(u32 lba, u16 count, const u8* inbuf { LOCKER(s_lock()); #ifdef PATA_DEBUG - dbg() << Process::current->name().characters() << "(" << Process::current->pid() << "): PATAChannel::ata_write_sectors_with_dma (" << lba << " x" << count << ") <- " << inbuf; + dbg() << "PATAChannel::ata_write_sectors_with_dma (" << lba << " x" << count << ") <- " << inbuf; #endif prdt().offset = m_dma_buffer_page->paddr(); @@ -401,7 +401,7 @@ bool PATAChannel::ata_read_sectors(u32 start_sector, u16 count, u8* outbuf, bool ASSERT(count <= 256); LOCKER(s_lock()); #ifdef PATA_DEBUG - dbg() << Process::current->name().characters() << "(" << Process::current->pid() << "): PATAChannel::ata_read_sectors request (" << count << " sector(s) @ " << start_sector << " into " << outbuf << ")"; + dbg() << "PATAChannel::ata_read_sectors request (" << count << " sector(s) @ " << start_sector << " into " << outbuf << ")"; #endif while (m_io_base.offset(ATA_REG_STATUS).in() & ATA_SR_BSY) diff --git a/Kernel/Devices/PIT.cpp b/Kernel/Devices/PIT.cpp index 9fa2e7a1901..e6e6ed6dda1 100644 --- a/Kernel/Devices/PIT.cpp +++ b/Kernel/Devices/PIT.cpp @@ -84,7 +84,7 @@ PIT::PIT() IO::out8(PIT_CTL, TIMER0_SELECT | WRITE_WORD | MODE_SQUARE_WAVE); - kprintf("PIT: %u Hz, square wave (%x)\n", TICKS_PER_SECOND, m_default_timer_reload); + klog() << "PIT: " << TICKS_PER_SECOND << " Hz, square wave (" << String::format("%x", m_default_timer_reload) << ")"; IO::out8(TIMER0_CTL, LSB(m_default_timer_reload)); IO::out8(TIMER0_CTL, MSB(m_default_timer_reload)); diff --git a/Kernel/Devices/PS2MouseDevice.cpp b/Kernel/Devices/PS2MouseDevice.cpp index 8248d4bcc4b..946e62f1722 100644 --- a/Kernel/Devices/PS2MouseDevice.cpp +++ b/Kernel/Devices/PS2MouseDevice.cpp @@ -246,7 +246,7 @@ void PS2MouseDevice::check_device_presence() u8 maybe_ack = mouse_read(); if (maybe_ack == I8042_ACK) { m_device_present = true; - kprintf("PS2MouseDevice: Device detected\n"); + klog() << "PS2MouseDevice: Device detected"; // the mouse will send a packet of data, since that's what we asked // for. we don't care about the content. @@ -255,7 +255,7 @@ void PS2MouseDevice::check_device_presence() mouse_read(); } else { m_device_present = false; - kprintf("PS2MouseDevice: Device not detected\n"); + klog() << "PS2MouseDevice: Device not detected"; } } @@ -307,9 +307,9 @@ void PS2MouseDevice::initialize_device() if (device_id == PS2MOUSE_INTELLIMOUSE_ID) { m_has_wheel = true; - kprintf("PS2MouseDevice: Mouse wheel enabled!\n"); + klog() << "PS2MouseDevice: Mouse wheel enabled!"; } else { - kprintf("PS2MouseDevice: No mouse wheel detected!\n"); + klog() << "PS2MouseDevice: No mouse wheel detected!"; } enable_irq(); diff --git a/Kernel/Devices/SB16.cpp b/Kernel/Devices/SB16.cpp index 5d30d817e28..b18a8622126 100644 --- a/Kernel/Devices/SB16.cpp +++ b/Kernel/Devices/SB16.cpp @@ -103,7 +103,7 @@ void SB16::initialize() auto data = dsp_read(); if (data != 0xaa) { - kprintf("SB16: sb not ready"); + klog() << "SB16: sb not ready"; return; } @@ -112,9 +112,9 @@ void SB16::initialize() m_major_version = dsp_read(); auto vmin = dsp_read(); - kprintf("SB16: found version %d.%d\n", m_major_version, vmin); + klog() << "SB16: found version " << m_major_version << "." << vmin; set_irq_register(SB16_DEFAULT_IRQ); - kprintf("SB16: IRQ %d\n", get_irq_line()); + klog() << "SB16: IRQ " << get_irq_line(); } void SB16::set_irq_register(u8 irq_number) @@ -235,7 +235,7 @@ ssize_t SB16::write(FileDescription&, const u8* data, ssize_t length) } #ifdef SB16_DEBUG - kprintf("SB16: Writing buffer of %d bytes\n", length); + klog() << "SB16: Writing buffer of " << length << " bytes"; #endif ASSERT(length <= PAGE_SIZE); const int BLOCK_SIZE = 32 * 1024; diff --git a/Kernel/Devices/VMWareBackdoor.cpp b/Kernel/Devices/VMWareBackdoor.cpp index 4505f1d0663..38068e72cf7 100644 --- a/Kernel/Devices/VMWareBackdoor.cpp +++ b/Kernel/Devices/VMWareBackdoor.cpp @@ -97,11 +97,11 @@ VMWareBackdoor& VMWareBackdoor::the() VMWareBackdoor::VMWareBackdoor() { if (!detect_presence()) { - kprintf("VMWare Backdoor: Not supported!\n"); + klog() << "VMWare Backdoor: Not supported!"; m_supported = false; return; } - kprintf("VMWare Backdoor: Supported.\n"); + klog() << "VMWare Backdoor: Supported."; m_supported = true; } bool VMWareBackdoor::detect_presence() @@ -153,7 +153,7 @@ void VMWareBackdoor::enable_absolute_vmmouse() command.command = VMMOUSE_STATUS; send(command); if (command.ax == 0xFFFF0000) { - kprintf("VMMouse retuned bad status.\n"); + klog() << "VMMouse retuned bad status."; return; } diff --git a/Kernel/FileSystem/DiskBackedFileSystem.cpp b/Kernel/FileSystem/DiskBackedFileSystem.cpp index 62b61285d4b..98233da3adc 100644 --- a/Kernel/FileSystem/DiskBackedFileSystem.cpp +++ b/Kernel/FileSystem/DiskBackedFileSystem.cpp @@ -125,7 +125,7 @@ DiskBackedFS::~DiskBackedFS() bool DiskBackedFS::write_block(unsigned index, const u8* data, FileDescription* description) { #ifdef DBFS_DEBUG - kprintf("DiskBackedFileSystem::write_block %u, size=%u\n", index, data.size()); + klog() << "DiskBackedFileSystem::write_block " << index << ", size=" << data.size(); #endif bool allow_cache = !description || !description->is_direct(); @@ -149,7 +149,7 @@ bool DiskBackedFS::write_block(unsigned index, const u8* data, FileDescription* bool DiskBackedFS::write_blocks(unsigned index, unsigned count, const u8* data, FileDescription* description) { #ifdef DBFS_DEBUG - kprintf("DiskBackedFileSystem::write_blocks %u x%u\n", index, count); + klog() << "DiskBackedFileSystem::write_blocks " << index << " x%u" << count; #endif for (unsigned i = 0; i < count; ++i) write_block(index + i, data + i * block_size(), description); @@ -159,7 +159,7 @@ bool DiskBackedFS::write_blocks(unsigned index, unsigned count, const u8* data, bool DiskBackedFS::read_block(unsigned index, u8* buffer, FileDescription* description) const { #ifdef DBFS_DEBUG - kprintf("DiskBackedFileSystem::read_block %u\n", index); + klog() << "DiskBackedFileSystem::read_block " << index; #endif bool allow_cache = !description || !description->is_direct(); diff --git a/Kernel/FileSystem/Ext2FileSystem.cpp b/Kernel/FileSystem/Ext2FileSystem.cpp index 868859d7814..fe6c282ff96 100644 --- a/Kernel/FileSystem/Ext2FileSystem.cpp +++ b/Kernel/FileSystem/Ext2FileSystem.cpp @@ -100,20 +100,20 @@ bool Ext2FS::initialize() auto& super_block = this->super_block(); #ifdef EXT2_DEBUG - kprintf("ext2fs: super block magic: %x (super block size: %u)\n", super_block.s_magic, sizeof(ext2_super_block)); + klog() << "ext2fs: super block magic: " << String::format("%x", super_block.s_magic) << " (super block size: " << sizeof(ext2_super_block) << ")"; #endif if (super_block.s_magic != EXT2_SUPER_MAGIC) return false; #ifdef EXT2_DEBUG - kprintf("ext2fs: %u inodes, %u blocks\n", super_block.s_inodes_count, super_block.s_blocks_count); - kprintf("ext2fs: block size = %u\n", EXT2_BLOCK_SIZE(&super_block)); - kprintf("ext2fs: first data block = %u\n", super_block.s_first_data_block); - kprintf("ext2fs: inodes per block = %u\n", inodes_per_block()); - kprintf("ext2fs: inodes per group = %u\n", inodes_per_group()); - kprintf("ext2fs: free inodes = %u\n", super_block.s_free_inodes_count); - kprintf("ext2fs: desc per block = %u\n", EXT2_DESC_PER_BLOCK(&super_block)); - kprintf("ext2fs: desc size = %u\n", EXT2_DESC_SIZE(&super_block)); + klog() << "ext2fs: " << super_block.s_inodes_count << " inodes, " << super_block.s_blocks_count << " blocks"; + klog() << "ext2fs: block size = " << EXT2_BLOCK_SIZE(&super_block); + klog() << "ext2fs: first data block = " << super_block.s_first_data_block; + klog() << "ext2fs: inodes per block = " << inodes_per_block(); + klog() << "ext2fs: inodes per group = " << inodes_per_group(); + klog() << "ext2fs: free inodes = " << super_block.s_free_inodes_count; + klog() << "ext2fs: desc per block = " << EXT2_DESC_PER_BLOCK(&super_block); + klog() << "ext2fs: desc size = " << EXT2_DESC_SIZE(&super_block); #endif set_block_size(EXT2_BLOCK_SIZE(&super_block)); @@ -123,7 +123,7 @@ bool Ext2FS::initialize() m_block_group_count = ceil_div(super_block.s_blocks_count, super_block.s_blocks_per_group); if (m_block_group_count == 0) { - kprintf("ext2fs: no block groups :(\n"); + klog() << "ext2fs: no block groups :("; return false; } @@ -135,11 +135,7 @@ bool Ext2FS::initialize() #ifdef EXT2_DEBUG for (unsigned i = 1; i <= m_block_group_count; ++i) { auto& group = group_descriptor(i); - kprintf("ext2fs: group[%u] { block_bitmap: %u, inode_bitmap: %u, inode_table: %u }\n", - i, - group.bg_block_bitmap, - group.bg_inode_bitmap, - group.bg_inode_table); + klog() << "ext2fs: group[" << i << "] { block_bitmap: " << group.bg_block_bitmap << ", inode_bitmap: " << group.bg_inode_bitmap << ", inode_table: " << group.bg_inode_table << " }"; } #endif @@ -662,7 +658,7 @@ ssize_t Ext2FSInode::read_bytes(off_t offset, ssize_t count, u8* buffer, FileDes m_block_list = fs().block_list_for_inode(m_raw_inode); if (m_block_list.is_empty()) { - kprintf("ext2fs: read_bytes: empty block list for inode %u\n", index()); + klog() << "ext2fs: read_bytes: empty block list for inode " << index(); return -EIO; } @@ -690,7 +686,7 @@ ssize_t Ext2FSInode::read_bytes(off_t offset, ssize_t count, u8* buffer, FileDes ASSERT(block_index); bool success = fs().read_block(block_index, block, description); if (!success) { - kprintf("ext2fs: read_bytes: read_block(%u) failed (lbi: %u)\n", block_index, bi); + klog() << "ext2fs: read_bytes: read_block(" << block_index << ") failed (lbi: " << bi << ")"; return -EIO; } @@ -1182,7 +1178,7 @@ unsigned Ext2FS::find_a_free_inode(GroupIndex preferred_group, off_t expected_si } if (!group_index) { - kprintf("Ext2FS: find_a_free_inode: no suitable group found for new inode with %u blocks needed :(\n", needed_blocks); + klog() << "Ext2FS: find_a_free_inode: no suitable group found for new inode with " << needed_blocks << " blocks needed :("; return 0; } @@ -1206,7 +1202,7 @@ unsigned Ext2FS::find_a_free_inode(GroupIndex preferred_group, off_t expected_si } if (!first_free_inode_in_group) { - kprintf("Ext2FS: first_free_inode_in_group returned no inode, despite bgd claiming there are inodes :(\n"); + klog() << "Ext2FS: first_free_inode_in_group returned no inode, despite bgd claiming there are inodes :("; return 0; } @@ -1433,7 +1429,7 @@ KResultOr> Ext2FS::create_inode(InodeIdentifier parent_id, // NOTE: This doesn't commit the inode allocation just yet! auto inode_id = find_a_free_inode(0, size); if (!inode_id) { - kprintf("Ext2FS: create_inode: allocate_inode failed\n"); + klog() << "Ext2FS: create_inode: allocate_inode failed"; return KResult(-ENOSPC); } diff --git a/Kernel/FileSystem/FIFO.cpp b/Kernel/FileSystem/FIFO.cpp index af84301e0b3..e1ae8d59b43 100644 --- a/Kernel/FileSystem/FIFO.cpp +++ b/Kernel/FileSystem/FIFO.cpp @@ -78,12 +78,12 @@ void FIFO::attach(Direction direction) if (direction == Direction::Reader) { ++m_readers; #ifdef FIFO_DEBUG - kprintf("open reader (%u)\n", m_readers); + klog() << "open reader (" << m_readers << ")"; #endif } else if (direction == Direction::Writer) { ++m_writers; #ifdef FIFO_DEBUG - kprintf("open writer (%u)\n", m_writers); + klog() << "open writer (" << m_writers << ")"; #endif } } @@ -92,13 +92,13 @@ void FIFO::detach(Direction direction) { if (direction == Direction::Reader) { #ifdef FIFO_DEBUG - kprintf("close reader (%u - 1)\n", m_readers); + klog() << "close reader (" << m_readers << " - 1)"; #endif ASSERT(m_readers); --m_readers; } else if (direction == Direction::Writer) { #ifdef FIFO_DEBUG - kprintf("close writer (%u - 1)\n", m_writers); + klog() << "close writer (" << m_writers << " - 1)"; #endif ASSERT(m_writers); --m_writers; diff --git a/Kernel/FileSystem/Inode.cpp b/Kernel/FileSystem/Inode.cpp index 862df5f5ec9..0442dd0a0e9 100644 --- a/Kernel/FileSystem/Inode.cpp +++ b/Kernel/FileSystem/Inode.cpp @@ -79,7 +79,7 @@ ByteBuffer Inode::read_entire(FileDescription* descriptor) const break; } if (nread < 0) { - kprintf("Inode::read_entire: ERROR: %d\n", nread); + klog() << "Inode::read_entire: ERROR: " << nread; return nullptr; } diff --git a/Kernel/FileSystem/VirtualFileSystem.cpp b/Kernel/FileSystem/VirtualFileSystem.cpp index d1d9064c128..65f28051da1 100644 --- a/Kernel/FileSystem/VirtualFileSystem.cpp +++ b/Kernel/FileSystem/VirtualFileSystem.cpp @@ -52,7 +52,7 @@ VFS& VFS::the() VFS::VFS() { #ifdef VFS_DEBUG - kprintf("VFS: Constructing VFS\n"); + klog() << "VFS: Constructing VFS"; #endif s_the = this; } @@ -112,7 +112,7 @@ KResult VFS::unmount(InodeIdentifier guest_inode_id) bool VFS::mount_root(FS& file_system) { if (m_root_inode) { - kprintf("VFS: mount_root can't mount another root\n"); + klog() << "VFS: mount_root can't mount another root"; return false; } @@ -121,7 +121,7 @@ bool VFS::mount_root(FS& file_system) auto root_inode_id = mount.guest().fs()->root_inode(); auto root_inode = mount.guest().fs()->get_inode(root_inode_id); if (!root_inode->is_directory()) { - kprintf("VFS: root inode (%02u:%08u) for / is not a directory :(\n", root_inode_id.fsid(), root_inode_id.index()); + klog() << "VFS: root inode (" << String::format("%02u", root_inode_id.fsid()) << ":" << String::format("%08u", root_inode_id.index()) << ") for / is not a directory :("; return false; } @@ -133,7 +133,7 @@ bool VFS::mount_root(FS& file_system) } else { sprintf(device_name, "not-a-disk"); } - kprintf("VFS: mounted root on %s (%s)\n", m_root_inode->fs().class_name(), device_name); + klog() << "VFS: mounted root on " << m_root_inode->fs().class_name() << " (" << device_name << ")"; m_mounts.append(move(mount)); return true; diff --git a/Kernel/Heap/kmalloc.cpp b/Kernel/Heap/kmalloc.cpp index 936e4b15537..f068a389121 100644 --- a/Kernel/Heap/kmalloc.cpp +++ b/Kernel/Heap/kmalloc.cpp @@ -124,7 +124,7 @@ void* kmalloc_impl(size_t size) if (sum_free < real_size) { Kernel::dump_backtrace(); - kprintf("%s(%u) kmalloc(): PANIC! Out of memory (sucks, dude)\nsum_free=%u, real_size=%u\n", Kernel::Process::current->name().characters(), Kernel::Process::current->pid(), sum_free, real_size); + klog() << "kmalloc(): PANIC! Out of memory (sucks, dude)\nsum_free=" << sum_free << ", real_size=" << real_size; Kernel::hang(); } @@ -174,7 +174,7 @@ void* kmalloc_impl(size_t size) } } - kprintf("%s(%u) kmalloc(): PANIC! Out of memory (no suitable block for size %u)\n", Kernel::Process::current->name().characters(), Kernel::Process::current->pid(), size); + klog() << "kmalloc(): PANIC! Out of memory (no suitable block for size " << size << ")"; Kernel::dump_backtrace(); Kernel::hang(); } diff --git a/Kernel/Interrupts/APIC.cpp b/Kernel/Interrupts/APIC.cpp index ef7abac3884..b950c85acd1 100644 --- a/Kernel/Interrupts/APIC.cpp +++ b/Kernel/Interrupts/APIC.cpp @@ -172,7 +172,7 @@ namespace APIC { return false; PhysicalAddress apic_base = get_base(); - kprintf("Initializing APIC, base: P%x\n", apic_base); + klog() << "Initializing APIC, base: P " << String::format("%p", apic_base); set_base(apic_base); g_apic_base = apic_base.as_ptr(); @@ -188,7 +188,7 @@ namespace APIC { void enable(u32 cpu) { - kprintf("Enabling local APIC for cpu #%u\n", cpu); + klog() << "Enabling local APIC for cpu #" << cpu; // set spurious interrupt vector write_register(APIC_REG_SIV, read_register(APIC_REG_SIV) | 0x100); diff --git a/Kernel/Interrupts/IOAPIC.cpp b/Kernel/Interrupts/IOAPIC.cpp index a3a312d9564..21700dc5962 100644 --- a/Kernel/Interrupts/IOAPIC.cpp +++ b/Kernel/Interrupts/IOAPIC.cpp @@ -51,9 +51,9 @@ IOAPIC::IOAPIC(ioapic_mmio_regs& regs, u32 gsi_base, Vector(kmalloc_eternal(sizeof(KSym) * ksym_count)); ++bufptr; // skip newline - kprintf("Loading ksyms..."); + klog() << "Loading ksyms..."; unsigned current_ksym_index = 0; @@ -110,7 +110,7 @@ static void load_ksyms_from_data(const ByteBuffer& buffer) ++bufptr; ++current_ksym_index; } - kprintf("ok\n"); + klog() << "ok"; ksyms_ready = true; } diff --git a/Kernel/Lock.cpp b/Kernel/Lock.cpp index 4d3625f2ee2..ae3a1b87366 100644 --- a/Kernel/Lock.cpp +++ b/Kernel/Lock.cpp @@ -34,7 +34,7 @@ void Lock::lock() { ASSERT(!Scheduler::is_active()); if (!are_interrupts_enabled()) { - kprintf("Interrupts disabled when trying to take Lock{%s}\n", m_name); + klog() << "Interrupts disabled when trying to take Lock{" << m_name << "}"; dump_backtrace(); hang(); } diff --git a/Kernel/Net/IPv4Socket.cpp b/Kernel/Net/IPv4Socket.cpp index df07aef537f..2ab9c553ff0 100644 --- a/Kernel/Net/IPv4Socket.cpp +++ b/Kernel/Net/IPv4Socket.cpp @@ -68,7 +68,7 @@ IPv4Socket::IPv4Socket(int type, int protocol) : Socket(AF_INET, type, protocol) { #ifdef IPV4_SOCKET_DEBUG - kprintf("%s(%u) IPv4Socket{%p} created with type=%u, protocol=%d\n", Process::current->name().characters(), Process::current->pid(), this, type, protocol); + dbg() << "IPv4Socket{" << this << "} created with type=" << type << ", protocol=" << protocol; #endif m_buffer_mode = type == SOCK_STREAM ? BufferMode::Bytes : BufferMode::Packets; if (m_buffer_mode == BufferMode::Bytes) { @@ -138,7 +138,7 @@ KResult IPv4Socket::listen(size_t backlog) m_role = Role::Listener; #ifdef IPV4_SOCKET_DEBUG - kprintf("IPv4Socket{%p} listening with backlog=%zu\n", this, backlog); + dbg() << "IPv4Socket{" << this << "} listening with backlog=" << backlog; #endif return protocol_listen(); @@ -201,7 +201,7 @@ ssize_t IPv4Socket::sendto(FileDescription&, const void* data, size_t data_lengt if (addr) { if (addr->sa_family != AF_INET) { - kprintf("sendto: Bad address family: %u is not AF_INET!\n", addr->sa_family); + klog() << "sendto: Bad address family: " << addr->sa_family << " is not AF_INET!"; return -EAFNOSUPPORT; } @@ -222,7 +222,7 @@ ssize_t IPv4Socket::sendto(FileDescription&, const void* data, size_t data_lengt return rc; #ifdef IPV4_SOCKET_DEBUG - kprintf("sendto: destination=%s:%u\n", m_peer_address.to_string().characters(), m_peer_port); + klog() << "sendto: destination=" << m_peer_address.to_string().characters() << ":" << m_peer_port; #endif if (type() == SOCK_RAW) { @@ -283,13 +283,13 @@ ssize_t IPv4Socket::receive_packet_buffered(FileDescription& description, void* packet = m_receive_queue.take_first(); m_can_read = !m_receive_queue.is_empty(); #ifdef IPV4_SOCKET_DEBUG - kprintf("IPv4Socket(%p): recvfrom without blocking %d bytes, packets in queue: %zu\n", this, packet.data.value().size(), m_receive_queue.size_slow()); + dbg() << "IPv4Socket(" << this << "): recvfrom without blocking " << packet.data.value().size() << " bytes, packets in queue: " << m_receive_queue.size_slow(); #endif } } if (!packet.data.has_value()) { if (protocol_is_disconnected()) { - kprintf("IPv4Socket{%p} is protocol-disconnected, returning 0 in recvfrom!\n", this); + dbg() << "IPv4Socket{" << this << "} is protocol-disconnected, returning 0 in recvfrom!"; return 0; } @@ -308,7 +308,7 @@ ssize_t IPv4Socket::receive_packet_buffered(FileDescription& description, void* packet = m_receive_queue.take_first(); m_can_read = !m_receive_queue.is_empty(); #ifdef IPV4_SOCKET_DEBUG - kprintf("IPv4Socket(%p): recvfrom with blocking %d bytes, packets in queue: %zu\n", this, packet.data.value().size(), m_receive_queue.size_slow()); + dbg() << "IPv4Socket(" << this << "): recvfrom with blocking " << packet.data.value().size() << " bytes, packets in queue: " << m_receive_queue.size_slow(); #endif } ASSERT(packet.data.has_value()); @@ -341,7 +341,7 @@ ssize_t IPv4Socket::recvfrom(FileDescription& description, void* buffer, size_t return -EINVAL; #ifdef IPV4_SOCKET_DEBUG - kprintf("recvfrom: type=%d, local_port=%u\n", type(), local_port()); + klog() << "recvfrom: type=" << type() << ", local_port=" << local_port(); #endif ssize_t nreceived = 0; @@ -367,7 +367,7 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port, if (buffer_mode() == BufferMode::Bytes) { size_t space_in_receive_buffer = m_receive_buffer.space_for_writing(); if (packet_size > space_in_receive_buffer) { - kprintf("IPv4Socket(%p): did_receive refusing packet since buffer is full.\n", this); + dbg() << "IPv4Socket(" << this << "): did_receive refusing packet since buffer is full."; ASSERT(m_can_read); return false; } @@ -377,7 +377,7 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port, } else { // FIXME: Maybe track the number of packets so we don't have to walk the entire packet queue to count them.. if (m_receive_queue.size_slow() > 2000) { - kprintf("IPv4Socket(%p): did_receive refusing packet since queue is full.\n", this); + dbg() << "IPv4Socket(" << this << "): did_receive refusing packet since queue is full."; return false; } m_receive_queue.append({ source_address, source_port, move(packet) }); @@ -386,9 +386,9 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port, m_bytes_received += packet_size; #ifdef IPV4_SOCKET_DEBUG if (buffer_mode() == BufferMode::Bytes) - kprintf("IPv4Socket(%p): did_receive %d bytes, total_received=%u\n", this, packet_size, m_bytes_received); + dbg() << "IPv4Socket(" << this << "): did_receive " << packet_size << " bytes, total_received=" << m_bytes_received; else - kprintf("IPv4Socket(%p): did_receive %d bytes, total_received=%u, packets in queue: %zu\n", this, packet_size, m_bytes_received, m_receive_queue.size_slow()); + dbg() << "IPv4Socket(" << this << "): did_receive " << packet_size << " bytes, total_received=" << m_bytes_received << ", packets in queue: " << m_receive_queue.size_slow(); #endif return true; } diff --git a/Kernel/Net/LocalSocket.cpp b/Kernel/Net/LocalSocket.cpp index eb956a2f7f6..4a72b267dcd 100644 --- a/Kernel/Net/LocalSocket.cpp +++ b/Kernel/Net/LocalSocket.cpp @@ -68,7 +68,7 @@ LocalSocket::LocalSocket(int type) m_prebind_mode = 0666; #ifdef DEBUG_LOCAL_SOCKET - kprintf("%s(%u) LocalSocket{%p} created with type=%u\n", Process::current->name().characters(), Process::current->pid(), this, type); + dbg() << "LocalSocket{" << this << "} created with type=" << type; #endif } @@ -105,7 +105,7 @@ KResult LocalSocket::bind(const sockaddr* user_address, socklen_t address_size) auto path = String(address.sun_path, strnlen(address.sun_path, sizeof(address.sun_path))); #ifdef DEBUG_LOCAL_SOCKET - kprintf("%s(%u) LocalSocket{%p} bind(%s)\n", Process::current->name().characters(), Process::current->pid(), this, safe_address); + dbg() << "LocalSocket{" << this << "} bind(" << safe_address << ")"; #endif mode_t mode = S_IFSOCK | (m_prebind_mode & 04777); @@ -145,7 +145,7 @@ KResult LocalSocket::connect(FileDescription& description, const sockaddr* addre memcpy(safe_address, local_address.sun_path, sizeof(local_address.sun_path)); #ifdef DEBUG_LOCAL_SOCKET - kprintf("%s(%u) LocalSocket{%p} connect(%s)\n", Process::current->name().characters(), Process::current->pid(), this, safe_address); + dbg() << "LocalSocket{" << this << "} connect(" << safe_address << ")"; #endif auto description_or_error = VFS::the().open(safe_address, O_RDWR, 0, Process::current->current_directory()); @@ -181,7 +181,7 @@ KResult LocalSocket::connect(FileDescription& description, const sockaddr* addre } #ifdef DEBUG_LOCAL_SOCKET - kprintf("%s(%u) LocalSocket{%p} connect(%s) status is %s\n", Process::current->name().characters(), Process::current->pid(), this, safe_address, to_string(setup_state())); + dbg() << "LocalSocket{" << this << "} connect(" << safe_address << ") status is " << to_string(setup_state()); #endif if (!is_connected()) { @@ -200,7 +200,7 @@ KResult LocalSocket::listen(size_t backlog) set_backlog(backlog); m_connect_side_role = m_role = Role::Listener; #ifdef DEBUG_LOCAL_SOCKET - kprintf("LocalSocket{%p} listening with backlog=%zu\n", this, backlog); + dbg() << "LocalSocket{" << this << "} listening with backlog=" << backlog; #endif return KSuccess; } diff --git a/Kernel/Net/NetworkTask.cpp b/Kernel/Net/NetworkTask.cpp index 9e3e8b296c9..3cd116e1efa 100644 --- a/Kernel/Net/NetworkTask.cpp +++ b/Kernel/Net/NetworkTask.cpp @@ -72,12 +72,7 @@ void NetworkTask_main() adapter.set_ipv4_gateway({ 10, 0, 2, 2 }); } - kprintf("NetworkTask: %s network adapter found: hw=%s address=%s netmask=%s gateway=%s\n", - adapter.class_name(), - adapter.mac_address().to_string().characters(), - adapter.ipv4_address().to_string().characters(), - adapter.ipv4_netmask().to_string().characters(), - adapter.ipv4_gateway().to_string().characters()); + klog() << "NetworkTask: " << adapter.class_name() << " network adapter found: hw=" << adapter.mac_address().to_string().characters() << " address=" << adapter.ipv4_address().to_string().characters() << " netmask=" << adapter.ipv4_netmask().to_string().characters() << " gateway=" << adapter.ipv4_gateway().to_string().characters(); adapter.on_receive = [&]() { pending_packets++; @@ -95,7 +90,7 @@ void NetworkTask_main() packet_size = adapter.dequeue_packet(buffer, buffer_size); pending_packets--; #ifdef NETWORK_TASK_DEBUG - kprintf("NetworkTask: Dequeued packet from %s (%d bytes)\n", adapter.name().characters(), packet_size); + klog() << "NetworkTask: Dequeued packet from " << adapter.name().characters() << " (" << packet_size << " bytes)"; #endif }); return packet_size; @@ -105,7 +100,7 @@ void NetworkTask_main() auto buffer_region = MM.allocate_kernel_region(buffer_size, "Kernel Packet Buffer", Region::Access::Read | Region::Access::Write, false, true); auto buffer = (u8*)buffer_region->vaddr().get(); - kprintf("NetworkTask: Enter main loop.\n"); + klog() << "NetworkTask: Enter main loop."; for (;;) { size_t packet_size = dequeue_packet(buffer, buffer_size); if (!packet_size) { @@ -113,36 +108,32 @@ void NetworkTask_main() continue; } if (packet_size < sizeof(EthernetFrameHeader)) { - kprintf("NetworkTask: Packet is too small to be an Ethernet packet! (%zu)\n", packet_size); + klog() << "NetworkTask: Packet is too small to be an Ethernet packet! (" << packet_size << ")"; continue; } auto& eth = *(const EthernetFrameHeader*)buffer; #ifdef ETHERNET_DEBUG - kprintf("NetworkTask: From %s to %s, ether_type=%w, packet_length=%u\n", - eth.source().to_string().characters(), - eth.destination().to_string().characters(), - eth.ether_type(), - packet_size); + klog() << "NetworkTask: From " << eth.source().to_string().characters() << " to " << eth.destination().to_string().characters() << ", ether_type=" << String::format("%w", eth.ether_type()) << ", packet_length=" << packet_size; #endif #ifdef ETHERNET_VERY_DEBUG for (size_t i = 0; i < packet_size; i++) { - kprintf("%b", buffer[i]); + klog() << String::format("%b", buffer[i]); switch (i % 16) { case 7: - kprintf(" "); + klog() << " "; break; case 15: - kprintf("\n"); + klog() << ""; break; default: - kprintf(" "); + klog() << " "; break; } } - kprintf("\n"); + klog() << ""; #endif switch (eth.ether_type()) { @@ -156,7 +147,7 @@ void NetworkTask_main() // ignore break; default: - kprintf("NetworkTask: Unknown ethernet type %#04x\n", eth.ether_type()); + klog() << "NetworkTask: Unknown ethernet type 0x" << String::format("%x", eth.ether_type()); } } } @@ -165,30 +156,21 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size) { constexpr size_t minimum_arp_frame_size = sizeof(EthernetFrameHeader) + sizeof(ARPPacket); if (frame_size < minimum_arp_frame_size) { - kprintf("handle_arp: Frame too small (%d, need %d)\n", frame_size, minimum_arp_frame_size); + klog() << "handle_arp: Frame too small (" << frame_size << ", need " << minimum_arp_frame_size << ")"; return; } auto& packet = *static_cast(eth.payload()); if (packet.hardware_type() != 1 || packet.hardware_address_length() != sizeof(MACAddress)) { - kprintf("handle_arp: Hardware type not ethernet (%w, len=%u)\n", - packet.hardware_type(), - packet.hardware_address_length()); + klog() << "handle_arp: Hardware type not ethernet (" << String::format("%w", packet.hardware_type()) << ", len=" << packet.hardware_address_length() << ")"; return; } if (packet.protocol_type() != EtherType::IPv4 || packet.protocol_address_length() != sizeof(IPv4Address)) { - kprintf("handle_arp: Protocol type not IPv4 (%w, len=%u)\n", - packet.hardware_type(), - packet.protocol_address_length()); + klog() << "handle_arp: Protocol type not IPv4 (" << String::format("%w", packet.hardware_type()) << ", len=" << packet.protocol_address_length() << ")"; return; } #ifdef ARP_DEBUG - kprintf("handle_arp: operation=%w, sender=%s/%s, target=%s/%s\n", - packet.operation(), - packet.sender_hardware_address().to_string().characters(), - packet.sender_protocol_address().to_string().characters(), - packet.target_hardware_address().to_string().characters(), - packet.target_protocol_address().to_string().characters()); + klog() << "handle_arp: operation=" << String::format("%w", packet.operation()) << ", sender=" << packet.sender_hardware_address().to_string().characters() << "/" << packet.sender_protocol_address().to_string().characters() << ", target=" << packet.target_hardware_address().to_string().characters() << "/" << packet.target_protocol_address().to_string().characters(); #endif if (!packet.sender_hardware_address().is_zero() && !packet.sender_protocol_address().is_zero()) { @@ -198,9 +180,9 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size) LOCKER(arp_table().lock()); arp_table().resource().set(packet.sender_protocol_address(), packet.sender_hardware_address()); - kprintf("ARP table (%d entries):\n", arp_table().resource().size()); + klog() << "ARP table (" << arp_table().resource().size() << " entries):"; for (auto& it : arp_table().resource()) { - kprintf("%s :: %s\n", it.value.to_string().characters(), it.key.to_string().characters()); + klog() << it.value.to_string().characters() << " :: " << it.key.to_string().characters(); } } @@ -208,8 +190,7 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size) // Who has this IP address? if (auto adapter = NetworkAdapter::from_ipv4_address(packet.target_protocol_address())) { // We do! - kprintf("handle_arp: Responding to ARP request for my IPv4 address (%s)\n", - adapter->ipv4_address().to_string().characters()); + klog() << "handle_arp: Responding to ARP request for my IPv4 address (" << adapter->ipv4_address().to_string().characters() << ")"; ARPPacket response; response.set_operation(ARPOperation::Response); response.set_target_hardware_address(packet.sender_hardware_address()); @@ -227,26 +208,24 @@ void handle_ipv4(const EthernetFrameHeader& eth, size_t frame_size) { constexpr size_t minimum_ipv4_frame_size = sizeof(EthernetFrameHeader) + sizeof(IPv4Packet); if (frame_size < minimum_ipv4_frame_size) { - kprintf("handle_ipv4: Frame too small (%d, need %d)\n", frame_size, minimum_ipv4_frame_size); + klog() << "handle_ipv4: Frame too small (" << frame_size << ", need " << minimum_ipv4_frame_size << ")"; return; } auto& packet = *static_cast(eth.payload()); if (packet.length() < sizeof(IPv4Packet)) { - kprintf("handle_ipv4: IPv4 packet too short (%u, need %u)\n", packet.length(), sizeof(IPv4Packet)); + klog() << "handle_ipv4: IPv4 packet too short (" << packet.length() << ", need " << sizeof(IPv4Packet) << ")"; return; } size_t actual_ipv4_packet_length = frame_size - sizeof(EthernetFrameHeader); if (packet.length() > actual_ipv4_packet_length) { - kprintf("handle_ipv4: IPv4 packet claims to be longer than it is (%u, actually %zu)\n", packet.length(), actual_ipv4_packet_length); + klog() << "handle_ipv4: IPv4 packet claims to be longer than it is (" << packet.length() << ", actually " << actual_ipv4_packet_length << ")"; return; } #ifdef IPV4_DEBUG - kprintf("handle_ipv4: source=%s, target=%s\n", - packet.source().to_string().characters(), - packet.destination().to_string().characters()); + klog() << "handle_ipv4: source=" << packet.source().to_string().characters() << ", target=" << packet.destination().to_string().characters(); #endif switch ((IPv4Protocol)packet.protocol()) { @@ -257,7 +236,7 @@ void handle_ipv4(const EthernetFrameHeader& eth, size_t frame_size) case IPv4Protocol::TCP: return handle_tcp(packet); default: - kprintf("handle_ipv4: Unhandled protocol %u\n", packet.protocol()); + klog() << "handle_ipv4: Unhandled protocol " << packet.protocol(); break; } } @@ -266,11 +245,7 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet) { auto& icmp_header = *static_cast(ipv4_packet.payload()); #ifdef ICMP_DEBUG - kprintf("handle_icmp: source=%s, destination=%s, type=%b, code=%b\n", - ipv4_packet.source().to_string().characters(), - ipv4_packet.destination().to_string().characters(), - icmp_header.type(), - icmp_header.code()); + klog() << "handle_icmp: source=" << ipv4_packet.source().to_string().characters() << ", destination=" << ipv4_packet.destination().to_string().characters() << ", type=" << String::format("%b", icmp_header.type()) << ", code=" << String::format("%b", icmp_header.code()); #endif { @@ -289,10 +264,7 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet) if (icmp_header.type() == ICMPType::EchoRequest) { auto& request = reinterpret_cast(icmp_header); - kprintf("handle_icmp: EchoRequest from %s: id=%u, seq=%u\n", - ipv4_packet.source().to_string().characters(), - (u16)request.identifier, - (u16)request.sequence_number); + klog() << "handle_icmp: EchoRequest from " << ipv4_packet.source().to_string().characters() << ": id=" << (u16)request.identifier << ", seq=" << (u16)request.sequence_number; size_t icmp_packet_size = ipv4_packet.payload_size(); auto buffer = ByteBuffer::create_zeroed(icmp_packet_size); auto& response = *(ICMPEchoPacket*)buffer.data(); @@ -311,29 +283,24 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet) void handle_udp(const IPv4Packet& ipv4_packet) { if (ipv4_packet.payload_size() < sizeof(UDPPacket)) { - kprintf("handle_udp: Packet too small (%u, need %zu)\n", ipv4_packet.payload_size()); + klog() << "handle_udp: Packet too small (" << ipv4_packet.payload_size() << ", need " << sizeof(UDPPacket) << ")"; return; } auto adapter = NetworkAdapter::from_ipv4_address(ipv4_packet.destination()); if (!adapter) { - kprintf("handle_udp: this packet is not for me, it's for %s\n", ipv4_packet.destination().to_string().characters()); + klog() << "handle_udp: this packet is not for me, it's for " << ipv4_packet.destination().to_string().characters(); return; } auto& udp_packet = *static_cast(ipv4_packet.payload()); #ifdef UDP_DEBUG - kprintf("handle_udp: source=%s:%u, destination=%s:%u length=%u\n", - ipv4_packet.source().to_string().characters(), - udp_packet.source_port(), - ipv4_packet.destination().to_string().characters(), - udp_packet.destination_port(), - udp_packet.length()); + klog() << "handle_udp: source=" << ipv4_packet.source().to_string().characters() << ":" << udp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << udp_packet.destination_port() << " length=" << udp_packet.length(); #endif auto socket = UDPSocket::from_port(udp_packet.destination_port()); if (!socket) { - kprintf("handle_udp: No UDP socket for port %u\n", udp_packet.destination_port()); + klog() << "handle_udp: No UDP socket for port " << udp_packet.destination_port(); return; } @@ -345,7 +312,7 @@ void handle_udp(const IPv4Packet& ipv4_packet) void handle_tcp(const IPv4Packet& ipv4_packet) { if (ipv4_packet.payload_size() < sizeof(TCPPacket)) { - kprintf("handle_tcp: IPv4 payload is too small to be a TCP packet (%u, need %zu)\n", ipv4_packet.payload_size(), sizeof(TCPPacket)); + klog() << "handle_tcp: IPv4 payload is too small to be a TCP packet (" << ipv4_packet.payload_size() << ", need " << sizeof(TCPPacket) << ")"; return; } @@ -354,62 +321,36 @@ void handle_tcp(const IPv4Packet& ipv4_packet) size_t minimum_tcp_header_size = 5 * sizeof(u32); size_t maximum_tcp_header_size = 15 * sizeof(u32); if (tcp_packet.header_size() < minimum_tcp_header_size || tcp_packet.header_size() > maximum_tcp_header_size) { - kprintf("handle_tcp: TCP packet header has invalid size %zu\n", tcp_packet.header_size()); + klog() << "handle_tcp: TCP packet header has invalid size " << tcp_packet.header_size(); } if (ipv4_packet.payload_size() < tcp_packet.header_size()) { - kprintf("handle_tcp: IPv4 payload is smaller than TCP header claims (%u, supposedly %u)\n", ipv4_packet.payload_size(), tcp_packet.header_size()); + klog() << "handle_tcp: IPv4 payload is smaller than TCP header claims (" << ipv4_packet.payload_size() << ", supposedly " << tcp_packet.header_size() << ")"; return; } size_t payload_size = ipv4_packet.payload_size() - tcp_packet.header_size(); #ifdef TCP_DEBUG - kprintf("handle_tcp: source=%s:%u, destination=%s:%u seq_no=%u, ack_no=%u, flags=%w (%s%s%s%s), window_size=%u, payload_size=%u\n", - ipv4_packet.source().to_string().characters(), - tcp_packet.source_port(), - ipv4_packet.destination().to_string().characters(), - tcp_packet.destination_port(), - tcp_packet.sequence_number(), - tcp_packet.ack_number(), - tcp_packet.flags(), - tcp_packet.has_syn() ? "SYN " : "", - tcp_packet.has_ack() ? "ACK " : "", - tcp_packet.has_fin() ? "FIN " : "", - tcp_packet.has_rst() ? "RST " : "", - tcp_packet.window_size(), - payload_size); + klog() << "handle_tcp: source=" << ipv4_packet.source().to_string().characters() << ":" << tcp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << tcp_packet.destination_port() << " seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", flags=" << String::format("%w", tcp_packet.flags()) << " (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << "), window_size=" << tcp_packet.window_size() << ", payload_size=" << payload_size; #endif auto adapter = NetworkAdapter::from_ipv4_address(ipv4_packet.destination()); if (!adapter) { - kprintf("handle_tcp: this packet is not for me, it's for %s\n", ipv4_packet.destination().to_string().characters()); + klog() << "handle_tcp: this packet is not for me, it's for " << ipv4_packet.destination().to_string().characters(); return; } IPv4SocketTuple tuple(ipv4_packet.destination(), tcp_packet.destination_port(), ipv4_packet.source(), tcp_packet.source_port()); #ifdef TCP_DEBUG - kprintf("handle_tcp: looking for socket; tuple=%s\n", tuple.to_string().characters()); + klog() << "handle_tcp: looking for socket; tuple=" << tuple.to_string().characters(); #endif auto socket = TCPSocket::from_tuple(tuple); if (!socket) { - kprintf("handle_tcp: No TCP socket for tuple %s\n", tuple.to_string().characters()); - kprintf("handle_tcp: source=%s:%u, destination=%s:%u seq_no=%u, ack_no=%u, flags=%w (%s%s%s%s), window_size=%u, payload_size=%u\n", - ipv4_packet.source().to_string().characters(), - tcp_packet.source_port(), - ipv4_packet.destination().to_string().characters(), - tcp_packet.destination_port(), - tcp_packet.sequence_number(), - tcp_packet.ack_number(), - tcp_packet.flags(), - tcp_packet.has_syn() ? "SYN " : "", - tcp_packet.has_ack() ? "ACK " : "", - tcp_packet.has_fin() ? "FIN " : "", - tcp_packet.has_rst() ? "RST " : "", - tcp_packet.window_size(), - payload_size); + klog() << "handle_tcp: No TCP socket for tuple " << tuple.to_string().characters(); + klog() << "handle_tcp: source=" << ipv4_packet.source().to_string().characters() << ":" << tcp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << tcp_packet.destination_port() << " seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", flags=" << String::format("%w", tcp_packet.flags()) << " (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << "), window_size=" << tcp_packet.window_size() << ", payload_size=" << payload_size; return; } @@ -417,18 +358,18 @@ void handle_tcp(const IPv4Packet& ipv4_packet) ASSERT(socket->local_port() == tcp_packet.destination_port()); #ifdef TCP_DEBUG - kprintf("handle_tcp: got socket; state=%s\n", socket->tuple().to_string().characters(), TCPSocket::to_string(socket->state())); + klog() << "handle_tcp: got socket; state=" << socket->tuple().to_string().characters() << " " << TCPSocket::to_string(socket->state()); #endif socket->receive_tcp_packet(tcp_packet, ipv4_packet.payload_size()); switch (socket->state()) { case TCPSocket::State::Closed: - kprintf("handle_tcp: unexpected flags in Closed state\n"); + klog() << "handle_tcp: unexpected flags in Closed state"; // TODO: we may want to send an RST here, maybe as a configurable option return; case TCPSocket::State::TimeWait: - kprintf("handle_tcp: unexpected flags in TimeWait state\n"); + klog() << "handle_tcp: unexpected flags in TimeWait state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -436,17 +377,17 @@ void handle_tcp(const IPv4Packet& ipv4_packet) switch (tcp_packet.flags()) { case TCPFlags::SYN: { #ifdef TCP_DEBUG - kprintf("handle_tcp: incoming connection\n"); + klog() << "handle_tcp: incoming connection"; #endif auto& local_address = ipv4_packet.destination(); auto& peer_address = ipv4_packet.source(); auto client = socket->create_client(local_address, tcp_packet.destination_port(), peer_address, tcp_packet.source_port()); if (!client) { - kprintf("handle_tcp: couldn't create client socket\n"); + klog() << "handle_tcp: couldn't create client socket"; return; } #ifdef TCP_DEBUG - kprintf("handle_tcp: created new client socket with tuple %s\n", client->tuple().to_string().characters()); + klog() << "handle_tcp: created new client socket with tuple " << client->tuple().to_string().characters(); #endif client->set_sequence_number(1000); client->set_ack_number(tcp_packet.sequence_number() + payload_size + 1); @@ -455,7 +396,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) return; } default: - kprintf("handle_tcp: unexpected flags in Listen state\n"); + klog() << "handle_tcp: unexpected flags in Listen state"; // socket->send_tcp_packet(TCPFlags::RST); return; } @@ -488,7 +429,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_setup_state(Socket::SetupState::Completed); return; default: - kprintf("handle_tcp: unexpected flags in SynSent state\n"); + klog() << "handle_tcp: unexpected flags in SynSent state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); socket->set_error(TCPSocket::Error::UnexpectedFlagsDuringConnect); @@ -503,7 +444,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) switch (socket->direction()) { case TCPSocket::Direction::Incoming: if (!socket->has_originator()) { - kprintf("handle_tcp: connection doesn't have an originating socket; maybe it went away?\n"); + klog() << "handle_tcp: connection doesn't have an originating socket; maybe it went away?"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -519,7 +460,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_connected(true); return; default: - kprintf("handle_tcp: got ACK in SynReceived state but direction is invalid (%s)\n", TCPSocket::to_string(socket->direction())); + klog() << "handle_tcp: got ACK in SynReceived state but direction is invalid (" << TCPSocket::to_string(socket->direction()) << ")"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -527,7 +468,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) return; default: - kprintf("handle_tcp: unexpected flags in SynReceived state\n"); + klog() << "handle_tcp: unexpected flags in SynReceived state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -535,7 +476,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) case TCPSocket::State::CloseWait: switch (tcp_packet.flags()) { default: - kprintf("handle_tcp: unexpected flags in CloseWait state\n"); + klog() << "handle_tcp: unexpected flags in CloseWait state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -547,7 +488,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_state(TCPSocket::State::Closed); return; default: - kprintf("handle_tcp: unexpected flags in LastAck state\n"); + klog() << "handle_tcp: unexpected flags in LastAck state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -563,7 +504,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_state(TCPSocket::State::Closing); return; default: - kprintf("handle_tcp: unexpected flags in FinWait1 state\n"); + klog() << "handle_tcp: unexpected flags in FinWait1 state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -578,7 +519,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_state(TCPSocket::State::Closed); return; default: - kprintf("handle_tcp: unexpected flags in FinWait2 state\n"); + klog() << "handle_tcp: unexpected flags in FinWait2 state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -590,7 +531,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_state(TCPSocket::State::TimeWait); return; default: - kprintf("handle_tcp: unexpected flags in Closing state\n"); + klog() << "handle_tcp: unexpected flags in Closing state"; socket->send_tcp_packet(TCPFlags::RST); socket->set_state(TCPSocket::State::Closed); return; @@ -610,12 +551,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet) socket->set_ack_number(tcp_packet.sequence_number() + payload_size); #ifdef TCP_DEBUG - kprintf("Got packet with ack_no=%u, seq_no=%u, payload_size=%u, acking it with new ack_no=%u, seq_no=%u\n", - tcp_packet.ack_number(), - tcp_packet.sequence_number(), - payload_size, - socket->ack_number(), - socket->sequence_number()); + klog() << "Got packet with ack_no=" << tcp_packet.ack_number() << ", seq_no=" << tcp_packet.sequence_number() << ", payload_size=" << payload_size << ", acking it with new ack_no=" << socket->ack_number() << ", seq_no=" << socket->sequence_number(); #endif if (payload_size) { diff --git a/Kernel/Net/Routing.cpp b/Kernel/Net/Routing.cpp index f101a4e4e0b..84b5fee6bae 100644 --- a/Kernel/Net/Routing.cpp +++ b/Kernel/Net/Routing.cpp @@ -76,8 +76,7 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source) if (!local_adapter && !gateway_adapter) { #ifdef ROUTING_DEBUG - kprintf("Routing: Couldn't find a suitable adapter for route to %s\n", - target.to_string().characters()); + klog() << "Routing: Couldn't find a suitable adapter for route to " << target.to_string().characters(); #endif return { nullptr, {} }; } @@ -87,22 +86,13 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source) if (local_adapter) { #ifdef ROUTING_DEBUG - kprintf("Routing: Got adapter for route (direct): %s (%s/%s) for %s\n", - local_adapter->name().characters(), - local_adapter->ipv4_address().to_string().characters(), - local_adapter->ipv4_netmask().to_string().characters(), - target.to_string().characters()); + klog() << "Routing: Got adapter for route (direct): " << local_adapter->name().characters() << " (" << local_adapter->ipv4_address().to_string().characters() << "/" << local_adapter->ipv4_netmask().to_string().characters() << ") for " << target.to_string().characters(); #endif adapter = local_adapter; next_hop_ip = target; } else if (gateway_adapter) { #ifdef ROUTING_DEBUG - kprintf("Routing: Got adapter for route (using gateway %s): %s (%s/%s) for %s\n", - gateway_adapter->ipv4_gateway().to_string().characters(), - gateway_adapter->name().characters(), - gateway_adapter->ipv4_address().to_string().characters(), - gateway_adapter->ipv4_netmask().to_string().characters(), - target.to_string().characters()); + klog() << "Routing: Got adapter for route (using gateway " << gateway_adapter->ipv4_gateway().to_string().characters() << "): " << gateway_adapter->name().characters() << " (" << gateway_adapter->ipv4_address().to_string().characters() << "/" << gateway_adapter->ipv4_netmask().to_string().characters() << ") for " << target.to_string().characters(); #endif adapter = gateway_adapter; next_hop_ip = gateway_adapter->ipv4_gateway(); @@ -115,18 +105,14 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source) auto addr = arp_table().resource().get(next_hop_ip); if (addr.has_value()) { #ifdef ROUTING_DEBUG - kprintf("Routing: Using cached ARP entry for %s (%s)\n", - next_hop_ip.to_string().characters(), - addr.value().to_string().characters()); + klog() << "Routing: Using cached ARP entry for " << next_hop_ip.to_string().characters() << " (" << addr.value().to_string().characters() << ")"; #endif return { adapter, addr.value() }; } } #ifdef ROUTING_DEBUG - kprintf("Routing: Sending ARP request via adapter %s for IPv4 address %s\n", - adapter->name().characters(), - next_hop_ip.to_string().characters()); + klog() << "Routing: Sending ARP request via adapter " << adapter->name().characters() << " for IPv4 address " << next_hop_ip.to_string().characters(); #endif ARPPacket request; @@ -146,19 +132,14 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source) auto addr = arp_table().resource().get(next_hop_ip); if (addr.has_value()) { #ifdef ROUTING_DEBUG - kprintf("Routing: Got ARP response using adapter %s for %s (%s)\n", - adapter->name().characters(), - next_hop_ip.to_string().characters(), - addr.value().to_string().characters()); + klog() << "Routing: Got ARP response using adapter " << adapter->name().characters() << " for " << next_hop_ip.to_string().characters() << " (" << addr.value().to_string().characters() << ")"; #endif return { adapter, addr.value() }; } } #ifdef ROUTING_DEBUG - kprintf("Routing: Couldn't find route using adapter %s for %s\n", - adapter->name().characters(), - target.to_string().characters()); + klog() << "Routing: Couldn't find route using adapter " << adapter->name().characters() << " for " << target.to_string().characters(); #endif return { nullptr, {} }; diff --git a/Kernel/Net/Socket.cpp b/Kernel/Net/Socket.cpp index 9d923e84bc6..ed1092902a6 100644 --- a/Kernel/Net/Socket.cpp +++ b/Kernel/Net/Socket.cpp @@ -65,7 +65,7 @@ Socket::~Socket() void Socket::set_setup_state(SetupState new_setup_state) { #ifdef SOCKET_DEBUG - kprintf("%s(%u) Socket{%p} setup state moving from %s to %s\n", Process::current->name().characters(), Process::current->pid(), this, to_string(m_setup_state), to_string(new_setup_state)); + dbg() << "Socket{" << this << "} setup state moving from " << to_string(m_setup_state) << " to " << to_string(new_setup_state); #endif m_setup_state = new_setup_state; @@ -77,7 +77,7 @@ RefPtr Socket::accept() if (m_pending.is_empty()) return nullptr; #ifdef SOCKET_DEBUG - kprintf("%s(%u) Socket{%p} de-queueing connection\n", Process::current->name().characters(), Process::current->pid(), this); + dbg() << "Socket{" << this << "} de-queueing connection"; #endif auto client = m_pending.take_first(); ASSERT(!client->is_connected()); @@ -91,7 +91,7 @@ RefPtr Socket::accept() KResult Socket::queue_connection_from(NonnullRefPtr peer) { #ifdef SOCKET_DEBUG - kprintf("%s(%u) Socket{%p} queueing connection\n", Process::current->name().characters(), Process::current->pid(), this); + dbg() << "Socket{" << this << "} queueing connection"; #endif LOCKER(m_lock); if (m_pending.size() >= m_backlog) diff --git a/Kernel/Net/TCPSocket.cpp b/Kernel/Net/TCPSocket.cpp index 508675a6d95..9e8fed62cc4 100644 --- a/Kernel/Net/TCPSocket.cpp +++ b/Kernel/Net/TCPSocket.cpp @@ -48,9 +48,7 @@ void TCPSocket::for_each(Function callback) void TCPSocket::set_state(State new_state) { #ifdef TCP_SOCKET_DEBUG - kprintf("%s(%u) TCPSocket{%p} state moving from %s to %s\n", - Process::current->name().characters(), Process::current->pid(), this, - to_string(m_state), to_string(new_state)); + dbg() << "TCPSocket{" << this << "} state moving from " << to_string(m_state) << " to " << to_string(new_state); #endif m_state = new_state; @@ -170,7 +168,7 @@ int TCPSocket::protocol_receive(const KBuffer& packet_buffer, void* buffer, size auto& tcp_packet = *static_cast(ipv4_packet.payload()); size_t payload_size = packet_buffer.size() - sizeof(IPv4Packet) - tcp_packet.header_size(); #ifdef TCP_SOCKET_DEBUG - kprintf("payload_size %u, will it fit in %u?\n", payload_size, buffer_size); + klog() << "payload_size " << payload_size << ", will it fit in " << buffer_size << "?"; #endif ASSERT(buffer_size >= payload_size); memcpy(buffer, tcp_packet.payload(), payload_size); @@ -243,18 +241,7 @@ void TCPSocket::send_outgoing_packets() #ifdef TCP_SOCKET_DEBUG auto& tcp_packet = *(TCPPacket*)(packet.buffer.data()); - kprintf("sending tcp packet from %s:%u to %s:%u with (%s%s%s%s) seq_no=%u, ack_no=%u, tx_counter=%u\n", - local_address().to_string().characters(), - local_port(), - peer_address().to_string().characters(), - peer_port(), - tcp_packet.has_syn() ? "SYN " : "", - tcp_packet.has_ack() ? "ACK " : "", - tcp_packet.has_fin() ? "FIN " : "", - tcp_packet.has_rst() ? "RST " : "", - tcp_packet.sequence_number(), - tcp_packet.ack_number(), - packet.tx_counter); + klog() << "sending tcp packet from " << local_address().to_string().characters() << ":" << local_port() << " to " << peer_address().to_string().characters() << ":" << peer_port() << " with (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << ") seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", tx_counter=" << packet.tx_counter; #endif routing_decision.adapter->send_ipv4( routing_decision.next_hop, peer_address(), IPv4Protocol::TCP, diff --git a/Kernel/Net/UDPSocket.cpp b/Kernel/Net/UDPSocket.cpp index c3d02d84216..8794b9b7a63 100644 --- a/Kernel/Net/UDPSocket.cpp +++ b/Kernel/Net/UDPSocket.cpp @@ -101,11 +101,7 @@ int UDPSocket::protocol_send(const void* data, size_t data_length) udp_packet.set_destination_port(peer_port()); udp_packet.set_length(sizeof(UDPPacket) + data_length); memcpy(udp_packet.payload(), data, data_length); - kprintf("sending as udp packet from %s:%u to %s:%u!\n", - routing_decision.adapter->ipv4_address().to_string().characters(), - local_port(), - peer_address().to_string().characters(), - peer_port()); + klog() << "sending as udp packet from " << routing_decision.adapter->ipv4_address().to_string().characters() << ":" << local_port() << " to " << peer_address().to_string().characters() << ":" << peer_port() << "!"; routing_decision.adapter->send_ipv4(routing_decision.next_hop, peer_address(), IPv4Protocol::UDP, buffer.data(), buffer.size(), ttl()); return data_length; } diff --git a/Kernel/PCI/Access.cpp b/Kernel/PCI/Access.cpp index cd86f257f52..99957c7ed6e 100644 --- a/Kernel/PCI/Access.cpp +++ b/Kernel/PCI/Access.cpp @@ -57,7 +57,7 @@ void PCI::Access::enumerate_functions(int type, u8 bus, u8 slot, u8 function, Fu if (read_type(address) == PCI_TYPE_BRIDGE) { u8 secondary_bus = read8_field(address, PCI_SECONDARY_BUS); #ifdef PCI_DEBUG - kprintf("PCI: Found secondary bus: %u\n", secondary_bus); + klog() << "PCI: Found secondary bus: " << secondary_bus; #endif ASSERT(secondary_bus != bus); enumerate_bus(type, secondary_bus, callback); diff --git a/Kernel/PCI/IOAccess.cpp b/Kernel/PCI/IOAccess.cpp index 2a2b486195b..4049b3672be 100644 --- a/Kernel/PCI/IOAccess.cpp +++ b/Kernel/PCI/IOAccess.cpp @@ -37,7 +37,7 @@ void PCI::IOAccess::initialize() PCI::IOAccess::IOAccess() { - kprintf("PCI: Using IO Mechanism for PCI Configuartion Space Access\n"); + klog() << "PCI: Using IO Mechanism for PCI Configuartion Space Access"; } u8 PCI::IOAccess::read8_field(Address address, u32 field) diff --git a/Kernel/PCI/Initializer.cpp b/Kernel/PCI/Initializer.cpp index 34f359da1a4..0ddd6e5fee9 100644 --- a/Kernel/PCI/Initializer.cpp +++ b/Kernel/PCI/Initializer.cpp @@ -58,13 +58,7 @@ void PCI::Initializer::initialize_pci_io_access() void PCI::Initializer::detect_devices() { PCI::enumerate_all([&](const PCI::Address& address, PCI::ID id) { - kprintf("PCI: device @ %w:%b:%b.%d [%w:%w]\n", - address.seg(), - address.bus(), - address.slot(), - address.function(), - id.vendor_id, - id.device_id); + klog() << "PCI: device @ " << String::format("%w", address.seg()) << ":" << String::format("%b", address.bus()) << ":" << String::format("%b", address.slot()) << "." << String::format("%d", address.function()) << " [" << String::format("%w", id.vendor_id) << ":" << String::format("%w", id.device_id) << "]"; E1000NetworkAdapter::detect(address); RTL8139NetworkAdapter::detect(address); }); @@ -76,7 +70,7 @@ void PCI::Initializer::test_and_initialize(bool disable_pci_mmio) if (test_pci_io()) { initialize_pci_io_access(); } else { - kprintf("No PCI Bus Access Method Detected, Halt!\n"); + klog() << "No PCI Bus Access Method Detected, Halt!"; ASSERT_NOT_REACHED(); // NO PCI Access ?! } return; @@ -88,7 +82,7 @@ void PCI::Initializer::test_and_initialize(bool disable_pci_mmio) if (test_pci_io()) { initialize_pci_io_access(); } else { - kprintf("No PCI Bus Access Method Detected, Halt!\n"); + klog() << "No PCI Bus Access Method Detected, Halt!"; ASSERT_NOT_REACHED(); // NO PCI Access ?! } } @@ -96,7 +90,7 @@ void PCI::Initializer::test_and_initialize(bool disable_pci_mmio) if (test_pci_io()) { initialize_pci_io_access(); } else { - kprintf("No PCI Bus Access Method Detected, Halt!\n"); + klog() << "No PCI Bus Access Method Detected, Halt!"; ASSERT_NOT_REACHED(); // NO PCI Access ?! } } @@ -114,16 +108,16 @@ bool PCI::Initializer::test_acpi() bool PCI::Initializer::test_pci_io() { - kprintf("Testing PCI via manual probing... "); + klog() << "Testing PCI via manual probing... "; u32 tmp = 0x80000000; IO::out32(PCI_ADDRESS_PORT, tmp); tmp = IO::in32(PCI_ADDRESS_PORT); if (tmp == 0x80000000) { - kprintf("PCI IO Supported!\n"); + klog() << "PCI IO Supported!"; return true; } - kprintf("PCI IO Not Supported!\n"); + klog() << "PCI IO Not Supported!"; return false; } @@ -141,7 +135,7 @@ void PCI::Initializer::dismiss() { if (s_pci_initializer == nullptr) return; - kprintf("PCI Subsystem Initializer dismissed.\n"); + klog() << "PCI Subsystem Initializer dismissed."; delete s_pci_initializer; s_pci_initializer = nullptr; } diff --git a/Kernel/PCI/MMIOAccess.cpp b/Kernel/PCI/MMIOAccess.cpp index e27282fc9af..bb7572d7b88 100644 --- a/Kernel/PCI/MMIOAccess.cpp +++ b/Kernel/PCI/MMIOAccess.cpp @@ -58,7 +58,7 @@ PCI::MMIOAccess::MMIOAccess(PhysicalAddress p_mcfg) , m_segments(*new HashMap()) , m_mapped_address(ChangeableAddress(0xFFFF, 0xFF, 0xFF, 0xFF)) { - kprintf("PCI: Using MMIO Mechanism for PCI Configuartion Space Access\n"); + klog() << "PCI: Using MMIO Mechanism for PCI Configuartion Space Access"; m_mmio_window_region = MM.allocate_kernel_region(PAGE_ROUND_UP(PCI_MMIO_CONFIG_SPACE_SIZE), "PCI MMIO", Region::Access::Read | Region::Access::Write); auto checkup_region = MM.allocate_kernel_region(p_mcfg.page_base(), (PAGE_SIZE * 2), "PCI MCFG Checkup", Region::Access::Read | Region::Access::Write); @@ -70,7 +70,7 @@ PCI::MMIOAccess::MMIOAccess(PhysicalAddress p_mcfg) u32 length = sdt->length; u8 revision = sdt->revision; - kprintf("PCI: MCFG, length - %u, revision %d\n", length, revision); + klog() << "PCI: MCFG, length - " << length << ", revision " << revision; checkup_region->unmap(); auto mcfg_region = MM.allocate_kernel_region(p_mcfg.page_base(), PAGE_ROUND_UP(length) + PAGE_SIZE, "PCI Parsing MCFG", Region::Access::Read | Region::Access::Write); @@ -86,10 +86,10 @@ PCI::MMIOAccess::MMIOAccess(PhysicalAddress p_mcfg) u32 lower_addr = mcfg.descriptors[index].base_addr; m_segments.set(index, new PCI::MMIOSegment(PhysicalAddress(lower_addr), start_bus, end_bus)); - kprintf("PCI: New PCI segment @ P 0x%x, PCI buses (%d-%d)\n", lower_addr, start_bus, end_bus); + klog() << "PCI: New PCI segment @ P " << String::format("%p", lower_addr) << ", PCI buses (" << start_bus << "-" << end_bus << ")"; } mcfg_region->unmap(); - kprintf("PCI: MMIO segments - %d\n", m_segments.size()); + klog() << "PCI: MMIO segments - " << m_segments.size(); InterruptDisabler disabler; #ifdef PCI_DEBUG dbg() << "PCI: mapped address (" << String::format("%w", m_mapped_address.seg()) << ":" << String::format("%b", m_mapped_address.bus()) << ":" << String::format("%b", m_mapped_address.slot()) << "." << String::format("%b", m_mapped_address.function()) << ")"; diff --git a/Kernel/Process.cpp b/Kernel/Process.cpp index 3f6679b1f08..5c22737c902 100644 --- a/Kernel/Process.cpp +++ b/Kernel/Process.cpp @@ -742,7 +742,7 @@ pid_t Process::sys$fork(RegisterState& regs) g_processes->prepend(child); } #ifdef TASK_DEBUG - kprintf("Process %u (%s) forked from %u @ %p\n", child->pid(), child->name().characters(), m_pid, child_tss.eip); + klog() << "Process " << child->pid() << " (" << child->name().characters() << ") forked from " << m_pid << " @ " << String::format("%p", child_tss.eip); #endif child_first_thread->set_state(Thread::State::Skip1SchedulerPass); @@ -915,14 +915,14 @@ int Process::do_exec(NonnullRefPtr main_program_description, Ve }; bool success = loader->load(); if (!success) { - kprintf("do_exec: Failure loading %s\n", path.characters()); + klog() << "do_exec: Failure loading " << path.characters(); return -ENOEXEC; } // FIXME: Validate that this virtual address is within executable region, // instead of just non-null. You could totally have a DSO with entry point of // the beginning of the text segement. if (!loader->entry().offset(totally_random_offset).get()) { - kprintf("do_exec: Failure loading %s, entry pointer is invalid! (%p)\n", path.characters(), loader->entry().offset(totally_random_offset).get()); + klog() << "do_exec: Failure loading " << path.characters() << ", entry pointer is invalid! (" << String::format("%p", loader->entry().offset(totally_random_offset).get()) << ")"; return -ENOEXEC; } @@ -934,7 +934,7 @@ int Process::do_exec(NonnullRefPtr main_program_description, Ve kill_threads_except_self(); #ifdef EXEC_DEBUG - kprintf("Memory layout after ELF load:"); + klog() << "Memory layout after ELF load:"; dump_regions(); #endif } @@ -1033,7 +1033,7 @@ int Process::do_exec(NonnullRefPtr main_program_description, Ve tss.ss2 = m_pid; #ifdef TASK_DEBUG - kprintf("Process %u (%s) exec'd %s @ %p\n", pid(), name().characters(), path.characters(), tss.eip); + klog() << "Process exec'd " << path.characters() << " @ " << String::format("%p", tss.eip); #endif if (was_profiling) @@ -1315,7 +1315,7 @@ Process* Process::create_user_process(Thread*& first_thread, const String& path, g_processes->prepend(process); } #ifdef TASK_DEBUG - kprintf("Process %u (%s) spawned @ %p\n", process->pid(), process->name().characters(), first_thread->tss().eip); + klog() << "Process " << process->pid() << " (" << process->name().characters() << ") spawned @ " << String::format("%p", first_thread->tss().eip); #endif error = 0; return process; @@ -1330,7 +1330,7 @@ Process* Process::create_kernel_process(Thread*& first_thread, String&& name, vo InterruptDisabler disabler; g_processes->prepend(process); #ifdef TASK_DEBUG - kprintf("Kernel process %u (%s) spawned @ %p\n", process->pid(), process->name().characters(), first_thread->tss().eip); + klog() << "Kernel process " << process->pid() << " (" << process->name().characters() << ") spawned @ " << String::format("%p", first_thread->tss().eip); #endif } @@ -1376,22 +1376,11 @@ Process::~Process() void Process::dump_regions() { - kprintf("Process %s(%u) regions:\n", name().characters(), pid()); - kprintf("BEGIN END SIZE ACCESS NAME\n"); + klog() << "Process regions:"; + klog() << "BEGIN END SIZE ACCESS NAME"; for (auto& region : m_regions) { - kprintf("%08x -- %08x %08x %c%c%c%c%c%c %s\n", - region.vaddr().get(), - region.vaddr().offset(region.size() - 1).get(), - region.size(), - region.is_readable() ? 'R' : ' ', - region.is_writable() ? 'W' : ' ', - region.is_executable() ? 'X' : ' ', - region.is_shared() ? 'S' : ' ', - region.is_stack() ? 'T' : ' ', - region.vmobject().is_purgeable() ? 'P' : ' ', - region.name().characters()); + klog() << String::format("%08x", region.vaddr().get()) << " -- " << String::format("%08x", region.vaddr().offset(region.size() - 1).get()) << " " << String::format("%08x", region.size()) << " " << (region.is_readable() ? 'R' : ' ') << (region.is_writable() ? 'W' : ' ') << (region.is_executable() ? 'X' : ' ') << (region.is_shared() ? 'S' : ' ') << (region.is_stack() ? 'T' : ' ') << (region.vmobject().is_purgeable() ? 'P' : ' ') << " " << region.name().characters(); } - MM.dump_kernel_regions(); } @@ -1399,7 +1388,7 @@ void Process::sys$exit(int status) { cli(); #ifdef TASK_DEBUG - kprintf("sys$exit: %s(%u) exit with status %d\n", name().characters(), pid(), status); + klog() << "sys$exit: exit with status " << status; #endif if (status != 0) @@ -2145,7 +2134,7 @@ KResult Process::do_kill(Process& process, int signal) if (!is_superuser() && m_euid != process.m_uid && m_uid != process.m_uid) return KResult(-EPERM); if (process.is_ring0() && signal == SIGKILL) { - kprintf("%s(%u) attempted to send SIGKILL to ring 0 process %s(%u)\n", name().characters(), m_pid, process.name().characters(), process.pid()); + klog() << "attempted to send SIGKILL to ring 0 process " << process.name().characters() << "(" << process.pid() << ")"; return KResult(-EPERM); } if (signal != 0) @@ -3561,7 +3550,7 @@ int Process::sys$shbuf_create(int size, void** buffer) copy_to_user(buffer, &address); ASSERT((int)shared_buffer->size() >= size); #ifdef SHARED_BUFFER_DEBUG - kprintf("%s(%u): Created shared buffer %d @ %p (%u bytes, vmobject is %u)\n", name().characters(), pid(), shbuf_id, buffer, size, shared_buffer->size()); + klog() << "Created shared buffer " << shbuf_id << " @ " << buffer << " (" << size << " bytes, vmobject is " << shared_buffer->size() << ")"; #endif shared_buffers().resource().set(shbuf_id, move(shared_buffer)); @@ -3615,7 +3604,7 @@ int Process::sys$shbuf_release(int shbuf_id) if (!shared_buffer.is_shared_with(m_pid)) return -EPERM; #ifdef SHARED_BUFFER_DEBUG - kprintf("%s(%u): Releasing shared buffer %d, buffer count: %u\n", name().characters(), pid(), shbuf_id, shared_buffers().resource().size()); + klog() << "Releasing shared buffer " << shbuf_id << ", buffer count: " << shared_buffers().resource().size(); #endif shared_buffer.deref_for_process(*this); return 0; @@ -3634,7 +3623,7 @@ void* Process::sys$shbuf_get(int shbuf_id, size_t* user_size) if (!shared_buffer.is_shared_with(m_pid)) return (void*)-EPERM; #ifdef SHARED_BUFFER_DEBUG - kprintf("%s(%u): Retaining shared buffer %d, buffer count: %u\n", name().characters(), pid(), shbuf_id, shared_buffers().resource().size()); + klog() << "Retaining shared buffer " << shbuf_id << ", buffer count: " << shared_buffers().resource().size(); #endif if (user_size) { size_t size = shared_buffer.size(); @@ -3654,7 +3643,7 @@ int Process::sys$shbuf_seal(int shbuf_id) if (!shared_buffer.is_shared_with(m_pid)) return -EPERM; #ifdef SHARED_BUFFER_DEBUG - kprintf("%s(%u): Sealing shared buffer %d\n", name().characters(), pid(), shbuf_id); + klog() << "Sealing shared buffer " << shbuf_id; #endif shared_buffer.seal(); return 0; @@ -3671,7 +3660,7 @@ int Process::sys$shbuf_set_volatile(int shbuf_id, bool state) if (!shared_buffer.is_shared_with(m_pid)) return -EPERM; #ifdef SHARED_BUFFER_DEBUG - kprintf("%s(%u): Set shared buffer %d volatile: %u\n", name().characters(), pid(), shbuf_id, state); + klog() << "Set shared buffer " << shbuf_id << " volatile: " << state; #endif if (!state) { bool was_purged = shared_buffer.vmobject().was_purged(); diff --git a/Kernel/RTC.cpp b/Kernel/RTC.cpp index 8c5e0d9eb9f..c1f1ed55b8e 100644 --- a/Kernel/RTC.cpp +++ b/Kernel/RTC.cpp @@ -25,6 +25,7 @@ */ #include +#include #include #include @@ -154,7 +155,7 @@ time_t now() unsigned year, month, day, hour, minute, second; read_registers(year, month, day, hour, minute, second); - kprintf("year: %d, month: %d, day: %d\n", year, month, day); + klog() << "year: " << year << ", month: " << month << ", day: " << day; ASSERT(year >= 2018); diff --git a/Kernel/SharedBuffer.cpp b/Kernel/SharedBuffer.cpp index 32b67a4ecd4..3ca3feb99c8 100644 --- a/Kernel/SharedBuffer.cpp +++ b/Kernel/SharedBuffer.cpp @@ -173,7 +173,7 @@ void SharedBuffer::destroy_if_unused() sanity_check("destroy_if_unused"); if (m_total_refs == 0) { #ifdef SHARED_BUFFER_DEBUG - kprintf("Destroying unused SharedBuffer{%p} id: %d\n", this, m_shbuf_id); + dbg() << "Destroying unused SharedBuffer{" << this << "} id: " << m_shbuf_id; #endif auto count_before = shared_buffers().resource().size(); shared_buffers().resource().remove(m_shbuf_id); diff --git a/Kernel/Syscall.cpp b/Kernel/Syscall.cpp index ed8cb39aa30..f3eb90ef024 100644 --- a/Kernel/Syscall.cpp +++ b/Kernel/Syscall.cpp @@ -70,7 +70,7 @@ static int handle(RegisterState&, u32 function, u32 arg1, u32 arg2, u32 arg3); void initialize() { register_user_callable_interrupt_handler(0x82, syscall_asm_entry); - kprintf("Syscall: int 0x82 handler installed\n"); + klog() << "Syscall: int 0x82 handler installed"; } #pragma GCC diagnostic ignored "-Wcast-function-type" diff --git a/Kernel/TestModule.cpp b/Kernel/TestModule.cpp index 2e2969573a1..3be421c9344 100644 --- a/Kernel/TestModule.cpp +++ b/Kernel/TestModule.cpp @@ -30,17 +30,14 @@ extern "C" const char module_name[] = "TestModule"; extern "C" void module_init() { - kprintf("TestModule has booted!\n"); + klog() << "TestModule has booted!"; for (int i = 0; i < 3; ++i) { - kprintf("i is now %d\n", i); + klog() << "i is now " << i; } - - kprintf("current pid: %d\n", Process::current->sys$getpid()); - kprintf("current process name: %s\n", Process::current->name().characters()); } extern "C" void module_fini() { - kprintf("TestModule is being removed!\n"); + klog() << "TestModule is being removed!"; } diff --git a/Kernel/Thread.cpp b/Kernel/Thread.cpp index bf7d1df503d..10d880c331d 100644 --- a/Kernel/Thread.cpp +++ b/Kernel/Thread.cpp @@ -284,7 +284,7 @@ const char* Thread::state_string() const ASSERT(m_blocker != nullptr); return m_blocker->state_string(); } - kprintf("Thread::state_string(): Invalid state: %u\n", state()); + klog() << "Thread::state_string(): Invalid state: " << state(); ASSERT_NOT_REACHED(); return nullptr; } @@ -485,7 +485,7 @@ ShouldUnblockThread Thread::dispatch_signal(u8 signal) ASSERT(!process().is_ring0()); #ifdef SIGNAL_DEBUG - kprintf("dispatch_signal %s(%u) <- %u\n", process().name().characters(), pid(), signal); + klog() << "dispatch_signal <- " << signal; #endif auto& action = m_signal_action_data[signal]; @@ -536,7 +536,7 @@ ShouldUnblockThread Thread::dispatch_signal(u8 signal) if (handler_vaddr.as_ptr() == SIG_IGN) { #ifdef SIGNAL_DEBUG - kprintf("%s(%u) ignored signal %u\n", process().name().characters(), pid(), signal); + klog() << "ignored signal " << signal; #endif return ShouldUnblockThread::Yes; } @@ -612,7 +612,7 @@ ShouldUnblockThread Thread::dispatch_signal(u8 signal) } #ifdef SIGNAL_DEBUG - kprintf("signal: Okay, %s(%u) {%s} has been primed with signal handler %w:%x\n", process().name().characters(), pid(), state_string(), m_tss.cs, m_tss.eip); + klog() << "signal: Okay, {" << state_string() << "} has been primed with signal handler " << String::format("%w", m_tss.cs) << ":" << String::format("%x", m_tss.eip); #endif return ShouldUnblockThread::Yes; } diff --git a/Kernel/VM/MemoryManager.cpp b/Kernel/VM/MemoryManager.cpp index 9e8a47a8433..88de838f163 100644 --- a/Kernel/VM/MemoryManager.cpp +++ b/Kernel/VM/MemoryManager.cpp @@ -31,11 +31,11 @@ #include #include #include -#include #include #include #include #include +#include #include //#define MM_DEBUG @@ -121,13 +121,7 @@ void MemoryManager::parse_memory_map() auto* mmap = (multiboot_memory_map_t*)(low_physical_to_virtual(multiboot_info_ptr->mmap_addr)); for (; (unsigned long)mmap < (low_physical_to_virtual(multiboot_info_ptr->mmap_addr)) + (multiboot_info_ptr->mmap_length); mmap = (multiboot_memory_map_t*)((unsigned long)mmap + mmap->size + sizeof(mmap->size))) { - kprintf("MM: Multiboot mmap: base_addr = 0x%x%08x, length = 0x%x%08x, type = 0x%x\n", - (uintptr_t)(mmap->addr >> 32), - (uintptr_t)(mmap->addr & 0xffffffff), - (uintptr_t)(mmap->len >> 32), - (uintptr_t)(mmap->len & 0xffffffff), - (uintptr_t)mmap->type); - + klog() << "MM: Multiboot mmap: base_addr = " << String::format("0x%08x", mmap->addr) << ", length = " << String::format("0x%08x", mmap->len) << ", type = 0x" << String::format("%x", mmap->type); if (mmap->type != MULTIBOOT_MEMORY_AVAILABLE) continue; @@ -140,23 +134,22 @@ void MemoryManager::parse_memory_map() auto diff = (uintptr_t)mmap->addr % PAGE_SIZE; if (diff != 0) { - kprintf("MM: got an unaligned region base from the bootloader; correcting %p by %d bytes\n", mmap->addr, diff); + klog() << "MM: got an unaligned region base from the bootloader; correcting " << String::format("%p", mmap->addr) << " by " << diff << " bytes"; diff = PAGE_SIZE - diff; mmap->addr += diff; mmap->len -= diff; } if ((mmap->len % PAGE_SIZE) != 0) { - kprintf("MM: got an unaligned region length from the bootloader; correcting %d by %d bytes\n", mmap->len, mmap->len % PAGE_SIZE); + klog() << "MM: got an unaligned region length from the bootloader; correcting " << mmap->len << " by " << (mmap->len % PAGE_SIZE) << " bytes"; mmap->len -= mmap->len % PAGE_SIZE; } if (mmap->len < PAGE_SIZE) { - kprintf("MM: memory region from bootloader is too small; we want >= %d bytes, but got %d bytes\n", PAGE_SIZE, mmap->len); + klog() << "MM: memory region from bootloader is too small; we want >= " << PAGE_SIZE << " bytes, but got " << mmap->len << " bytes"; continue; } #ifdef MM_DEBUG - kprintf("MM: considering memory at %p - %p\n", - (uintptr_t)mmap->addr, (uintptr_t)(mmap->addr + mmap->len)); + klog() << "MM: considering memory at " << String::format("%p", (uintptr_t)mmap->addr) << " - " << String::format("%p", (uintptr_t)(mmap->addr + mmap->len)); #endif for (size_t page_base = mmap->addr; page_base < (mmap->addr + mmap->len); page_base += PAGE_SIZE) { @@ -301,7 +294,7 @@ PageFaultResponse MemoryManager::handle_page_fault(const PageFault& fault) #endif auto* region = region_from_vaddr(fault.vaddr()); if (!region) { - kprintf("NP(error) fault at invalid address V%p\n", fault.vaddr().get()); + klog() << "NP(error) fault at invalid address V" << String::format("%p", fault.vaddr().get()); return PageFaultResponse::ShouldCrash; } @@ -366,9 +359,7 @@ void MemoryManager::deallocate_user_physical_page(PhysicalPage&& page) { for (auto& region : m_user_physical_regions) { if (!region.contains(page)) { - kprintf( - "MM: deallocate_user_physical_page: %p not in %p -> %p\n", - page.paddr().get(), region.lower().get(), region.upper().get()); + klog() << "MM: deallocate_user_physical_page: " << page.paddr() << " not in " << region.lower() << " -> " << region.upper(); continue; } @@ -378,7 +369,7 @@ void MemoryManager::deallocate_user_physical_page(PhysicalPage&& page) return; } - kprintf("MM: deallocate_user_physical_page couldn't figure out region for user page @ %p\n", page.paddr().get()); + klog() << "MM: deallocate_user_physical_page couldn't figure out region for user page @ " << page.paddr(); ASSERT_NOT_REACHED(); } @@ -400,7 +391,7 @@ RefPtr MemoryManager::allocate_user_physical_page(ShouldZeroFill s if (!page) { if (m_user_physical_regions.is_empty()) { - kprintf("MM: no user physical regions available (?)\n"); + klog() << "MM: no user physical regions available (?)"; } for_each_vmobject([&](auto& vmobject) { @@ -408,7 +399,7 @@ RefPtr MemoryManager::allocate_user_physical_page(ShouldZeroFill s auto& purgeable_vmobject = static_cast(vmobject); int purged_page_count = purgeable_vmobject.purge_with_interrupts_disabled({}); if (purged_page_count) { - kprintf("MM: Purge saved the day! Purged %d pages from PurgeableVMObject{%p}\n", purged_page_count, &purgeable_vmobject); + klog() << "MM: Purge saved the day! Purged " << purged_page_count << " pages from PurgeableVMObject{" << &purgeable_vmobject << "}"; page = find_free_user_physical_page(); ASSERT(page); return IterationDecision::Break; @@ -418,7 +409,7 @@ RefPtr MemoryManager::allocate_user_physical_page(ShouldZeroFill s }); if (!page) { - kprintf("MM: no user physical pages available\n"); + klog() << "MM: no user physical pages available"; ASSERT_NOT_REACHED(); return {}; } @@ -442,9 +433,7 @@ void MemoryManager::deallocate_supervisor_physical_page(PhysicalPage&& page) { for (auto& region : m_super_physical_regions) { if (!region.contains(page)) { - kprintf( - "MM: deallocate_supervisor_physical_page: %p not in %p -> %p\n", - page.paddr().get(), region.lower().get(), region.upper().get()); + klog() << "MM: deallocate_supervisor_physical_page: " << page.paddr() << " not in " << region.lower() << " -> " << region.upper(); continue; } @@ -453,7 +442,7 @@ void MemoryManager::deallocate_supervisor_physical_page(PhysicalPage&& page) return; } - kprintf("MM: deallocate_supervisor_physical_page couldn't figure out region for super page @ %p\n", page.paddr().get()); + klog() << "MM: deallocate_supervisor_physical_page couldn't figure out region for super page @ " << page.paddr(); ASSERT_NOT_REACHED(); } @@ -470,10 +459,10 @@ RefPtr MemoryManager::allocate_supervisor_physical_page() if (!page) { if (m_super_physical_regions.is_empty()) { - kprintf("MM: no super physical regions available (?)\n"); + klog() << "MM: no super physical regions available (?)"; } - kprintf("MM: no super physical pages available\n"); + klog() << "MM: no super physical pages available"; ASSERT_NOT_REACHED(); return {}; } @@ -680,20 +669,10 @@ void MemoryManager::unregister_region(Region& region) void MemoryManager::dump_kernel_regions() { - kprintf("Kernel regions:\n"); - kprintf("BEGIN END SIZE ACCESS NAME\n"); + klog() << "Kernel regions:"; + klog() << "BEGIN END SIZE ACCESS NAME"; for (auto& region : MM.m_kernel_regions) { - kprintf("%08x -- %08x %08x %c%c%c%c%c%c %s\n", - region.vaddr().get(), - region.vaddr().offset(region.size() - 1).get(), - region.size(), - region.is_readable() ? 'R' : ' ', - region.is_writable() ? 'W' : ' ', - region.is_executable() ? 'X' : ' ', - region.is_shared() ? 'S' : ' ', - region.is_stack() ? 'T' : ' ', - region.vmobject().is_purgeable() ? 'P' : ' ', - region.name().characters()); + klog() << String::format("%08x", region.vaddr().get()) << " -- " << String::format("%08x", region.vaddr().offset(region.size() - 1).get()) << " " << String::format("%08x", region.size()) << " " << (region.is_readable() ? 'R' : ' ') << (region.is_writable() ? 'W' : ' ') << (region.is_executable() ? 'X' : ' ') << (region.is_shared() ? 'S' : ' ') << (region.is_stack() ? 'T' : ' ') << (region.vmobject().is_purgeable() ? 'P' : ' ') << " " << region.name().characters(); } } diff --git a/Kernel/VM/PageDirectory.cpp b/Kernel/VM/PageDirectory.cpp index 0f6fc4ad727..aff510ce72a 100644 --- a/Kernel/VM/PageDirectory.cpp +++ b/Kernel/VM/PageDirectory.cpp @@ -63,9 +63,9 @@ PageDirectory::PageDirectory() PhysicalAddress boot_pdpt_paddr(virtual_to_low_physical((uintptr_t)boot_pdpt)); PhysicalAddress boot_pd0_paddr(virtual_to_low_physical((uintptr_t)boot_pd0)); PhysicalAddress boot_pd3_paddr(virtual_to_low_physical((uintptr_t)boot_pd3)); - kprintf("MM: boot_pdpt @ P%p\n", boot_pdpt_paddr.get()); - kprintf("MM: boot_pd0 @ P%p\n", boot_pd0_paddr.get()); - kprintf("MM: boot_pd3 @ P%p\n", boot_pd3_paddr.get()); + klog() << "MM: boot_pdpt @ " << boot_pdpt_paddr; + klog() << "MM: boot_pd0 @ " << boot_pd0_paddr; + klog() << "MM: boot_pd3 @ " << boot_pd3_paddr; m_directory_table = PhysicalPage::create(boot_pdpt_paddr, true, false); m_directory_pages[0] = PhysicalPage::create(boot_pd0_paddr, true, false); m_directory_pages[3] = PhysicalPage::create(boot_pd3_paddr, true, false); diff --git a/Kernel/VM/RangeAllocator.cpp b/Kernel/VM/RangeAllocator.cpp index edbb76192dc..6ceee3ce688 100644 --- a/Kernel/VM/RangeAllocator.cpp +++ b/Kernel/VM/RangeAllocator.cpp @@ -130,7 +130,7 @@ Range RangeAllocator::allocate_anywhere(size_t size, size_t alignment) #endif return allocated_range; } - kprintf("VRA: Failed to allocate anywhere: %zu, %zu\n", size, alignment); + klog() << "VRA: Failed to allocate anywhere: " << size << ", " << alignment; return {}; } @@ -155,7 +155,7 @@ Range RangeAllocator::allocate_specific(VirtualAddress base, size_t size) #endif return allocated_range; } - kprintf("VRA: Failed to allocate specific range: %x(%u)\n", base.get(), size); + dbg() << "VRA: Failed to allocate specific range: " << base << "(" << size << ")"; return {}; } diff --git a/Kernel/VM/Region.cpp b/Kernel/VM/Region.cpp index 1fd3b48cba5..d498ca910a1 100644 --- a/Kernel/VM/Region.cpp +++ b/Kernel/VM/Region.cpp @@ -124,7 +124,7 @@ bool Region::commit(size_t page_index) return true; auto physical_page = MM.allocate_user_physical_page(MemoryManager::ShouldZeroFill::Yes); if (!physical_page) { - kprintf("MM: commit was unable to allocate a physical page\n"); + klog() << "MM: commit was unable to allocate a physical page"; return false; } vmobject_physical_page_entry = move(physical_page); @@ -322,7 +322,7 @@ PageFaultResponse Region::handle_fault(const PageFault& fault) } return handle_cow_fault(page_index_in_region); } - kprintf("PV(error) fault in Region{%p}[%u] at V%p\n", this, page_index_in_region, fault.vaddr().get()); + dbg() << "PV(error) fault in Region{" << this << "}[" << page_index_in_region << "] at " << fault.vaddr(); return PageFaultResponse::ShouldCrash; } @@ -350,7 +350,7 @@ PageFaultResponse Region::handle_zero_fault(size_t page_index_in_region) auto physical_page = MM.allocate_user_physical_page(MemoryManager::ShouldZeroFill::Yes); if (physical_page.is_null()) { - kprintf("MM: handle_zero_fault was unable to allocate a physical page\n"); + klog() << "MM: handle_zero_fault was unable to allocate a physical page"; return PageFaultResponse::ShouldCrash; } @@ -385,7 +385,7 @@ PageFaultResponse Region::handle_cow_fault(size_t page_index_in_region) auto physical_page_to_copy = move(vmobject_physical_page_entry); auto physical_page = MM.allocate_user_physical_page(MemoryManager::ShouldZeroFill::No); if (physical_page.is_null()) { - kprintf("MM: handle_cow_fault was unable to allocate a physical page\n"); + klog() << "MM: handle_cow_fault was unable to allocate a physical page"; return PageFaultResponse::ShouldCrash; } u8* dest_ptr = MM.quickmap_page(*physical_page); @@ -436,7 +436,7 @@ PageFaultResponse Region::handle_inode_fault(size_t page_index_in_region) auto& inode = inode_vmobject.inode(); auto nread = inode.read_bytes((first_page_index() + page_index_in_region) * PAGE_SIZE, PAGE_SIZE, page_buffer, nullptr); if (nread < 0) { - kprintf("MM: handle_inode_fault had error (%d) while reading!\n", nread); + klog() << "MM: handle_inode_fault had error (" << nread << ") while reading!"; return PageFaultResponse::ShouldCrash; } if (nread < PAGE_SIZE) { @@ -446,7 +446,7 @@ PageFaultResponse Region::handle_inode_fault(size_t page_index_in_region) cli(); vmobject_physical_page_entry = MM.allocate_user_physical_page(MemoryManager::ShouldZeroFill::No); if (vmobject_physical_page_entry.is_null()) { - kprintf("MM: handle_inode_fault was unable to allocate a physical page\n"); + klog() << "MM: handle_inode_fault was unable to allocate a physical page"; return PageFaultResponse::ShouldCrash; } diff --git a/Kernel/init.cpp b/Kernel/init.cpp index 956d461e81f..33407c7ecde 100644 --- a/Kernel/init.cpp +++ b/Kernel/init.cpp @@ -117,7 +117,7 @@ extern "C" [[noreturn]] void init() new Console; - kprintf("Starting SerenityOS...\n"); + klog() << "Starting SerenityOS..."; __stack_chk_guard = get_good_random(); @@ -146,7 +146,7 @@ extern "C" [[noreturn]] void init() VirtualConsole::switch_to(0); // Sample test to see if the ACPI parser is working... - kprintf("ACPI: HPET table @ P 0x%x\n", ACPI::Parser::the().find_table("HPET").get()); + klog() << "ACPI: HPET table @ " << ACPI::Parser::the().find_table("HPET"); setup_pci(); @@ -229,7 +229,7 @@ void init_stage2() } if (!root.starts_with("/dev/hda")) { - kprintf("init_stage2: root filesystem must be on the first IDE hard drive (/dev/hda)\n"); + klog() << "init_stage2: root filesystem must be on the first IDE hard drive (/dev/hda)"; hang(); } @@ -243,14 +243,14 @@ void init_stage2() unsigned partition_number = root.to_uint(ok); if (!ok) { - kprintf("init_stage2: couldn't parse partition number from root kernel parameter\n"); + klog() << "init_stage2: couldn't parse partition number from root kernel parameter"; hang(); } MBRPartitionTable mbr(root_dev); if (!mbr.initialize()) { - kprintf("init_stage2: couldn't read MBR from disk\n"); + klog() << "init_stage2: couldn't read MBR from disk"; hang(); } @@ -258,12 +258,12 @@ void init_stage2() dbg() << "GPT Partitioned Storage Detected!"; GPTPartitionTable gpt(root_dev); if (!gpt.initialize()) { - kprintf("init_stage2: couldn't read GPT from disk\n"); + klog() << "init_stage2: couldn't read GPT from disk"; hang(); } auto partition = gpt.partition(partition_number); if (!partition) { - kprintf("init_stage2: couldn't get partition %d\n", partition_number); + klog() << "init_stage2: couldn't get partition " << partition_number; hang(); } root_dev = *partition; @@ -272,23 +272,23 @@ void init_stage2() if (mbr.contains_ebr()) { EBRPartitionTable ebr(root_dev); if (!ebr.initialize()) { - kprintf("init_stage2: couldn't read EBR from disk\n"); + klog() << "init_stage2: couldn't read EBR from disk"; hang(); } auto partition = ebr.partition(partition_number); if (!partition) { - kprintf("init_stage2: couldn't get partition %d\n", partition_number); + klog() << "init_stage2: couldn't get partition " << partition_number; hang(); } root_dev = *partition; } else { if (partition_number < 1 || partition_number > 4) { - kprintf("init_stage2: invalid partition number %d; expected 1 to 4\n", partition_number); + klog() << "init_stage2: invalid partition number " << partition_number << "; expected 1 to 4"; hang(); } auto partition = mbr.partition(partition_number); if (!partition) { - kprintf("init_stage2: couldn't get partition %d\n", partition_number); + klog() << "init_stage2: couldn't get partition " << partition_number; hang(); } root_dev = *partition; @@ -297,12 +297,12 @@ void init_stage2() } auto e2fs = Ext2FS::create(root_dev); if (!e2fs->initialize()) { - kprintf("init_stage2: couldn't open root filesystem\n"); + klog() << "init_stage2: couldn't open root filesystem"; hang(); } if (!VFS::the().mount_root(e2fs)) { - kprintf("VFS::mount_root failed\n"); + klog() << "VFS::mount_root failed"; hang(); } @@ -318,16 +318,16 @@ void init_stage2() RefPtr fd1; if ((detect >> 4) & 0x4) { fd0 = FloppyDiskDevice::create(FloppyDiskDevice::DriveType::Master); - kprintf("fd0 is 1.44MB floppy drive\n"); + klog() << "fd0 is 1.44MB floppy drive"; } else { - kprintf("fd0 type unsupported! Type == 0x%x\n", detect >> 4); + klog() << "fd0 type unsupported! Type == 0x", String::format("%x", detect >> 4); } if (detect & 0x0f) { fd1 = FloppyDiskDevice::create(FloppyDiskDevice::DriveType::Slave); - kprintf("fd1 is 1.44MB floppy drive"); + klog() << "fd1 is 1.44MB floppy drive"; } else { - kprintf("fd1 type unsupported! Type == 0x%x\n", detect & 0x0f); + klog() << "fd1 type unsupported! Type == 0x", String::format("%x", detect & 0x0f); } int error; @@ -340,7 +340,7 @@ void init_stage2() Thread* thread = nullptr; Process::create_user_process(thread, "/bin/Shell", (uid_t)0, (gid_t)0, (pid_t)0, error, {}, {}, tty0); if (error != 0) { - kprintf("init_stage2: error spawning Shell: %d\n", error); + klog() << "init_stage2: error spawning Shell: " << error; hang(); } thread->set_priority(THREAD_PRIORITY_HIGH); @@ -349,7 +349,7 @@ void init_stage2() Thread* thread = nullptr; Process::create_user_process(thread, "/bin/SystemServer", (uid_t)0, (gid_t)0, (pid_t)0, error, {}, {}, tty0); if (error != 0) { - kprintf("init_stage2: error spawning SystemServer: %d\n", error); + klog() << "init_stage2: error spawning SystemServer: " << error; hang(); } thread->set_priority(THREAD_PRIORITY_HIGH); @@ -376,7 +376,7 @@ void setup_serial_debug() return true; }; - // serial_debug will output all the kprintf and dbgprintf data to COM1 at + // serial_debug will output all the klog() and dbg() data to COM1 at // 8-N-1 57600 baud. this is particularly useful for debugging the boot // process on live hardware. // @@ -420,7 +420,7 @@ void setup_acpi() ACPI::StaticParser::initialize_without_rsdp(); return; } - kprintf("acpi boot argmuent has an invalid value.\n"); + klog() << "acpi boot argmuent has an invalid value."; hang(); } @@ -438,7 +438,7 @@ void setup_vmmouse() VMWareBackdoor::the().enable_absolute_vmmouse(); return; } - kprintf("vmmouse boot argmuent has an invalid value.\n"); + klog() << "vmmouse boot argmuent has an invalid value."; hang(); } @@ -455,7 +455,7 @@ void setup_pci() } else if (pci_mmio == "off") { PCI::Initializer::the().test_and_initialize(true); } else { - kprintf("pci_mmio boot argmuent has an invalid value.\n"); + klog() << "pci_mmio boot argmuent has an invalid value."; hang(); } PCI::Initializer::the().dismiss(); @@ -482,7 +482,7 @@ void setup_interrupts() return; } - kprintf("smp boot argmuent has an invalid value.\n"); + klog() << "smp boot argmuent has an invalid value."; hang(); } }