//! The kernel's multi-sink **diagnostic** log — the machine-readable stream of //! what the kernel is doing, separate from any user-facing display. //! //! Output is a *diagnostic convenience, never a correctness dependency* — the //! kernel must boot and run correctly with zero output channels. So logging fans //! out to a set of registered **sinks**, each best-effort and self-guarding: the //! serial UART and the 0xE9 debug console. A message reaches whatever channels //! exist; if none do, the kernel runs on, silent but correct. //! //! Retention is the tagged RING (log-ring.zig): every emission becomes one //! record per line, stamped with the sender's pid, task name (its binary path), //! level, sequence number, and monotonic timestamp — attribution is structural, //! stamped by the kernel, not a naming convention a process could forge. The //! stamping is per LINE: an embedded '\n' ends the record, so a payload cannot //! imitate another sender on the line that follows. Oldest records are //! overwritten when the ring is full; sequence gaps make the loss countable. //! `klog_read`/`klog_status` expose the stream to userspace (the logger service //! drains it into per-process files once storage is up). //! //! Locking: a dedicated log spinlock, NOT the big kernel lock. `print` is //! called both inside and outside BKL sections (and from ISRs), so the log //! lock is taken with interrupts off and nothing inside it ever takes the BKL — //! lock order is strictly BKL -> log lock, never the reverse. Panic paths use a //! bounded try-acquire and fall back to sinks-only: a panic must never deadlock //! on its own diagnostics. //! //! The **framebuffer is deliberately not a sink here.** It's a separate output //! surface (a bootstrap text console today, a graphics device driver later), so //! the log never assumes the machine is text-based. Two channels bypass the //! sink list because they must survive even a total-output failure: //! `checkpoint` (a one-byte POST code) and `recordPanic` (a fixed breadcrumb). const std = @import("std"); const architecture = @import("architecture"); const abi = @import("abi"); const log_ring = @import("log-ring.zig"); const wall_clock = @import("wall-clock.zig"); pub const SinkFn = *const fn ([]const u8) void; const maximum_sinks = 8; var sinks: [maximum_sinks]SinkFn = undefined; var sink_count: usize = 0; /// Register an output sink. Every registered sink receives every message; sinks /// must be self-guarding (safe to call when their device is absent). pub fn addSink(sink: SinkFn) void { if (sink_count < maximum_sinks) { sinks[sink_count] = sink; sink_count += 1; } } // --- the log lock ------------------------------------------------------------ var lock_held = std.atomic.Value(u32).init(0); fn lockAcquire() u64 { const flags = architecture.saveInterrupts(); while (lock_held.cmpxchgWeak(0, 1, .acquire, .monotonic) != null) std.atomic.spinLoopHint(); return flags; } fn lockTryAcquire(spins: usize) ?u64 { const flags = architecture.saveInterrupts(); var i: usize = 0; while (i < spins) : (i += 1) { if (lock_held.cmpxchgWeak(0, 1, .acquire, .monotonic) == null) return flags; std.atomic.spinLoopHint(); } architecture.restoreInterrupts(flags); return null; } fn lockRelease(flags: u64) void { lock_held.store(0, .release); architecture.restoreInterrupts(flags); } // --- the ring + renderer ----------------------------------------------------- /// 512 KiB: the tagged frames cost ~30% over the raw text, and the ring only /// needs to cover the pre-mount backlog (a boot is ~15 KiB of text) — the /// logger service tails it continuously once storage is up. const ring_capacity = 512 * 1024; var ring: log_ring.Ring(ring_capacity) = .{}; /// Renderer state: whether the sinks sit at a line start, and which pid's line /// is currently open — when a different sender interleaves mid-line, the /// renderer closes the line so serial output can't visually merge two senders. var at_line_start: bool = true; var open_line_pid: u32 = 0; /// Append `bytes` as one tagged record per line and render them to the sinks. /// The core emission path: `debug_write` calls this with the sender's identity; /// kernel-internal `write`/`print` funnel here as pid 0 ("kernel", raw). pub fn append(pid: u32, name: []const u8, level: abi.KlogLevel, bytes: []const u8) void { if (bytes.len == 0) return; const now = architecture.nanos(); const flags = lockAcquire(); defer lockRelease(flags); appendLocked(pid, name, level, now, bytes); } /// The panic-safe variant: bounded lock wait; on failure, sinks only — the ring /// entry is lost but the message still reaches serial, and the panic cannot /// deadlock on a core that died holding the log lock. pub fn appendPanic(bytes: []const u8) void { if (lockTryAcquire(100_000)) |flags| { defer lockRelease(flags); appendLocked(0, "kernel", .raw, architecture.nanos(), bytes); } else { for (sinks[0..sink_count]) |sink| sink(bytes); } } fn appendLocked(pid: u32, name: []const u8, level: abi.KlogLevel, now: u64, bytes: []const u8) void { var rest = bytes; while (rest.len != 0) { const newline = std.mem.indexOfScalar(u8, rest, '\n'); // The record payload excludes the newline: a record IS a line. Raw // emissions may leave a line open (kernel boot tables build lines from // pieces); a LEVELED record is a complete line by contract — std.log // payloads carry no trailing newline. const line = if (newline) |i| rest[0..i] else rest; const line_complete = newline != null or level != .raw; if (line.len != 0 or line_complete) _ = ring.append(pid, name, level, now, line, line.len > abi.klog_maximum_message); render(pid, name, level, now, line, line_complete); rest = if (newline) |i| rest[i + 1 ..] else rest[rest.len..]; } } /// Serial/debugcon rendering. Kernel output and legacy raw user output pass /// through byte-identical to the historical stream (services still write their /// own "name: " prefixes until the std.log migration). Leveled (std.log) /// records get a kernel-rendered ": " prefix at line start — err/warn/ /// debug also get their level spelled out. fn render(pid: u32, name: []const u8, level: abi.KlogLevel, now: u64, line: []const u8, line_complete: bool) void { if (sink_count == 0) return; if (line.len == 0 and !line_complete) return; // Compose the whole rendered piece first and emit it in ONE sink call per // sink: fewer, larger UART writes, and no partial-line window should any // path ever reach a sink without the log lock. var buffer: [render_buffer_size]u8 = undefined; var used: usize = 0; if (!at_line_start and open_line_pid != pid) { buffer[used] = '\n'; used += 1; at_line_start = true; } if (at_line_start) { // Every line starts with its boot-relative time: the live transcript // (serial AND the on-screen boot console) is a readable timeline — // which is how a slow real-hardware boot gets diagnosed by eye. const seconds = now / 1_000_000_000; const millis = (now / 1_000_000) % 1000; used += (std.fmt.bufPrint(buffer[used..], "[{d:>4}.{d:0>3}] ", .{ seconds, millis }) catch buffer[used..used]).len; } if (at_line_start and level != .raw) { used += place(buffer[used..], name); used += place(buffer[used..], ": "); used += place(buffer[used..], switch (level) { .err => "error: ", .warn => "warning: ", .debug => "debug: ", .info, .raw => "", }); } used += place(buffer[used..], line); if (line_complete and used < buffer.len) { buffer[used] = '\n'; used += 1; } fanOut(buffer[0..used]); at_line_start = line_complete; open_line_pid = pid; } /// newline + timestamp + name + ": warning: " + a full payload line + newline. const render_buffer_size = 1 + 16 + abi.maximum_process_name + 11 + abi.klog_maximum_message + 1; fn place(destination: []u8, bytes: []const u8) usize { const n = @min(destination.len, bytes.len); @memcpy(destination[0..n], bytes[0..n]); return n; } fn fanOut(bytes: []const u8) void { for (sinks[0..sink_count]) |sink| sink(bytes); } /// Kernel-internal write — a raw record from "kernel" (pid 0). The signature is /// unchanged so every existing kernel call site stays as it is. pub fn write(bytes: []const u8) void { append(0, "kernel", .raw, bytes); } /// A formatted log line. Truncates past 256 bytes; the buffer is on the stack, so /// this is safe to call from interrupt context and from a panic. pub fn print(comptime fmt: []const u8, args: anytype) void { var buffer: [256]u8 = undefined; write(std.fmt.bufPrint(&buffer, fmt, args) catch return); } /// klog_read: copy ring stream bytes from `offset` into `out`. Null when the /// cursor was overwritten or lies past the end — the reader re-syncs via /// status(). Zero bytes means caught up. pub fn readAt(offset: u64, out: []u8) ?usize { const flags = lockAcquire(); defer lockRelease(flags); return ring.read(offset, out); } /// klog_status: the ring cursors plus the boot wall-clock anchor. pub fn status() abi.KlogStatus { const flags = lockAcquire(); defer lockRelease(flags); var s = ring.status(); s.boot_unix_seconds = wall_clock.bootSeconds(); return s; } /// Emit a one-byte checkpoint/POST code (I/O port 0x80) — the always-available /// progress channel for when there is no text output at all. Independent of the /// sink list, so it works even before any sink is registered. pub fn checkpoint(code: u8) void { architecture.checkpoint(code); } // --- persistent panic breadcrumb ------------------------------------------- // // A fixed record in the kernel image that a panic fills in, so a post-mortem — an // attached debugger, a RAM dump, or (later) a file/pstore reader — can recover // what killed the kernel even when there was no live console. `magic` is written // *last*, so a reader only trusts a fully-written record. pub const panic_magic: u64 = 0xD1ED_B00B_5EED_F00D; pub const PanicRecord = extern struct { magic: u64 = 0, len: u32 = 0, _pad: u32 = 0, message: [512]u8 = undefined, }; /// Findable by symbol (`log.panic_record`) for a debugger or RAM dump. pub var panic_record: PanicRecord = .{}; /// Stamp the panic message into the breadcrumb record. pub fn recordPanic(message: []const u8) void { const n: u32 = @intCast(@min(message.len, panic_record.message.len)); @memcpy(panic_record.message[0..n], message[0..n]); panic_record.len = n; panic_record.magic = panic_magic; // set last: a reader sees a complete record }