fleet/fleetd
3
0
Fork 0
Code Issues 104 Pull Requests 2 Actions Packages Projects Releases 1 Wiki Activity

#801 regression: a timed-out blocking send now puts the reply in the inbox twice, the second copy a pane scrape #808

New Issue
Closed
opened 2026-10-07 06:23:58 +02:00 by ltms · 1 comment
ltms commented 2026-10-07 06:23:58 +02:00
Owner
Copy Link
Copy Source

Introduced by #801 (11352d0, merged by me today) and found by dogfooding the live daemon minutes after the redeploy. My review of PR #807 reasoned about this and got it wrong; the reasoning error is named at the bottom.

What happens

After a blocking fleet_send times out, if the member then calls fleet_reply and its turn ends, the target's inbox holds two entries for one answer. The second is the turn-completion pane scrape, not the structured reply.

Measured on the live daemon, jar 4b90c35793af, 2026-10-07

Spawned a sonnet reviewer, sent it a blocking fleet_send with timeoutMs: 1500 asking only for fleet_reply{content:"OK"}.

Receipt (the new #801 wording, working as intended):

[no reply within 1500ms — worker working. this send created no ticket, and a resend can
 duplicate the delivery. Poll fleet_poll{target="term_65d387382fa954b"} to drain its inbox
 for a late reply.]

fleet_poll{target} then returned two messages:

[{"msgId":"8295c29c-5981-4524-87e9-e9fa2d41a860","content":"OK"},
 {"msgId":"5b5d5c14-7ffd-4f57-944e-4c63923b232d","content":"OK"}]

fleetd.out shows which path produced each:

06:21:55.269 DEBUG [boundedElastic-1]  MessageService    - send to term_… timed out (delivered=true)
06:22:00.350 DEBUG [boundedElastic-1]  ReplyPushLoop     - push: starting reminder loop for nudge target term_65d2a09b91f8f3d
06:22:02.255 DEBUG [status-poller]     SessionManager    - session transitioned … BUSY -> DONE turn=1
06:22:03.128 DEBUG [completion-term_…] CompletionResolver- resolved send to term_… via turn-completion fallback (2 chars scraped)
06:22:15.688 WARN  [bridge-health-]    FleetHealthMonitor- fleet health member=term_… state=REPLY_STRANDED previous=IDLE

Two publishes, two threads, and both publish sites call pushLoop.onReplyQueued, which is why one line starts the reminder loop and the other coalesces into it:

  • 06:22:00.350, on boundedElastic-1 — the member's explicit fleet_reply, through MessageService.reply's stranded path (MessageService.java:623, then strandedReplies.put and onReplyQueued at 625-631).
  • 06:22:03.128, on completion-term_… — the new strandLateResolution (MessageService.java:1101). "2 chars scraped" is exactly OK.

Why it is wrong

Before #801, the completion fallback resolved a captured future nobody awaited and the scrape went nowhere. In the case above that was the correct outcome: reply() had already put the real answer in the inbox, so the scrape was redundant. #801 now publishes it as a second entry.

So #801 only wins when the member ends its turn without fleet_reply — then the scrape is the only answer there is. When the member does reply, #801 strictly makes things worse, and it does it in the direction CLAUDE.md warns about twice: a scrape can be up to 4000 characters of pane tail and is not the structured reply, so a lead draining the inbox sees two entries and may act on the wrong one. Here both read OK only because the answer was one word.

What a fix must do

  • No duplicate: when a turn already produced an explicit fleet_reply that was published to the inbox, its turn-completion scrape must not be published as well.
  • No regression of #801: when a turn ends with no fleet_reply, the scrape must still reach the inbox, which is what #801 bought.
  • strandedReplies is not the signal to test. It is a sticky per-target flag, so reading it would also suppress a legitimate completion for some later turn on the same member. The discriminator has to be per-turn.
  • A test for each direction, both driving a real timeout then a real status transition: one where fleet_reply is called (expect exactly one inbox entry) and one where it is not (expect exactly one, the scrape). A test that only asserts "at least one" would pass on the current broken code.

My review error, for the record

I checked that rendezvous.close(target, reply) runs in send()'s finally (MessageService.java:1061-1064) and concluded that filtering strandLateResolution to Kind.COMPLETION could not double-publish, because an explicit fleet_reply would reach the inbox through reply()'s own lookup instead. Both halves of that are true. The conclusion still did not follow: reply() and the completion fallback are two different resolutions of the same turn, not two routes to one resolution, and nothing suppresses the second once the first has landed. I reasoned about which path a single answer would take, when the actual question was how many answers one turn can produce.

Not reverted, deliberately

The daemon is live with this. The trigger is narrow — a blocking send that times out, where the fleet almost always uses wait:false — the extra entry is visible rather than silent, and the first entry is still the correct structured reply. Reverting would restore the older bug where a genuinely reply-less turn's answer is discarded. Fixing forward is the smaller risk, but that is a judgement, not a measurement.

Introduced by #801 (`11352d0`, merged by me today) and found by dogfooding the live daemon minutes after the redeploy. My review of PR #807 reasoned about this and got it wrong; the reasoning error is named at the bottom. ## What happens After a blocking `fleet_send` times out, if the member then calls `fleet_reply` and its turn ends, the target's inbox holds **two** entries for one answer. The second is the turn-completion pane scrape, not the structured reply. ## Measured on the live daemon, jar `4b90c35793af`, 2026-10-07 Spawned a `sonnet` reviewer, sent it a blocking `fleet_send` with `timeoutMs: 1500` asking only for `fleet_reply{content:"OK"}`. Receipt (the new #801 wording, working as intended): ``` [no reply within 1500ms — worker working. this send created no ticket, and a resend can duplicate the delivery. Poll fleet_poll{target="term_65d387382fa954b"} to drain its inbox for a late reply.] ``` `fleet_poll{target}` then returned **two** messages: ```json [{"msgId":"8295c29c-5981-4524-87e9-e9fa2d41a860","content":"OK"}, {"msgId":"5b5d5c14-7ffd-4f57-944e-4c63923b232d","content":"OK"}] ``` `fleetd.out` shows which path produced each: ``` 06:21:55.269 DEBUG [boundedElastic-1] MessageService - send to term_… timed out (delivered=true) 06:22:00.350 DEBUG [boundedElastic-1] ReplyPushLoop - push: starting reminder loop for nudge target term_65d2a09b91f8f3d 06:22:02.255 DEBUG [status-poller] SessionManager - session transitioned … BUSY -> DONE turn=1 06:22:03.128 DEBUG [completion-term_…] CompletionResolver- resolved send to term_… via turn-completion fallback (2 chars scraped) 06:22:15.688 WARN [bridge-health-] FleetHealthMonitor- fleet health member=term_… state=REPLY_STRANDED previous=IDLE ``` Two publishes, two threads, and both publish sites call `pushLoop.onReplyQueued`, which is why one line starts the reminder loop and the other coalesces into it: - **06:22:00.350**, on `boundedElastic-1` — the member's explicit `fleet_reply`, through `MessageService.reply`'s stranded path (`MessageService.java:623`, then `strandedReplies.put` and `onReplyQueued` at 625-631). - **06:22:03.128**, on `completion-term_…` — the new `strandLateResolution` (`MessageService.java:1101`). "2 chars scraped" is exactly `OK`. ## Why it is wrong Before #801, the completion fallback resolved a captured future nobody awaited and the scrape went nowhere. In the case above that was the **correct** outcome: `reply()` had already put the real answer in the inbox, so the scrape was redundant. #801 now publishes it as a second entry. So #801 only wins when the member ends its turn **without** `fleet_reply` — then the scrape is the only answer there is. When the member does reply, #801 strictly makes things worse, and it does it in the direction `CLAUDE.md` warns about twice: a scrape can be up to 4000 characters of pane tail and is not the structured reply, so a lead draining the inbox sees two entries and may act on the wrong one. Here both read `OK` only because the answer was one word. ## What a fix must do - No duplicate: when a turn already produced an explicit `fleet_reply` that was published to the inbox, its turn-completion scrape must not be published as well. - No regression of #801: when a turn ends with no `fleet_reply`, the scrape must still reach the inbox, which is what #801 bought. - `strandedReplies` is **not** the signal to test. It is a sticky per-target flag, so reading it would also suppress a legitimate completion for some later turn on the same member. The discriminator has to be per-turn. - A test for each direction, both driving a real timeout then a real status transition: one where `fleet_reply` is called (expect exactly one inbox entry) and one where it is not (expect exactly one, the scrape). A test that only asserts "at least one" would pass on the current broken code. ## My review error, for the record I checked that `rendezvous.close(target, reply)` runs in `send()`'s `finally` (`MessageService.java:1061-1064`) and concluded that filtering `strandLateResolution` to `Kind.COMPLETION` could not double-publish, because an explicit `fleet_reply` would reach the inbox through `reply()`'s own lookup instead. Both halves of that are true. The conclusion still did not follow: `reply()` and the completion fallback are **two different resolutions of the same turn**, not two routes to one resolution, and nothing suppresses the second once the first has landed. I reasoned about which path a single answer would take, when the actual question was how many answers one turn can produce. ## Not reverted, deliberately The daemon is live with this. The trigger is narrow — a blocking send that times out, where the fleet almost always uses `wait:false` — the extra entry is visible rather than silent, and the first entry is still the correct structured reply. Reverting would restore the older bug where a genuinely reply-less turn's answer is discarded. Fixing forward is the smaller risk, but that is a judgement, not a measurement.
ltms commented 2026-10-07 07:09:37 +02:00
Author
Owner
Copy Link
Copy Source

Fixed and merged locally as 0ff0d6c, pushed to main. PR #810 closed — Gitea does not see a local merge.

What shipped

reply(), on its stranded path only, now claims the timed-out send's captured waiter before publishing. A new lateWaiters map holds that waiter per target, and a new Rendezvous.resolveLateReply completes it with Kind.REPLY. strandLateResolution's whenComplete then sees a kind that is not COMPLETION and publishes nothing, so one turn produces one entry.

The discriminator is the CompletableFuture identity, not a flag. Each send() opens a fresh waiter per turn, lateWaiters is overwritten rather than merged, and the entry removes itself in whenComplete. abandon also clears it. That is why it is per-turn and not the sticky per-target read this ticket warned against.

What I verified myself, not the worker's word

The tests are not vacuous. In a throwaway worktree at the branch tip I reverted MessageService.java and Rendezvous.java to main, kept the new tests, and ran them:

Tests run: 119, Failures: 2, Errors: 0, Skipped: 0   -- MessageServiceTest
  anExplicitReplyAfterATimeoutLandsExactlyOnceNotTwice:202
      a completion scrape for a turn that already got an explicit fleet_reply must not
      publish a second entry ==> expected: <true> but was: <false>
  theSuppressionIsPerTurnNotPerTarget:232
      turn 1's own scrape must still be suppressed ==> expected: <true> but was: <false>

Both new tests fail without the fix, with the message that names this defect. The two absence assertions use a 300/500ms window, which on its own could pass by being slow — but theSuppressionIsPerTurnNotPerTarget pairs each absence with a positive probe in the same test (turn 2's scrape must land, asserted with awaitDrained), so a scrape path that had simply stopped working would fail the test rather than pass it.

The build. mvn -o clean install at 0ff0d6c in that throwaway worktree, not piped: BUILD SUCCESS, Tests run: 2246, Failures: 0, Errors: 0, Skipped: 0, and 0 lines matching ^\[ERROR\] in the full log. The merge is a fast-forward, and HEAD^{tree} equals the tree I built.

The diff. 35 lines of main source across two files, 98 of test. I read every line rather than spawning reviewers — at that size the fan-out buys less than the mutation check above, and I am not the implementer, so I am already the independent reader.

One observation, not a blocker, and not tested

reply() returns early on the async-ticket path (RESOLVED_ASYNC_TICKET) before reaching the new lookup. So a member that has both a timed-out blocking send and an open async ticket would have its reply taken by the ticket while the late scrape still publishes one inbox entry. That is one entry, not a duplicate, and it is #801's behaviour rather than something this change introduced. I did not try to reach that combination, so I do not know whether it is reachable in practice. Worth its own ticket if anyone sees a stray inbox entry after a ticket resolved cleanly.

Not done

The daemon still runs the 06:21 jar, so this fix is merged and not live. Redeploy is a separate step.

Fixed and merged locally as `0ff0d6c`, pushed to `main`. PR #810 closed — Gitea does not see a local merge. ## What shipped `reply()`, on its stranded path only, now claims the timed-out send's **captured waiter** before publishing. A new `lateWaiters` map holds that waiter per target, and a new `Rendezvous.resolveLateReply` completes it with `Kind.REPLY`. `strandLateResolution`'s `whenComplete` then sees a kind that is not `COMPLETION` and publishes nothing, so one turn produces one entry. The discriminator is the `CompletableFuture` identity, not a flag. Each `send()` opens a fresh waiter per turn, `lateWaiters` is overwritten rather than merged, and the entry removes itself in `whenComplete`. `abandon` also clears it. That is why it is per-turn and not the sticky per-target read this ticket warned against. ## What I verified myself, not the worker's word **The tests are not vacuous.** In a throwaway worktree at the branch tip I reverted `MessageService.java` and `Rendezvous.java` to `main`, kept the new tests, and ran them: ``` Tests run: 119, Failures: 2, Errors: 0, Skipped: 0 -- MessageServiceTest anExplicitReplyAfterATimeoutLandsExactlyOnceNotTwice:202 a completion scrape for a turn that already got an explicit fleet_reply must not publish a second entry ==> expected: <true> but was: <false> theSuppressionIsPerTurnNotPerTarget:232 turn 1's own scrape must still be suppressed ==> expected: <true> but was: <false> ``` Both new tests fail without the fix, with the message that names this defect. The two absence assertions use a 300/500ms window, which on its own could pass by being slow — but `theSuppressionIsPerTurnNotPerTarget` pairs each absence with a positive probe in the same test (turn 2's scrape must land, asserted with `awaitDrained`), so a scrape path that had simply stopped working would fail the test rather than pass it. **The build.** `mvn -o clean install` at `0ff0d6c` in that throwaway worktree, not piped: `BUILD SUCCESS`, `Tests run: 2246, Failures: 0, Errors: 0, Skipped: 0`, and 0 lines matching `^\[ERROR\]` in the full log. The merge is a fast-forward, and `HEAD^{tree}` equals the tree I built. **The diff.** 35 lines of main source across two files, 98 of test. I read every line rather than spawning reviewers — at that size the fan-out buys less than the mutation check above, and I am not the implementer, so I am already the independent reader. ## One observation, not a blocker, and not tested `reply()` returns early on the async-ticket path (`RESOLVED_ASYNC_TICKET`) before reaching the new lookup. So a member that has **both** a timed-out blocking send and an open async ticket would have its reply taken by the ticket while the late scrape still publishes one inbox entry. That is one entry, not a duplicate, and it is #801's behaviour rather than something this change introduced. I did not try to reach that combination, so I do not know whether it is reachable in practice. Worth its own ticket if anyone sees a stray inbox entry after a ticket resolved cleanly. ## Not done The daemon still runs the 06:21 jar, so this fix is merged and **not live**. Redeploy is a separate step.
ltms closed this issue 2026-10-07 07:09:41 +02:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
blocked
Cannot start until something else lands. The body says what.
 needs-live-proof
Merged and green, but never shown working on the running daemon. Not the same as done.
 ready-to-delegate
Scope, files and acceptance criteria are written. A worker can be briefed from the body alone.
 silent-default
A feature that compiles, passes tests, and ships turned off. Nine recurrences and counting.
No Label
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
agent kevin ltms
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: fleet/fleetd#808
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?