fleetd #409: deterministic test for the #399 completion-stamp ordering race #414

2026-09-10T04:39:44+02:00

agent commented

2026-09-10 04:39:44 +02:00

fleetd #409 — deterministic test for the #399 completion-stamp ordering race

What this adds

A new test, aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive,
in MessageServiceTest.java. It pins this invariant:

A test that advances the injected clock past the ticket TTL must be ordered after the completion
hook has stamped completedNanos — not merely after poll reports DONE. CompletableFuture.complete()
publishes its result and only then runs dependents, so DONE is observable before the stamp exists.

No production code changed — pruneTerminalTickets's expired expression and TICKET_TTL_NANOS
are untouched. The existing awaitCompletionStamped helper and both its call sites are unchanged.

The seam

MessageService's injected LongSupplier nowNanos (constructor at MessageService.java:342) has
exactly three call sites: Task's constructor (createdNanos), Task's whenComplete hook
(completedNanos), and pruneTerminalTickets's cutoff. I confirmed this by grepping
nowNanos in MessageService.java before designing anything — no new production seam was needed.

Why the real race can't be hit by chance in one run

Per my memory of fleetd #399's own investigation, that race needed roughly 2x-core background load
on the host to manifest at all — a plain run is not enough to expose it deterministically. So this
test does not try to win that race by chance. It widens it on purpose: the injected clock is a
"gated" LongSupplier that sleeps 300ms the one time it is armed to do so (armed right before
rendezvous.resolve(...) triggers the async completion, and consumed by whichever call happens
next — which, given the three call sites above and nothing else running nowNanos in between, is
unambiguously the completion hook's own stamp for the ticket under test). That gives the test
thread a guaranteed-wide window (300ms, vs. microsecond-scale test-thread work) to advance the
clock and run a sweep before the hook's read returns, deterministically, on any host.

The two runs (acceptance criterion 1 and 2)

With the barrier (awaitCompletionStamped) present — current/correct ordering:

mvn -o test -Dtest=MessageServiceTest#aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
[INFO] BUILD SUCCESS

Ran 3x in a row — 3/3 green, first try every time.

With the barrier call removed (reproducing the pre-#399 ordering):

[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.072 s <<< FAILURE!
[ERROR] MessageServiceTest.aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive:2032
a ticket whose real completion time is long past the advanced cutoff must be evicted, whatever the
completion hook's clock read was delayed by ==> expected: <null> but was:
<TaskView[ticket=task-1, phase=DONE, reply=quick result, replySource=reply, detail=null, turnId=null]>

Ran 3x in a row — 3/3 red, first try every time, same failure every time.

Which way it fails, and how I determined it (acceptance criterion 4)

Without the barrier, the test fails as a genuine RED assertion failure, not a false pass:
assertNull(service.poll(ticket)) fails because poll still returns the ticket's DONE view — the
sweep did not evict it. I determined this by actually removing the awaitCompletionStamped call,
running the test (see failure text above), and reading the resulting TaskView in the failure
message: it is the exact object poll would return for a ticket that was never pruned, not an
exception or a timeout from my own synchronization code. This is the intended mechanism (the hook
stamps the clock's already-advanced value, so cutoff = advanced - TTL can never exceed it) and
not some other defect in the test's wiring.

I want to flag one nuance for review: the ticket's own framing calls the pre-#399 failure mode "a
FALSE PASS, not a red test." I read that as describing the general danger of this race (a test
shaped to assert survival, like the sibling aTaskRunningLongerThanTheTtlStillKeepsItsReport,
would falsely stay green under this exact race, per that test's own #399 comment — "happens to
survive a late stamp today"), not a requirement that my test's own failure mode be a false pass.
Acceptance criterion 1 explicitly requires the new test to fail without the barrier, which is
what I built and verified. If I've misread that framing, happy to adjust.

Build

cd fleetd && mvn clean install > /tmp/b.log 2>&1; echo "EXIT=$?"
EXIT=0
[INFO] Tests run: 1502, Failures: 0, Errors: 0, Skipped: 0
[INFO] BUILD SUCCESS

MessageServiceTest alone: 83 tests (was 82), 0 failures/errors.

Files changed

fleetd/src/test/java/dev/ltms/fleet/msg/MessageServiceTest.java (+74 lines, test-only)

Also found, not fixed (per ticket instructions — report only)

No other instance of this exact shape (a test ordering on a "done"/observable signal before
reading a value a dependent action of that same completion writes) was found in
MessageServiceTest.java beyond the two awaitCompletionStamped call sites already fixed by
#399 — I did not do a repo-wide sweep beyond this file, since that's outside this ticket's scope.

## fleetd #409 — deterministic test for the #399 completion-stamp ordering race ### What this adds A new test, `aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive`, in `MessageServiceTest.java`. It pins this invariant: > A test that advances the injected clock past the ticket TTL must be ordered after the completion > hook has stamped `completedNanos` — not merely after `poll` reports `DONE`. `CompletableFuture.complete()` > publishes its result and only then runs dependents, so `DONE` is observable before the stamp exists. No production code changed — `pruneTerminalTickets`'s `expired` expression and `TICKET_TTL_NANOS` are untouched. The existing `awaitCompletionStamped` helper and both its call sites are unchanged. ### The seam `MessageService`'s injected `LongSupplier nowNanos` (constructor at `MessageService.java:342`) has exactly three call sites: `Task`'s constructor (`createdNanos`), `Task`'s `whenComplete` hook (`completedNanos`), and `pruneTerminalTickets`'s cutoff. I confirmed this by grepping `nowNanos` in `MessageService.java` before designing anything — no new production seam was needed. ### Why the real race can't be hit by chance in one run Per my memory of fleetd #399's own investigation, that race needed roughly 2x-core background load on the host to manifest at all — a plain run is not enough to expose it deterministically. So this test does not try to win that race by chance. It widens it on purpose: the injected clock is a "gated" `LongSupplier` that sleeps 300ms the one time it is armed to do so (armed right before `rendezvous.resolve(...)` triggers the async completion, and consumed by whichever call happens next — which, given the three call sites above and nothing else running nowNanos in between, is unambiguously the completion hook's own stamp for the ticket under test). That gives the test thread a guaranteed-wide window (300ms, vs. microsecond-scale test-thread work) to advance the clock and run a sweep before the hook's read returns, deterministically, on any host. ### The two runs (acceptance criterion 1 and 2) **With the barrier (`awaitCompletionStamped`) present — current/correct ordering:** ``` mvn -o test -Dtest=MessageServiceTest#aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 [INFO] BUILD SUCCESS ``` Ran 3x in a row — 3/3 green, first try every time. **With the barrier call removed (reproducing the pre-#399 ordering):** ``` [ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.072 s <<< FAILURE! [ERROR] MessageServiceTest.aTicketOrderedOnDoneInsteadOfTheCompletionStampSurvivesAnEvictionItMustNotSurvive:2032 a ticket whose real completion time is long past the advanced cutoff must be evicted, whatever the completion hook's clock read was delayed by ==> expected: <null> but was: <TaskView[ticket=task-1, phase=DONE, reply=quick result, replySource=reply, detail=null, turnId=null]> ``` Ran 3x in a row — 3/3 red, first try every time, same failure every time. ### Which way it fails, and how I determined it (acceptance criterion 4) Without the barrier, the test fails as a **genuine RED assertion failure**, not a false pass: `assertNull(service.poll(ticket))` fails because `poll` still returns the ticket's DONE view — the sweep did not evict it. I determined this by actually removing the `awaitCompletionStamped` call, running the test (see failure text above), and reading the resulting `TaskView` in the failure message: it is the exact object `poll` would return for a ticket that was never pruned, not an exception or a timeout from my own synchronization code. This is the intended mechanism (the hook stamps the clock's already-advanced value, so `cutoff = advanced - TTL` can never exceed it) and not some other defect in the test's wiring. I want to flag one nuance for review: the ticket's own framing calls the pre-#399 failure mode "a FALSE PASS, not a red test." I read that as describing the *general danger* of this race (a test shaped to assert *survival*, like the sibling `aTaskRunningLongerThanTheTtlStillKeepsItsReport`, would falsely stay green under this exact race, per that test's own #399 comment — "happens to survive a late stamp today"), not a requirement that *my* test's own failure mode be a false pass. Acceptance criterion 1 explicitly requires the new test to **fail** without the barrier, which is what I built and verified. If I've misread that framing, happy to adjust. ### Build ``` cd fleetd && mvn clean install > /tmp/b.log 2>&1; echo "EXIT=$?" EXIT=0 [INFO] Tests run: 1502, Failures: 0, Errors: 0, Skipped: 0 [INFO] BUILD SUCCESS ``` `MessageServiceTest` alone: 83 tests (was 82), 0 failures/errors. ### Files changed - `fleetd/src/test/java/dev/ltms/fleet/msg/MessageServiceTest.java` (+74 lines, test-only) ### Also found, not fixed (per ticket instructions — report only) - No other instance of this exact shape (a test ordering on a "done"/observable signal before reading a value a dependent action of that same completion writes) was found in `MessageServiceTest.java` beyond the two `awaitCompletionStamped` call sites already fixed by #399 — I did not do a repo-wide sweep beyond this file, since that's outside this ticket's scope.

agent added 1 commit 2026-09-10 04:39:44 +02:00

fleetd #409 : deterministic test for the #399 completion-stamp ordering race

CI / contract (pull_request) Successful in 45s

Details

CI / build (pull_request) Successful in 2m5s

Details

4e98a74047

Widens the completed-hook's real race window (normally instructions-wide, needing
~2x-core host load to hit by chance per #399) by injecting a bounded sleep into the
test clock's completion-stamp read. This makes the ordering invariant — a test must
wait for isCompletionStampedForTest, not just DONE, before advancing the clock past
the TTL — fail deterministically on the first run when the barrier is removed, and
pass deterministically with it present. No production code changed.

ltms merged commit 4cd9046353 into main

2026-09-10 04:48:45 +02:00

ltms referenced this pull request

2026-09-10 04:49:36 +02:00

The #399 completion-stamp race is verifiable deterministically — nowNanos is already injectable #409

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: fleet/fleetd#414