From 65a44a556845fd86d316be20cf2c4237ebba2754 Mon Sep 17 00:00:00 2001 From: Daniel Samson <12231216+daniel-samson@users.noreply.github.com> Date: Tue, 21 Jul 2026 16:36:27 +0100 Subject: [PATCH] docs: per-process logging + the kernel VFS root logging.md rewritten around the pipeline (std.log -> leveled debug_write -> tagged ring -> logger service -> /var/log//.log), why the buffer is a kernel ring rather than a logging server (the storage stack must log; early boot needs the buffer anyway), the announce-once and counted-loss disciplines, and the accepted gaps. vfs-protocol.md: the router is the kernel (fs_resolve names, backends serve data); endpoint comes from resolve, not a registry lookup; mount/ unmount retired from the wire; the rewrite-prefix mount semantics. vdso.md: klog_status + the fs naming calls join the future table; the no-file-I/O line sharpened (kernel resolves names, never blocks on a filesystem). syscall.md: the placeholder status blurb replaced with the real call families. --- docs/logging.md | 164 ++++++++++++++++++++----------------------- docs/syscall.md | 17 +++-- docs/vdso.md | 9 ++- docs/vfs-protocol.md | 44 +++++++----- 4 files changed, 120 insertions(+), 114 deletions(-) diff --git a/docs/logging.md b/docs/logging.md index 3092ef3..88c72a9 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -1,104 +1,96 @@ -# Logging: the diagnostic log vs. the display +# Logging -danos separates two things that are easy to conflate: the **diagnostic log** — the -machine-readable stream of *what the kernel is doing* — and the **display**, the -framebuffer surface the OS draws on. They are different concerns with different -lifetimes, so they're different code paths. +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 and deliberately not a log sink; +`main.zig` mirrors a few user-facing status lines and panics to it explicitly. -The guiding rule: **output is a diagnostic convenience, never a correctness -dependency.** The kernel must boot and run correctly with *zero* output channels — -no serial, no screen. Logging that can take the kernel down isn't robust; it's a -liability. This is the same [resilience](resilience.md) posture the rest of the -kernel follows. - -## The log is multi-sink - -`system/kernel/log.zig` is the diagnostic log. It fans a message out to a set of -registered **sinks**, each best-effort and self-guarding: - -```zig -log.addSink(arch.serialWrite); // the serial UART -if (arch.debugconPresent()) log.addSink(arch.debugconWrite); // 0xE9 debug console -// later: log.addSink(fs.logWrite); // a file on a ramdisk / USB / SSD -log.write("…"); log.print("x={d}\n", .{x}); -``` - -Properties that matter: - -- **No allocation.** The sink table is a fixed array, so the log works before the - heap is up and inside a panic. -- **Best-effort.** A sink whose device is absent is a no-op (e.g. writing to a - missing UART just goes nowhere — the TX-wait is bounded so it can't hang). A - message reaches whatever channels exist; if none do, the kernel runs on, silent. -- **Order-independent.** Every registered sink gets every message. Adding the file - logger later is one `addSink` call and **zero** changes to call sites. - -## The framebuffer is *not* a log sink - -The framebuffer is a general graphics surface, **not inherently a text terminal**. -Today `system/kernel/console.zig` paints a text grid on it as a *bootstrap* console, but -that's a stop-gap: once the driver machinery exists the framebuffer becomes a proper -**graphics device driver**, and the text crutch goes away. So the log must not assume -it — routing the verbose log through a pixel console would bake in "the OS is text". - -Instead the two paths are explicit: +## The pipeline ``` -verbose diagnostics ──► log ──► serial, debugcon, (file later) -user status / panics ──► status() ──► log (above) + framebuffer (if present) +process std.log ──▶ debug_write(level) ──▶ tagged kernel ring ──▶ logger service ──▶ /var/log//.log +kernel log.print ─┘ │ + └▶ serial / 0xE9 sinks (QEMU, -Dserial) ``` -A handful of user-facing lines (`kernel initialised`, a panic) go through -`main.zig`'s `status()` / `statusPrint()`, which write to the log **and** paint the -framebuffer when one is present. Everything else uses `log.*` and never touches the -screen. `console.write` is a no-op when the firmware gave us no framebuffer. +1. **Emit.** A program calls `std.log.info("mounted {s}", .{path})` — the + runtime's `logFn` (installed for every binary by the root shim, + `library/runtime/log.zig`) formats one line and issues one `debug_write` + carrying the level. The payload does NOT contain the process's name. + `runtime.system.write` remains as the raw/bring-up path (panics, test + fixtures); raw bytes ride the same ring, attributed all the same. -## Optional framebuffer (headless machines) +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. -A framebuffer is not guaranteed — a headless server exposes no UEFI Graphics Output -Protocol. That used to be *fatal* (the loader failed the boot). Now the loader hands -over a "no framebuffer" descriptor (`base == 0`) rather than failing, and -`Framebuffer.present()` (in `system/boot-handoff.zig`) gates every on-screen path. A headless, -serial-less machine boots and runs correctly — it just goes quiet. +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. -## Last-resort channels (no text output at all) +4. **Render.** Registered sinks (serial under `-Dserial`, the 0xE9 debug + console) get a live transcript: kernel/raw output verbatim, leveled records + as `: 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. -Two signals bypass the sink list, because they must survive even a total -output-channel failure: +5. **Persist.** The **logger service** (`system/services/logger`) drains the + ring every 250 ms and demultiplexes records into one file per source under + `/var/log//`, e.g. -- **`log.checkpoint(code)`** — a one-byte **POST code** to I/O port `0x80` (a POST - card or BMC shows it). `main.zig` emits one at each boot milestone (`cp_paging`, - `cp_heap`, …) and on a fault/panic, so "where did it hang?" is answerable with no - text output whatsoever. Writing `0x80` is universally safe. -- **`log.recordPanic(msg)`** — stamps the panic message into a fixed record - (`log.panic_record`, with a `magic` written last). A post-mortem — an attached - debugger, a RAM dump, or a future file/pstore reader — recovers *what killed it* - even though nothing was on screen. + ``` + /var/log/2026-07-21T150434Z/kernel.log + /var/log/2026-07-21T150434Z/system/services/fat.log + /var/log/2026-07-21T150434Z/system/drivers/usb-storage.log + ``` -The panic and CPU-exception handlers fan out to every sink, emit a POST code, and -drop the breadcrumb — they never assume a console. + 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. -## The 0xE9 debug console +## Why a ring in the kernel, not a logging server -Port `0xE9` is the Bochs/QEMU debug console. It's detected safely: the port returns -`0xE9` when read if present, and `0xFF` on real hardware, so `debugconPresent()` -only enables the sink when it's really there. Under QEMU it's captured with -`-debugcon file:…`, giving CI a log channel independent of `-serial`. +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. -## The robustness spectrum +Two disciplines keep it honest: -The result handles every combination — framebuffer only, serial only, both, or -**neither**. With no channels at all the kernel still boots and runs; port-`0x80` -checkpoints track progress and the panic breadcrumb captures failures. *Runs blind -but correct* is the goal, not *always has output*. +- 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. -## Related +## Last-resort channels -- [framebuffer.md](framebuffer.md) — the display surface itself (pitch, format), the - thing that becomes a graphics device driver. -- [efi.md](efi.md) — where the loader captures (or, headless, doesn't capture) the - framebuffer before `ExitBootServices`. -- [device-interrupts.md](device-interrupts.md) — the serial UART bring-up the log's - primary sink rides on. -- [resilience.md](resilience.md) — why "never let a missing peripheral take the - kernel down" is a core design stance. +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. +- `/var/log` 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. diff --git a/docs/syscall.md b/docs/syscall.md index 6447b41..61da6f4 100644 --- a/docs/syscall.md +++ b/docs/syscall.md @@ -1,15 +1,18 @@ # System Calls System calls (syscalls) are the bridge between your programs and the operating system's restricted core (kernel). -> **Status:** danos has real user processes (M3). User programs enter the kernel +> **Status:** danos has real user processes. User programs enter the kernel > via the `syscall` instruction (STAR/LSTAR/SFMASK set per core; the entry stub in > `isr.s` does the `swapgs` + kernel-stack switch and reuses the interrupt -> dispatcher). The `int 0x80` gate is kept alongside as a minimal test path. The -> current call set is still a placeholder — `0 = exit(code)`, `1 = ping`, -> `2 = write(ptr, len)`, `3 = sleep(ms)` (see `system/kernel/process.zig`); the -> handler dispatches on whether the caller is a scheduled process (its own address -> space) or a borrowed test thread. The microkernel set below (IPC_Call / -> IPC_ReplyWait / Yield) replaces it once a second user server exists. +> dispatcher); the `int 0x80` gate is kept alongside as a minimal test path. +> The live table is `system/abi.zig` (private, renumberable — see +> [vdso.md](vdso.md) for the public boundary): process lifecycle + threads, +> memory (mmap/dma/shm), synchronous + async IPC with capability passing, +> device access, time, the tagged-log diagnostics (`debug_write` with a level, +> `klog_read`/`klog_status`), and filesystem NAMING (`fs_resolve`/`fs_node`/ +> `fs_mount`/`fs_unmount` — the kernel VFS root routes paths and serves the +> read-only /system initrd mount; file DATA stays with userspace filesystem +> servers over the vfs-protocol, docs/vfs-protocol.md). ## The Mechanism of a Syscall diff --git a/docs/vdso.md b/docs/vdso.md index 3c2d89c..3db0114 100644 --- a/docs/vdso.md +++ b/docs/vdso.md @@ -133,7 +133,8 @@ Grouped as `abi.zig` groups them: | ipc | `danos_endpoint_create`, `danos_ipc_register`, `danos_ipc_lookup`, `danos_ipc_call`, `danos_ipc_reply_wait`, `danos_ipc_send` | | devices | `danos_device_enumerate`, `danos_device_claim`, `danos_device_register`, `danos_mmio_map`, `danos_irq_bind`, `danos_irq_ack`, `danos_msi_bind`, `danos_io_read`, `danos_io_write` | | time | `danos_clock`, `danos_wall_clock`, `danos_timer_bind` | -| diagnostics | `danos_debug_write`, `danos_klog_read` | +| diagnostics | `danos_debug_write` (leveled, kernel-stamped records), `danos_klog_read`, `danos_klog_status` | +| filesystem naming | `danos_fs_resolve`, `danos_fs_node`, `danos_fs_mount`, `danos_fs_unmount` (naming only — file DATA still crosses the vfs-protocol IPC, see below) | The constants that ride alongside the calls — mmap protection bits, DMA flags, notification badge bits, `ExitReason`, `Signal`, well-known service @@ -197,8 +198,10 @@ Phased so every step ships alone (the M-milestone discipline): across processes stays what it is today: a service behind IPC, or source compiled into each binary. - **No file/device I/O in the vDSO.** The microkernel line doesn't move: the - vDSO wraps the same deliberately tiny table (docs/syscall.md); files are - still the VFS server's business over IPC. + vDSO wraps the same deliberately tiny table (docs/syscall.md). The kernel + resolves file NAMES (`fs_resolve` — the mount table moved in-kernel), but + file data is still the filesystem server's business over the vfs-protocol + IPC; the kernel never blocks on a userspace filesystem. - **No fast-path user-mode implementations yet.** Linux's vDSO exists mostly to answer `gettimeofday` without a kernel entry. `danos_clock` could one day read the calibrated TSC in user mode the same way — the blob is where diff --git a/docs/vfs-protocol.md b/docs/vfs-protocol.md index 33298db..fad1eca 100644 --- a/docs/vfs-protocol.md +++ b/docs/vfs-protocol.md @@ -1,20 +1,24 @@ # The VFS wire protocol > **Status:** built and spoken today between `runtime.fs` (the client) and the -> VFS server (`system/services/vfs`), with mounted backends (the FAT server) -> speaking the same protocol behind the router. The Zig source of truth is -> `system/services/vfs/protocol.zig` (the `vfs-protocol` module), whose unit -> tests pin the sizes and values below. This page is the **language-neutral -> wire specification** of that contract — what a Rust or C client implements -> ([vdso.md](vdso.md) explains why the IPC protocols, not the syscall -> numbers, are danos's public ABI). +> filesystem BACKENDS (the FAT server). The mount router lives in the +> **kernel** (`system/kernel/vfs.zig`): `fs_resolve` routes a path and either +> serves it directly (the read-only /system initrd mount, via `fs_node`) or +> redirects the caller to the owning backend's endpoint plus the rewritten +> mount-relative path — after which the client speaks THIS protocol to the +> backend, unchanged. The Zig source of truth is `system/vfs-protocol.zig` +> (the `vfs-protocol` module), whose unit tests pin the sizes and values +> below. This page is the **language-neutral wire specification** of that +> contract — what a Rust or C client implements ([vdso.md](vdso.md) explains +> why the IPC protocols, not the syscall numbers, are danos's public ABI). ## Transport A VFS exchange is one synchronous IPC rendezvous (`ipc_call`, docs/ipc.md): the client sends one message and blocks; the server replies -with one message. The endpoint is found by well-known service id -(`ipc_lookup`, service id **1** = vfs). +with one message. The endpoint comes from the kernel's `fs_resolve` — which +also hands back the path rewritten relative to the mount — not from a +registry lookup. (Service id 1, the old userspace router, is retired.) - A message is at most **256 bytes** (`message_maximum`). - A request is a fixed 32-byte **Request** header followed by an inline @@ -26,8 +30,11 @@ with one message. The endpoint is found by well-known service id - All integers are **little-endian**; layouts are C layout for x86-64 (`extern struct`), offsets given below so nothing need be inferred. -The kernel never parses any of this — it only moves the bytes -(docs/syscall.md); files are entirely a user-space affair. +The kernel resolves NAMES (the mount table) but never parses these +messages — it moves the bytes; file state is entirely the backend's affair. +With clients holding backend node ids directly, a backend records each open +handle's owner and sweeps a dead client's handles via the published process +exit events. ## Request header — 32 bytes @@ -90,13 +97,14 @@ Notes per operation: position. Each call returns exactly one entry; the client increments the cursor by 1. A reply with `len` 0 is end-of-directory. The directory must have been opened with the `directory` flag. -- **mount** — the one operation that passes a **capability**: the caller - (a filesystem server, e.g. FAT) sends its own request endpoint as the - `ipc_call` capability argument, and the router forwards everything under - the mount point to it — speaking this same protocol, with paths rewritten - relative to the mount. Prefixes match at path boundaries only - (`/mnt/usb` never captures `/mnt/usbextra`); the longest matching prefix - wins. +- **mount / unmount** — RETIRED from the wire: mounting is the `fs_mount` + syscall now (a filesystem server passes its endpoint handle; possession is + the capability, exactly the trust of the old cap-passing op). The op + numbers stay reserved. Mount-prefix semantics are unchanged: prefixes + match at path boundaries only (`/mnt/usb` never captures `/mnt/usbextra`), + the longest matching prefix wins, and an optional backend-side rewrite + prefix maps a mount into the backend's namespace (fat serves `/mnt/usb` + from its volume root and `/var` from its `/var` subtree). - **rename** — same-directory rename only (the router requires old and new to resolve under one mount).