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

completionFallbackResolvesATurnThatNeverCalledFleetReply shares one 5000ms wall-clock budget with its own setup, so a loaded machine fails it as a wrong outcome — blocked a redeploy 2026-10-03 #683

New Issue
Closed
opened 2026-10-03 21:48:23 +02:00 by ltms · 1 comment
ltms commented 2026-10-03 21:48:23 +02:00
Owner
Copy Link
Copy Source

What happened

scripts/redeploy-fleetd.sh --yes failed its build gate at 21:45 on 2026-10-03. One test failed out of the whole suite:

[ERROR] dev.ltms.fleet.msg.MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply
        -- Time elapsed: 5.014 s <<< FAILURE!
org.opentest4j.AssertionFailedError: an unreplied but finished turn resolves via the
completion fallback ==> expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED>
	at dev.ltms.fleet.msg.MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply(MessageServiceTest.java:93)

The script's build-before-stop design worked exactly as intended: the running daemon was not touched, and the fleet never went down. The cost was a blocked deployment, not an outage.

Why this is a timing defect and not a logic defect

Measured, both ways round:

  • The same tree (209e123, tree a0bd9fb) built green in a throwaway worktree about 20 minutes earlier: Tests run: 1932, Failures: 0, Errors: 0, Skipped: 0.
  • That one test, run alone in that worktree, passed 5 times out of 5.
  • It failed once, inside a full suite, on a machine that was also running the live daemon.

So it is load-sensitive. Isolation passing 5/5 is weak evidence on its own — it says nothing about contention — which is why the full-suite result above is the one that matters.

The mechanism, read from the code

This part is a reading of MessageServiceTest.java, not a captured trace.

sendAsync() starts the send with its own timeout:

return CompletableFuture.supplyAsync(() -> messages.send(T, content, 5000));

The test then calls awaitWaiting(), which has a 2000 ms deadline of its own, and only afterwards drives the status transitions and asserts with send.get(5, TimeUnit.SECONDS).

The two 5 s numbers are not independent. The send's 5000 ms clock starts first, and everything after it — awaitWaiting(), four onStatus calls, two readText calls, the scrape — spends that same budget. awaitWaiting() alone may take up to 2000 ms of it before the test begins driving at all.

The elapsed time points at the send's budget rather than the harness's: 5.014 s with an assertion failure. Had send.get(5, …) been the one to expire, the test would have thrown TimeoutException, not compared two outcomes. So the send returned TIMED_OUT_QUEUED at its own deadline and the assertion then reported it.

Why the failure reads as the wrong thing

TIMED_OUT_QUEUED means the message was never delivered. A reader who sees expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED> naturally reads it as "the completion fallback is broken" — a correctness claim about the feature. It is not. It is the clock.

This is the barrier-by-hope shape: the test passes most easily on an idle machine, and when it does fail it fails as a plausible-looking functional regression. That is the expensive kind, because the next person to hit it will go looking in MessageService.

Suggested direction

Not a decision — whoever takes this should pick.

  1. Decouple the two budgets. The subject under test is the completion fallback, not the send timeout. Giving the send a much larger budget (and keeping send.get's bound as the real harness limit) removes the coupling with no loss of coverage. Cheapest, and it keeps the test honest about what it is testing.
  2. Take the wall clock out of it. LeadRollover already takes an injectable nowMillis supplier for this reason. If MessageService's timeout path can take the same, the test stops depending on machine load entirely. More work, and it is the only option that actually makes the test deterministic.
  3. Do not simply raise both numbers. That lowers the failure rate without removing the shape, so it comes back on a slower host or under a parallel build — and the next failure looks identical to this one.

Check the shape, not just this instance

Before fixing, sweep fleetd/src/test/java/dev/ltms/fleet/msg/ for other tests that start an operation with its own timeout and then assert within a comparable window. Report what is found; do not fix them in the same change. awaitWaiting() is shared helper code, so anything calling it inherits the same coupling.

Acceptance criteria

  1. The chosen fix, with the reason it removes the coupling rather than widening it.
  2. A test that fails if the coupling returns — for option 1, that means proving the send's budget is no longer the binding constraint, not merely that the test passes today.
  3. The sweep result from the section above, as a list, with no changes made to the other sites.
  4. State plainly which of the two clocks the test now depends on.

Found how

Found by the lead while redeploying after merging #651. Filed rather than fixed inline because the redeploy was the task in hand and this is a separate, self-contained unit.

## What happened `scripts/redeploy-fleetd.sh --yes` failed its build gate at 21:45 on 2026-10-03. One test failed out of the whole suite: ``` [ERROR] dev.ltms.fleet.msg.MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply -- Time elapsed: 5.014 s <<< FAILURE! org.opentest4j.AssertionFailedError: an unreplied but finished turn resolves via the completion fallback ==> expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED> at dev.ltms.fleet.msg.MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply(MessageServiceTest.java:93) ``` The script's build-before-stop design worked exactly as intended: the running daemon was not touched, and the fleet never went down. The cost was a blocked deployment, not an outage. ## Why this is a timing defect and not a logic defect Measured, both ways round: - The same tree (`209e123`, tree `a0bd9fb`) built **green** in a throwaway worktree about 20 minutes earlier: `Tests run: 1932, Failures: 0, Errors: 0, Skipped: 0`. - That one test, run alone in that worktree, passed **5 times out of 5**. - It failed **once**, inside a full suite, on a machine that was also running the live daemon. So it is load-sensitive. Isolation passing 5/5 is weak evidence on its own — it says nothing about contention — which is why the full-suite result above is the one that matters. ## The mechanism, read from the code This part is a reading of `MessageServiceTest.java`, not a captured trace. `sendAsync()` starts the send with its own timeout: ```java return CompletableFuture.supplyAsync(() -> messages.send(T, content, 5000)); ``` The test then calls `awaitWaiting()`, which has a 2000 ms deadline of its own, and only afterwards drives the status transitions and asserts with `send.get(5, TimeUnit.SECONDS)`. The two 5 s numbers are not independent. The send's 5000 ms clock starts first, and everything after it — `awaitWaiting()`, four `onStatus` calls, two `readText` calls, the scrape — spends that same budget. `awaitWaiting()` alone may take up to 2000 ms of it before the test begins driving at all. The elapsed time points at the send's budget rather than the harness's: 5.014 s with an **assertion** failure. Had `send.get(5, …)` been the one to expire, the test would have thrown `TimeoutException`, not compared two outcomes. So the send returned `TIMED_OUT_QUEUED` at its own deadline and the assertion then reported it. ## Why the failure reads as the wrong thing `TIMED_OUT_QUEUED` means the message was never delivered. A reader who sees `expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED>` naturally reads it as "the completion fallback is broken" — a correctness claim about the feature. It is not. It is the clock. This is the barrier-by-hope shape: the test passes most easily on an idle machine, and when it does fail it fails as a plausible-looking functional regression. That is the expensive kind, because the next person to hit it will go looking in `MessageService`. ## Suggested direction Not a decision — whoever takes this should pick. 1. **Decouple the two budgets.** The subject under test is the completion fallback, not the send timeout. Giving the send a much larger budget (and keeping `send.get`'s bound as the real harness limit) removes the coupling with no loss of coverage. Cheapest, and it keeps the test honest about what it is testing. 2. **Take the wall clock out of it.** `LeadRollover` already takes an injectable `nowMillis` supplier for this reason. If `MessageService`'s timeout path can take the same, the test stops depending on machine load entirely. More work, and it is the only option that actually makes the test deterministic. 3. Do **not** simply raise both numbers. That lowers the failure rate without removing the shape, so it comes back on a slower host or under a parallel build — and the next failure looks identical to this one. ## Check the shape, not just this instance Before fixing, sweep `fleetd/src/test/java/dev/ltms/fleet/msg/` for other tests that start an operation with its own timeout and then assert within a comparable window. Report what is found; do not fix them in the same change. `awaitWaiting()` is shared helper code, so anything calling it inherits the same coupling. ## Acceptance criteria 1. The chosen fix, with the reason it removes the coupling rather than widening it. 2. A test that fails if the coupling returns — for option 1, that means proving the send's budget is no longer the binding constraint, not merely that the test passes today. 3. The sweep result from the section above, as a list, with no changes made to the other sites. 4. State plainly which of the two clocks the test now depends on. ## Found how Found by the lead while redeploying after merging #651. Filed rather than fixed inline because the redeploy was the task in hand and this is a separate, self-contained unit.
ltms commented 2026-10-03 22:30:08 +02:00
Author
Owner
Copy Link
Copy Source

Fixed by PR #684, merged as 133f03e on main (pushed; main is now 2eb2d61).

The test's own setup no longer competes with the production send budget for the same clock. The one
clock it depends on is send.get(5, TimeUnit.SECONDS). A new test,
completionFallbackSurvivesASlowHarnessBecauseItsSendBudgetIsNotTheBindingClock, injects a
deterministic 5500 ms delay — past the old 5000 ms budget — and pins the fix.

Verified on the merged tree: 1942 tests, 0 failures, BUILD SUCCESS.

The redeploy trap this ticket came from is therefore gone: a failing
MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply during a redeploy
build should now be treated as a real failure, not re-run and ignored.

Closing.

Fixed by PR #684, merged as `133f03e` on `main` (pushed; `main` is now `2eb2d61`). The test's own setup no longer competes with the production send budget for the same clock. The one clock it depends on is `send.get(5, TimeUnit.SECONDS)`. A new test, `completionFallbackSurvivesASlowHarnessBecauseItsSendBudgetIsNotTheBindingClock`, injects a deterministic 5500 ms delay — past the old 5000 ms budget — and pins the fix. Verified on the merged tree: **1942 tests, 0 failures, BUILD SUCCESS**. The redeploy trap this ticket came from is therefore gone: a failing `MessageServiceTest.completionFallbackResolvesATurnThatNeverCalledFleetReply` during a redeploy build should now be treated as a real failure, not re-run and ignored. Closing.
ltms closed this issue 2026-10-03 22:30:11 +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#683
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?