From b3e49590a73e6facbfe1736addbb9f241340c642 Mon Sep 17 00:00:00 2001
From: "Justin C. Miller" <justin@devjustinian.com>
Date: Sat, 28 Apr 2018 19:18:53 -0700
Subject: [PATCH] Add logging framework

---
 src/kernel/console.cpp          |  26 ++++--
 src/kernel/console.h            |  13 ++-
 src/kernel/device_manager.cpp   |  38 +++------
 src/kernel/interrupts.cpp       | 147 ++++++++++----------------------
 src/kernel/log.cpp              | 103 ++++++++++++++++++++++
 src/kernel/log.h                |  48 +++++++++++
 src/kernel/main.cpp             |  16 ++--
 src/kernel/memory.cpp           |   1 -
 src/kernel/memory_bootstrap.cpp |   6 --
 src/kernel/memory_pages.cpp     |  50 ++++++-----
 10 files changed, 274 insertions(+), 174 deletions(-)
 create mode 100644 src/kernel/log.cpp
 create mode 100644 src/kernel/log.h

diff --git a/src/kernel/console.cpp b/src/kernel/console.cpp
index e2622df..039374b 100644
--- a/src/kernel/console.cpp
+++ b/src/kernel/console.cpp
@@ -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);
 }
diff --git a/src/kernel/console.h b/src/kernel/console.h
index 4dccd57..945fb6a 100644
--- a/src/kernel/console.h
+++ b/src/kernel/console.h
@@ -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);
diff --git a/src/kernel/device_manager.cpp b/src/kernel/device_manager.cpp
index 6bf55e9..46e1523 100644
--- a/src/kernel/device_manager.cpp
+++ b/src/kernel/device_manager.cpp
@@ -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;
 		}
 
diff --git a/src/kernel/interrupts.cpp b/src/kernel/interrupts.cpp
index 6de596a..05487e9 100644
--- a/src/kernel/interrupts.cpp
+++ b/src/kernel/interrupts.cpp
@@ -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));
+		}
 	}
 }
diff --git a/src/kernel/log.cpp b/src/kernel/log.cpp
new file mode 100644
index 0000000..39e91ef
--- /dev/null
+++ b/src/kernel/log.cpp
@@ -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>;
diff --git a/src/kernel/log.h b/src/kernel/log.h
new file mode 100644
index 0000000..a94a9de
--- /dev/null
+++ b/src/kernel/log.h
@@ -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;
+};
diff --git a/src/kernel/main.cpp b/src/kernel/main.cpp
index 44d8669..45462e8 100644
--- a/src/kernel/main.cpp
+++ b/src/kernel/main.cpp
@@ -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;
diff --git a/src/kernel/memory.cpp b/src/kernel/memory.cpp
index 6ef373c..656dcdb 100644
--- a/src/kernel/memory.cpp
+++ b/src/kernel/memory.cpp
@@ -1,5 +1,4 @@
 #include "assert.h"
-#include "console.h"
 #include "memory.h"
 #include "memory_pages.h"
 
diff --git a/src/kernel/memory_bootstrap.cpp b/src/kernel/memory_bootstrap.cpp
index 93ef5f4..077a9dc 100644
--- a/src/kernel/memory_bootstrap.cpp
+++ b/src/kernel/memory_bootstrap.cpp
@@ -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);
 
diff --git a/src/kernel/memory_pages.cpp b/src/kernel/memory_pages.cpp
index 00e19ff..a2680c2 100644
--- a/src/kernel/memory_pages.cpp
+++ b/src/kernel/memory_pages.cpp
@@ -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]",
-				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)",
+			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],
-					end[0], end[1], end[2], end[3]);
+					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);
 		}
-
-		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) {