diff --git a/system/kernel/kernel.zig b/system/kernel/kernel.zig index 4806f7c..6bfa459 100644 --- a/system/kernel/kernel.zig +++ b/system/kernel/kernel.zig @@ -162,6 +162,13 @@ fn kmain(boot_information: *const BootInformation) noreturn { // uncached crawl). Routine boot output goes only to the log; this console now exists for // early-boot and fatal (`fatal`/panic) output, until the display service takes over. console.init(fb); + // The console joins the log sinks: the boot transcript — kernel AND + // userspace lines, each timestamped by the renderer — shows on screen + // until the display service claims the framebuffer (which flips the + // console's `suppressed` and silences this sink). On a machine with no + // serial this is the only live view of the boot, and a slow boot becomes + // diagnosable by eye: the timeline is right there. + if (console.present()) log.addSink(console.write); log.write(if (console.present()) "/system/kernel: framebuffer ready (early-boot + fatal fallback; the display service drives it in normal operation)\n" else diff --git a/system/kernel/log.zig b/system/kernel/log.zig index ce1d418..b5c3d63 100644 --- a/system/kernel/log.zig +++ b/system/kernel/log.zig @@ -126,7 +126,7 @@ fn appendLocked(pid: u32, name: []const u8, level: abi.KlogLevel, now: u64, byte 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, line, line_complete); + render(pid, name, level, now, line, line_complete); rest = if (newline) |i| rest[i + 1 ..] else rest[rest.len..]; } } @@ -136,7 +136,7 @@ fn appendLocked(pid: u32, name: []const u8, level: abi.KlogLevel, now: u64, byte /// 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, line: []const u8, line_complete: bool) void { +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 @@ -149,6 +149,14 @@ fn render(pid: u32, name: []const u8, level: abi.KlogLevel, line: []const u8, li 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..], ": "); @@ -169,8 +177,8 @@ fn render(pid: u32, name: []const u8, level: abi.KlogLevel, line: []const u8, li open_line_pid = pid; } -/// newline + name + ": warning: " + a full payload line + newline. -const render_buffer_size = 1 + abi.maximum_process_name + 11 + abi.klog_maximum_message + 1; +/// 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);