SMP boot dies silently under WM traffic: the extra core-0 switch is survivable, the death is not guest-side

[drawmeanelephant]

Claim

• Owner: buffy (agent/buffy/1261-probes)
• Scope: Find the mechanism behind the silent death of the SMP boot under WM traffic: with the Forensics recorder: a dying boot names its own last instant (#1278) #1281 recorder landed, instrument exception entry (before GIC consumption), spurious acks, comparator re-arms, and a console-free liveness sample; re-run the dying boot until it names its own last instant; and settle "the PPIs stopped being delivered" vs "the notes stopped being reached" as measured evidence. Then either fix it or bound it in writing.
• Touches: kernel/src/scheduler.zig,kernel/src/timer.zig,kernel/src/exceptions.zig,kernel/src/main.zig,kernel/src/monitor.zig,kernel/src/shell.zig,kernel/src/forensics.zig,kernel/tests/scheduler_test.zig,kernel/tests/monitor_test.zig,tools/gate/specs/live-wm-pacing.spec,tools/gate/specs/live-forensics.spec
• Depends on: claim: Forensics: a recorder that survives the guest dying, so a boot names its own last instant (#1261 unblock) #1278 (landed — the recorder this was blocked on)
• Verification: live-forensics PASS with every probe pinned; the death's mechanism stated as observed evidence (trace + VZ verdict), not a hypothesis.
• Status: ⛔
• Blocked on: nothing mechanical — the recorder landed (Forensics recorder: a dying boot names its own last instant (#1278) #1281) and the probes measure clean (PPIs delivered AND recorded to the last second; VZErrorDomain code=1, so VZ aborts the VM rather than the guest faulting). What remains is diagnosis: no handler is entered on the death and VZ offers no reason beyond code=1, so the open question is which guest action makes VZ abort, and whether the abort can be turned into an observable.

---

⚠️ Measured 2026-09-14 — the premise of everything below is wrong

Read the measurement comment before this document. Three instrumented class-B boots overturned the causal claim in the title and the "Starvation, not a crash" line below:

• The boot does not starve. A failing run prints 451,721 smp: secondary runs= lines and the shell prints every one (drained == staged), then leaves that drain and proceeds into script2. It is not stuck in the drain and not starved.
• The staging storm is survivable. With script2 withheld to t=120 s the guest survives 120 s inside a 489,187-line staging storm with the nudge armed the whole time — and dies the instant the first dui command lands. The trigger is the script2 WM traffic, not the backlog and not time.
• The nudge measures clean. 19–21 requests per 20 s, coalesced=1, all on core 0 (nudge c1=0); ticks=20 at cntpct=486,449,908 = 20.27 s, so 1 Hz exact. The extra rotation is one per second: period tick idle → shell, then ~2.4 ms later the nudge shell → user-exec.

So there are two symptoms where this card assumed one, and only one of them is fatal. The text below is kept as the record of how the premise was reached and is not to be relied on where it conflicts with that comment.

Summary

An extra preemption/context switch on core 0 during an SMP desktop boot starves the boot. The guest does not fault — it starves. This is the defect underneath #1252's reschedule nudge (815 ms → 2.5 ms input→present), and it sits in front of anything else that changes when core 0 switches: the WFE-with-tick-wake idle experiment recorded under #122 (closed; still cited by kernel/src/shell.zig:4028 as "the recorded option"), and any change to the tick period or the quantum.

It is filed as its own card because the nudge is a latency win blocked by a defect that is not about latency, and because nothing in the current design exercises a core-0 switch off the period boundary — which is why it went unnoticed.

Symptom (observed)

live-wnd5-gate2-policy — SMP, WND + NOTEPAD, dui orientation chords:

tree	result
current kernel, re-measured 2026-09-14	PASS (2/2 runs)
with the nudge applied (#1255, bc89e9c)	FAIL (0/4 attempts)

The failing boot does not fault: no [EXC] parking:, no tombstone, timer heartbeat ticks=N irq=N exact throughout. The WM keeps presenting on ticks while the shell stops completing dui commands, and the boot ends in VZVirtualMachine.State.error (state=3). Starvation, not a crash.

Baseline line from today's run, in order:

gate-run: host 27.0/arm64; kern.hv_support=1 hv_vmm_present=0; hv_vm_create -> 0x00000000 (HV_SUCCESS)
vgate live-wnd5-gate2-policy: PASS (2/2 runs)

Bisection (observed)

Each row is the probe, then the gate result.

probe	result
baseline origin/main	PASS 3/3
timer.nudge() disabled entirely (flag bookkeeping + tick(period) signature kept)	PASS 2/2
comparator pulled forward, but tick returns before the rotation	PASS 1/1
full rotation on a nudge	FAIL 0/4
rotation skipped when the successor is the WFE-parked idle fallback	FAIL 0/2
targeted handoff (claim exactly the woken slot, nobody else)	FAIL 3/3
handoff suppressed when the wake is raised inside on_tick	PASS 2/3 — and the win is gone (827 ms)

Read together: the comparator move is harmless; the extra switch is what harms; and the win and the harm come from the same place. The last row is the entanglement proof — suppressing the wakes raised inside the tick's own beat (wm_server.on_tick, the WM's kind-18 delivery) restores the boot and takes resched_requests from 32 to 1, removing exactly the handoffs that produced the 2.5 ms. No subset was found that keeps one and drops the other.

Two traps (observed) — both look like progress

1. "Rotate only if the woken task is the round-robin successor" passed 6/7, but only because the target was being cleared before delivery: it was effectively a nudge with no rotation at all, and measured 807 ms. A guard that looks principled and silently disables the feature.
2. The target's lifetime is subtle. The dominant wake (the WM's kind-18) is raised from inside the period tick's on_tick, so a rotation-based discharge cleared the handoff the very same beat had just armed — observed as handoff_attempts=1 out of nudge_served=16. Fixing it (discharge only when no nudge is pending) produced the 2.5 ms — and therefore the starvation.

Mechanism — a hypothesis, explicitly not a measurement

Best current reading: a handoff switches away from the interrupted task mid-quantum, and when the woken task blocks, round-robin resumes from its slot. The always-ready idle fallback sits at the highest slot, so it is reached before the wrap back to slot 0 (the shell), and it then parks in WFE until the next period tick — so the interrupted task waits ~1 s for what used to be its own quantum.

That is consistent with the starvation symptom, with why the WM is unaffected, and with why it needs more than one handoff to become fatal. It is not confirmed, and the probe that should have discriminated it (rotation skipped when the successor is the idle fallback) failed, which argues the story is incomplete. The 2026-09-14 measurement above argues further: the storm is survivable, so this hypothesis cannot be the whole story.

First step when this is picked up

Instrument the ring contents and current[0] across a failing boot before writing any fix. The smallest failing shape known so far is "an extra tick()-driven rotation on core 0 during a NOTEPAD boot".

Done, 2026-09-14 — see the measurement comment. The instrument was built, two defects in the instrument itself were found and fixed, and the result was not the expected one: the rotation log is clean, the storm is survivable, and the death is a silent VM-level error on the WM dui path. The blocker named at the top of this claim ("Blocked on") is what now stands between this card and its acceptance criteria.

Reproduction

git fetch origin agent/buffy/wmp3-nudge-recovered
git checkout agent/buffy/wmp3-nudge-recovered        # bc89e9c — draft PR #1255, NOT for merge
bash tools/gate/fleet.sh run live-wnd5-gate2-policy   # expect FAIL (starvation)

Contrast: the same command on current main passes. The branch is the pre-fix revision — it still writes the shared period_deadline global from every core's arm(), and lacks the targeted handoff; both are described on #1252.

Acceptance (proposed)

• The defect reproduces on demand (stated N runs, same shape).
• The mechanism is identified from observed evidence — ring contents and current[0] across a failing boot — not from the hypothesis above.
• Either fixed, or bounded in writing: with the change in place, live-wnd5-gate2-policy stays PASS and live-sb6-perf-payoff (the 1 Hz determinism gate) stays PASS.
• Then claim: WMP card 3: serve a wake by pulling the comparator forward, not by waiting for the 1 Hz tick #1252's nudge can be re-applied and its 2.5 ms re-measured.

Notes

• Not claimed. Claim it (just claim-card / bash tools/status/new-claim.sh) before editing, so the coordination gate sees the file ownership. Likely files: kernel/src/scheduler.zig, kernel/src/timer.zig, possibly kernel/src/exceptions.zig and a spec.
• Refs: claim: WMP card 3: serve a wake by pulling the comparator forward, not by waiting for the 1 Hz tick #1252 (the blocked nudge and its full write-up), PR DRAFT / BLOCKED (#1261): WMP card 3 reschedule nudge — 815 ms -> 2.5 ms, blocked by a silent VM death on the WM dui path #1255 (the reproduction artifact), Stale idle-loop comment: 'no GIC programming this milestone' contradicts claim 9187 (real PPI delivery) #122 (closed — scoped the optional WFE-with-tick-wake idle experiment).

[drawmeanelephant]

Reproduction artifact: draft PR #1255 (agent/buffy/wmp3-nudge-recovered, bc89e9c) — the pre-fix revision. It is deliberately a draft and must not be merged: it is the code that produced the 2.5 ms live-wm-pacing result, and it is the same code that starves this boot. Verified 2026-09-14 that it is the only ref in the repository containing that mechanism (no other branch, local or remote).

[drawmeanelephant]

Mechanism hunt: the hypothesis is now a measurement, and the measurement overturns the card's premise

Three instrumented boots on agent/buffy/smp-starvation (nudge cherry-picked onto today's main as 71f6118, scaffolding dirty). All local class-B (VZ), no hosted runner.

First, two defects in my own instrument — both caught, neither silent

1. The core-0 counter could not see core 0. I put the staging attribution (stage_sites[c][site] += 1) inside if (c != 0) in stage_selected. For a whole boot it reported c0 sites park=0 switch=0 other=0 while switches=77 — which reads as "core 0 never stages a task" and is really "this counter cannot record core 0". The card is about an extra core-0 switch, so the first cut of this instrument was blind to its own subject. Fixed: c0 sites park=0 switch=38 other=20.
2. builtin.cpu.arch == .aarch64 is not "this is the guest" on an Apple silicon host. My new dump was guarded on arch alone, so it printed into the host tests' mock console and broke scheduler: worker report snapshots once and prints from the shell side. builtin.is_test is the discriminator that means what I wanted. Caught by zig build test (3441/3441 green again after the fix).

The card's premise is not supported: the boot does not starve

The failing run prints 451,721 smp: secondary runs= lines. I read the tail rather than the count, and the shell gets out of that drain and keeps working:

smp: secondary runs=451721 task=worker
smp: steal runs=2 task=NOTEPAD.BIN from=0
tasks user-el0 exited status=7
tasks user-exec sleeping 2 ticks
dui tile 2

Every one of the 451,721 lines was printed (drained == staged) and the shell proceeded into script2. It is not stuck in the drain loop and it is not starved — and the last line of the boot is still script2's first command, which is also where the two smaller runs end (secondary-run lines: 7 and 9).

The fatal event, named by the host

FAILURE: VM ended before the expected transcript appeared (state=3).

state=3 is VZVirtualMachine.State.error. The runner has no virtualMachine(_:didStopWithError:) delegate, so VZ reports no reason — I checked, it only prints the raw state. Every failing run ends identically: dui tile 2 → wnd: present → VM error.

And there is no [EXC] block — 0 in all three runs — despite the kernel routing sync exceptions through report_writer (exceptions.zig), which would print. So the guest did not take a synchronous exception it could report. The death is silent at the kernel's own reporting layer.

The decisive experiment: withhold the input, keep everything else

tmp-wnd5-B.spec runs the identical boot with --script2-delay 120 (five times the ~25 s at which boot A dies), so nothing but the script2 traffic changes:

	run A (script2-delay 20)	run B (script2-delay 120)
heartbeats survived to	tick 25	tick 120 (8 heartbeats)
secondary-run lines	451,721	489,187
died at	dui tile 2	dui tile 2 + wnd: present

The guest sat 120 seconds inside a 489k-line staging storm with the nudge armed the whole time and stayed healthy, then died the instant dui tile 2 arrived. So the storm is survivable and is not the killer; the trigger is the script2 WM dui path. The card currently attributes the death to the extra core-0 switch starving the boot — that is now measured and false.

The nudge itself measures clean

• Not storming, not coalescing hard: nudge armed=19..21, coalesced=1, nudge_req==disp (20/20) over 20 s. All on core 0 (nudge c1=0).
• Wall clock exact: ticks=20 at cntpct=486,449,908 (20.27 s at 24 MHz) with period_ticks=24,000,000 — 1 Hz to the sample. deadline_ahead≈23,991,335 at a period boundary, i.e. the comparator is a full period out, not mis-programmed.
• The extra rotation, at last measured: one per second, and it is idle → shell (period tick) then, ~2.4 ms later, shell → user-exec (nudge). Task ids decoded against the live task table: 0:shell 1:worker 2: 3:user-exec 4:user-exec; 10 is idle_id (max_tasks-1), not a garbage slot — I checked before concluding, having nearly read it the other way.
• 32 logged rotations: own-ring depth 2 after the preempted task rejoins, every one; spsr always EL1h with IRQs enabled. Two rotations landed inside a console write (cd=2) — but so did a period tick, so that is not yet a discriminator.

What this changes, and the next step

Two symptoms, previously conflated, and only one is fatal: (a) a survivable staging storm, (b) a silent VM-level death on the WM dui path. The card's title, symptom table and bisection all read as if (a) is what ends the boot; the evidence says (b) does.

The next step is forensics, not scheduling: the killer leaves no trace because the kernel has no IRQ-context-safe path to record one before the VM errors. Something cheap and decisive is a minimal fault/state recorder into RAM plus a host-side post-mortem read, so the last instant survives the death instead of being inferred from the line before it.

Scaffolding is temporary and uncommitted (3 files dirty); it is deliberately not a merge candidate.

[drawmeanelephant]

The recorder exists, and this is what it says

Run with the recorder armed on the nudge tree (PR #1255's commit bc89e9c
cherry-picked onto a scratch tree at 7c617b9, live-wnd5-gate2-policy's
dui tile 2 traffic, script2-delay 20). It died — and for the first time it
said why.

The host half: the reason that was always there and was being thrown away

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=Internal Virtualization error.
NSLocalizedFailureReason=The virtual machine stopped unexpectedly.}
vm-stop: state=3 reason=domain=VZErrorDomain code=1 …

code=1 in VZErrorDomain is VZErrorInternal. That reframes the whole
investigation: VZ aborted the VM, the guest did not fault. It is now
explained why no [EXC] block ever appeared and why the tombstone path
never ran — there was no synchronous exception to take, because the
process was not the guest's. state=3 was never the mystery; the missing
half was this line, and the runner was discarding it by setting no
VZVirtualMachineDelegate.

The guest half: the last instant

quantity	value
serial log lines	507,829
smp: secondary runs= lines	507,457 (storm starts at line 103)
fx: records emitted	240 (229 of them during the storm)
last fx: line	line 460,772
storm lines after the last record	47,057
last serial line	wnd: present
[EXC] blocks	0

Last records (site, core, seq, cntpct; CNTFRQ 24 MHz, arg=10 is the
idle task, arg=0 the shell):

irq    core=0 seq=192 t=967120420 arg=30
wake   core=0 seq=193 t=967163013 arg=3
rotate core=0 seq=194 t=967163121 arg=0     leaving shell
irq    core=1 seq=42  t=967178881 arg=30
irq    core=0 seq=195 t=967240352 arg=30
rotate core=0 seq=196 t=967240501 arg=10    leaving idle   <- LAST RECORD

The mechanism does what it claims. In the last full beat: the period
PPI at t=967,120,420, then a wake 1.77 ms later (t=967,163,013), served by
a rotation 4.5 µs after that. The 1 Hz beat is intact across the run
(rotate 191 → 194 is 23.96e6 counts = 998 ms), and in the final 3.2 ms
window there are two core-0 rotations — the extra switch, live.

What the silent tail says

The irq probe sits in irq_dispatch() immediately after gic.ack() and
the spurious check. So after t=967,240,501 no interrupt was acked and
dispatched on either core, while the guest went on to print 47,057 more
console lines. The drain was demonstrably live in exactly that window (229
of the 240 records were emitted during the storm), so that is not a
recorder artefact.

That is a sharper place to look than "an extra context switch starves the
boot": the trace says the interrupt delivery itself stops, ~40 s of
counter time in, on both cores, with the guest still executing. Two
readings remain open, and they are separable:

1. the PPIs genuinely stop being delivered or taken (GIC state, priority
   masking, or a comparator/period_deadline clobber — this WIP revision
   is known to write the shared period_deadline from every core); or
2. interrupts are still taken but the note is not reached — which the
   dispatch-site placement argues against, but does not exclude.

The measurement that separates them is a record taken before gic.ack()
(i.e. at exception entry) rather than after it, plus a periodic
counter-only sample that needs no console line to reach serial. Both are
now possible; neither existed this morning.

Caveats, stated

• The re-run went through my own scratch spec, whose forensics: enabled=1
  assertion was simply wrong about the output format (forensics on prints
  forensics: on (records prefix the next console line)). The gate line
  "A: FAIL" is that typo, not the feature — the python assert that read
  the trace PASSED.
• The death is intermittent (earlier this session: FAIL on one run, PASS on
  the next with identical inputs), so one run is one sample. The reason line
  is deterministic given a death; the death is not.
• The scratch tree is not a merge candidate and is not proposed as one. The
  resolution I used is committed on scratch/1278-nudge-dying-boot
  (unpushed) so the diagnostic is re-runnable, and the recorder itself is
  PR Forensics recorder: a dying boot names its own last instant (#1278) #1281.

[drawmeanelephant]

Settled: the PPIs are delivered AND recorded to the last second — the death is not guest-side

Probes added for this run: entry (exception entry, before
gic.ack()), rearm (comparator programmed, arg = the programmed
delta), spur (spurious ack — zero for the whole run), and a
console-free periodic sample from the shell idle loop (every 4 ticks,
self-draining, needs no console line to reach serial). Tree: nudge +
recorder + probes, one run to a fresh death at the same trigger.

The two readings from the last comment, answered

The last comment left two readings of the silent tail: (1) the timer PPIs
genuinely stop being delivered or taken, or (2) they are still taken but
the irq note is not reached. The trace rules out both.

• entry records continue on both cores — core 0 to t=558,462,714,
  core 1 to t=558,402,107 — i.e. to within ~1.2 ms of the final
  console line (wnd: present, the death instant). Zero spurious acks
  all run: every entry is a real interrupt, and the post-ack irq records
  appear immediately (23–37 ns later) every time.
• The re-arm probe shows both comparators were reprogrammed with a sane
  24,000,000-tick (1.000 s) deadline on their final entries
  (core 0 t=558,402,194, core 1 t=558,402,191). No gap, no clobber.
• The console-free sample — the part that cannot be explained away by
  console traffic — fired on cadence through the entire storm:
  arg = 4, 8, 12, 16, 20 ticks, the last at t=534,348,808, followed by a
  final period beat at t=558.46 M. The guest was executing, scheduling,
  and taking interrupts past every sample.

Interrupt delivery is intact to the end. The earlier "47,057 lines with no
irq record" reading was an artifact of the drain being console-driven: in
this run the storm's last 618 lines still carry 217 fx records. Same
death, same trigger, no silence.

What the final second actually contains

22.2645s entry core=0 arg=1   ← period PPI
22.2670s entry core=0 arg=1   ← nudge 2.5 ms later
...
23.2668s entry core=0 arg=1   ← period PPI (delta 1.0022s — exactly on beat)
23.2693s entry core=0 arg=1   ← nudge (delta 0.0025s — the design working)
23.2695s rotate core=0 arg=10 ← rotation away from idle
      ...9 worker-report lines, then the script2 traffic...
23.2712s? wnd: present        ← last line; VZ: VZErrorDomain code=1

No missed period beat anywhere in the run: every beat-to-beat delta is
1.000–1.002 s, right through the death. The nudge mechanism measures
clean: the 2.5 ms pair recurs at every boundary, healthy, to the end.

The conclusion, and what it changes

Three independent clocks — core-0 exception entry, core-1 exception entry,
and the 24 MHz cntpct timestamps themselves — all agree the guest was
healthy and mid-beat when VZ killed it. The scheduler starvation the
storm visually suggests is not what ends the boot; the storm is a
co-symptom (and was already shown survivable: 120 s of it in an earlier
run, then death only on dui tile 2). What remains, by elimination, is a
host-side VZ fault: VZErrorDomain code=1 is VZ's own internal error,
and nothing observable in the guest now contradicts it.

The guest-side investigation path — more probes, more state, better
traces — has hit its measurement floor. The next step is on the host:
either reproduce with Apple's official runner for the same image
(every gate here uses this repo's launcher, so a divergence would itself
be a finding), or take it to Apple with the pinned artifact: reproducible
guest image, exact trigger, code=1, and a 23-second counter-accurate
guest trace showing a healthy machine at the death instant. PR #1255
stays the pinned reproduction; the probes land with #1281's follow-up.

Caveat, unchanged: the death is intermittent (one run in two fails), so
this is one representative sample — but the question this run answered
(delivered vs recorded) is now closed, and every future dying boot will
carry these probes' answer with it.

[drawmeanelephant]

Probes landed — PR #1284

The probe set this card's investigation needed is up as PR #1284 (Closes #1261): entry before GIC consumption, spur on the spurious early-return, rearm with the programmed delta, and a console-free shot sample — every site pinned by the extended live-forensics gate.

Settled by measurement (twice, on the scratch dying-boot tree): the PPIs are delivered AND recorded to the last second — the death is not guest-side. entry cadence matches the 1 Hz timer to the end, spurious acks are zero, rearm args are exactly 24,000,000 (a 1 s comparator at 24 MHz), and the samples march at 4.0 s spacing through the final second. The host names the killer: VZErrorDomain code=1 — VZ aborts the VM rather than the guest faulting, which is why no [EXC] block and no tombstone ever appeared.

Two extra findings came out of the landing:

1. The gate caught a real sampler bug pre-merge: the first shot clock was timer.irq_ticks — shared by both cores' PPIs and reset by re-init paths (it went 1 → 0 in early boot) — and the census came back shot: 6624. The shipped clock is cntpct()/freq.
2. The counter itself is not monotonic for the first ~0.9 s under VZ (a ~0.1 s backward step at t≈0.89 s, observed twice). Any trace sorting t= across the first second of a boot is misordered.

Follow-on (which guest action makes VZ abort, and whether the abort can be surfaced as a reason): #1287.