justin/jsix_import
1
0
Fork 0
Code Issues 1 Pull Requests Actions Packages Projects Releases Wiki Activity

Add logging framework

Browse Source
This commit is contained in:
Justin C. Miller
2018-04-28 19:18:53 -07:00
parent 358837ed69
commit b16abb94c2
10 changed files with 274 additions and 174 deletions
Download Patch File Download Diff File Expand all files Collapse all files

26
src/kernel/console.cpp
View File

@@ -1,4 +1,3 @@
#include <stdarg.h>
#include "console.h"
#include "io.h"
@@ -229,6 +228,9 @@ serial_write(char c) {
console::console() :
m_screen(nullptr)
{
const char *fgseq = "\x1b[2J";
while (*fgseq)
serial_write(*fgseq++);
}
void
@@ -236,6 +238,22 @@ console::set_color(uint8_t fg, uint8_t bg)
{
if (m_screen)
m_screen->set_color(fg, bg);
const char *fgseq = "\x1b[38;5;";
while (*fgseq)
serial_write(*fgseq++);
if (fg >= 100) serial_write('0' + (fg/100));
if (fg >= 10) serial_write('0' + (fg/10) % 10);
serial_write('0' + fg % 10);
serial_write('m');
const char *bgseq = "\x1b[48;5;";
while (*bgseq)
serial_write(*bgseq++);
if (bg >= 100) serial_write('0' + (bg/100));
if (bg >= 10) serial_write('0' + (bg/10) % 10);
serial_write('0' + bg % 10);
serial_write('m');
}
void
@@ -250,7 +268,7 @@ console::puts(const char *message)
}
}
void console::printf(const char *fmt, ...)
void console::vprintf(const char *fmt, va_list args)
{
static const unsigned buf_size = 256;
char buffer[256];
@@ -259,9 +277,6 @@ void console::printf(const char *fmt, ...)
char *w = buffer;
char *wend = buffer + buf_size;
va_list args;
va_start(args, fmt);
#define flush() do { *w = 0; puts(buffer); w = buffer; } while(0)
while (r && *r) {
@@ -330,5 +345,4 @@ void console::printf(const char *fmt, ...)
}
flush();
va_end(args);
}

13
src/kernel/console.h
View File

@@ -1,4 +1,5 @@
#pragma once
#include <stdarg.h>
#include "kutil/coord.h"
#include "font.h"
@@ -11,10 +12,18 @@ class console
public:
console();
void set_color(uint8_t fg, uint8_t bg);
void set_color(uint8_t fg = 7, uint8_t bg = 0);
void puts(const char *message);
void printf(const char *fmt, ...);
void vprintf(const char *fmt, va_list args);
inline void printf(const char *fmt, ...)
{
va_list args;
va_start(args, fmt);
vprintf(fmt, args);
va_end(args);
}
template <typename T>
void put_hex(T x, int width = 0);

38
src/kernel/device_manager.cpp
View File

@@ -5,7 +5,7 @@
#include "acpi_tables.h"
#include "assert.h"
#include "device_manager.h"
#include "console.h"
#include "log.h"
static const char expected_signature[] = "RSD PTR ";
@@ -78,12 +78,9 @@ device_manager::device_manager(const void *root_table) :
}
static void
put_sig(console *cons, uint32_t type)
put_sig(char *into, uint32_t type)
{
char sig[5] = {0,0,0,0,0};
for (int j=0; j<4; ++j)
sig[j] = reinterpret_cast<char *>(&type)[j];
cons->puts(sig);
for (int j=0; j<4; ++j) into[j] = reinterpret_cast<char *>(&type)[j];
}
void
@@ -91,16 +88,18 @@ device_manager::load_xsdt(const acpi_xsdt *xsdt)
{
kassert(xsdt && acpi_validate(xsdt), "Invalid ACPI XSDT.");
console *cons = console::get();
cons->puts("ACPI 2.0 tables loading: ");
put_sig(cons, xsdt->header.type);
char sig[5] = {0,0,0,0,0};
log::info(logs::devices, "ACPI 2.0 tables loading:");
put_sig(sig, xsdt->header.type);
log::info(logs::devices, " Found table %s", sig);
size_t num_tables = acpi_table_entries(xsdt, sizeof(void*));
for (size_t i = 0; i < num_tables; ++i) {
const acpi_table_header *header = xsdt->headers[i];
cons->puts(" ");
put_sig(cons, header->type);
put_sig(sig, header->type);
log::info(logs::devices, " Found table %s", sig);
kassert(header->validate(), "Table failed validation.");
@@ -113,19 +112,13 @@ device_manager::load_xsdt(const acpi_xsdt *xsdt)
break;
}
}
cons->puts("\n");
}
void
device_manager::load_apic(const acpi_apic *apic)
{
console *cons = console::get();
m_local_apic = reinterpret_cast<uint32_t *>(apic->local_address);
cons->puts(" ");
cons->put_hex(apic->local_address);
log::info(logs::devices, " APIC local address %lx", apic->local_address);
uint8_t const *p = apic->controller_data;
uint8_t const *end = p + acpi_table_entries(apic, 1);
@@ -134,8 +127,7 @@ device_manager::load_apic(const acpi_apic *apic)
const uint8_t type = p[0];
const uint8_t length = p[1];
cons->puts(" ");
cons->put_hex(type);
log::debug(logs::devices, " APIC entry type %d", type);
switch (type) {
case 0: // Local APIC
@@ -144,10 +136,8 @@ device_manager::load_apic(const acpi_apic *apic)
case 1: // I/O APIC
m_io_apic = reinterpret_cast<uint32_t *>(kutil::read_from<uint32_t>(p+4));
m_global_interrupt_base = kutil::read_from<uint32_t>(p+8);
cons->puts(" ");
cons->put_hex((uint64_t)m_io_apic);
cons->puts(" ");
cons->put_hex(m_global_interrupt_base);
log::info(logs::devices, " IO APIC address %lx base %d",
m_io_apic, m_global_interrupt_base);
break;
}

147
src/kernel/interrupts.cpp
View File

@@ -4,6 +4,7 @@
#include "kutil/memory.h"
#include "console.h"
#include "interrupts.h"
#include "log.h"
enum class gdt_flags : uint8_t
{
@@ -141,6 +142,9 @@ interrupts_init()
#undef ISR
idt_write();
log::info(logs::interrupt, "Interrupts enabled.");
gdt_dump(g_gdtr);
idt_dump(g_idtr);
}
struct registers
@@ -151,17 +155,16 @@ struct registers
uint64_t rip, cs, eflags, user_esp, ss;
};
#define print_reg(name, value) \
cons->puts(" " name ": "); \
cons->put_hex((value)); \
cons->puts("\n");
#define print_reg(name, value) cons->printf(" %s: %lx\n", name, (value));
void
isr_handler(registers regs)
{
console *cons = console::get();
cons->puts("received ISR interrupt:\n");
cons->set_color(9);
cons->puts("\nReceived ISR interrupt:\n");
cons->set_color();
uint64_t cr2 = 0;
__asm__ __volatile__ ("mov %%cr2, %0" : "=r"(cr2));
@@ -169,7 +172,7 @@ isr_handler(registers regs)
print_reg("ISR", regs.interrupt);
print_reg("ERR", regs.errorcode);
print_reg("CR2", cr2);
console::get()->puts("\n");
cons->puts("\n");
print_reg(" ds", regs.ds);
print_reg("rdi", regs.rdi);
@@ -180,7 +183,7 @@ isr_handler(registers regs)
print_reg("rdx", regs.rdx);
print_reg("rcx", regs.rcx);
print_reg("rax", regs.rax);
console::get()->puts("\n");
cons->puts("\n");
print_reg("rip", regs.rip);
print_reg(" cs", regs.cs);
@@ -195,11 +198,13 @@ irq_handler(registers regs)
{
console *cons = console::get();
cons->puts("received IRQ interrupt:\n");
cons->set_color(9);
cons->puts("\nReceived IRQ interrupt:\n");
cons->set_color();
print_reg("ISR", regs.interrupt);
print_reg("ERR", regs.errorcode);
console::get()->puts("\n");
cons->puts("\n");
print_reg(" ds", regs.ds);
print_reg("rdi", regs.rdi);
@@ -210,7 +215,7 @@ irq_handler(registers regs)
print_reg("rdx", regs.rdx);
print_reg("rcx", regs.rcx);
print_reg("rax", regs.rax);
console::get()->puts("\n");
cons->puts("\n");
print_reg("rip", regs.rip);
print_reg(" cs", regs.cs);
@@ -224,17 +229,12 @@ irq_handler(registers regs)
void
gdt_dump(const table_ptr &table)
{
console *cons = console::get();
cons->puts("Loaded GDT at: ");
cons->put_hex(table.base);
cons->puts(" size: ");
cons->put_dec(table.limit + 1);
cons->puts(" bytes\n");
log::info(logs::interrupt, "Loaded GDT at: %lx size: %d bytes", table.base, table.limit+1);
int count = (table.limit + 1) / sizeof(gdt_descriptor);
const gdt_descriptor *gdt =
reinterpret_cast<const gdt_descriptor *>(table.base);
for (int i = 0; i < count; ++i) {
uint32_t base =
(gdt[i].base_high << 24) |
@@ -245,113 +245,58 @@ gdt_dump(const table_ptr &table)
static_cast<uint32_t>(gdt[i].granularity & 0x0f) << 16 |
gdt[i].limit_low;
cons->puts(" Entry ");
cons->put_dec(i);
cons->puts(": Base ");
cons->put_hex(base);
cons->puts(" Limit ");
cons->put_hex(limit);
cons->puts(" Privs ");
cons->put_dec((gdt[i].flags >> 5) & 0x03);
cons->puts(" Flags ");
if (gdt[i].flags & 0x80) {
cons->puts("P ");
log::debug(logs::interrupt,
" Entry %3d: Base %x limit %x privs %d flags %s%s%s%s%s%s",
i, base, limit, ((gdt[i].flags >> 5) & 0x03),
if (gdt[i].flags & 0x08)
cons->puts("EX ");
else
cons->puts(" ");
(gdt[i].flags & 0x80) ? "P " : " ",
(gdt[i].flags & 0x08) ? "ex " : " ",
(gdt[i].flags & 0x04) ? "dc " : " ",
(gdt[i].flags & 0x02) ? "rw " : " ",
if (gdt[i].flags & 0x04)
cons->puts("DC ");
else
cons->puts(" ");
if (gdt[i].flags & 0x02)
cons->puts("RW ");
else
cons->puts(" ");
if (gdt[i].granularity & 0x80)
cons->puts("KB ");
else
cons->puts(" B ");
if ((gdt[i].granularity & 0x60) == 0x20)
cons->puts("64");
else if ((gdt[i].granularity & 0x60) == 0x40)
cons->puts("32");
else
cons->puts("16");
(gdt[i].granularity & 0x80) ? "kb " : "b ",
(gdt[i].granularity & 0x60) == 0x60 ? "64" :
(gdt[i].granularity & 0x60) == 0x40 ? "32" : "16"
);
}
cons->puts("\n");
}
}
void
idt_dump(const table_ptr &table)
{
console *cons = console::get();
cons->puts("Loaded IDT at: ");
cons->put_hex(table.base);
cons->puts(" size: ");
cons->put_dec(table.limit + 1);
cons->puts(" bytes\n");
log::info(logs::interrupt, "Loaded IDT at: %lx size: %d bytes", table.base, table.limit+1);
int count = (table.limit + 1) / sizeof(idt_descriptor);
const idt_descriptor *idt =
reinterpret_cast<const idt_descriptor *>(table.base);
if (count > 32) count = 32;
for (int i = 0; i < count; ++i) {
uint64_t base =
(static_cast<uint64_t>(idt[i].base_high) << 32) |
(static_cast<uint64_t>(idt[i].base_mid) << 16) |
idt[i].base_low;
cons->puts(" Entry ");
cons->put_dec(i);
cons->puts(": Base ");
cons->put_hex(base);
cons->puts(" Sel(");
cons->put_dec(idt[i].selector & 0x3);
cons->puts(",");
cons->put_dec((idt[i].selector & 0x4) >> 2);
cons->puts(",");
cons->put_dec(idt[i].selector >> 3);
cons->puts(") ");
cons->puts("IST ");
cons->put_dec(idt[i].ist);
char const *type;
switch (idt[i].flags & 0xf) {
case 0x5: cons->puts(" 32tsk "); break;
case 0x6: cons->puts(" 16int "); break;
case 0x7: cons->puts(" 16trp "); break;
case 0xe: cons->puts(" 32int "); break;
case 0xf: cons->puts(" 32trp "); break;
default:
cons->puts(" ?");
cons->put_hex(idt[i].flags & 0xf);
cons->puts(" ");
break;
case 0x5: type = " 32tsk "; break;
case 0x6: type = " 16int "; break;
case 0x7: type = " 16trp "; break;
case 0xe: type = " 32int "; break;
case 0xf: type = " 32trp "; break;
default: type = " ????? "; break;
}
cons->puts("DPL ");
cons->put_dec((idt[i].flags >> 5) & 0x3);
if (idt[i].flags & 0x80)
cons->puts(" P");
cons->puts("\n");
if (idt[i].flags & 0x80) {
log::debug(logs::interrupt,
" Entry %3d: Base:%lx Sel(rpl %d, ti %d, %3d) IST:%d %s DPL:%d", i, base,
(idt[i].selector & 0x3),
((idt[i].selector & 0x4) >> 2),
(idt[i].selector >> 3),
idt[i].ist,
type,
((idt[i].flags >> 5) & 0x3));
}
}
}

103
src/kernel/log.cpp Normal file
View File

@@ -0,0 +1,103 @@
#include <type_traits>
#include "kutil/memory.h"
#include "console.h"
#include "log.h"
static const uint64_t default_enabled[] = {0x09, 0x0f, 0x0f, 0x0f};
static const uint8_t level_colors[] = {0x07, 0x0f, 0x0b, 0x09};
static const char *levels[] = {"debug", " info", " warn", "error", "fatal"};
static const char *areas[] = {
"boot",
"mem ",
"intr",
"dev ",
nullptr
};
log log::s_log;
log::log() :
m_cons(nullptr)
{
for (int i = 0; i < sizeof(m_enabled) / sizeof(uint64_t); ++i)
m_enabled[i] = default_enabled[i];
}
log::log(console *cons) :
m_cons(cons)
{
for (int i = 0; i < sizeof(m_enabled) / sizeof(uint64_t); ++i)
m_enabled[i] = default_enabled[i];
}
void
log::init(console *cons)
{
new (&s_log) log(cons);
log::info(logs::boot, "Logging system initialized.");
}
static inline uint64_t
bit_mask(logs area) { return 1 << static_cast<uint64_t>(area); }
void
log::enable(logs type, level at_level)
{
using under_t = std::underlying_type<level>::type;
under_t at = static_cast<under_t>(at_level);
under_t max = sizeof(m_enabled) / sizeof(under_t);
for (under_t i = 0; i < max; ++i) {
if (i <= at)
s_log.m_enabled[i] |= bit_mask(type);
else
s_log.m_enabled[i] &= ~bit_mask(type);
}
}
template <>
void
log::trylog<log::level::fatal>(logs area, const char *fmt, ...)
{
va_list args;
va_start(args, fmt);
s_log.output(level::fatal, area, fmt, args);
va_end(args);
while(1) __asm__ ("hlt");
}
template <log::level L>
void
log::trylog(logs area, const char *fmt, ...)
{
auto i = static_cast<std::underlying_type<level>::type>(L);
if ((s_log.m_enabled[i] & bit_mask(area)) == 0) return;
va_list args;
va_start(args, fmt);
s_log.output(L, area, fmt, args);
va_end(args);
}
void
log::output(level severity, logs area, const char *fmt, va_list args)
{
m_cons->set_color(level_colors[static_cast<int>(severity)]);
m_cons->printf("%s %s: ",
areas[static_cast<int>(area)],
levels[static_cast<int>(severity)]);
m_cons->vprintf(fmt, args);
m_cons->set_color();
m_cons->puts("\n");
}
const log::trylog_p log::debug = &trylog<level::debug>;
const log::trylog_p log::info = &trylog<level::info>;
const log::trylog_p log::warn = &trylog<level::warn>;
const log::trylog_p log::error = &trylog<level::error>;
const log::trylog_p log::fatal = &trylog<level::fatal>;

48
src/kernel/log.h Normal file
View File

@@ -0,0 +1,48 @@
#pragma once
#include <stdarg.h>
#include <stdint.h>
class console;
enum class logs
{
boot,
memory,
interrupt,
devices,
max
};
class log
{
public:
enum class level {debug, info, warn, error, fatal, max};
static void init(console *cons);
static void enable(logs type, level at_level);
template <level L>
static void trylog(logs area, const char *fmt, ...);
using trylog_p = void (*)(logs area, const char *fmt, ...);
static const trylog_p debug;
static const trylog_p info;
static const trylog_p warn;
static const trylog_p error;
static const trylog_p fatal;
private:
void output(level severity, logs area, const char *fmt, va_list args);
/// Bitmasks for what categories are enabled. fatal is
/// always enabled, so leave it out.
uint64_t m_enabled[static_cast<uint64_t>(level::max) - 1];
console *m_cons;
log();
log(console *cons);
static log s_log;
};

16
src/kernel/main.cpp
View File

@@ -7,6 +7,7 @@
#include "font.h"
#include "interrupts.h"
#include "kernel_data.h"
#include "log.h"
#include "memory.h"
#include "memory_pages.h"
#include "screen.h"
@@ -32,11 +33,6 @@ load_console(const popcorn_data *header)
header->log,
header->log_length};
cons.set_color(0x21, 0x00);
cons.puts("Popcorn OS ");
cons.set_color(0x08, 0x00);
cons.puts(GIT_VERSION " booting...\n");
return cons;
}
*/
@@ -45,6 +41,12 @@ void
kernel_main(popcorn_data *header)
{
console *cons = new (&g_console) console();
cons->set_color(0x21, 0x00);
cons->puts("Popcorn OS ");
cons->set_color(0x08, 0x00);
cons->puts(GIT_VERSION " booting...\n");
log::init(cons);
page_manager *pager = new (&g_page_manager) page_manager;
pager->mark_offset_pointer(&header->frame_buffer, header->frame_buffer_length);
@@ -56,13 +58,11 @@ kernel_main(popcorn_data *header)
size_t n = 5000;
void *p = kalloc(n);
g_console.printf("kalloc'd %d bytes at %lx\n", n, p);
log::info(logs::memory, "kalloc'd %d bytes at %lx", n, p);
interrupts_init();
interrupts_enable();
g_console.puts("Interrupts initialized.\n");
device_manager devices(header->acpi_table);
// int x = 1 / 0;

1
src/kernel/memory.cpp
View File

@@ -1,5 +1,4 @@
#include "assert.h"
#include "console.h"
#include "memory.h"
#include "memory_pages.h"

6
src/kernel/memory_bootstrap.cpp
View File

@@ -1,6 +1,5 @@
#include "kutil/memory.h"
#include "assert.h"
#include "console.h"
#include "memory.h"
#include "memory_pages.h"
@@ -410,8 +409,6 @@ page_in_ident(
void
memory_initialize_managers(const void *memory_map, size_t map_length, size_t desc_length)
{
console *cons = console::get();
// The bootloader reserved 16 pages for page tables, which we'll use to bootstrap.
// The first one is the already-installed PML4, so grab it from CR3.
uint64_t cr3;
@@ -525,9 +522,6 @@ memory_initialize_managers(const void *memory_map, size_t map_length, size_t des
pm->page_in(pml4, cur->physical_address, cur->virtual_address, cur->count);
}
page_block::dump(used_head, "used", true);
page_block::dump(free_head, "free", true);
// Put our new PML4 into CR3 to start using it
page_manager::set_pml4(pml4);

52
src/kernel/memory_pages.cpp
View File

@@ -1,7 +1,7 @@
#include <algorithm>
#include "assert.h"
#include "console.h"
#include "log.h"
#include "memory.h"
#include "memory_pages.h"
@@ -119,8 +119,7 @@ page_block::consolidate(page_block *list)
void
page_block::dump(page_block *list, const char *name, bool show_unmapped)
{
console *cons = console::get();
cons->printf("Block list %s:\n", name);
log::debug(logs::memory, "Block list %s:", name);
int count = 0;
for (page_block *cur = list; cur; cur = cur->next) {
@@ -128,25 +127,24 @@ page_block::dump(page_block *list, const char *name, bool show_unmapped)
if (!(show_unmapped || cur->has_flag(page_block_flags::mapped)))
continue;
cons->printf(" %lx %x [%6d]",
if (cur->virtual_address) {
page_table_indices start{cur->virtual_address};
log::debug(logs::memory, " %lx %x [%6d] %lx (%d,%d,%d,%d)",
cur->physical_address,
cur->flags,
cur->count,
cur->virtual_address,
start[0], start[1], start[2], start[3]);
} else {
page_table_indices start{cur->virtual_address};
log::debug(logs::memory, " %lx %x [%6d]",
cur->physical_address,
cur->flags,
cur->count);
if (cur->virtual_address) {
page_table_indices start{cur->virtual_address};
page_table_indices end{cur->virtual_address + cur->count * page_manager::page_size - 1};
cons->printf(" %lx (%d,%d,%d,%d)-(%d,%d,%d,%d)",
cur->virtual_address,
start[0], start[1], start[2], start[3],
end[0], end[1], end[2], end[3]);
}
}
cons->printf("\n");
}
cons->printf(" Total: %d\n", count);
log::debug(logs::memory, " Total: %d", count);
}
void
@@ -213,7 +211,7 @@ page_manager::init(
page_block_flags::mapped |
page_block_flags::mmio;
console::get()->printf("Fixing up pointer %lx [%3d] -> %lx\n", *p, c, v);
log::info(logs::memory, "Fixing up pointer %lx [%3d] -> %lx", *p, c, v);
m_used = page_block::insert(m_used, block);
page_in(pml4, *p, v, c);
@@ -301,7 +299,7 @@ page_manager::get_table_page()
}
reinterpret_cast<free_page_header *>(virt)->next = nullptr;
g_console.printf("Mappd %d new page table pages at %lx\n", n, phys);
log::info(logs::memory, "Mappd %d new page table pages at %lx", n, phys);
}
free_page_header *page = m_page_cache;
@@ -515,29 +513,29 @@ page_manager::pop_pages(size_t count, addr_t *address)
void
page_table::dump(int level, uint64_t offset)
{
console *cons = console::get();
cons->printf("Level %d page table @ %lx (off %lx):\n", level, this, offset);
log::info(logs::memory, "Level %d page table @ %lx (off %lx):", level, this, offset);
for (int i=0; i<512; ++i) {
uint64_t ent = entries[i];
if (ent == 0) continue;
cons->printf(" %3d: %lx ", i, ent);
if (ent & 0x1 == 0) {
cons->printf(" NOT PRESENT\n");
log::info(logs::memory, " %3d: %lx NOT PRESENT", i, ent);
continue;
}
if ((level == 2 || level == 3) && (ent & 0x80) == 0x80) {
cons->printf(" -> Large page at %lx\n", ent & ~0xfffull);
log::info(logs::memory, " %3d: %lx -> Large page at %lx",
i, ent, ent & ~0xfffull);
continue;
} else if (level == 1) {
cons->printf(" -> Page at %lx\n", (ent & ~0xfffull));
log::info(logs::memory, " %3d: %lx -> Page at %lx",
i, ent, ent & ~0xfffull);
} else {
cons->printf(" -> Level %d table at %lx\n", level - 1, (ent & ~0xfffull) + offset);
log::info(logs::memory, " %3d: %lx -> Level %d table at %lx",
i, ent, level - 1, (ent & ~0xfffull) + offset);
continue;
}
}
cons->printf("\n");
if (--level > 0) {
for (int i=0; i<512; ++i) {