Skip to content
fishbowl

Logging

How the system observes itself. Two independent mechanisms — kernel logging for system events, shell tracing for command execution — connected by clear boundaries.

Design Decisions

Why not console?

Decision: custom scoped logger, not console. console is a host concept — it writes to the Node terminal or browser devtools. The kernel ring buffer is a system concept — it lives inside fishbowl. If we hijack console, we lose the ability to debug the TypeScript implementation itself. console.log("why is this broken") during development must reach the developer’s terminal, not the in-system ring buffer. Two audiences, two channels: console for host developers debugging TypeScript, klog for the kernel recording system events.

Why not an external logging library?

Decision: no dependency on pino, winston, bunyan, etc. JS logging libraries solve problems we don’t have: log rotation, file transports, pretty-printing, worker threads for async I/O, serializers for HTTP objects. They’re designed for server applications, not OS kernels. Our logging surface is ~100 lines of code: one ring buffer class, one scoped helper, ~15-20 call sites. An adapter to pino would be more code than the implementation. The consumers are cat, grep, and dmesg — not Datadog. Zero dependencies is a feature of this project.

Why a data structure, not a fileserver?

Decision: the ring buffer is a plain TypeScript class, not a fileserver. If the ring buffer were a mounted fileserver, the kernel would need to write to it through its own I/O path — but the kernel manages that I/O path. Circular dependency. Instead, the kernel writes to the ring buffer directly (synchronous, in-memory). A separate read-only view in procFS provides the /proc/log interface for guest access. This mirrors Linux: printk() writes to a memory buffer; /proc/kmsg and dmesg are views onto it.

Why /proc/log, not /dev/klog?

Decision: extend procFS rather than adding a new fileserver. procFS already synthesizes read-only content from kernel state (/proc/<pid>/status, /proc/<pid>/fd/). A kernel log is the same pattern — read-only, generated from an internal data structure. Adding it to procFS avoids a new fileserver, a new mount point, and a new preset. It fits the existing architecture exactly.

Why syslog encoding?

Decision: use standard syslog priority encoding (RFC 5424). The pri field encodes facility and severity as facility * 8 + severity, recoverable via severity = pri & 0x7, facility = pri >> 3. This is the universal Unix convention. It makes the output grep-able with standard tools, forward-compatible with a future syslog service, and immediately recognizable to anyone who has read /var/log/syslog. Numeric severity (0-7) is more composable than string enums — awk '$sev <= 3' filters warnings and above.

Why separate shell tracing from kernel logging?

Decision: set -x writes to stderr, not the ring buffer. Shell tracing is per-shell, high-volume, user-facing output. It follows the data flow the user configured (redirects, pipes). Mixing it into the kernel log would pollute system diagnostics with shell-level noise. This matches bash, zsh, and POSIX sh behavior. Two independent mechanisms for two different concerns.

What about WASM programs?

Decision: WASM programs don’t touch the logging system. WASM bins already have their diagnostic path: Emscripten’s print() routes to proc.stdout, printErr() routes to proc.stderr. They’re regular processes — they write to stderr like any bin. The kernel may log about WASM operations (module loaded, asyncify bridge initialized), but WASM code itself never writes to the ring buffer. The boundary is clean: kernel internals log to the ring buffer, processes log to stderr.

Cross-platform considerations

Decision: no platform-specific code in the logging system. The ring buffer is a plain TypeScript array with a write head. procFS is pure TypeScript. The scoped logger is a thin wrapper. The only platform-dependent piece is the clock source — performance.now() for monotonic timing — which is available in both Node and browsers. Everything lives inside the fishbowl abstraction layer. This is a benefit of keeping it as a data structure + fileserver view rather than using an external library with Node-specific fast paths.

Architecture

Two independent mechanisms:

Kernel Logging                          Shell Tracing
─────────────────────                   ─────────────────
KernelLog (ring buffer)                 set -x / set +x
  ↑ write via scoped logger               ↑ flag in shell state
  │                                        │
  ├─ kernel call sites (~15-20)            ├─ interpreter checks flag
  ├─ init/supervisor events (future)        │  before each command
  ├─ pkg system events (future)            │
  └─ TRACE env var (opt-in debug)          ↓
  │                                     stderr (+ prefix)
  ↓ read-only view
/proc/log (virtual file in procFS)
  │
  ├─ cat /proc/log (snapshot)
  ├─ dmesg (formatted)
  └─ dmesg -w (follow mode — not yet implemented)

Component 1: Kernel Ring Buffer

A plain TypeScript class. Not a fileserver. Not mounted. The kernel writes to it directly and synchronously.

Types

export const LogSeverity = {
  Emergency: 0,  // system is unusable
  Alert:     1,  // action must be taken immediately
  Critical:  2,  // critical conditions
  Error:     3,  // error conditions
  Warning:   4,  // warning conditions
  Notice:    5,  // normal but significant
  Info:      6,  // informational
  Debug:     7,  // debug-level messages
} as const
export type LogSeverity = typeof LogSeverity[keyof typeof LogSeverity]


export const LogFacility = {
  Kern:   0,   // kernel messages
  User:   1,   // user-level messages
  Daemon: 3,   // system daemons (init, services)
  Local0: 16,  // pkg system
  Local1: 17,  // shell
  Local2: 18,  // wasm runtime
} as const
export type LogFacility = typeof LogFacility[keyof typeof LogFacility]


interface KernelLogEntry {
  seq: number            // monotonically increasing sequence number
  pri: number            // facility * 8 + severity
  time: number           // monotonic ms since boot (via performance.now())
  pid: Pid | undefined   // originating process, if applicable
  msg: string            // human-readable message
}

Ring Buffer Behavior

  • Fixed-size, configurable (default 1024 entries)
  • Oldest entries evicted when full (circular overwrite)
  • seq assigned on write, monotonically increasing (never resets)
  • write(facility, severity, pid, msg) — append, assign seq, notify waiting readers
  • entries() — return all current entries (for test assertions)
  • readFrom(cursor) — return entries with seq >= cursor (direct ring index, no intermediate copy)
  • waitForNew() — block (Promise) until new entries arrive
  • Timer function cached once in constructor (performance.now() or Date.now() fallback); time = delta from boot

Scoped Logger (Developer Experience)

The call-site API. One scoped logger per subsystem, created once:

// created once in createKernel()
const klog = kernelLog.scoped(LogFacility.Kern)


// at call sites — one line, minimal noise
klog.info(pid, `started ${argv[0]}`)
klog.warn(pid, `signal ${sig} unhandled`)
klog.error(pid, `exec failed: ${path}`)
klog.debug(pid, `open ${path} flags=${flags} -> fd:${fd}`)

scoped(facility) returns an object with one method per severity level. Each method handles pri encoding, seq assignment, and timestamping internally. The caller provides only what varies: pid and message.

For subsystems outside the kernel:

// init supervisor
const dlog = kernelLog.scoped(LogFacility.Daemon)
dlog.notice(pid, `restarting '${name}' (attempt ${count})`)


// package system
const plog = kernelLog.scoped(LogFacility.Local0)
plog.info(pid, `installed ${name}@${version}`)

Injection

createKernel(opts?: KernelOpts) accepts a log?: KernelLog field. The KernelLog instance is created by the boot sequence (image.ts) before the kernel, passed to both procFS() and createKernel(), ensuring availability from the first kernel operation.

Call Sites

Direct calls at high-signal event points. Not every function — only events that matter for troubleshooting.

Implemented:

FacilityEventSeverityData
KernProcess spawnedInfopid, command, argv
KernProcess exitedInfopid, exit code
KernProcess killed by signalWarningpid, signal
KernExec failedErrorpid, bin name
KernMountInfopid, path

Planned (not yet implemented):

FacilityEventSeverityData
KernNamespace resolution failureWarningpath, reason
DaemonService startedInfoname, pid
DaemonService exitedInfo/Warningname, exit code
DaemonService restartingNoticename, count, backoff
DaemonService gave upErrorname, reason
Local0Package installedInfoname, version
Local0Package install failedErrorname, reason
Local0Bundle evaluation failedErrorname, error

Component 2: /proc/log

A read-only virtual file in the existing procFS fileserver.

Read Behavior

Snapshot read: cat /proc/log returns all entries currently in the buffer as text, then EOF:

<6>[0.001] pid:1 started /bin/init
<6>[0.003] mount /dev -> devFS
<27>[1.200] pid:5 service 'httpd' exited with code 1

Where <6> = kern.info, <27> = daemon.error.

Blocking read (follow mode): when a reader reaches the end of the buffer, read() returns a Promise that resolves when new entries arrive. Same async blocking pattern as createPipe(). Enables dmesg -w.

Current Implementation

The current implementation uses snapshot-at-open semantics: when /proc/log is opened, all current entries are rendered to text and stored on the fd. Subsequent reads return from this snapshot. This is simpler than cursor-based streaming but means new entries written after open are not visible.

The procFS parsePath() was refactored to return a { virtual, pid, file } tuple, checking for well-known non-PID paths (log) before PID parsing. This supports future virtual files (self, mounts, etc.).

The fd uses a discriminated union: LogFd ({ kind: 'log', snapshot }) alongside the existing ProcFd ({ kind: 'proc', pid, file, content }).

Future: Cursor-Based Streaming

For dmesg -w follow mode, the fd would need to track an internal sequence cursor instead of a text snapshot. Each read() would return new entries since the last read, blocking when caught up. This matches the createPipe() async blocking pattern but is not yet implemented.

Component 3: Shell Tracing (set -x)

A shell interpreter feature. Independent of kernel logging.

Behavior (matches bash)

Terminal window
$ set -x
$ echo $HOME
+ echo /home/user
/home/user
$ ls | grep foo
+ ls
+ grep foo
$ set +x
  • set -x enables, set +x disables
  • Output written to stderr with + prefix
  • Shows expanded command (after variable/glob expansion)
  • Subshell depth indicated by prefix depth (+, ++, +++)

Implementation

The interpreter maintains a shellOpts: ShellOpts object ({ xtrace: boolean }) in its closure state. The set builtin accesses this via (proc as { shellOpts?: ShellOpts }).shellOpts — a type assertion since shellOpts is not part of the public ProcContext interface (it’s shell-internal state).

Key details:

  • Child interpreters (redirects, blocks, functions, pipelines) receive the same shellOpts reference — changes propagate
  • Subshells and command substitutions receive a shallow copy ({ ...shellOpts }) — changes don’t propagate back
  • The xtrace check runs in executeSimple() after alias expansion and before command dispatch
  • createInterpreter() accepts an optional parentShellOpts parameter for inheritance

Component 4: Opt-in Kernel Tracing (TRACE env var)

Fine-grained debug tracing. The strace equivalent.

Behavior

  • TRACE=fs,proc command — traces specified subsystems for that process tree
  • Trace entries go to the ring buffer at severity Debug (7)
  • When tracing is off (default), no debug entries written — zero overhead
  • Per-process via env var inheritance. TRACE=fs sh traces the shell and its children

Traceable Subsystems

Implemented:

SubsystemOperationsData
fsopen, read, write, close, statpaths, fd numbers, byte counts, flags

Planned:

SubsystemOperationsData
procspawn, exec, exit, signalpids, argv
mountmount, unmountpaths, fileserver types
nsnamespace resolutionpath → mount → fileserver

Guard

Inside createKernel(), a shouldTrace(pid, subsystem) helper reads the process’s TRACE env var:

function shouldTrace(pid: Pid, subsystem: string): boolean {
  const proc = processes.get(pid)
  if (proc === undefined) return false
  const tracing = proc.env['TRACE']
  if (tracing === undefined) return false
  return tracing.split(',').includes(subsystem)
}

Each traceable operation is guarded with if (klog !== undefined && shouldTrace(pid, 'fs')). The klog !== undefined check short-circuits when no log is configured (e.g., in tests without logging).

Component 5: Test Utilities

Not a kernel feature. Test helpers for diagnostics.

Silent by Default

The ring buffer accumulates entries during tests. Nothing reads them unless the test explicitly opts in.

Assertion Helper

const entries = kernelLog.entries()
expect(entries).toContainEqual(
  expect.objectContaining({ msg: expect.stringContaining('started /bin/sh') })
)

Dump on Failure (opt-in)

useLogDumpOnFailure(kernelLog)

Registers a vitest afterEach hook. On test failure (ctx.task.result?.state === 'fail'), formats and prints all ring buffer entries. Silent on success.

Component 6: dmesg Bin

A system bin (src/bins/system/) for human-readable log output. Reads from /proc/log, decodes <pri> into labels, formats timestamps.

Terminal window
$ dmesg
[0.600] kern.info pid:1 started echo hello
[1.600] kern.info pid:1 exited with code 0
[1.900] kern.info pid:2 started echo world


$ dmesg -l err,warn     # filter by severity (accepts: err, error, warn, warning, etc.)
$ dmesg -f kern,daemon  # filter by facility
$ dmesg -r              # raw output (pass through <pri> prefix)

Not yet implemented: dmesg -w (follow mode) — requires cursor-based streaming on /proc/log.

Process Logging (Bins and WASM)

Bins and WASM programs do not use the kernel logging system. They use the existing pattern:

// bins write to stderr — unchanged
await proc.stderr.write(`cat: ${path}: No such file or directory\n`)
// WASM programs use Emscripten's print/printErr — unchanged
// print() → proc.stdout, printErr() → proc.stderr

The ring buffer is for system internals. Process output is for processes. These are separate concerns with separate channels.

Multi-Instance Behavior

Each UnixInstance boots its own kernel with its own KernelLog. Ring buffers are per-instance, fully isolated. No shared state between instances.

Outstanding Work

Near-term items that build on the implemented foundation:

  • Init/supervisor logging: add daemon-facility events (service started, exited, restarting, gave up) to src/runtime/init/init.ts. Requires threading KernelLog through the init boot path.
  • Package system logging: add local0-facility events (installed, failed) to src/runtime/pkg/evaluator.ts.
  • dmesg -w follow mode: requires cursor-based streaming on /proc/log (replace snapshot-at-open with seq-tracking fd).
  • Additional TRACE subsystems: proc, mount, ns subsystems for shouldTrace().

Future Considerations (Not In Scope)

  • Syslog service: userspace daemon for multi-destination log routing. Deferred until enough services exist to justify configurable routing. The pri encoding ensures forward compatibility.
  • Log persistence: a service that reads /proc/log and writes to a file. The ring buffer is in-memory and lost on shutdown.
  • Structured log access: the text format requires parsing. A future JSON or binary variant of /proc/log could serve structured consumers directly. The ring buffer already stores structured KernelLogEntry objects — this is purely a presentation concern.
  • set -e / trap: deferred per existing architecture decisions in errors/README.md.

Error Flow Integration

Logging complements, does not replace, the existing error propagation model. Errors still flow through the system as described in the errors architecture: fileserver errors propagate transparently, uncaught bin exceptions become stderr + exit code 1, pipeline failures cascade via EPIPE/EOF.

The ring buffer captures the system’s perspective on these events (process exited, fileserver error occurred). The process stderr captures the bin’s perspective (what went wrong from its point of view). Both exist simultaneously, serving different consumers.