introduce debug log levels

arch/x86_64/addr_space.cpp

@@ -52,8 +52,10 @@ AddrSpace::AddrSpace()
   /* Create a new address space by allocating
    * a fresh Page Map Level 4 */
   m_pml4 = PageMap::get().alloc();
-
   updateKernelMappings();
+
+  debug(VSPACE) << "allocated new virtual address space (PML4 @ "
+                << PPN_TO_PTR(m_pml4) << ")\n";
 }
 
 AddrSpace* AddrSpace::clone()
@@ -89,6 +91,9 @@ AddrSpace* AddrSpace::clone()
     pageMap.addRef(pml4_old[i].ppn);
   }
 
+  debug(VSPACE) << "cloned address space with cow-semantics (PML4 @ "
+                << PPN_TO_PTR(m_pml4) << ")\n";
+
   /* it's important that the TLB will be flushed after setting all
    * the tables readonly by calling apply(). */
   this->apply();
@@ -100,26 +105,24 @@ void AddrSpace::setup()
     assert(sizeof(GenericPagingTable) == 8);
 
     /* Create a new virtual address space for the kernel */
-    debug() << "allocating kernel virtual address space\n";
     auto kernelSpace = new (&s_kernelAddrSpace) AddrSpace();
 
     /* map the whole physical memory to the upper half */
-    debug() << "mapping physical memory to the upper half...";
+    debug(VSPACE) << "mapping physical memory to the upper half...\n";
     const size_t totalPages = PageMap::get().getTotalPageCount();
     const size_t ident_page_offset = IDENT_OFFSET >> PAGE_SHIFT;
     for (size_t page = 0; page < totalPages; page++)
         kernelSpace->map(page + ident_page_offset, page, MAP_WRITE);
-    debug() << " done\n";
 
     /* Enable support for NX pages */
     s_nxEnabled = enable_nx();
-    debug() << "trying to enable NX: "
+    debug(VSPACE) << "trying to enable NX: "
             << (s_nxEnabled ? "ok\n" : "not available\n");
 
     /* Switch to the newly created address space. */
     kernelSpace->apply();
     s_initialized = true;
-    debug() << "successfully written %cr3\n";
+    debug(VSPACE) << "successfully written %cr3\n";
 }
 
 AddrSpace &AddrSpace::kernel()
@@ -212,6 +215,9 @@ void AddrSpace::map(size_t virt, size_t phys, int flags)
 
     currentTablePPN = currentLevelTableEntry.ppn;
   }
+
+  //debug(VSPACE) << PPN_TO_PTR(virt) << " -> " PPN_TO_PTR(phys)
+  //              << " (PML4 @ " << PPN_TO_PTR(m_pml4) << ")\n";
 }
 
 void AddrSpace::unmap(size_t virt)
@@ -260,9 +266,6 @@ bool AddrSpace::triggerCow(size_t virt)
   indices[1] = (virt >> 9) & 0x1ff;
   indices[0] = (virt) & 0x1ff;
 
-  debug() << "COW triggered for addr "
-          << (void*)(virt << PAGE_SHIFT) << "\n";
-
   size_t currentTablePpn = m_pml4;
   for (int level = 3; level >= 0; level--)
   {
@@ -303,6 +306,7 @@ bool AddrSpace::triggerCow(size_t virt)
          * actual table. That means we must not set any bits
          * but just copy the page */
         memcpy(new_table_ptr, old_table_ptr, PAGE_SIZE);
+        debug(VSPACE) << "cow: copying page: " << PPN_TO_PTR(virt) << "\n";
       }
       else
       {
@@ -444,7 +448,8 @@ AddrSpace::~AddrSpace()
   }
 
   pageMap.free(m_pml4);
-  m_pml4 = (size_t)-1;
 
-  debug() << "address space deleted\n";
+  debug(VSPACE) << "deleted address space (had PML4 @ "
+          << PPN_TO_PTR(m_pml4) << ")\n";
+  m_pml4 = (size_t)-1;
 }

arch/x86_64/context.cpp

@@ -44,14 +44,15 @@ void IrqContext::newKernelCtx()
 
 void IrqContext::print()
 {
-  debug() << "--- Register dump (x86) ---\n"
-          << DEBUG_HEX << "  rip=" << rip
-          << ", rsp=" << rsp
-          << ", err=" << error_id << "\n"
-          << DEBUG_HEX << "  rax=" << rax
-          << ", rbx=" << rbx
-          << ", rcx=" << rcx << "\n"
-          << DEBUG_HEX << "  rdx=" << rdx
-          << ", rdi=" << rdi
-          << ", rsi=" << rsi << "\n";
+  debug(EXCEPT)
+    << "--- REGISTER DUMP (x86_64) ---\n"
+    << DEBUG_HEX << "  rip=" << rip
+    << ", rsp=" << rsp
+    << ", err=" << error_id << "\n"
+    << DEBUG_HEX << "  rax=" << rax
+    << ", rbx=" << rbx
+    << ", rcx=" << rcx << "\n"
+    << DEBUG_HEX << "  rdx=" << rdx
+    << ", rdi=" << rdi
+    << ", rsi=" << rsi << "\n";
 }

arch/x86_64/idt.cpp

@@ -33,7 +33,7 @@ static IrqDescriptor g_idt[256];
 
 static void setup_pic()
 {
-  debug() << "reconfigure PIC\n";
+  debug(BOOT) << "reconfigure PIC\n";
 
   outb(0x20, 0x11);   // init PIC1
   outb(0xA0, 0x11);   // init PIC2
@@ -84,8 +84,6 @@ extern "C" {
 
 static void setup_idt()
 {
-    debug() << "Setting up interrupt descriptor table\n";
-
   install_descriptor(0,  &irq0,  IDT_PRESENT | IDT_SUPV | IDT_GATE, 0);
   install_descriptor(1,  &irq1,  IDT_PRESENT | IDT_SUPV | IDT_GATE, 0);
   install_descriptor(2,  &irq2,  IDT_PRESENT | IDT_SUPV | IDT_GATE, 0);

arch/x86_64/syscall.cpp

@@ -5,15 +5,24 @@
 #include <context.h>
 #include <errno.h>
 #include <debug.h>
+#include <scheduler.h>
 
 #include "../../kernel/syscall_list.h"
 
+static void invalidSyscall(IrqContext* ctx)
+{
+  debug(SYSCALL) << "PID " << sched::currentPid()
+                 << ": invalid system call: #"
+                 << ctx->returnValue() << "\n";
+}
+
 void do_syscall(IrqContext* ctx)
 {
   /* check for an invalid system call number */
   if (ctx->rax >= sizeof(syscalls) / sizeof(void*))
   {
     ctx->rax = -ENOSYS;
+    invalidSyscall(ctx);
     return;
   }
 
@@ -22,6 +31,7 @@ void do_syscall(IrqContext* ctx)
   if (syscall_addr == nullptr)
   {
     ctx->rax = -ENOSYS;
+    invalidSyscall(ctx);
     return;
   }
 

arch/x86_common/interrupt.cpp

@@ -59,19 +59,20 @@ extern "C" IrqContext* x86_irq_handler(IrqContext* ctx)
         void* addr = getPageFaultAddr();
         sti();
 
-        debug() << "fault: " << addr
-                << ", present=" << (ctx->error() & PF_PRESENT ? "y" : "n")
-                << ", user=" << (ctx->error() & PF_USER ? "y" : "n")
-                << ", write=" << (ctx->error() & PF_WRITE ? "y" : "n")
-                << ", reserved=" << (ctx->error() & PF_RESERVED ? "y" : "n")
-                << ", data=" << (ctx->error() & PF_CODE ? "n" : "y") << "\n";
-
         if (handlePageFault((size_t)addr, (FaultFlags)ctx->error())) {
           return ctx;
         }
+
+        debug(PAGEFAULT)
+          << "fault @ " << addr << ": "
+          << (ctx->error() & PF_PRESENT ? "protection, " : "non-present, ")
+          << (ctx->error() & PF_USER ? "user, " : "kernel,")
+          << (ctx->error() & PF_WRITE ? "write, " : "read, ")
+          << (ctx->error() & PF_RESERVED ? "reserved, " : "")
+          << (ctx->error() & PF_CODE ? "code" : "data") << "\n";
       }
 
-      debug() << "(!!) exception #" << ctx->irq()
+      debug(EXCEPT) << "(!!) exception #" << ctx->irq()
               << " (" << strexcept(ctx->irq()) << ")\n";
       ctx->print();
 

arch/x86_common/pagemap.cpp

@@ -71,28 +71,29 @@ static const char* get_mmap_type_str(uint32_t type)
 
 static void print_mmap_entry(stivale_mmap_entry& entry)
 {
-    debug() << "  " << DEBUG_HEX
-            << entry.base << " - " << (entry.base + entry.length - 1)
-            << ": " << get_mmap_type_str(entry.type) << "\n";
+  debug(MEMORY)
+    << "  " << DEBUG_HEX
+    << entry.base << " - " << (entry.base + entry.length - 1)
+    << ": " << get_mmap_type_str(entry.type) << "\n";
 }
 
 void create_page_bitmap()
 {
     /* Compute total RAM size */
     const auto total_pages = getSystemPageCount();
-    debug() << "Total RAM size: " << (total_pages >> 8) << "MB ("
+    debug(MEMORY) << "Total RAM size: " << (total_pages >> 8) << "MB ("
             << total_pages << " page frames)\n";
 
     /* Compute the amount of pages needed to store the page refcounter */
     size_t pagemap_pages = total_pages >> PAGE_SHIFT;
     if (total_pages % PAGE_SIZE != 0)
         pagemap_pages++;
-    debug() << "PageMap: ref counter size: ~" << (total_pages >> 10) << "KB\n";
+    debug(MEMORY) << "PageMap: ref counter size: ~" << (total_pages >> 10) << "KB\n";
 
     /* Get a memory location to store the page bitmap */
     const size_t pagemap_start_page = getFirstNFreePages(pagemap_pages);
     const auto pagemap = (uint8_t*)PPN_TO_VIRT(pagemap_start_page);
-    debug() << "PageMap: stored at " << (void*)pagemap << "\n";
+    debug(MEMORY) << "PageMap: stored at " << (void*)pagemap << "\n";
 
     /* Set initial refcount for all pages to 0xff (max) */
     memset(pagemap, 0xff, total_pages);
@@ -128,6 +129,6 @@ void create_page_bitmap()
     /* Initialize the PageManager class */
     new (&s_pagemap) PageMap(total_pages, free_pages, usable_pages, pagemap);
 
-    debug() << "Usable RAM: " << (free_pages >> 8)
+    debug(MEMORY) << "Usable RAM: " << (free_pages >> 8)
             << "/" << (total_pages >> 8) << " MB\n";
 }

arch/x86_common/start.cpp

@@ -58,18 +58,18 @@ extern "C" void _NORETURN _start(struct stivale_struct *stivale)
   debug_init();
 
   s_stivale = stivale;
-  debug() << "Hello, world!\n";
+  debug(BOOT) << "Hello, world!\n";
 
   /* Load our own Global Descriptor Table */
-  debug() << "Setting up Global Descriptor Table ...";
+  debug(BOOT) << "Setup: Global Descriptor Table\n";
   setup_gdt();
-  debug() << " done\n";
 
   /* Create a map of free pages from the stivale
    * memory map. */
   create_page_bitmap();
 
   /* Load an interrupt descriptor table */
+  debug(BOOT) << "Setup: Interrupt Descriptor Table\n";
   x86_irq_init();
 
   /* Create the kernel virtual memory address space and
@@ -79,7 +79,7 @@ extern "C" void _NORETURN _start(struct stivale_struct *stivale)
 
   /* enable SSE and AVX if available */
   s_sseEnabled = sse_enable();
-  debug() << "trying to enable SSE: "
+  debug(BOOT) << "trying to enable SSE: "
           << (s_sseEnabled ? "ok\n" : "not available\n");
   s_sseEnabled = sse_enable();
 

kernel/boot.cpp

@@ -14,11 +14,11 @@
 
 static void printIssue()
 {
-  debug() << "Koerix OS kernel\n"
+  debug(BOOT) << "Koerix OS kernel\n"
              "Copyright (C) 2017-2021 Alexander Ulmer\n";
 
   auto& pagemap = PageMap::get();
-  debug() << "Memory: " << (pagemap.getUsedMemory() >> 20) << "/"
+  debug(BOOT) << "Memory: " << (pagemap.getUsedMemory() >> 20) << "/"
           << (pagemap.getUsableMemory() >> 20) << " MB used"
              " of total " << (pagemap.getTotalMemory() >> 20) << " MB\n\n";
 }
@@ -44,7 +44,7 @@ void kernel_init(const char* cmdline)
     int error;
     auto fd = fs::open(valueBuffer, error);
     if (!fd.valid()) {
-      debug() << "warning: " << valueBuffer << ": "
+      debug(BOOT) << "warning: " << valueBuffer << ": "
               << strerror(error) << "\n";
     } else {
       mainTerm = ktl::shared_ptr<Terminal>(new Terminal(fd));

kernel/debug.cpp

@@ -9,7 +9,7 @@
 #include <mm.h>
 #include <pc/serial.h>
 
-using namespace debugging;
+using namespace dbg;
 
 static Spinlock s_debugLock;
 static bool s_initialized = false;
@@ -18,7 +18,7 @@ static pc::SerialPort s_serial;
 void panic(const char* message)
 {
   cli();
-  debug() << "**** kernel panic: " << message << "\n\n\n";
+  debug(KERNEL) << "**** kernel panic: " << message << "\n\n\n";
   for (;;) { hlt(); }
 }
 
@@ -37,6 +37,9 @@ DebugStream::~DebugStream()
   if (!s_initialized)
     return;
 
+  if ((m_loglevel & OUTPUT_ENABLE) == 0)
+    return;
+
   size_t len = strlen(m_buffer);
   s_debugLock.lock();
 #ifdef DEBUG

kernel/debug_stream.cpp

@@ -4,13 +4,14 @@
 #include <debug.h>
 #include <string.h>
 
-using namespace debugging;
+using namespace dbg;
 
-DebugStream::DebugStream()
+DebugStream::DebugStream(int loglevel)
     : m_currentMode(DEC)
+    , m_loglevel(loglevel)
 {
-    m_buffer[0] = 0;
-    m_destPtr = m_buffer;
+  m_buffer[0] = 0;
+  m_destPtr = m_buffer;
 }
 
 DebugStream& DebugStream::operator<<(Modifier modif)

kernel/devices.cpp

@@ -34,6 +34,7 @@ namespace dev {
 
   void registerDevice(const char* name, DeviceFile* dev)
   {
+    debug(DEVICES) << "registered device '" << name << "'\n";
     DeviceFs* devfs = (DeviceFs*)s_devfs.get();
     devfs->registerDevice(name, ktl::shared_ptr<DeviceFile>(dev));
   }