Skip to content

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

Draft
drawmeanelephant wants to merge 1 commit into
mainfrom
agent/buffy/wmp3-nudge-recovered
Draft

drawmeanelephant wants to merge 1 commit into
mainfrom
agent/buffy/wmp3-nudge-recovered

Conversation

@drawmeanelephant

@drawmeanelephant drawmeanelephant commented Sep 14, 2026

Copy link
Copy Markdown
Owner

DRAFT / WIP — parked, not a merge candidate

Reproduction artifact for #1252 (WMP card 3, the reschedule nudge). It is not
a closing reference for that card and is not intended to merge as-is.

Read this first: the branch head is knowingly red on
live-wnd5-gate2-policy (PASS 3/3 on mainFAIL 0/4). That is the
finding, not an oversight — see below.

Status update (2026-09-14, #1261).

The blocker is now a card: #1261.
The defect under this PR is no longer described here as "SMP starvation" —
that diagnosis was measured and is wrong. Instrumented boots on the nudge tree:

  • A failing run prints 451,721 smp: secondary runs= lines and the shell
    prints every one (drained == staged), then leaves the drain and
    proceeds into script2. It is not stuck and not starved.
  • With script2 withheld to t=120 s the guest survives 120 s inside a
    489,187-line staging storm with the nudge armed throughout, then dies the
    instant the first dui command lands. So the storm is survivable and the
    trigger is the script2 WM traffic.
  • The death is a silent VM-level .error: the host reports
    VM ended before the expected transcript appeared (state=3), the runner has
    no didStopWithError delegate so VZ gives no reason, and there is no
    [EXC] block even though the kernel routes sync exceptions through
    report_writer and would have printed one. Nothing synchronous was taken.

Everything else here still holds, including the 815 ms → 2.5 ms result and the
seven-probe bisection. Full measurements are on #1261.

This branch is 22 commits behind main and still merges cleanly
(git merge-tree --write-tree origin/main … reports no conflicts). Every check
on this PR is green.

The result this branch exists to reproduce

Same live-wm-pacing spec, running the latency bound the fix earned:

main (card 2, #1250) this branch
input → present avg 815 ms 2.5 ms
input → present max 1005 ms 3.9 ms
tick interval 1000 ms 1034 ms
handoff attempts / done 31 / 30

live-sb6-perf-payoff (the 1 Hz determinism gate) was green throughout, so the
"repair every 1 Hz assumption" half of the card genuinely holds.

Mechanism

The wake funnel (push_home_locked) raises a coalesced reschedule request;
scheduler.request_resched_for(id) pulls core 0's comparator forward ~2 ms
via timer.nudge(), so the same IRQ rotation a period tick uses serves the owed
preemption. A nudge is deliberately not a second: timer.handle() now
returns whether the PPI was the 1 Hz period boundary, and
scheduler.tick(period_tick) gates on_tick (tick_count, sleepers, app timers,
WM pacing, CPU accounting) on it — so sys_sleep(1), heartbeat_every, SB6's
one-tick-per-frame determinism and CPU-limit accounting keep their 1 Hz meaning.

Why it is not shipped — seven probes

live-wnd5-gate2-policy (WND + NOTEPAD, dui orientation chords) goes from
PASS 3/3 on main to FAIL 0/4. The guest does not fault — no
[EXC] parking:, heartbeats exact — the WM keeps presenting while the shell
stops completing dui commands, and the boot dies in
VZVirtualMachine.State.error (state=3).

Corrected (see the status note above and #1261): "starvation" was the wrong
word for it. The staging backlog is survivable — 489,187 lines over 120 s with a
healthy guest — and the fatal event is the WM dui path itself, which ends the
VM without taking a synchronous exception the kernel can report. The seven-probe
table below still stands; only the name of the blocker was wrong.

probe result
timer.nudge() disabled entirely PASS 2/2
comparator pulled forward, no rotation PASS 1/1
full rotation on a nudge FAIL 0/4
targeted handoff (claim only the woken slot) FAIL 3/3
handoff suppressed for wakes raised inside on_tick PASS 2/3 — win gone (827 ms)

The last row is decisive: suppressing the wakes that arrive inside the tick's
own beat (wm_server.on_tick, the WM's kind-18 delivery) fixes the boot and
takes resched_requests from 32 to 1 — it removes exactly the handoffs that
produced the 2.5 ms. The win and the breakage are the same mechanism, and no
subset keeps one without the other.

Two traps for the next attempt

Both look like progress.

  1. A "rotate only if the woken task is the round-robin successor" guard passed
    6/7 purely because the target was being cleared before delivery — it was a
    nudge with no rotation, measuring 807 ms.
  2. The target's lifetime is subtle: the dominant wake is raised from inside
    the period tick, so a rotation-based discharge cleared the handoff the same
    beat had just armed — visible as handoff_attempts=1 out of nudge_served=16.

Defects specific to this revision

  • timer.arm() still writes the shared period_deadline global from every
    core, so core 1 clobbers core 0's deadline. (Fixed on the abandoned working
    tree; not in this commit.)
  • The targeted-handoff / in-tick-arm discrimination is not here.

Evidence

  • Host suite: zig build test172/172 steps, 3441/3441 tests passed;
    zig build rc=0; zig fmt --check clean; inventory-gates --check OK.
  • Class-B: needs VZ hardware (just verify-vz).

History note

This branch was refreshed: it previously carried two raw git stash commits
(On agent/buffy/wmp3-resched-nudge: … / index on …) pushed straight from a
stash, and a stale docs/gate-fleet-inventory.md line that would have reverted
main. It is now one commit on top of current main, with the inventory
re-rendered rather than reverted.

… by an SMP starvation defect

Parked WIP, not a merge candidate. This is the card-3 (#1252) reschedule
nudge as it stood when it measured 815 ms -> 2.5 ms average input-to-present
on live-wm-pacing, kept on a branch so the finding stays reproducible rather
than living only in an issue comment.

Mechanism: the wake funnel (push_home_locked) raises a coalesced reschedule
request; scheduler.request_resched_for(id) pulls core 0's comparator forward
~2 ms via timer.nudge so the SAME IRQ rotation a period tick uses serves the
owed preemption. timer.handle() now reports whether the PPI was the 1 Hz
period boundary and scheduler.tick(period_tick) gates on_tick (tick_count,
sleepers, app timers, WM pacing, CPU accounting) on it, so a nudge does not
advance the wall clock and every 1 Hz assumption keeps its meaning.

Why it is not shipped: an extra core-0 context switch starves the SMP NOTEPAD
boot (live-wnd5-gate2-policy, PASS 3/3 on main -> FAIL 0/4, ending in
VZVirtualMachine.State.error with heartbeats exact and the WM still
presenting). Seven probes bisect it; the win and the breakage are the same
mechanism, and every variant that keeps the win breaks the boot. Full table
and defect list are on issue #1252.

Known defects in THIS revision: timer.arm() still writes the shared
period_deadline global from every core (core 1 clobbers core 0's deadline);
the targeted-handoff / in-tick-arm discrimination is not here.

Refs #1252
@drawmeanelephant
drawmeanelephant force-pushed the agent/buffy/wmp3-nudge-recovered branch from 6701c1d to bc89e9c Compare September 14, 2026 16:10
@drawmeanelephant drawmeanelephant changed the title DRAFT / WIP: WMP card 3 (#1252) — reschedule nudge: 815 ms -> 2.5 ms, blocked by an SMP starvation defect DRAFT / BLOCKED (#1261): WMP card 3 reschedule nudge — 815 ms -> 2.5 ms, blocked by a silent VM death on the WM dui path Sep 14, 2026
@drawmeanelephant

Copy link
Copy Markdown
Owner Author

Verification record (this is the comment that was promised hours ago and never landed)

Re-verified the branch head bc89e9c rather than re-deriving from my notes, and found the one thing that was genuinely unresolved here — a defect in this PR's own description.

The PR was one merge away from closing the card it says it doesn't close

Line 4 of the original body read:

Reproduction artifact for #1252 … It does not close #1252 and is not intended to merge as-is.

GitHub's closing-keyword parser matches the literal substring close #1252. It does not care that the word in front of it is "not". So closingIssuesReferences was [1252] — armed to auto-close #1252, the WMP card 3 claim, on a merge nobody intends to perform. A draft PR whose body explicitly promises it will not close a card, silently set up to close that card, is the kind of thing that only shows up when someone merges it by accident.

Fixed by rewording the sentence; closingIssuesReferences is now [], and a sweep of the whole body for any close|fix|resolve + #N adjacency comes back clean.

Also corrected while I was in there:

What is unchanged and still true

check state
closingIssuesReferences [] (was [1252])
every CI check on this PR pass (incl. both Build jobs and all four vz shards)
merges into today's main clean — git merge-tree --write-tree origin/main agent/buffy/wmp3-nudge-recovered reports no conflicts, despite being 22 commits behind
host suite at the head 172/172 steps, 3441/3441 tests
the 815 ms → 2.5 ms result unchanged, and now corroborated by #1261's instrumentation

The reproduction is pinned by the branch, not by this PR staying open: agent/buffy/wmp3-nudge-recovered exists on origin at bc89e9c, and 71f6118 is a cherry-pick of it on agent/buffy/smp-starvation. Deleting the branch is what would lose the artifact, not closing this.

The blocker's diagnosis, corrected

Instrumented boots on the nudge tree (local class-B, on agent/buffy/smp-starvation):

  • A failing boot prints 451,721 smp: secondary runs= lines, and the shell prints every one (drained == staged) before leaving the drain and proceeding into script2. Nothing is starved or stuck.
  • With script2 withheld to t=120 s the guest survives a full 120 s inside a 489,187-line staging storm with the nudge armed the whole time — and then dies the instant the first dui command arrives. So the storm is survivable, and the trigger is the WM traffic.
  • The death is VM-level and silent: FAILURE: VM ended before the expected transcript appeared (state=3) (VZVirtualMachine.State.error), the runner has no didStopWithError delegate so VZ gives no reason, and there is no [EXC] block although the kernel would have printed one. No synchronous exception was taken.

Full measurements, including the two defects I found in my own instrument, are on #1261.

@drawmeanelephant

Copy link
Copy Markdown
Owner Author

Split landed: the pull-free half is #1276

This PR is now explicitly two halves, and the safe half has its own home.

Landed separately as #1276 (agent/buffy-wmp3d/wmp3-demand, claim #1274): the coalesced reschedule request raised from the wake funnel and discharged at the tail of every core-0 rotation, its four counters, the timer/wm monitor reporting, two host tests for the coalescing rule, and a live non-vacuity assertion on live-wm-pacing. No comparator is moved and no rotation is added.

Live evidence from that tree, both gates local class-B:

live-wm-pacing            PASS 1/1
  M53 pacing OBSERVED: lat_avg_us=778716 lat_max_us=1001334 tick_avg_ms=1001
  M53 resched demand OBSERVED: requests=17 coalesced=0 discharged=17
live-wnd5-gate2-policy    PASS 2/2   <- the boot this branch kills; unaffected there

The latency row is the one that matters for this PR: 778.7 ms average, unchanged from card 1's 786–1216 ms range and card 2's 815 ms, while 17 wakes in a 28 s window each owed a rotation and each was served by the next tick. That is the timer.nudge() disabled entirely → PASS 2/2 probe from #1261's bisection, made permanent.

What stayed here, deliberately: timer.nudge(), the comparator pull, nudge_ticks/nudge_target, the period_deadline restructure, the period_tick/tick(period_tick) threading, and this PR's latency bound. The threading and the nudge counters were the obvious "safe half" candidates and I left them out on purpose — with nothing armed, period_tick is trivially true and those counters would be permanently zero, so they are only safe because they would be dead. Unwired scaffolding for a mechanism that does not exist is not an improvement.

So this PR is unchanged in substance and still the reproduction it says it is. Its remaining content is the comparator pull and the 815 → 2.5 ms measurement, blocked on #1261. The delay between the two halves is now measurable in the open rather than asserted: #1274 counts the demand, and this PR is the thing that would serve it.

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.

1 participant