Persist the kernel boot log to the USB FAT volume

On a headless or real board nothing captures serial, so the boot log — the whole
diagnostic stream — is lost at power-off. This retains it in the kernel and copies
it to the boot USB volume as /mnt/usb/DANOS.LOG, the on-disk equivalent of QEMU's
`-serial file:`. Pull the stick, read DANOS.LOG on another machine.

How it fits together:
- Kernel RAM sink (log.zig): a fixed 256 KiB in-image buffer registered as a log
  sink in kmain, right after serial. Because userspace debug_write funnels through
  log.write, it captures the entire stream — kernel lines and every service's
  output — from the first line. Fills linearly and stops when full (earliest boot
  output, the most valuable, is kept); no allocation, so it is panic-safe.
- klog_read syscall (32): copies that buffer out to a user buffer, the mirror of
  debug_write — same overflow-safe user-half bounds check, kernel -> user copy,
  under the kernel lock so the snapshot can't grow mid-copy. Wrapped by
  runtime.system.klogRead.
- log-flush (new one-shot, in the initial-ramdisk): waits for the fat server to
  mount /mnt/usb, then copies the whole log to /mnt/usb/DANOS.LOG. init spawns it
  once the boot services are up (fire-and-forget; it polls the mount itself). If
  no volume is mounted — no stick, or the no-VFS ramdisk sweep — it exits silently.
- init shutdown flush: init repeats the copy inline at the top of shutDown(),
  BEFORE it tears down the storage services (the fat server is stopped first), so
  a clean poweroff captures the fullest log while /mnt/usb is still writable.
- unistd.writeAll: loops write() past the 224-byte VFS payload cap; both flush
  paths use it.

The filename is 8.3 (DANOS.LOG) at the mount root — the FAT short-name rule, and
there is no mkdir on the FAT path yet. Extend-only writes mean the two same-session
flushes never leave stale bytes (the shutdown log is a superset of the boot log);
a shorter log on a later boot of the same stick can leave a stale tail — a noted,
cosmetic limitation, not worth pulling O_TRUNC into the FAT write path for now.

Verified end to end under QEMU: a new `log-flush` case (reusing the orderly-shutdown
build) asserts both markers then S5, and DANOS.LOG is read back out of the image
afterwards (11804 bytes, containing the kernel init line, the FAT mount line, and
the boot flush marker). Regression stays green: zig build, zig build test, zig
build check-fat-image, and a sequential QEMU sweep — smoke, init, initial-ramdisk
(log-flush silent in the bare sweep), orderly-shutdown, fat-mount, usb-storage,
usb-hid, vfs, input, device-manager, process, signals, dma, fault-pf.
This commit is contained in:
Daniel Samson 2026-07-13 18:18:34 +01:00
parent 77d2e22ed1
commit f52c591f5e
No known key found for this signature in database
GPG Key ID: A9EB2589C60F7268
10 changed files with 215 additions and 3 deletions

View File

@ -434,6 +434,7 @@ pub fn build(b: *std.Build) void {
const input_test_exe = addUserBinary(b, kernel_target, runtime_module, posix_module, mmio_module, xkeyboard_config_module, acpi_ids_module, "input-test", "system/services/input-test/input-test.zig");
const args_echo_exe = addUserBinary(b, kernel_target, runtime_module, posix_module, mmio_module, xkeyboard_config_module, acpi_ids_module, "args-echo", "system/services/args-echo/args-echo.zig");
const process_test_exe = addUserBinary(b, kernel_target, runtime_module, posix_module, mmio_module, xkeyboard_config_module, acpi_ids_module, "process-test", "system/services/process-test/process-test.zig");
const log_flush_exe = addUserBinary(b, kernel_target, runtime_module, posix_module, mmio_module, xkeyboard_config_module, acpi_ids_module, "log-flush", "system/services/log-flush/log-flush.zig");
// Pack the user binaries into the initial_ramdisk image with the host-side Python tool
// (the container format is trivial, and Python sidesteps std API churn). Args:
@ -483,6 +484,8 @@ pub fn build(b: *std.Build) void {
mk_run.addFileArg(args_echo_exe.getEmittedBin());
mk_run.addArg("process-test");
mk_run.addFileArg(process_test_exe.getEmittedBin());
mk_run.addArg("log-flush");
mk_run.addFileArg(log_flush_exe.getEmittedBin());
// Also install the packed binaries to their FHS homes, so zig-out is a true image
// of the filesystem even though at boot they arrive inside the initial-ramdisk.
@ -498,6 +501,7 @@ pub fn build(b: *std.Build) void {
.{ usb_hid_mouse_exe, "system/drivers" },
.{ usb_storage_exe, "system/drivers" },
.{ fat_exe, "system/services" },
.{ log_flush_exe, "system/services" },
}) |entry| {
const step = b.addInstallArtifact(entry[0], .{ .dest_dir = .{ .override = .{ .custom = entry[1] } } });
b.getInstallStep().dependOn(&step.step);

View File

@ -101,6 +101,19 @@ pub fn write(fd: i32, data: []const u8) isize {
return @intCast(r.reply.len);
}
/// Write all of `data`, looping until it is fully written (a single `write` caps
/// each call at the VFS payload size). Returns the total written, or -1 if a
/// underlying write failed before any progress on that chunk.
pub fn writeAll(fd: i32, data: []const u8) isize {
var written: usize = 0;
while (written < data.len) {
const n = write(fd, data[written..]);
if (n <= 0) return if (written == 0) -1 else @intCast(written);
written += @intCast(n);
}
return @intCast(written);
}
/// Reposition the fd's offset. Returns the new offset or -1. (SEEK_END needs the
/// file size, which `stat` provides; handled by fetching it here.)
pub fn lseek(fd: i32, off: i64, whence: u32) i64 {

View File

@ -51,6 +51,16 @@ pub fn clock() u64 {
return @intCast(sc.systemCall0(.clock));
}
/// Copy bytes out of the kernel's in-memory diagnostic log the accumulated
/// stream of everything `write` (and the kernel itself) has emitted starting at
/// `offset`, into `out`. Returns the number of bytes copied (0 at end of buffer).
/// A program reads the whole log by looping from offset 0, advancing by the return
/// value, until it gets 0. This is how the boot log is persisted to disk on a
/// headless/real machine where serial output is otherwise lost.
pub fn klogRead(offset: usize, out: []u8) usize {
return sc.systemCall3(.klog_read, offset, @intFromPtr(out.ptr), out.len);
}
/// End the process. Never returns.
pub fn exit(code: usize) noreturn {
_ = sc.systemCall1(.exit, code);

View File

@ -58,6 +58,7 @@ pub const SystemCall = enum(u64) {
signal_bind = 29, // signal_bind(endpoint) -> 0/-errno: nominate the endpoint this process's signals arrive on
process_signal = 30, // process_signal(id, signal) -> 0/-errno: post a signal to a child (or to yourself)
timer_bind = 31, // timer_bind(endpoint, ms) -> 0/-errno: one-shot timer posts a notification when ms elapse
klog_read = 32, // klog_read(offset, ptr, len) -> bytes copied: copy the kernel RAM log buffer out to a user buffer (for persisting the boot log to disk)
_,
};

View File

@ -62,6 +62,10 @@ fn kmain(boot_information: *const BootInformation) noreturn {
architecture.serialInit();
log.addSink(architecture.serialWrite);
if (architecture.debugconPresent()) log.addSink(architecture.debugconWrite);
// Retain the whole stream in a RAM buffer too, so a user program can later
// read it back (klog_read) and persist the boot log to disk the only way to
// see it on a headless/real machine with no host capturing serial.
log.addSink(log.ramSink);
// The **framebuffer** is deliberately *not* a log sink. It's a separate output
// surface a bootstrap text console today, a graphics device driver later so

View File

@ -41,6 +41,39 @@ pub fn write(bytes: []const u8) void {
for (sinks[0..sink_count]) |sink| sink(bytes);
}
// --- the RAM sink: a retained copy of the whole diagnostic stream ------------
//
// A fixed in-image buffer that accumulates every logged byte, so a user program
// (`log-flush`, and init at shutdown) can read it back through `klog_read` and
// persist it to a file the boot log survives on a headless/real machine that
// has no host capturing serial. It is a *sink like any other*: register it with
// `addSink(ramSink)` at boot. No allocation (works pre-heap and in a panic).
//
// It fills linearly and stops when full: the earliest output the most valuable
// for diagnosing a boot is kept, and the tail is still on the live serial sink.
// 256 KiB comfortably holds a full boot plus a long run (a boot is ~15 KiB).
const ram_capacity = 256 * 1024;
var ram_buffer: [ram_capacity]u8 = undefined;
var ram_len: usize = 0;
/// The RAM sink. Best-effort and self-guarding like every sink: appends what fits
/// and silently drops the rest once full. (Concurrency matches the other sinks
/// the dominant writer, debug_write, already holds the kernel lock; a rare torn
/// append on a kernel-internal line is an accepted diagnostic imperfection.)
pub fn ramSink(bytes: []const u8) void {
const n = @min(ram_buffer.len - ram_len, bytes.len);
if (n != 0) {
@memcpy(ram_buffer[ram_len..][0..n], bytes[0..n]);
ram_len += n;
}
}
/// The accumulated log so far what `klog_read` copies out.
pub fn ramSnapshot() []const u8 {
return ram_buffer[0..ram_len];
}
/// 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 {

View File

@ -206,6 +206,7 @@ fn system_call(state: *architecture.CpuState) void {
.signal_bind => systemSignalBind(state),
.process_signal => systemProcessSignal(state),
.timer_bind => systemTimerBind(state),
.klog_read => systemKlogRead(state),
_ => fail(state),
}
}
@ -974,6 +975,37 @@ fn systemDebugWrite(state: *architecture.CpuState) void {
}
}
/// klog_read(offset, ptr, len) -> bytes copied: copy the kernel's in-memory
/// diagnostic log (the RAM sink in log.zig) out to the user buffer at `ptr`,
/// starting at `offset`. Returns the count copied 0 once `offset` reaches the
/// end so a program reads the whole log by looping from 0 until it gets 0.
///
/// The mirror of `debug_write`: the same overflow-safe user-half bounds check,
/// but the copy runs kernel -> user. Written under the kernel lock so the source
/// snapshot can't grow underneath the copy. A read-only diagnostic it exposes
/// only the log the kernel already broadcasts to serial, nothing else.
fn systemKlogRead(state: *architecture.CpuState) void {
const offset = architecture.systemCallArg(state, 0);
const ptr = architecture.systemCallArg(state, 1);
const len = architecture.systemCallArg(state, 2);
// Confine the whole destination span to the user (low) half. `len <=
// user_half_end - ptr` bounds the length without an overflowing add.
if (ptr < user_half_end and len <= user_half_end - ptr) {
const flags = sync.enter();
defer sync.leave(flags);
const snapshot = log.ramSnapshot();
var n: usize = 0;
if (offset < snapshot.len) {
n = @min(len, snapshot.len - offset);
const dest: [*]u8 = @ptrFromInt(ptr);
@memcpy(dest[0..n], snapshot[offset..][0..n]);
}
architecture.setSystemCallResult(state, n);
} else {
fail(state);
}
}
/// mmap(len, prot) -> base: grant `len` bytes (rounded up to whole pages) of
/// fresh, zeroed, writable+NX memory in the caller's mmap arena, and return the
/// base virtual address. `prot` is accepted but not yet honoured (grants are

View File

@ -19,8 +19,14 @@
const std = @import("std");
const runtime = @import("runtime");
const unistd = @import("posix").unistd;
const power = runtime.power_protocol;
/// Where the kernel boot log is persisted on the USB FAT volume an 8.3 name at
/// the mount root (see system/services/log-flush). init writes it at shutdown;
/// the log-flush one-shot writes it once at boot.
const log_path = "/mnt/usb/DANOS.LOG";
/// The system services init brings up at boot, in order. This is init's policy the
/// microkernel keeps such choices in user space, not the kernel. Drivers are absent
/// on purpose: the device manager owns those. (A future init reads this from a
@ -65,6 +71,14 @@ pub fn main() void {
}
}
// Once the storage stack is up, a one-shot copies the boot log to the USB
// volume (/mnt/usb/DANOS.LOG) so it can be read on another machine the only
// way to see it on a headless/real board with no host capturing serial. Fire
// and forget: it polls for the mount itself, and is deliberately NOT one of
// init's supervised children (a transient one-shot must not be stopped-and-
// waited-for during shutdown).
_ = runtime.system.spawn("log-flush");
// Subscribe to power events (retry: the power service registers well after
// init starts). Best-effort without it, a `terminate` signal still
// triggers the same shutdown path.
@ -115,11 +129,36 @@ fn subscribePower() void {
_ = runtime.ipc.callCap(h, std.mem.asBytes(&request), &reply, supervision_endpoint) catch {};
}
/// The stop sequence: terminate each child in reverse spawn order (vfs last
/// other services may flush through it), waiting up to a deadline for each to
/// exit before killing it, then ask the power service to enter S5.
/// Copy the whole kernel log to /mnt/usb/DANOS.LOG (the same file log-flush
/// writes at boot), so a poweroff captures the fullest log. Best-effort: if the
/// USB volume is not mounted, the open fails and it does nothing. Must run while
/// the storage services are still alive (see shutDown).
fn flushKernelLog() void {
const fd = unistd.open(log_path, unistd.O_CREAT);
if (fd < 0) return; // no USB volume mounted nothing to persist to
defer unistd.close(fd);
var chunk: [4096]u8 = undefined;
var offset: usize = 0;
while (true) {
const got = runtime.system.klogRead(offset, &chunk);
if (got == 0) break; // reached the end of the accumulated log
if (unistd.writeAll(fd, chunk[0..got]) < 0) break; // storage went away
offset += got;
}
var line: [96]u8 = undefined;
_ = runtime.system.write(std.fmt.bufPrint(&line, "/system/services/init: flushed log to {s} ({d} bytes)\n", .{ log_path, offset }) catch "");
}
/// The stop sequence: persist the log while storage is still up, then terminate
/// each child in reverse spawn order (vfs last other services may flush through
/// it), waiting up to a deadline for each to exit before killing it, then ask the
/// power service to enter S5.
fn shutDown() void {
_ = runtime.system.write("/system/services/init: shutting down\n");
// Persist the fullest log to the USB volume BEFORE tearing anything down: the
// reverse-order stop loop below kills the fat server (children[3]) first, so
// /mnt/usb must be written while it is still mounted.
flushKernelLog();
var i = child_count;
while (i > 0) {
i -= 1;

View File

@ -0,0 +1,62 @@
//! system/services/log-flush a one-shot that copies the kernel's in-memory
//! diagnostic log to a file on the mounted USB FAT volume, so the boot log
//! survives to be read on another machine. On a headless or real board there is
//! no host capturing serial, so without this the log is lost at power-off; this
//! is the on-disk equivalent of QEMU's `-serial file:`.
//!
//! It reads the whole kernel log back through `klog_read` (the RAM sink in
//! system/kernel/log.zig) and writes it to /mnt/usb/DANOS.LOG. The name is 8.3
//! (FAT short-name rule: base <= 8, extension <= 3) and lives at the mount root
//! (there is no mkdir on the FAT path yet). init spawns this once the boot
//! services are up; init itself repeats the flush at shutdown for a fuller log.
//!
//! If no USB volume is mounted no stick, or the initial-ramdisk sweep that
//! spawns every bundled binary bare with no VFS it waits briefly, then exits
//! silently, deranging no other test's output.
const std = @import("std");
const runtime = @import("runtime");
const unistd = @import("posix").unistd;
const log_path = "/mnt/usb/DANOS.LOG";
/// Copy the whole kernel log to the open fd, looping klog_read -> write until the
/// log is exhausted. Returns the number of bytes written.
fn drainKernelLog(fd: i32) usize {
var chunk: [4096]u8 = undefined;
var offset: usize = 0;
while (true) {
const got = runtime.system.klogRead(offset, &chunk);
if (got == 0) break; // reached the end of the accumulated log
if (unistd.writeAll(fd, chunk[0..got]) < 0) break; // storage went away
offset += got;
}
return offset;
}
pub fn main() void {
// Wait for the fat server to mount /mnt/usb (it must bring up the whole USB
// storage chain first, so it races us at boot). Bounded: if the mount never
// appears no volume, or the no-VFS ramdisk sweep give up silently.
var dir: i32 = -1;
var tries: u32 = 0;
while (dir < 0 and tries < 1400) : (tries += 1) {
dir = unistd.opendir("/mnt/usb");
if (dir < 0) runtime.system.sleep(50);
}
if (dir < 0) return; // /mnt/usb never became available nothing to persist to
unistd.closedir(dir);
const fd = unistd.open(log_path, unistd.O_CREAT);
if (fd < 0) return; // could not create the file exit quietly
const written = drainKernelLog(fd);
unistd.close(fd);
var line: [96]u8 = undefined;
_ = runtime.system.write(std.fmt.bufPrint(&line, "log-flush: wrote {d} bytes to {s}\n", .{ written, log_path }) catch return);
}
pub const panic = runtime.panic;
comptime {
_ = &runtime.start._start; // pull the runtime entry shim into the image
}

View File

@ -368,6 +368,20 @@ CASES = [
r"init: shutting down[\s\S]*"
r"power: entering S5",
"fail": r"power: S5 write did not take|DANOS-TEST-RESULT: FAIL"},
# M8: the boot log is persisted to the USB FAT volume. Reuses the orderly-
# shutdown build (full tree + power button): init spawns log-flush at boot,
# which copies the kernel log to /mnt/usb/DANOS.LOG once /mnt/usb is mounted
# (first marker); then the power button drives init's own pre-teardown flush
# (second marker), proving both triggers write the file while storage is up.
{"name": "log-flush",
"build_case": "orderly-shutdown",
"smp": 4,
"timeout": 150,
"qmp_after": {"delay": 8, "command": "system_powerdown"},
"expect": r"log-flush: wrote \d+ bytes to /mnt/usb/DANOS\.LOG[\s\S]*"
r"init: flushed log to /mnt/usb/DANOS\.LOG[\s\S]*"
r"power: entering S5",
"fail": r"DANOS-TEST-RESULT: FAIL"},
# M20.2: the acpi service evaluates _CRS/_STA in ring 3 and registers +
# reports its _HID devices — the two PS/2 nodes must appear with resources
# (keyboard: io 0x60/0x64 + IRQ = 3; mouse: IRQ = 1) (docs/discovery.md).