fleetd #683: decouple completionFallback test's send budget from its setup clock #684

2026-10-03T22:07:03+02:00

agent commented

2026-10-03 22:07:03 +02:00

Fixes fleetd #683.

Problem

completionFallbackResolvesATurnThatNeverCalledFleetReply gave messages.send a 5000 ms budget that starts ticking the instant sendAsync() runs. The test then spends real wall-clock time on awaitWaiting() (its own 2000 ms deadline) plus several onStatus/readText calls before asserting with send.get(5, TimeUnit.SECONDS). On a loaded machine that setup can eat enough of the 5000 ms budget that the production call's own deadline fires first, returning TIMED_OUT_QUEUED instead of COMPLETED_UNREPLIED -- a wrong-outcome assertion failure that reads like a real regression in the completion fallback, not a timing artifact. Verified from MessageService.send: deadlineNanos is computed at entry and reply.get(remainingMillis(deadlineNanos), MILLISECONDS) is what throws into the TIMED_OUT_QUEUED branch.

Fix (ticket option 1: decouple the budgets)

Added sendAsync(String content, long timeoutMillis) alongside the existing helper (which still defaults to 5000 ms for every other caller) and gave only this one test a 30 000 ms budget via a new GENEROUS_SEND_BUDGET_MILLIS constant. send.get(5, TimeUnit.SECONDS) is unchanged and is now the only clock this test actually depends on -- the production send budget can no longer compete with the test's own setup overhead for the same window.

Proof the coupling is removed (acceptance criterion 3)

Added completionFallbackSurvivesASlowHarnessBecauseItsSendBudgetIsNotTheBindingClock, which injects a deterministic 5500 ms delay between awaitWaiting() and the status transitions that drive completion -- well past the old 5000 ms budget -- and still asserts COMPLETED_UNREPLIED. This is deterministic (no dependence on real machine load).

Mutation check (acceptance criterion 6)

Temporarily reverted GENEROUS_SEND_BUDGET_MILLIS to 5000 and reran both tests: the new regression test went red with the exact same mismatch as the original report (expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED>, ~5.5 s elapsed). The original test did not fail under this mutation since it has no injected delay -- consistent with the original bug being load-dependent rather than deterministic. Reverted the mutation; git diff was clean before committing the real fix.

Sweep of fleetd/src/test/java/dev/ltms/fleet/msg/ (acceptance criterion 4 -- reported only, not fixed)

Confirmed NOT coupled: every test using the public messages.sendAsync(target, content) ticket API runs under ASYNC_TIMEOUT_MS = 30 minutes (verified in MessageService.java), so its own setup overhead can never compete with that budget.

Tier 1 -- exact same shape as the fixed test (the private sendAsync()/sendAsync(content) helper's hardcoded messages.send(target, content, 5000), raced by awaitWaiting()'s up-to-2000 ms busy-wait before a send.get(5, TimeUnit.SECONDS)/comparable assertion): completionFallbackReplacesAnEchoedInjectedBriefWithNoReportOutcome, completionFallbackKeepsARealReportThatRestatesTheWholeBrief, completionFallbackKeepsTheClippedMarkerWhenAnEchoedBriefIsTooLong, completionFallbackNamesTheKnownWorktreeAndBranchForAnEchoedBrief (inlines its own copy of the same pattern against a local MessageService), backendErrorScrapeThroughMessageServiceFailsInsteadOfBecomingReplyText, explicitFleetReplyResolvesAsReplied, aWedgedWorkerResolvesTheSendAsFailedWithTheErrorContext, aWorkerThatVanishesMidTurnResolvesTheSendAsFailed, droppedQueuedAndDeliveredTurnsExposeTheRealCauseExactlyOnce, askSurfacesAsAQuestionAndTheAnswerResumesTheSameTurn, duplicateAsksFromTheSameSessionCoalesceToOneTurn, askTimesOutWhenThePrimaryNeverAnswers, answerTimesOutWhenTheResumedWorkerNeverReplies, answerReleasesTheSessionLockAfterANormalReply, answerReleasesTheSessionLockAfterATimedOutWorkingReturn, answerReleasesTheSessionLockWhenTheReplyFutureFailsExceptionally, answerReleasesTheSessionLockWhenInterrupted, replyResolvesOpenSendDoesNotQueue, completionFallbackIsNeverQueued, hasQueuedDeliveryClearsOnceTheTargetsNextDeliveryIsAccepted, hasStrandedReplyIsFalseWhenTheReplyResolvedALiveSend, hasStrandedReplyClearsOnceTheTargetsNextDeliveryIsAccepted.

Tier 2 -- same shape one layer up (messages.ask(...) given its own ~5000 ms budget, immediately raced by awaitTicketPhase(...)'s own up-to-3000 ms busy-wait loop before the turnId is used): answerLosingTheRaceToAnAlreadyAnsweredAskStillReturnsStaleTurnAndCleansUpOnce, abandonDoesNotFailAnAsyncTicketWaitingForAnAnswer, abandonWithoutSweepAskingBehavesLikeTheTwoArgOverload, fleetStopAfterAnOrphanedReplyDoesNotFailTheTicket, finishAsyncTaskSurvivesTurnIdGoingNullBetweenItsTwoReads, aReplyRacingAsksTimeoutCleanupStillCompletesTheAsyncTicket, replyToAnOrphanedTaskSurvivesTurnIdGoingNullBetweenItsTwoReads, asyncQuestionBelongsToTheTaskThatOwnsItsForwardWaiter, secondFleetAskInTheSameResumedTurnDoesNotKillTheAsyncTicket, pendingAskReturnsTheOpenQuestionForAnAsyncTicket.

Other files in the directory (LeadHeartbeatLoopTest, ReplyPushLoopTest, AmqpReplyInboxRecoveryRaceTest, AmqpReplyInboxContractTest, LeadMailboxTest, AmqpReplyInboxReleaseRaceTest) use generous (5-20 s) poll-until-true loops against eventually-consistent state rather than racing one fixed-size production timeout against a comparable-size harness window, so they do not share this shape.

None of the above were changed, per the ticket's instruction to report only.

Build

cd fleetd && rm -rf target/surefire-reports && mvn -o clean install: Tests run: 1933, Failures: 0, Errors: 0, Skipped: 0, BUILD SUCCESS, 172 target/surefire-reports/*.xml files afterward as a control (baseline before this change was 1932 tests).

Which clock the fixed test now depends on: send.get(5, TimeUnit.SECONDS) only -- the production send budget (30 000 ms) is no longer reachable under any realistic setup delay.

Fixes fleetd #683. ## Problem `completionFallbackResolvesATurnThatNeverCalledFleetReply` gave `messages.send` a 5000 ms budget that starts ticking the instant `sendAsync()` runs. The test then spends real wall-clock time on `awaitWaiting()` (its own 2000 ms deadline) plus several `onStatus`/`readText` calls before asserting with `send.get(5, TimeUnit.SECONDS)`. On a loaded machine that setup can eat enough of the 5000 ms budget that the production call's own deadline fires first, returning `TIMED_OUT_QUEUED` instead of `COMPLETED_UNREPLIED` -- a wrong-outcome assertion failure that reads like a real regression in the completion fallback, not a timing artifact. Verified from `MessageService.send`: `deadlineNanos` is computed at entry and `reply.get(remainingMillis(deadlineNanos), MILLISECONDS)` is what throws into the `TIMED_OUT_QUEUED` branch. ## Fix (ticket option 1: decouple the budgets) Added `sendAsync(String content, long timeoutMillis)` alongside the existing helper (which still defaults to 5000 ms for every other caller) and gave only this one test a 30 000 ms budget via a new `GENEROUS_SEND_BUDGET_MILLIS` constant. `send.get(5, TimeUnit.SECONDS)` is unchanged and is now the only clock this test actually depends on -- the production send budget can no longer compete with the test's own setup overhead for the same window. ## Proof the coupling is removed (acceptance criterion 3) Added `completionFallbackSurvivesASlowHarnessBecauseItsSendBudgetIsNotTheBindingClock`, which injects a deterministic 5500 ms delay between `awaitWaiting()` and the status transitions that drive completion -- well past the old 5000 ms budget -- and still asserts `COMPLETED_UNREPLIED`. This is deterministic (no dependence on real machine load). ## Mutation check (acceptance criterion 6) Temporarily reverted `GENEROUS_SEND_BUDGET_MILLIS` to 5000 and reran both tests: the new regression test went red with the exact same mismatch as the original report (`expected: <COMPLETED_UNREPLIED> but was: <TIMED_OUT_QUEUED>`, ~5.5 s elapsed). The original test did not fail under this mutation since it has no injected delay -- consistent with the original bug being load-dependent rather than deterministic. Reverted the mutation; `git diff` was clean before committing the real fix. ## Sweep of fleetd/src/test/java/dev/ltms/fleet/msg/ (acceptance criterion 4 -- reported only, not fixed) **Confirmed NOT coupled:** every test using the public `messages.sendAsync(target, content)` ticket API runs under `ASYNC_TIMEOUT_MS` = 30 minutes (verified in `MessageService.java`), so its own setup overhead can never compete with that budget. **Tier 1 -- exact same shape as the fixed test** (the private `sendAsync()`/`sendAsync(content)` helper's hardcoded `messages.send(target, content, 5000)`, raced by `awaitWaiting()`'s up-to-2000 ms busy-wait before a `send.get(5, TimeUnit.SECONDS)`/comparable assertion): `completionFallbackReplacesAnEchoedInjectedBriefWithNoReportOutcome`, `completionFallbackKeepsARealReportThatRestatesTheWholeBrief`, `completionFallbackKeepsTheClippedMarkerWhenAnEchoedBriefIsTooLong`, `completionFallbackNamesTheKnownWorktreeAndBranchForAnEchoedBrief` (inlines its own copy of the same pattern against a local `MessageService`), `backendErrorScrapeThroughMessageServiceFailsInsteadOfBecomingReplyText`, `explicitFleetReplyResolvesAsReplied`, `aWedgedWorkerResolvesTheSendAsFailedWithTheErrorContext`, `aWorkerThatVanishesMidTurnResolvesTheSendAsFailed`, `droppedQueuedAndDeliveredTurnsExposeTheRealCauseExactlyOnce`, `askSurfacesAsAQuestionAndTheAnswerResumesTheSameTurn`, `duplicateAsksFromTheSameSessionCoalesceToOneTurn`, `askTimesOutWhenThePrimaryNeverAnswers`, `answerTimesOutWhenTheResumedWorkerNeverReplies`, `answerReleasesTheSessionLockAfterANormalReply`, `answerReleasesTheSessionLockAfterATimedOutWorkingReturn`, `answerReleasesTheSessionLockWhenTheReplyFutureFailsExceptionally`, `answerReleasesTheSessionLockWhenInterrupted`, `replyResolvesOpenSendDoesNotQueue`, `completionFallbackIsNeverQueued`, `hasQueuedDeliveryClearsOnceTheTargetsNextDeliveryIsAccepted`, `hasStrandedReplyIsFalseWhenTheReplyResolvedALiveSend`, `hasStrandedReplyClearsOnceTheTargetsNextDeliveryIsAccepted`. **Tier 2 -- same shape one layer up** (`messages.ask(...)` given its own ~5000 ms budget, immediately raced by `awaitTicketPhase(...)`'s own up-to-3000 ms busy-wait loop before the turnId is used): `answerLosingTheRaceToAnAlreadyAnsweredAskStillReturnsStaleTurnAndCleansUpOnce`, `abandonDoesNotFailAnAsyncTicketWaitingForAnAnswer`, `abandonWithoutSweepAskingBehavesLikeTheTwoArgOverload`, `fleetStopAfterAnOrphanedReplyDoesNotFailTheTicket`, `finishAsyncTaskSurvivesTurnIdGoingNullBetweenItsTwoReads`, `aReplyRacingAsksTimeoutCleanupStillCompletesTheAsyncTicket`, `replyToAnOrphanedTaskSurvivesTurnIdGoingNullBetweenItsTwoReads`, `asyncQuestionBelongsToTheTaskThatOwnsItsForwardWaiter`, `secondFleetAskInTheSameResumedTurnDoesNotKillTheAsyncTicket`, `pendingAskReturnsTheOpenQuestionForAnAsyncTicket`. **Other files in the directory** (`LeadHeartbeatLoopTest`, `ReplyPushLoopTest`, `AmqpReplyInboxRecoveryRaceTest`, `AmqpReplyInboxContractTest`, `LeadMailboxTest`, `AmqpReplyInboxReleaseRaceTest`) use generous (5-20 s) poll-until-true loops against eventually-consistent state rather than racing one fixed-size production timeout against a comparable-size harness window, so they do not share this shape. None of the above were changed, per the ticket's instruction to report only. ## Build `cd fleetd && rm -rf target/surefire-reports && mvn -o clean install`: `Tests run: 1933, Failures: 0, Errors: 0, Skipped: 0`, `BUILD SUCCESS`, 172 `target/surefire-reports/*.xml` files afterward as a control (baseline before this change was 1932 tests). Which clock the fixed test now depends on: `send.get(5, TimeUnit.SECONDS)` only -- the production send budget (30 000 ms) is no longer reachable under any realistic setup delay.

agent added 1 commit 2026-10-03 22:07:03 +02:00

fleetd #683 : decouple the completion-fallback test's send budget from its own setup clock

CI / shell-tests (pull_request) Failing after 9s

Details

CI / contract (pull_request) Successful in 56s

Details

CI / build (pull_request) Failing after 1m53s

Details

1a397e962e

completionFallbackResolvesATurnThatNeverCalledFleetReply gave messages.send a 5000 ms budget
that started ticking the instant sendAsync() ran, then raced that same clock against
awaitWaiting()'s own 2000 ms deadline plus several onStatus/readText calls before asserting with
send.get(5, SECONDS). On a loaded machine the setup could eat enough of the 5000 ms that the
production call expired first, returning TIMED_OUT_QUEUED instead of COMPLETED_UNREPLIED.

Give this one test's send a 30 000 ms budget (sendAsync(content, timeoutMillis)) so the setup can
never compete with it; send.get(5, SECONDS) stays the one clock the test depends on. A new
regression test injects a deterministic 5500 ms delay in the same spot and proves the budget is no
longer the binding constraint — reverting it to 5000 ms turns that test red with the same
TIMED_OUT_QUEUED mismatch, confirmed by mutation.

ltms referenced this issue from a commit

2026-10-03 22:27:55 +02:00

Merge PR #684: fleetd #683 — decouple the completion-fallback test's two 5s budgets

ltms commented

2026-10-03 22:29:26 +02:00

Merged locally as 133f03e on main (pushed; main is now 2eb2d61). Closing by hand because we
merge locally, so Gitea does not close the PR itself.

What I checked myself, not taken from the report:

The full diff. Test file only; MessageService.java is untouched. The sendAsync(content)
overload still defaults to 5000 ms, so no other caller changes.
Trial merge in a throwaway worktree, then rm -rf target/surefire-reports && mvn -o clean install
on the combined tree with #687 and #688: 1942 tests, 0 failures, BUILD SUCCESS, 173 report
files as a control. 1932 baseline + 1 (#684) + 8 (#687) + 1 (#688) = 1942, which matches.
The merged main tree hash equals the tree I built (35b81eb), so that green build covers
exactly what landed.

Two notes, neither blocking:

The new test adds a real Thread.sleep(5500) to every build. That is the price of making it
deterministic instead of load-dependent, and I think it is worth paying, but it is 5.5 s of wall
clock on every run.
The new test's javadoc says "the 5000 ms budget this send no longer uses". "No longer" is history,
which our comment rule keeps out of code. Not worth another round trip; whoever next edits that
method can drop the phrase.

Merged locally as `133f03e` on `main` (pushed; `main` is now `2eb2d61`). Closing by hand because we merge locally, so Gitea does not close the PR itself. What I checked myself, not taken from the report: - The full diff. Test file only; `MessageService.java` is untouched. The `sendAsync(content)` overload still defaults to 5000 ms, so no other caller changes. - Trial merge in a throwaway worktree, then `rm -rf target/surefire-reports && mvn -o clean install` on the combined tree with #687 and #688: **1942 tests, 0 failures, BUILD SUCCESS**, 173 report files as a control. 1932 baseline + 1 (#684) + 8 (#687) + 1 (#688) = 1942, which matches. - The merged `main` tree hash equals the tree I built (`35b81eb`), so that green build covers exactly what landed. Two notes, neither blocking: - The new test adds a real `Thread.sleep(5500)` to every build. That is the price of making it deterministic instead of load-dependent, and I think it is worth paying, but it is 5.5 s of wall clock on every run. - The new test's javadoc says "the 5000 ms budget this send no longer uses". "No longer" is history, which our comment rule keeps out of code. Not worth another round trip; whoever next edits that method can drop the phrase.

ltms closed this pull request

2026-10-03 22:29:29 +02:00

ltms referenced this pull request

2026-10-03 22:29:42 +02:00

fleetd #669 Unit A: split SEND and READ into their real call shapes #687

ltms referenced this pull request

2026-10-03 22:29:56 +02:00

fleetd #675: pin assembly loop timing defaults #688

ltms referenced this pull request

2026-10-03 22:30:08 +02:00

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