From f16145cff61f324594e5ede67fc2fbb9f03e5669 Mon Sep 17 00:00:00 2001 From: Kevin Lange Date: Sat, 5 Apr 2014 15:23:17 -0700 Subject: [PATCH] lots of log overhauling --- kernel/cpu/isrs_ext.c | 2 +- kernel/fs/pipe.c | 30 +++++++++---------- kernel/main.c | 2 +- kernel/mem/mem.c | 10 +++---- kernel/mem/shm.c | 51 ++------------------------------ kernel/misc/elf.c | 2 +- kernel/misc/multiboot.c | 64 ++++++++++++++++++++--------------------- kernel/sys/panic.c | 59 +++++++++++++++++-------------------- kernel/sys/signal.c | 4 +-- kernel/sys/syscall.c | 17 ++--------- 10 files changed, 90 insertions(+), 151 deletions(-) diff --git a/kernel/cpu/isrs_ext.c b/kernel/cpu/isrs_ext.c index 25e5c57e..edb2fe57 100644 --- a/kernel/cpu/isrs_ext.c +++ b/kernel/cpu/isrs_ext.c @@ -122,7 +122,7 @@ static const char *exception_messages[32] = { }; void fault_error(struct regs *r) { - kprintf("Unhandled exception: [%d] %s\n", r->int_no, exception_messages[r->int_no]); + debug_print(CRITICAL, "Unhandled exception: [%d] %s", r->int_no, exception_messages[r->int_no]); HALT_AND_CATCH_FIRE("Process caused an unhandled exception", r); STOP; } diff --git a/kernel/fs/pipe.c b/kernel/fs/pipe.c index cfe011f2..edef0943 100644 --- a/kernel/fs/pipe.c +++ b/kernel/fs/pipe.c @@ -73,13 +73,13 @@ uint32_t read_pipe(fs_node_t *node, uint32_t offset, uint32_t size, uint8_t *buf #if DEBUG_PIPES if (pipe->size > 300) { /* Ignore small pipes (ie, keyboard) */ - kprintf("[debug] Call to read from pipe 0x%x\n", node->device); - kprintf(" Unread bytes: %d\n", pipe_unread(pipe)); - kprintf(" Total size: %d\n", pipe->size); - kprintf(" Request size: %d\n", size); - kprintf(" Write pointer: %d\n", pipe->write_ptr); - kprintf(" Read pointer: %d\n", pipe->read_ptr); - kprintf(" Buffer address: 0x%x\n", pipe->buffer); + debug_print(INFO, "[debug] Call to read from pipe 0x%x", node->device); + debug_print(INFO, " Unread bytes: %d", pipe_unread(pipe)); + debug_print(INFO, " Total size: %d", pipe->size); + debug_print(INFO, " Request size: %d", size); + debug_print(INFO, " Write pointer: %d", pipe->write_ptr); + debug_print(INFO, " Read pointer: %d", pipe->read_ptr); + debug_print(INFO, " Buffer address: 0x%x", pipe->buffer); } #endif @@ -116,14 +116,14 @@ uint32_t write_pipe(fs_node_t *node, uint32_t offset, uint32_t size, uint8_t *bu #if DEBUG_PIPES if (pipe->size > 300) { /* Ignore small pipes (ie, keyboard) */ - kprintf("[debug] Call to write to pipe 0x%x\n", node->device); - kprintf(" Available space: %d\n", pipe_available(pipe)); - kprintf(" Total size: %d\n", pipe->size); - kprintf(" Request size: %d\n", size); - kprintf(" Write pointer: %d\n", pipe->write_ptr); - kprintf(" Read pointer: %d\n", pipe->read_ptr); - kprintf(" Buffer address: 0x%x\n", pipe->buffer); - kprintf(" Write: %s\n", buffer); + debug_print(INFO, "[debug] Call to write to pipe 0x%x", node->device); + debug_print(INFO, " Available space: %d", pipe_available(pipe)); + debug_print(INFO, " Total size: %d", pipe->size); + debug_print(INFO, " Request size: %d", size); + debug_print(INFO, " Write pointer: %d", pipe->write_ptr); + debug_print(INFO, " Read pointer: %d", pipe->read_ptr); + debug_print(INFO, " Buffer address: 0x%x", pipe->buffer); + debug_print(INFO, " Write: %s", buffer); } #endif diff --git a/kernel/main.c b/kernel/main.c index 50ad3279..12d1cf4e 100644 --- a/kernel/main.c +++ b/kernel/main.c @@ -90,7 +90,7 @@ int kmain(struct multiboot *mboot, uint32_t mboot_mag, uintptr_t esp) { last_mod = module_end; } } - debug_print(NOTICE, "Moving kernel heap start to 0x%x\n", last_mod); + debug_print(NOTICE, "Moving kernel heap start to 0x%x", last_mod); kmalloc_startat(last_mod); } } diff --git a/kernel/mem/mem.c b/kernel/mem/mem.c index fa54176a..26551f26 100644 --- a/kernel/mem/mem.c +++ b/kernel/mem/mem.c @@ -149,7 +149,7 @@ uint32_t first_frame(void) { } } - kprintf("\033[1;37;41mWARNING: System claims to be out of usable memory, which means we probably overwrote the page frames.\033[0m\n"); + debug_print(CRITICAL, "System claims to be out of usable memory, which means we probably overwrote the page frames.\033[0m"); #if 0 signal_t * sig = malloc(sizeof(signal_t)); @@ -341,7 +341,7 @@ page_fault( int reserved = r->err_code & 0x8 ? 1 : 0; int id = r->err_code & 0x10 ? 1 : 0; - kprintf("\033[1;37;41mSegmentation fault. (p:%d,rw:%d,user:%d,res:%d,id:%d) at 0x%x eip:0x%x pid=%d,%d [%s]\033[0m\n", + debug_print(ERROR, "\033[1;37;41mSegmentation fault. (p:%d,rw:%d,user:%d,res:%d,id:%d) at 0x%x eip:0x%x pid=%d,%d [%s]\033[0m", present, rw, user, reserved, id, faulting_address, r->eip, current_process->id, current_process->group, current_process->name); if (r->eip < heap_end) { @@ -370,7 +370,7 @@ page_fault( } } - kprintf("\033[1;31mClosest symbol to faulting address:\033[0m %s [0x%x]\n", closest, addr); + debug_print(ERROR, "\033[1;31mClosest symbol to faulting address:\033[0m %s [0x%x]", closest, addr); hash_keys = hashmap_keys(modules_get_list()); foreach(_key, hash_keys) { @@ -378,13 +378,13 @@ page_fault( module_data_t * m = (module_data_t *)hashmap_get(modules_get_list(), key); if ((r->eip >= (uintptr_t)m->bin_data) && (r->eip < m->end)) { - kprintf("\033[1;31mIn module:\033[0m %s (starts at 0x%x)\n", m->mod_info->name, m->bin_data); + debug_print(ERROR, "\033[1;31mIn module:\033[0m %s (starts at 0x%x)", m->mod_info->name, m->bin_data); break; } } } else { - kprintf("\033[1;31m(In userspace)\033[0m\n"); + debug_print(ERROR, "\033[1;31m(In userspace)\033[0m"); } #endif diff --git a/kernel/mem/shm.c b/kernel/mem/shm.c index 0b2df8bb..a8501917 100644 --- a/kernel/mem/shm.c +++ b/kernel/mem/shm.c @@ -102,7 +102,7 @@ static shm_chunk_t * create_chunk (shm_node_t * parent, size_t size) { set_frame(index * 0x1000); chunk->frames[i] = index; #if 0 - kprintf("Using frame #%d for chunk[%d] (name=%s)\n", index, i, parent->name); + debug_print(INFO, "Using frame #%d for chunk[%d] (name=%s)", index, i, parent->name); #endif } @@ -116,7 +116,7 @@ static int release_chunk (shm_chunk_t * chunk) { /* Does the chunk need to be freed? */ if (chunk->ref_count < 1) { #if 0 - kprintf("[shm] Freeing chunk with name %s\n", chunk->parent->name); + debug_print(INFO, "Freeing chunk with name %s", chunk->parent->name); #endif /* First, free the frames used by this chunk */ @@ -175,7 +175,7 @@ static void * map_in (shm_chunk_t * chunk, process_t * proc) { mapping->vaddrs[i] = new_vpage; #if 0 - kprintf("[kernel] [shm] mapping vaddr 0x%x --> #%d\n", new_vpage, page->frame); + debug_print(INFO, "mapping vaddr 0x%x --> #%d", new_vpage, page->frame); #endif } @@ -305,48 +305,3 @@ void shm_release_all (process_t * proc) { } -/* XXX: oh god don't use this */ - -#if 0 -void shm_debug_frame (uintptr_t vaddr) { - uintptr_t vframe = vaddr / 0x1000; - uintptr_t pframe, paddr; - - kprintf("[kernel] Inspecting user page 0x%x\n", vframe * 0x1000); - - uintptr_t table_index = vframe / 1024; - - if (!current_directory->tables[table_index]) { - kprintf("[kernel] Page does not exist!\n"); - return; - } else { - - // Where is the vaddr pointing to? - page_t * page = ¤t_directory->tables[table_index]->pages[vframe % 1024]; - pframe = page->frame; - paddr = pframe * 0x1000; - - kprintf("[kernel] Refers to physical frame #%d (present=%d rw=%d user=%d accessed=%d dirty=%d)\n", page->frame, page->present, page->rw, page->user, page->accessed, page->dirty); - -#if 0 - // Map the page into kernel memory. Oh god. - assert((heap_end % 0x1000 == 0) && "Kernel heap not page-aligned!"); - - uintptr_t address = heap_end; - heap_end += 0x1000; - page_t * kpage = get_page(address, 1, kernel_directory); - kpage->frame = pframe; - alloc_frame(kpage, 0, 1); -#endif - - // Read it out... -#if 0 - kprintf("[kernel] Data in frame: "); - for (int i = 0; i < 0x1000; i++) { - kprintf("%c", ((char *)vaddr)[i]); - } - kprintf("\n"); -#endif - } -} -#endif diff --git a/kernel/misc/elf.c b/kernel/misc/elf.c index 5dd56216..9ba93866 100644 --- a/kernel/misc/elf.c +++ b/kernel/misc/elf.c @@ -71,7 +71,7 @@ exec( header->e_ident[2] != ELFMAG2 || header->e_ident[3] != ELFMAG3) { /* What? This isn't an ELF... */ - kprintf("Fatal: Not a valid ELF executable.\n"); + debug_print(ERROR, "Not a valid ELF executable."); for (uintptr_t x = TMP_ZONE; x < TMP_ZONE + file->length; x += 0x1000) { free_frame(get_page(x, 0, current_directory)); } diff --git a/kernel/misc/multiboot.c b/kernel/misc/multiboot.c index dd1d6ee7..aeb725cf 100644 --- a/kernel/misc/multiboot.c +++ b/kernel/misc/multiboot.c @@ -3,6 +3,7 @@ * Multiboot (GRUB) handler */ #include +#include #include char * ramdisk = NULL; @@ -21,51 +22,50 @@ void dump_multiboot( struct multiboot *mboot_ptr ) { - kprintf("MULTIBOOT header at 0x%x:\n", (uintptr_t)mboot_ptr); - kprintf("Flags : 0x%x ", mboot_ptr->flags); - kprintf("Mem Lo: 0x%x ", mboot_ptr->mem_lower); - kprintf("Mem Hi: 0x%x ", mboot_ptr->mem_upper); - kprintf("Boot d: 0x%x\n", mboot_ptr->boot_device); - kprintf("cmdlin: 0x%x ", mboot_ptr->cmdline); - kprintf("Mods : 0x%x ", mboot_ptr->mods_count); - kprintf("Addr : 0x%x ", mboot_ptr->mods_addr); - kprintf("ELF n : 0x%x\n", mboot_ptr->num); - kprintf("ELF s : 0x%x ", mboot_ptr->size); - kprintf("ELF a : 0x%x ", mboot_ptr->addr); - kprintf("ELF h : 0x%x ", mboot_ptr->shndx); - kprintf("MMap : 0x%x\n", mboot_ptr->mmap_length); - kprintf("Addr : 0x%x ", mboot_ptr->mmap_addr); - kprintf("Drives: 0x%x ", mboot_ptr->drives_length); - kprintf("Addr : 0x%x ", mboot_ptr->drives_addr); - kprintf("Config: 0x%x\n", mboot_ptr->config_table); - kprintf("Loader: 0x%x ", mboot_ptr->boot_loader_name); - kprintf("APM : 0x%x ", mboot_ptr->apm_table); - kprintf("VBE Co: 0x%x ", mboot_ptr->vbe_control_info); - kprintf("VBE Mo: 0x%x\n", mboot_ptr->vbe_mode_info); - kprintf("VBE In: 0x%x ", mboot_ptr->vbe_mode); - kprintf("VBE se: 0x%x ", mboot_ptr->vbe_interface_seg); - kprintf("VBE of: 0x%x ", mboot_ptr->vbe_interface_off); - kprintf("VBE le: 0x%x\n", mboot_ptr->vbe_interface_len); + debug_print(INFO, "MULTIBOOT header at 0x%x:", (uintptr_t)mboot_ptr); + debug_print(INFO, "Flags : 0x%x", mboot_ptr->flags); + debug_print(INFO, "Mem Lo: 0x%x", mboot_ptr->mem_lower); + debug_print(INFO, "Mem Hi: 0x%x", mboot_ptr->mem_upper); + debug_print(INFO, "Boot d: 0x%x", mboot_ptr->boot_device); + debug_print(INFO, "cmdlin: 0x%x", mboot_ptr->cmdline); + debug_print(INFO, "Mods : 0x%x", mboot_ptr->mods_count); + debug_print(INFO, "Addr : 0x%x", mboot_ptr->mods_addr); + debug_print(INFO, "ELF n : 0x%x", mboot_ptr->num); + debug_print(INFO, "ELF s : 0x%x", mboot_ptr->size); + debug_print(INFO, "ELF a : 0x%x", mboot_ptr->addr); + debug_print(INFO, "ELF h : 0x%x", mboot_ptr->shndx); + debug_print(INFO, "MMap : 0x%x", mboot_ptr->mmap_length); + debug_print(INFO, "Addr : 0x%x", mboot_ptr->mmap_addr); + debug_print(INFO, "Drives: 0x%x", mboot_ptr->drives_length); + debug_print(INFO, "Addr : 0x%x", mboot_ptr->drives_addr); + debug_print(INFO, "Config: 0x%x", mboot_ptr->config_table); + debug_print(INFO, "Loader: 0x%x", mboot_ptr->boot_loader_name); + debug_print(INFO, "APM : 0x%x", mboot_ptr->apm_table); + debug_print(INFO, "VBE Co: 0x%x", mboot_ptr->vbe_control_info); + debug_print(INFO, "VBE Mo: 0x%x", mboot_ptr->vbe_mode_info); + debug_print(INFO, "VBE In: 0x%x", mboot_ptr->vbe_mode); + debug_print(INFO, "VBE se: 0x%x", mboot_ptr->vbe_interface_seg); + debug_print(INFO, "VBE of: 0x%x", mboot_ptr->vbe_interface_off); + debug_print(INFO, "VBE le: 0x%x", mboot_ptr->vbe_interface_len); if (mboot_ptr->flags & (1 << 2)) { - kprintf("Started with: %s\n", (char *)mboot_ptr->cmdline); + debug_print(INFO, "Started with: %s", (char *)mboot_ptr->cmdline); } if (mboot_ptr->flags & (1 << 9)) { - kprintf("Booted from: %s\n", (char *)mboot_ptr->boot_loader_name); + debug_print(INFO, "Booted from: %s", (char *)mboot_ptr->boot_loader_name); } if (mboot_ptr->flags & (1 << 0)) { - kprintf("%dkB lower memory\n", mboot_ptr->mem_lower); - kprintf("%dkB higher memory ", mboot_ptr->mem_upper); + debug_print(INFO, "%dkB lower memory", mboot_ptr->mem_lower); int mem_mb = mboot_ptr->mem_upper / 1024; - kprintf("(%dMB)\n", mem_mb); + debug_print(INFO, "%dkB higher memory (%dMB)", mboot_ptr->mem_upper, mem_mb); } if (mboot_ptr->flags & (1 << 3)) { - kprintf("Found %d module(s).\n", mboot_ptr->mods_count); + debug_print(INFO, "Found %d module(s).", mboot_ptr->mods_count); if (mboot_ptr->mods_count > 0) { uint32_t i; for (i = 0; i < mboot_ptr->mods_count; ++i ) { uint32_t module_start = *((uint32_t*)mboot_ptr->mods_addr + 8 * i); uint32_t module_end = *(uint32_t*)(mboot_ptr->mods_addr + 8 * i + 4); - kprintf("Module %d is at 0x%x:0x%x\n", i+1, module_start, module_end); + debug_print(INFO, "Module %d is at 0x%x:0x%x", i+1, module_start, module_end); } } } diff --git a/kernel/sys/panic.c b/kernel/sys/panic.c index b515b6c3..2f8fcac0 100644 --- a/kernel/sys/panic.c +++ b/kernel/sys/panic.c @@ -3,42 +3,37 @@ * Panic functions */ #include +#include -void kernel_halt(void) { - kprintf("\n System Halted!\n\n"); +void halt_and_catch_fire(char * error_message, const char * file, int line, struct regs * regs) { + IRQ_OFF; + debug_print(ERROR, "HACF: %s", error_message); + debug_print(ERROR, "Proc: %d", getpid()); + debug_print(ERROR, "File: %s", file); + debug_print(ERROR, "Line: %d", line); + if (regs) { + debug_print(ERROR, "Registers at interrupt:"); + debug_print(ERROR, "eax=0x%x ebx=0x%x", regs->eax, regs->ebx); + debug_print(ERROR, "ecx=0x%x edx=0x%x", regs->ecx, regs->edx); + debug_print(ERROR, "esp=0x%x ebp=0x%x", regs->esp, regs->ebp); + debug_print(ERROR, "Error code: 0x%x", regs->err_code); + debug_print(ERROR, "EFLAGS: 0x%x", regs->eflags); + debug_print(ERROR, "User ESP: 0x%x", regs->useresp); + debug_print(ERROR, "eip=0x%x", regs->eip); + } + debug_print(ERROR, "This process has been descheduled."); + kexit(1); +} + +void assert_failed(const char *file, uint32_t line, const char *desc) { + IRQ_OFF; + debug_print(INSANE, "Kernel Assertion Failed: %s", desc); + debug_print(INSANE, "File: %s", file); + debug_print(INSANE, "Line: %d", line); + debug_print(INSANE, "System Halted!"); while (1) { IRQ_OFF; PAUSE; } } - -void halt_and_catch_fire(char * error_message, const char * file, int line, struct regs * regs) { - IRQ_OFF; - kprintf("\033[1;37;44m"); - kprintf("HACF: %s\n", error_message); - kprintf("Proc: %d\n", getpid()); - kprintf("File: %s\n", file); - kprintf("Line: %d\n", line); - if (regs) { - kprintf("Registers at interrupt:\n"); - kprintf("eax=0x%x ebx=0x%x\n", regs->eax, regs->ebx); - kprintf("ecx=0x%x edx=0x%x\n", regs->ecx, regs->edx); - kprintf("esp=0x%x ebp=0x%x\n", regs->esp, regs->ebp); - kprintf("Error code: 0x%x\n", regs->err_code); - kprintf("EFLAGS: 0x%x\n", regs->eflags); - kprintf("User ESP: 0x%x\n", regs->useresp); - kprintf("eip=0x%x\n", regs->eip); - } - kprintf("This process has been descheduled.\n"); - kprintf("\033[0m"); - kexit(1); -} - -void assert_failed(const char *file, uint32_t line, const char *desc) { - IRQ_OFF; - kprintf("Kernel Assertion Failed: %s\n", desc); - kprintf("File: %s\n", file); - kprintf("Line: %d\n", line); - kernel_halt(); -} diff --git a/kernel/sys/signal.c b/kernel/sys/signal.c index dd36f0b4..469c3b48 100644 --- a/kernel/sys/signal.c +++ b/kernel/sys/signal.c @@ -30,7 +30,7 @@ void enter_signal_handler(uintptr_t location, int signum, uintptr_t stack) { "iret\n" : : "m"(location), "m"(signum), "r"(stack) : "%ax", "%esp", "%eax"); - kprintf("Failed to jump to signal handler!\n"); + debug_print(CRITICAL, "Failed to jump to signal handler!"); } static uint8_t volatile sig_lock; @@ -126,7 +126,7 @@ list_t * rets_from_sig; void return_from_signal_handler(void) { #if 0 - kprintf("[debug] Return From Signal for process %d\n", current_process->id); + debug_print(INFO, "Return From Signal for process %d", current_process->id); #endif if (__builtin_expect(!rets_from_sig, 0)) { diff --git a/kernel/sys/syscall.c b/kernel/sys/syscall.c index 30d68b2b..9684a9a7 100644 --- a/kernel/sys/syscall.c +++ b/kernel/sys/syscall.c @@ -612,24 +612,13 @@ static int system_function(int fn, char ** args) { /* System Functions are special debugging system calls */ if (current_process->user == USER_ROOT_UID) { switch (fn) { - case 1: - /* Print memory information */ - /* Future: /proc/meminfo */ - kprintf("Memory used: %d\n", memory_use()); - kprintf("Memory available: %d\n", memory_total()); - return 0; - case 2: - /* Print process tree */ - /* Future: /proc in general */ - debug_print_process_tree(); - return 0; case 3: debug_print(ERROR, "sync is currently unimplemented"); //ext2_disk_sync(); return 0; case 4: /* Request kernel output to file descriptor in arg0*/ - kprintf("Setting output to file object in process %d's fd=%d!\n", getpid(), (int)args); + debug_print(NOTICE, "Setting output to file object in process %d's fd=%d!", getpid(), (int)args); kprint_to_file = current_process->fds->entries[(int)args]; break; case 5: @@ -654,7 +643,7 @@ static int system_function(int fn, char ** args) { uint8_t * buffer = malloc(length); read_fs(file, 0, length, (uint8_t *)buffer); close_fs(file); - debug_print(WARNING, "Finished reading file, going to write it now.\n"); + debug_print(WARNING, "Finished reading file, going to write it now."); fs_node_t * f = kopen("/dev/sdb", 0); if (!f) { @@ -667,7 +656,7 @@ static int system_function(int fn, char ** args) { return 0; } default: - kprintf("Bad system function %d\n", fn); + debug_print(ERROR, "Bad system function %d", fn); break; } }