Drain staged follow-ups once, in order, and let watch --off take its wakes (#304) - #309
Conversation
|
Gate on 7478915, private DerivedData: Fail-without / pass-with, on the branch base's Not in scope: #306 (why the queue fills) — this makes the drain correct, not less starved. |
…wakes (#304) drainPendingFollowUps iterated a copy of the pending list, awaited per item, and finished by assigning pendingFollowUps = remaining. The presence poll re-entered it every fifteen seconds, so two drains overlapped: both delivered the same items, and the later assignment overwrote the earlier drain's bookkeeping — mail duplicated, mail dropped, mail out of order. The drain is now non-reentrant and takes-and-clears in one actor step, delivering from the local batch and folding its retries back in front of whatever was queued meanwhile. Watcher wakes carry the post they are about: mail watch --off drops the wakes still staged for that watcher, and a wake for a post the reader has since read is not sent. Closes #304. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01DeGL2CxuGmq16RSZpJYm2N
7478915 to
79dd8d9
Compare
|
Head moved to 79dd8d9 — test-only: the drain tests attached a bare |
|
Gate on 79dd8d9, private DerivedData: |
Independent review — I would merge this, with one small follow-up and one caveat about #306Reviewed in my own worktree ( Gate (private DerivedData,
|
| Step | Exit | Result |
|---|---|---|
xcodebuild -scheme graphcode … test |
0 |
Test run with 1651 tests in 173 suites passed, ** TEST SUCCEEDED ** |
xcodebuild -scheme graphcode-cli … build |
0 |
✅ |
xcodebuild -scheme graphcoded … build |
0 |
✅ |
swiftlint lint |
0 |
0 error: |
swift format lint --recursive --strict |
0 |
clean |
scripts/cli-smoke.sh |
0 |
five verbs ok against a throwaway daemon |
| Linux build | pass | run 34070361927 |
⚠️ Trap for the next reviewer, not a defect here:worktree-build-checktells you to symlink.buildto the main checkout, andcli-smoke.shguards itsswift buildon[ -x "$bin/graphcode" ]. So the smoke run silently exercised a Sep-1 binary from the shared.buildand reported three falseFAILs (unknown command: mail). Replacing the symlink with a real dir and runningswift buildgave the exit 0 above. The two skills collide.
The three symptoms, verified separately — all three genuinely fixed
Your tests are not vacuous. Checking out origin/main's GraphStore.swift under the same test files, all three of yours fail, and so do two of mine that pass on this head:
| Property | On main |
On this head |
|---|---|---|
| Exactly once — 3 staged + 1 staged mid-overlap | 12 deliveries for 4 messages (each ×3) | exactly 4 ✅ |
| In order under overlap | [1, 2, 1, 1, 3, 2, 2, late, 3, 3, late, late] |
[1, 2, 3, late] ✅ |
| Staged during an overlapping drain | duplicated, order broken | arrives once, last ✅ |
--off racing an in-flight drain (queue already taken into the local batch) |
wake delivered twice | dropped ✅ |
| Wake for an already-read post | delivered | not sent ✅ |
That last row matters: --off's removeAll cannot see a batch a drain has already taken, and I expected that to leak. It does not, because the delivery-time guard re-checks mailroomWatch != nil per item. Belt and braces, and the braces are the ones that hold.
Starvation: retries-in-front cannot starve a newly staged message. Each drain takes the whole list — retries and new alike — and visits every element; front-placement changes order, not reachability. ✅
In-flight guard exit paths: the defer is registered after the guard and after the flag is set, so an early return never clears a flag it did not set; nothing in the drain throws, and Swift cancellation does not unwind an async function. The flag clears on every path that returns. No wedge from a throw. ✅
What I could still break — two ordering holes survive, so "in order" in the title is overstated
Both are pre-existing (they fail on main identically, so neither is a regression), but both produce #304's stated reordering symptom, so I don't think #304 should be closed as fully fixed without a word about them.
1. A later follow-up jumps the whole queue. Two different readings decide "deliver now": deliversLater consults the cached node.presence the poll last wrote, while the drain takes a live reading per item. When they disagree — poll saw idle, session is mid-tool-call when the drain asks — three messages already queued are retried while a fourth staged afterwards bypasses the queue and is typed in first. Deterministic, no overlap involved:
delivered == ["staged late"] // while "staged 1", "staged 2", "staged 3" sit queued
2. A turn ending mid-drain reorders the same loop's queue. The presence read is per item, so busy for item 1 and idle for item 2 delivers 2 and 3 and retries 1 — and retries-in-front then delivers 1 on the next drain, after the two that overtook it:
delivered == ["staged 2", "staged 3", "staged 1"]
That is literally #304's "#357 delivered before #347", reached with a single drain, so the in-flight guard cannot see it. Cheap fix: once an item for a node goes to remaining, continue past the rest of that node's items in this drain, and have deliversLater return true whenever anything is already queued for the target.
One real gap in the --off half: re-scoping keeps the abandoned topic's wakes
--off drops staged wakes; watch --on --topic other does not — the removeAll lives only in the else branch, and the delivery-time guard asks whether a watch stands, never watch.matches(post.topic). #304 records the watch being "re-scoped to a different topic in between" as part of the observed sequence, so this is squarely in scope:
// watch --topic alpha; post to alpha; watch --topic beta; go idle
delivered contains "an alpha post" // ✗ — wake for a topic no longer watched
The guard already has the post id and graph.mailroom still holds the post, so this is a small addition to the existing if let postID block rather than new state. I'd take this one before merge if it's easy; it's the only finding that's inside the PR's own claim surface.
Two smaller notes
- No timeout on the presence read.
onReadPresence→PTYProcessSession.waitCollectingOutput()has no deadline, andssh'sConnectTimeout=10bounds the connect, not a hung remote command. Anawaitthat never returns now holdsisDrainingFollowUpsforever and freezes the queue permanently. I checked whether the guard makes this worse thanmainand it does not —mainre-enters into the same hang and additionally re-delivers everything before the stuck item — but a bounded read is worth a follow-up, because "frozen" and "working" look identical from outside. - Latency. A message staged during a drain now waits for the next drain (≤15 s poll, or the next command's
drainAndBroadcast) rather than being picked up by the re-entrant one. Against mail watch --off leaves staged deliveries queued, and they can duplicate #304's measured 511–835 s lag that is noise; a boundedwhile !pendingFollowUps.isEmptyre-loop at the end would remove it entirely. - nit: the queue's doc paragraph ("Queued rather than delivered… the content is in the target's memory log…") now attaches to
struct PendingFollowUpinstead of topendingFollowUps.
Is this worth shipping while #306 is open?
Ship it, but ship them together. With #306 open this fix is correct and unobservable on the default backend: a Claude Code loop idle over 60 s sits at presence == awaitingInput, MessageBus.deliverability returns .targetBusyWithACheck, and the drain appends to remaining and continues — it never reaches the presence read this PR governs. So on Claude Code loops nothing is delivered either way, and no field observation can distinguish this fix from main.
Merging it alone is still right: it is a strict improvement, it is what makes the backlog safe to deliver at all once #306 unblocks it, and landing the drain fix after #306 would mean shipping one beta in which a large stale queue drains through the buggy path — exactly the 18-post window that produced the duplicates and the 5 losses. Order matters: #309 first or same beta, never #306 first. But the release note shouldn't claim #304 is verified until a beta carries both and an end-to-end watcher measures 18 of 18, in order, once each.
The five probes I ran (drop into graphcode/Tests/, tuist generate first — new test files are invisible until you do)
Three fail on this head (the two ordering holes and the re-scope gap); all five fail on main. Shared harness: a scripted onReadPresence that is busy by default and hands out a queued list of readings for the target, so every case is deterministic with no sleep-based racing except the two that deliberately overlap two polls.
/// Two readings decide "deliver now": `deliversLater` reads the cached presence, the
/// drain reads live per item. When they disagree, a later message bypasses the queue.
@Test
func aLaterFollowUpDoesNotBypassOnesAlreadyQueuedForTheSameLoop() async {
let (store, target, sender) = await makeStore(readings: readings, delivered: delivered)
await stage(store, target, sender, ["staged 1", "staged 2", "staged 3"])
await readings.scriptTargetReads([.idle]) // refresh caches idle; drain reads busy
await store.pollPresence()
#expect(delivered.value.isEmpty)
await stage(store, target, sender, ["staged late"])
#expect(texts(delivered) == []) // actual: ["staged late"]
}
/// The turn ends between item 1 and item 2 of a single drain.
@Test
func aRetriedMessageIsNotOvertakenByALaterOneForTheSameLoop() async {
let (store, target, sender) = await makeStore(readings: readings, delivered: delivered)
await stage(store, target, sender, ["staged 1", "staged 2", "staged 3"])
await readings.scriptTargetReads([.busy, .busy, .idle, .idle])
await store.pollPresence()
await readings.scriptTargetReads([.idle, .idle, .idle, .idle])
await store.pollPresence()
// actual: ["staged 2", "staged 3", "staged 1"]
#expect(texts(delivered) == ["staged 1", "staged 2", "staged 3"])
}
/// #304's "re-scoped to a different topic in between".
@Test
func rescopingAWatchDropsTheWakesForTheTopicItLeft() async {
let (store, target, sender) = await makeStore(readings: readings, delivered: delivered)
await store.handle(.mailroomWatch(on: true, topic: "alpha", from: target))
await store.handle(.mailroomPost(text: "an alpha post", topic: "alpha", from: sender))
await store.handle(.mailroomWatch(on: true, topic: "beta", from: target))
await readings.scriptTargetReads(Array(repeating: .idle, count: 20))
await store.pollPresence()
#expect(!delivered.value.contains { $0.contains("an alpha post") }) // fails
}The other two — aMessageStagedDuringADrainArrivesLastNotMerelyOnce (asserts the full
order [1, 2, 3, late], not just "once") and watchOffLandingDuringADrainStillDropsTheWake
(--off landing while the batch is already taken) — pass on this head and fail on
main with 12 deliveries for 4 messages and 4 for 2 respectively. They're worth adding to
FollowUpDrainTests as-is: the existing overlap test asserts prefix(3) and per-message
counts, which would not have caught a late message arriving first.
An idle loop stays idle when Claude Code says it is idle (#306) Claude Code fires an `idle_prompt` notification about sixty seconds after a turn ends, and the hook mapped every notification to `awaitingInput`. Follow-ups and watch wakes deliver only on `presence == idle`. So a loop settled to idle and then its own idle notification flipped it out of the one state that receives mail — measured at 60.0s and 60.1s on two loops, with 0 of 18 watched posts delivered. `mail watch` and `node send --follow-up` were therefore silently dead for any Claude Code loop idle over a minute, which is most loops most of the time. The feature reported itself armed and delivered nothing. Filtered on the notification kind rather than by ignoring the hook: `idle_prompt` confirms idle, `permission_prompt` and `elicitation_dialog` stay `awaitingInput`, `auth_success` leaves presence alone, and an unknown or absent kind keeps today's behaviour. That distinction is the point — a loop that genuinely needs a human must stay visible, and fixing silence in one direction by creating it in the other would have been worse than the bug. Proven end to end rather than at the hook: the real generated reporter runs under /bin/sh against a recording fake zmx for each kind, and a staged wake plus a follow-up arrive on the presence written for `idle_prompt` and do not on the one written for a permission prompt. The audit that came with it found the second symptom: every needs-you surface was over-reporting for loops idle past a minute. `MessageBus` keys on `LoopState`, so a plain `node send` was unaffected — which is why direct sends landed all day while watch wakes did not. Gated on the merged result together with #309: 1662 tests / 175 suites / 0 failures, no restarts, CLI smoke green. Closes #306.
The defect
drainPendingFollowUps— the delivery of staged--follow-upmessages and Mailroom watcher wakes to a loop once it goes idle — iterated a copy of the pending list, awaited a presence read and a delivery per item, and finished by assigningpendingFollowUps = remaining. The presence poll calls it every fifteen seconds, so a second drain routinely started while the first was suspended mid-delivery. Two overlapping drains both delivered the same items (the duplicates #304 saw), and the later one's final assignment overwrote the earlier one's — dropping whatever had been appended meanwhile and whatever the other drain had retained (the 5 of 18 that never arrived, and the reordering). Separately,mail watch --offremoved the subscription but not the wakes already staged, which then arrived for minutes — past the reader's cursor.The change
PendingFollowUp.watchedPostID).mail watch --offdrops the wakes still staged for that watcher — a peer's--follow-upmessage to the same loop is not a wake and stays. And at delivery time a wake is only owed while the watch stands and the post is still unread: a reader whose cursor has passed the post (an inbox in between) is not woken for it.Verification
Gate: full Xcode suite (gate on this head in flight; numbers and exit codes in a comment when it completes), swiftlint 0 errors, swift-format clean,
graphcodedandgraphcode-clischemes build; SwiftPM build and CLI smoke pass.FollowUpDrainTests: two polls overlapping on a slow idle reading deliver three staged messages exactly once each and in order, and a fourth staged during the overlap is delivered once afterwards (fails onmain: duplicates and a loss);--offdrops the staged wake and still delivers the peer's follow-up; a wake for a post the reader has since read is not sent.Related: #306 (why the queue fills), #288.
Closes #304.
🤖 Generated with Claude Code
https://claude.ai/code/session_01DeGL2CxuGmq16RSZpJYm2N