mail watch --off leaves staged deliveries queued, and they can duplicate

[scgopi]

Found by accident while cleaning up after a test loop, on the shipped 0.1.64-beta2 (build 252).

What happens

A loop watching the Mailroom while it is busy has matching posts staged to its memory rather than typed in live — that is the documented design, the same path a --follow-up message takes. But:

1. graphcode mail watch --off removes the subscription and does not cancel or drain what is already staged.
2. Staged deliveries keep arriving for many minutes afterwards, in strict post order.
3. They arrive even though the reader's cursor is already past them — lastMailroomRead = 353 while posts #276, #277, #280, #281 were still being delivered.
4. At least one was delivered twice (#280 arrived two times).

Evidence

The watching node's persisted state after --off shows no watch at all:

PerfTriage mailroom-related keys: ['lastMailroomRead']
  lastMailroomRead = 353

So the subscription is genuinely gone from the graph, and the deliveries are coming from a queue that --off does not reach.

Sequence observed: filler 1 of 70, 2 of 70, 3, 4, 5, 5 (duplicate), 6 … continuing after the watch was turned off twice, re-scoped to a different topic in between, and the inbox marked read to #353.

Why it matters

• There is no way to stop it. --off is the only control, and it does not apply to in-flight deliveries. A loop that accidentally subscribes to a busy topic will be fed that backlog into its context regardless of what its operator does — and for an agent session, that is context budget spent on posts it has already read.
• The duplicate is the more serious half. Delivery is supposed to be at-most-once into a session; a post arriving twice means a watcher cannot treat delivery as a signal to act exactly once.
• Redundant with the cursor: delivering posts below lastMailroomRead contradicts what the cursor is for.

Suggested behaviour

• --off should drop staged-but-undelivered posts for that watcher, not just the subscription.
• A staged post whose id is at or below the reader's lastMailroomRead should be dropped rather than delivered.
• Delivery should be idempotent per post id per watcher.

Related

This is the delivery half of the Mailroom, which #293 did not touch — that PR rewrote how mail is read. Every review in the #288 series concentrated on the read path, so delivery has had no scrutiny. MailWatcher was created to test exactly this and found the ordering side; this is the teardown side.

Related: #288, #293

🤖 Generated with Claude Code

https://claude.ai/code/session_01BP43ags4cn8fq2ZZdv85J9

[scgopi]

Second confirmed duplicate, from continued observation while the queue drains.

Post #282 ("MailPruning e2e-prune filler 7 of 70") was delivered twice, several minutes apart, to a session whose watch had already been turned off and whose lastMailroomRead is 353 — far past #282.

That is now two independently observed duplicates in one drain:

Post	Deliveries
#280	2
#282	2

Both are posts the reader's cursor is already past, delivered to a node with no watch recorded in the persisted graph.

So the duplicate is not a one-off race. Whatever holds the staged queue is re-delivering entries rather than consuming them, and neither --off nor advancing the cursor drains it.

Worth adding to the suggested behaviour in the issue body: staged deliveries should be consumed on delivery, not merely read — a queue that can replay an entry is one a watcher can never treat as a signal to act once.

[scgopi]

Root cause found, and it is deeper than this issue described. Reported by the MailWatcher end-to-end loop after observing a full delivery window on 0.1.64-beta2.

drainPendingFollowUps is reentrant, and loses updates

The drain awaits the actor per item. So two drains — the presence poll's and the settle path's — interleave over one snapshot of the pending list, and the final pendingFollowUps = remaining write is a lost update: whichever drain finishes last overwrites what the other consumed or left.

That single defect produces all three symptoms, which is why they looked like separate bugs:

Symptom	Cause
Duplicates (this issue — #280, #282, #283 each twice)	An item consumed by one drain is restored by the other's stale write
Skips — 5 of 18 posts never arrived at all (#345, #347, #349, #351, #355)	An item is dropped from the list by a stale write before being delivered
Reordering — #357 delivered before #347 and #356	Interleaved drains deliver from different points in the snapshot

Measured window: 13 of 18 delivered, lag 511–835 s, nothing live.

So the duplicate was the visible half of a lost update

I filed this issue believing the queue "replays entries rather than consuming them". That is a symptom, not the mechanism. A queue that can lose an update can equally drop an item — and the dropped ones are invisible, which is why I only noticed the duplicates.

That makes this materially worse than filed: mail can be silently lost, not merely repeated.

Relationship to #306

#306 is why the queue fills at all — a Claude Code loop idle over 60 s flips to awaitingInput and never reaches the presence == idle state the drain requires. This issue is what the drain then does wrong to the backlog once it does run. Fixing #306 alone would make the queue shorter and the race rarer, not correct.

Suggested fix

Make the drain non-reentrant and consume atomically: take the pending list and clear it in one actor step, then deliver from the local copy, rather than awaiting per item against shared state. An in-flight guard so two drains cannot overlap at all is the smaller change and probably sufficient.

--off still printed stopped watching; whether the 5 missing posts can still arrive after it was not tested — the loop was stopped first.

Related: #306, #288

[scgopi]

Reopening. I closed this with #309's merge; the independent review says plainly that it should not close as fully fixed, and it is right.

What #309 genuinely fixed — verified, not asserted

The reviewer checked out origin/main's GraphStore.swift into its own worktree and reran the author's tests against both, so the before/after is measured:

	deliveries for 4 messages	order
main	12	[1,2,1,1,3,2,2,late,3,3,late,late]
#309	4	[1,2,3,late]

Duplicates and loss are genuinely fixed. That is the larger half of this issue and it is done.

What remains

Three of the reviewer's five probes still fail on the PR head — and also on main, so these are pre-existing rather than regressions:

1. A later follow-up jumps the queue. deliversLater reads the cached node.presence; the drain reads live per item. When they disagree, a message staged afterwards is delivered first. (Filed as A follow-up staged later can jump the queue, and the presence read it depends on has no deadline #311.)
2. A turn ending mid-drain reorders to [2,3,1]. This is exactly this issue's original #357 before #347 symptom, reached with a single drain — so Drain staged follow-ups once, in order, and let watch --off take its wakes (#304) #309's in-flight guard cannot see it. The guard addresses overlap; this needs no overlap.
3. watch --on --topic other keeps the abandoned topic's staged wakes on a re-scope.

So "in order" in #309's title is overstated. Ordering is improved and not correct.

Scope of this issue now

Duplicates and loss: fixed. Ordering: not fixed — item 2 above is the live remainder, and it is the same symptom this issue was filed for.

Also confirmed, and worth recording because it was the reason for landing the two together: no wedge is possible from #309's guard — the defer is registered after the flag is set, nothing between throws, and cancellation does not unwind. The residual risk is onReadPresence having no timeout (#311), where main re-enters the same hang and duplicates, so #309 is not worse.

#306's merge resolves the interaction the reviewer flagged: with #306 open, #309's fix was correct but unobservable on Claude Code loops, because awaitingInput returns targetBusyWithACheck and the drain never reaches the presence read #309 governs.

Related: #309, #310, #311

[scgopi]

Ordering characterised: all three remainders reproduce deterministically, none blocks stable

Probes on main @ 8dbf548 (0.1.64-beta5), branch probe/304-ordering (053f83f), graphcode/Tests/OrderingProbeTests.swift. Every presence read is scripted per node, so these are deterministic reproductions, not races that happened to land — identical output on three consecutive runs.

What reproduces

Probe	Claim	Delivered order	Reproduces
A	A turn ending mid-drain reorders, single drain	[2, 1, 3]	✅ 3/3
B	A later follow-up jumps the queue (cached vs live presence)	[second, first]	✅ 3/3
D	…and it needs no exotic timing (see below)	[2, third, 1]	✅ 3/3
C	watch --on --topic beta keeps the abandoned alpha wake	alpha wake delivered	✅ 3/3
E	--off then --on --topic beta is clean	nothing delivered	✅ passes — this is the workaround

A — the reorder is a continue, not a race

guard presence == .idle else {
  remaining.append(pending)
  continue          // ← walks on to the next item instead of stopping
}

Once item k is requeued, items k+1…n are still attempted. Any busy→idle flip inside the walk reorders. The window is one presence read: measured on this machine, zmx ls 7.2 ms + zmx get <session> presence 2.8 ms, so ~10 ms per item plus PTY setup. Narrow, and #309's in-flight guard cannot see it because there is no second drain.

D — the queue jump is the common case, not the corner

This is the part worth correcting in the issue's framing. deliversLater reads the cached node.presence, which only refreshPresence writes — once per 15 s poll. And delivering an item is itself what makes the target busy. So the ordinary shape of a partly-drained queue is:

1. Poll's refresh reads idle → cache = idle
2. Drain delivers item 1 → the session is now busy
3. Item 2's live read says busy → requeued
4. Any follow-up arriving in the next ≤15 s consults the stale idle cache → typed straight in, ahead of item 2

No flip has to be caught in a 10 ms window. The precondition is guaranteed whenever a drain hands over anything with more still queued. Probe D shows both defects firing together: [staged 2, third, staged 1].

So of the two, B/D (#311) is materially more likely than A, by roughly three orders of magnitude in window size (15 s vs 10 ms).

Consequence — mostly cosmetic, with one real edge

The honest answer to "does a reordered follow-up mislead a loop?" is usually no, for three reasons that are worth recording because they are what keeps this off the blocker list:

Mitigation	Verified
A wake is a doorbell, not a letter. The text is mailroom — new post #N (topic) … — read it with: graphcode mail inbox <path>. The loop then reads its inbox, which serves unread posts in id order (unread(in: posts, since: lastRead)) and is topic-agnostic.	Mailroom.swift:400
The memory log keeps true order. recordMemory(nodeID, "follow-up staged: …") runs at stage time, before the queue append — so the durable record is correctly ordered even when the typed-in copy is not.	GraphStore.swift:2656
The Mailroom keeps true order. Every direct message is mirrored to topic direct on arrival, before the staging decision.	GraphStore.swift:2640

Reordering therefore corrupts only the transient typed-in stream, never any durable record, and for Mailroom wakes — which is what this issue was filed about — the payload is a pointer that resolves in the correct order regardless.

Where it does bite: two or more node send --follow-up messages to the same busy target, where the content is inline and the second may qualify the first ("the API changed under you" / "stop, I already fixed that file"). Reversed, that genuinely misleads. Measured against this graph's live Mailroom (391 posts, read-only listing): of 165 consecutive direct-message pairs to a single target, 28 (17%) land in the same minute and 45 (27%) within a minute — so the burst regime is real, not hypothetical, though it needs a partial drain on top.

C — stale-topic wake: lowest severity of the three

mailroomWatch(on:) overwrites the subscription and never touches the queue, and the drain's guard asks only whether some watch stands — never whether it still matches the post's topic:

guard node.mailroomWatch != nil, (node.lastMailroomRead ?? 0) < postID else { continue }

Consequence is bounded: the wake names the abandoned topic in its own text, the inbox it points at is topic-agnostic anyway, and the cost is context spend on a doorbell the loop did not want. It is the same shape as the 70-filler-post episode that opened this issue.

Workaround today (probe E, passing): spell a re-scope as two commands — mail watch --off then mail watch --on --topic beta. --off is the only path that reaches the staged wakes.

Verdict on a stable release

Not a blocker. Against the bar that mattered for #309:

Property	Status
Mail lost	❌ none — every probe delivered every message eventually
Mail duplicated	❌ none
Drain wedged	❌ none — requeued items drain on the next 15 s poll
Order of durable records	✅ correct (memory log + Mailroom)
Order of the live typed-in stream	⚠️ wrong — the remainder

#309 fixed the half that could corrupt state. What is left degrades a convenience: a loop may hear two things in the wrong order in its live pane, while both its written records — and the inbox it is being told to read — are correct. That is a real defect and worth fixing, but it is not a reason to hold a stable tag.

Suggested fix, for whoever takes it (the continue and the cache are one change): stop the walk at the first requeue rather than continuing, and have deliversLater consult the same live read the drain uses — or, cheaper and sufficient, treat "this node has anything pending" as itself a reason to stage, so nothing can ever overtake a queued item.

Related: #309, #311

🤖 Generated with Claude Code

https://claude.ai/code/session_0176dTYpDj8STu8pmkx1KYMu

[scgopi]

PR #316 carries MailOrderingCheck's five probes (probe/304-ordering@053f83f, OrderingProbeTests.swift) verbatim; all five pass there unchanged, alongside five tests of my own. Two answers to its note:

On the suggested fix. I took the second half — deliversLater no longer consults node.presence at all — and went one step further than "any already-pending item is itself a reason to stage": every live target's follow-up is staged, so the drain is the only place presence is read and there is no second reading left to disagree with. Cached-vs-live is deleted rather than narrowed.

I did not take the first half. Stopping the walk at the first requeue preserves order, but it keeps the delivery rate MailDeliveryCheck measured on the live daemon: about two deliveries per 17s tick, because delivering an item is itself what makes the target busy, so the second read of any pass says busy and the walk stops after one delivery. Instead the drain takes one reading per target per pass, before it has typed anything into that session. Order is preserved for the same reason (a reading taken once cannot disagree with itself) and a backlog of ten now goes out in one pass rather than five ticks — aBacklogDrainsInOnePassRatherThanOnePerTick, which delivers 1 of 10 on main.

On the test gotcha. Confirmed, and it cost me a rewrite too: handle() ends in a settle drain, so with staging now unconditional each send's own drain delivered immediately and my first ordering test asserted nothing. The fix that made the suite deterministic was to settle with .memoNode instead of .refreshUsage — the latter runs refreshPresence first and eats a scripted reading before the drain ever asks. Every one of the five was then re-run against origin/main's GraphStore.swift checked out into the worktree, and each fails there for its own reason, so none is a false positive: the re-scope one delivers 2 wakes on main against 1 here.

Verdict on priority taken as read — the ordering half was done properly rather than quickly, and the wedge (#311) is the half that gates the release.