Skip to content

Forensics recorder: a dying boot names its own last instant (#1278) - #1281

Merged
drawmeanelephant merged 2 commits into
mainfrom
agent/buffy/1261-forensics
Sep 14, 2026
Merged

drawmeanelephant merged 2 commits into
mainfrom
agent/buffy/1261-forensics

Conversation

@drawmeanelephant

Copy link
Copy Markdown
Owner

Closes #1278. Unblocks #1261.

What this is

Two recorders, because the problem had two halves and only one of them
had ever been attempted.

Guest side — kernel/src/forensics.zig. #1261 spent a whole
investigation unable to say anything about a boot that died: guest RAM is
not readable post-mortem (VZ exposes no dump, and serial_ring.zig is
RAM-only), and no [EXC] block appeared, so no handler was ever entered.
The design follows from that single constraint — a record only survives
if it reaches serial before the death
:

  • note(site, arg) is a per-core counter and one fixed BSS slot: no
    allocation, no lock, no console, no comparator write, so it is callable
    from IRQ/SVC/lock-held contexts. Race-freedom by construction: each core
    writes only its own slots, so there is nothing to synchronise.
  • note never prints. Emission is deferred to the console write path, so
    the next ordinary line the guest prints carries the pending records
    with it
    . The kernel's "no console in IRQ context" rule is preserved
    exactly: printing still only happens where it already happened.
  • Off by default, enabled by forensics on, so default boots are
    byte-identical (the gate asserts enabled=0 on a boot that armed
    nothing).
  • Probes at the seams a silent death lands between: interrupt dispatch
    (arg = INTID), the core-0 rotation (arg = the task switched away
    from
    — the half a post-hoc "who is current" dump can never recover),
    the wake funnel (arg = the task that became runnable), and a dump
    subcommand to force the tail out.

Host side — VMPostmortem + the runner. The runner set no
VZVirtualMachineDelegate, so VZ's error object was discarded and every
gate could only report the bare state rawValue. That is precisely what
made state=3 unfalsifiable. The delegate is now installed, and the
recording rules live in a pure-Swift module with zero Virtualization
imports
(the VFWire/VSSH precedent), so swift test pins them on a
machine that never boots a VM. The runner reports a stop verdict on
every run, not only the failing one.

What it found on the tree it was built for

Run against the nudge tree (PR #1255's commit) with the recorder armed,
the boot dies at dui tile 2 and now says why:

FAILURE: VM ended before the expected transcript appeared (state=3).
reason=domain=VZErrorDomain code=1 desc=Internal Virtualization error.
The virtual machine stopped unexpectedly.
userInfo={NSLocalizedFailure=… NSLocalizedFailureReason=…}

That is the datum #1261 could not obtain. code=1 in VZErrorDomain is
the internal error — VZ aborted the VM itself, which is why there was no
guest exception, no tombstone, and an ordinary last serial line. The full
trace is written up on #1261.

Two defects the new host tests found (in the recorder itself)

  1. A record whose line did not fit the output buffer was marked drained
    before formatting, so it was silently lost — the one way this
    recorder could drop exactly the newest record a dying boot is read for.
    Now left pending and counted.
  2. "Never written" was inferred from a slot's fields being all zero, which
    swallows a legitimate event at seq=0 with arg=0 — the head of a
    trace. A live flag now marks written slots.

Verification

gate result
live-forensics (class B, live VZ) PASS 1/1 — 360 records, irq 238 / rotate 121 / shot 1, dense per-core sequences, enabled=0 on an unarmed boot, host verdict line present
swift test --package-path host/vm-runner 33/33, including 9 new StopReasonTests
zig build test --summary all 194/194 steps, 3566/3566 tests
zig fmt --check / inventory-gates --check / verify-issue-coordination clean / OK / ok

Gaps I am not papering over

  • No spec induces a VZ error, so the delegate's invocation is not
    asserted by a gate. What is asserted live is that the verdict is
    reported on every boot (vm-stop: state=… reason=<none reported by VZ>),
    which fails if the delegate stops being installed; the formatting and
    ordering rules are unit-tested; and the callback names are witnessed by
    #selector resolution, since every protocol member is @optional and a
    wrong spelling would compile silently and never be called.
  • The recorder cannot see past the last console line before the death:
    it emits on the next ordinary print. On the diagnostic run that cost
    nothing (the trace's last record is 47,057 lines before the end, and the
    drain was demonstrably live during the storm), but a death immediately
    after a drain would carry one line less.

A boot can end in VZVirtualMachine.State.error with no [EXC] block, no
tombstone, and an ordinary last serial line. Guest RAM is unreadable
post-mortem, so a record only survives if it reaches serial BEFORE the
death -- hence a lock-free per-core ring plus a drain that rides the
console line that was going to be written anyway, off by default so
default boots stay byte-identical.

The host half was the cheap half nobody had: the runner set no
VZVirtualMachineDelegate, so VZ's error object was discarded and every
gate could only ever report the bare state rawValue. The recording rules
now live in a pure-Swift VMPostmortem module (the VFWire/VSSH precedent)
so `swift test` pins them without booting a VM, and the runner reports a
stop verdict on every run, not only the failing ones.

Two defect fixes the new host tests found, both in the recorder itself: a
record whose line did not fit the output buffer was marked drained and
lost (now left pending and counted, since the newest record is the most
valuable one in a dying boot), and a never-written slot was inferred from
all-zero fields, which silently swallowed a legitimate event at seq=0 with
arg=0 -- the head of a trace. A `live` flag now marks written slots.

Closes #1278

🤖 Generated with Codebuff
Co-Authored-By: Codebuff <noreply@codebuff.com>
@drawmeanelephant

Copy link
Copy Markdown
Owner Author

CI failure root cause (one line): the new forensics command appears in help output but the canonical fixture wasn't updated, so transcript gate 2 diffs:

   type        echo stdin (the pipe source) to stdout — the right half of `a | type`
+  forensics   last-words recorder: on|off|dump|reset (off by default)
   dmesg       system log viewer: last bytes of serial output (D12)

Fix: insert that line in tests/transcript-console.txt between the type and dmesg lines (matches kernel/src/shell.zig help text order). Everything else in the failing job is green — 494/494 unit tests pass; only bash tools/verify-transcript.sh fails on this hunk.

The forensics command's help entry grows the shell `help` listing by one
line, so the M1.5 transcript gate (verify-transcript.sh, byte-exact diff
against tests/transcript-console.txt) failed on CI while every local run
I had made passed -- test-console is not part of `zig build test`, only
of `just verify-portable`. The one added line is the intended diff; the
fixture is regenerated from the captured mock transcript.

🤖 Generated with Codebuff
Co-Authored-By: Codebuff <noreply@codebuff.com>
@drawmeanelephant
drawmeanelephant merged commit 8d52a01 into main Sep 14, 2026
9 checks passed
@drawmeanelephant
drawmeanelephant deleted the agent/buffy/1261-forensics branch September 14, 2026 23:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

claim: Forensics: a recorder that survives the guest dying, so a boot names its own last instant (#1261 unblock)

1 participant