danos/docs/os-development/logging.md

Logging

Output is a diagnostic convenience, never a correctness dependency: the kernel and every service must run correctly with zero output channels. On top of that rule, danos has per-process logging — every process's output is attributed by the kernel and lands in its own file on the flash volume, which is what makes a headless real machine (no serial port) debuggable. The display (the framebuffer surface) is a separate concern with one bootstrap exception: the kernel's framebuffer console (system/kernel/console.zig) joins the log sinks at boot, so the whole transcript shows on screen until the display service claims the framebuffer and silences it; after that only panic/fatal messages are mirrored to it explicitly (system/kernel/kernel.zig).

The pipeline

process std.log ──▶ debug_write(level) ──▶ tagged kernel ring ──▶ logger service ──▶ /system/logs/<boot-stamp>/<binary-path>.log
kernel log.print ─┘                            │
                                               └▶ serial / 0xE9 sinks (QEMU, -Dserial)

1. Emit. A program calls std.log.info("mounted {s}", .{path}) — the runtime's logFn (installed for every binary by the root shim, library/kernel/logging.zig) formats one line and issues one debug_write carrying the level. The payload does NOT contain the process's name. logging.write remains as the raw/bring-up path (panics, test fixtures); raw bytes ride the same ring, attributed all the same.

2. Stamp. The kernel wraps every payload LINE in a record stamped with the sender's pid, task name (its binary path, e.g. /system/services/fat), level, a per-boot sequence number, and a monotonic timestamp (system/kernel/log.zig + log-ring.zig). Attribution is structural — a payload cannot forge another sender's tag, and an embedded newline just ends the record, so the forged "prefix" lands inside the forger's own next line.

3. Retain. The 512 KiB ring overwrites oldest-first; sequence gaps make any loss countable. klog_read (#32) copies stream bytes from a free-running offset; klog_status (#45) returns the cursors plus the wall-clock time of boot. The framing (abi.KlogRecordHeader) is 32 bytes + name + payload, 8-byte aligned.

4. Render. Registered sinks (serial under -Dserial, the 0xE9 debug console, and the framebuffer console until the display service claims the screen) get a live transcript: kernel/raw output verbatim, leveled records as <binary path>: message — one composed write per line, under the log's own spinlock (never the big kernel lock; panic paths try-acquire with a bound and fall back to sinks-only). Sinks are best-effort and self-guarding; a serial-less machine just goes quiet.

5. Persist. The logger service (system/services/logger) drains the ring every 250 ms and demultiplexes records into one file per source under /system/logs/<boot-stamp>/, e.g.

   /system/logs/2026-07-21T150434Z/kernel.log
   /system/logs/2026-07-21T150434Z/system/services/fat.log
   /system/logs/2026-07-21T150434Z/system/drivers/usb-storage.log
   

   The boot stamp is the RTC anchor from klog_status (FAT-safe: no colons; a dead RTC yields the 1970 directory rather than no logs). Each line carries the record's monotonic timestamp and level. Storage is best-effort and late: the ring buffers a whole boot many times over, and the first successful makePath of the per-boot directory (also the readiness probe) triggers a full backlog write. Files close — which is the fat server's SCSI cache flush — after a ~2 s quiet period, bounding data-at-risk without per-record flush thrash. At shutdown init stops the logger FIRST (it is last in the boot order), so its final drain runs over a live storage chain.

Why a ring in the kernel, not a logging server

The storage stack must be able to log. If the fat server wrote its own log file through the VFS it would rendezvous-deadlock on itself; if processes sent records to a logging server over IPC, early boot would need a buffer that is — a ring, one hop later. The kernel ring is that buffer, placed where every process (and the kernel itself) can reach it with one syscall, before any service exists. The logger service is a reader, not a hop.

Two disciplines keep it honest:

• the logger announces itself once — a periodic status line would feed the very stream it drains;
• lost records surface as an explicit -- N records lost -- line, computed from sequence gaps, never silently.

Last-resort channels

Unchanged, and independent of the sink list so they survive a total output failure: checkpoint (a one-byte POST code on port 0x80) and recordPanic (a fixed breadcrumb record, log.panic_record, findable in a RAM dump; magic written last so a reader only trusts a complete record).

Accepted gaps

• A write-spamming process can evict other processes' unread records from the ring (a per-process quota is future work); the loss is at least visible via sequence gaps in every affected file.
• /system/logs files have no privacy until the VFS grows permissions.
• Records emitted after the logger's final shutdown drain reach serial and the ring but not the files.