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

Closed
opened 2026-09-10 04:27:34 +02:00 by ltms · 2 comments
Owner

Why this ticket exists

#399 is fixed and merged (ae74cc0), but nobody can verify the fix, and the reason is a
measurement problem rather than a code problem.

The evidence we have is a flake. On fleet01 at 799014e, in time order:

01:04  full suite    -> FAIL
01:05  method alone  -> FAIL
01:18-01:24  method alone x12 -> 12 PASS

So the unfixed code passes 12 times in a row. That makes a passing run worthless as evidence
about the fix:

P(12 green | unfixed, p=2/14 = .143) = 0.157
P(12 green | unfixed, p=1/13 = .077) = 0.383
runs needed for 95% confidence at p=2/14: 19.4   (at 1/13: 37.4)

I confirmed the same uselessness from the other side on this host: 10 separate cold JVMs of
MessageServiceTest at current main, all green, 82 tests each, elapsed 6.644-6.701 s. Ten green
runs that tell me nothing, because the unfixed code would very likely have produced them too.

A probabilistic test of a race needs ~20-40 runs to say anything. A deterministic one needs one.

The goal

MessageServiceTest should contain a test that fails on the pre-#399 ordering and passes on the
current ordering
, every time, on any host, with no repeat runs and no dependence on machine load.

The invariant to pin is the ordering itself:

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.

Why this is reachable — the seam already exists

MessageService takes its clock as an injected LongSupplier (MessageService.java:342), and
both sides of the race read from that one supplier:

  • MessageService.java:259-260 — the task's createdNanos, and the hook:
    future.whenComplete((reply, ex) -> completedNanos = nowNanos.getAsLong());
  • MessageService.java:1374 — the sweep: long cutoff = nowNanos.getAsLong() - TICKET_TTL_NANOS;

So a test-supplied clock can observe and influence when the hook stamps, without touching
production code. No new production seam is needed. Confirm that before designing anything — if it
turns out a new seam is required, say so in your reply and stop; do not add one on your own
judgment.

What makes the old ordering fail

MessageServiceTest.java:1955 carries the explanation in a comment added by the fix:

DONE can be observed before the completion hook stamps completedNanos. Wait for the real stamp
before advancing the clock, or the hook can run late and stamp the ADVANCED time — making
cutoff = advanced - TTL unreachable and hiding the very eviction this test exists to pin.

That is the mechanism to weaponise: make the hook stamp late but bounded, so that a test which
orders on DONE proceeds, advances the clock, sweeps, and then receives a stamp carrying the
advanced value. The eviction is then missed and the bug is hidden behind a false pass.

Note the direction: the pre-fix failure mode here is a false pass, not a red test. A test that
merely goes red on the old code is not sufficient evidence you reproduced this — check which way it
fails and say so.

This mechanism is a candidate, not an instruction. A bounded delay inside the supplier is the
obvious lever, but a latch, a counting supplier that stalls on the Nth call, or something else may
be cleaner. Pick what makes the test readable and reliable, and explain the choice. If the
mechanism cannot work, say why — that answer is worth as much as the test.

Constraints

  • Do not change the production expired expression in pruneTerminalTickets, and do not change
    the TTL. This ticket adds test coverage; it is not a behaviour change.
  • Any production change must be additive and test-only in effect. If you believe production must
    change, stop and report instead.
  • No Thread.sleep as the synchronisation primitive in the assertion path. A sleep long enough
    to be reliable is slow, and a short one reintroduces the flake this ticket exists to remove.
    Sleeping inside the injected clock to widen the window is a different thing and is acceptable.
  • The test must be bounded: it fails with a clear message rather than hanging if the stamp never
    lands.
  • Keep the existing awaitCompletionStamped barrier and both of its call sites.

Acceptance

  1. A new test in MessageServiceTest that fails deterministically when the barrier call at
    MessageServiceTest.java:1955 is removed, and passes with it present. Demonstrate both
    directions by actually running them, and paste the two results.
  2. It must fail on the first run — no repetition, no load, no retry loop.
  3. mvn clean install green. Report the real Tests run: line, unpiped.
  4. State plainly whether the pre-fix shape fails as a red test or as a false pass, and how you
    determined which.

Report back

The two run results (barrier removed / barrier present), the mechanism you chose and why, the full
build line, and anything you found that has this same shape elsewhere — report it, do not fix it.

Context: fleetd #399, merged as PR #405. The barrier is already known to be load-bearing: removing
the production stamp fails 3 tests. What is not pinned is the ordering guarantee itself.

## Why this ticket exists #399 is fixed and merged (`ae74cc0`), but **nobody can verify the fix**, and the reason is a measurement problem rather than a code problem. The evidence we have is a flake. On fleet01 at `799014e`, in time order: ``` 01:04 full suite -> FAIL 01:05 method alone -> FAIL 01:18-01:24 method alone x12 -> 12 PASS ``` So the unfixed code **passes 12 times in a row**. That makes a passing run worthless as evidence about the fix: ``` P(12 green | unfixed, p=2/14 = .143) = 0.157 P(12 green | unfixed, p=1/13 = .077) = 0.383 runs needed for 95% confidence at p=2/14: 19.4 (at 1/13: 37.4) ``` I confirmed the same uselessness from the other side on this host: 10 separate cold JVMs of `MessageServiceTest` at current main, all green, 82 tests each, elapsed 6.644-6.701 s. Ten green runs that tell me nothing, because the unfixed code would very likely have produced them too. **A probabilistic test of a race needs ~20-40 runs to say anything. A deterministic one needs one.** ## The goal `MessageServiceTest` should contain a test that **fails on the pre-#399 ordering and passes on the current ordering**, every time, on any host, with no repeat runs and no dependence on machine load. The invariant to pin is the ordering itself: > 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. ## Why this is reachable — the seam already exists `MessageService` takes its clock as an injected `LongSupplier` (`MessageService.java:342`), and **both** sides of the race read from that one supplier: - `MessageService.java:259-260` — the task's `createdNanos`, and the hook: `future.whenComplete((reply, ex) -> completedNanos = nowNanos.getAsLong());` - `MessageService.java:1374` — the sweep: `long cutoff = nowNanos.getAsLong() - TICKET_TTL_NANOS;` So a test-supplied clock can observe and influence *when the hook stamps*, without touching production code. No new production seam is needed. Confirm that before designing anything — if it turns out a new seam **is** required, say so in your reply and stop; do not add one on your own judgment. ## What makes the old ordering fail `MessageServiceTest.java:1955` carries the explanation in a comment added by the fix: > `DONE` can be observed before the completion hook stamps `completedNanos`. Wait for the real stamp > before advancing the clock, or the hook can run late and stamp the **ADVANCED** time — making > `cutoff = advanced - TTL` unreachable and hiding the very eviction this test exists to pin. That is the mechanism to weaponise: make the hook stamp **late but bounded**, so that a test which orders on `DONE` proceeds, advances the clock, sweeps, and then receives a stamp carrying the advanced value. The eviction is then missed and the bug is hidden behind a false pass. Note the direction: the pre-fix failure mode here is a **false pass**, not a red test. A test that merely goes red on the old code is not sufficient evidence you reproduced this — check which way it fails and say so. **This mechanism is a candidate, not an instruction.** A bounded delay inside the supplier is the obvious lever, but a latch, a counting supplier that stalls on the Nth call, or something else may be cleaner. Pick what makes the test readable and reliable, and explain the choice. If the mechanism cannot work, say why — that answer is worth as much as the test. ## Constraints - **Do not change the production `expired` expression** in `pruneTerminalTickets`, and do not change the TTL. This ticket adds test coverage; it is not a behaviour change. - Any production change must be additive and test-only in effect. If you believe production must change, stop and report instead. - **No `Thread.sleep` as the synchronisation primitive** in the assertion path. A sleep long enough to be reliable is slow, and a short one reintroduces the flake this ticket exists to remove. Sleeping *inside the injected clock* to widen the window is a different thing and is acceptable. - The test must be bounded: it fails with a clear message rather than hanging if the stamp never lands. - Keep the existing `awaitCompletionStamped` barrier and both of its call sites. ## Acceptance 1. A new test in `MessageServiceTest` that **fails deterministically** when the barrier call at `MessageServiceTest.java:1955` is removed, and passes with it present. Demonstrate both directions by actually running them, and paste the two results. 2. It must fail on the **first** run — no repetition, no load, no retry loop. 3. `mvn clean install` green. Report the real `Tests run:` line, unpiped. 4. State plainly whether the pre-fix shape fails as a red test or as a false pass, and how you determined which. ## Report back The two run results (barrier removed / barrier present), the mechanism you chose and why, the full build line, and anything you found that has this same shape elsewhere — report it, do not fix it. Context: fleetd #399, merged as PR #405. The barrier is already known to be load-bearing: removing the production stamp fails 3 tests. What is *not* pinned is the ordering guarantee itself.
Author
Owner

Correction to this ticket's premise — a reproduction recipe now exists

Posted after the brief went out, so read this if you are working the ticket. Nothing in the goal,
the constraints or the acceptance criteria changes. What changes is one claim I made in the framing,
and one new tool you can use to check your own work.

What I got wrong above

I wrote "a probabilistic test of a race needs ~20-40 runs to say anything." That was derived from
runs taken below the load threshold, where the race essentially never fires. The fleet01 lead then
ran the controlled A/B — one host, one commit, one command, load as the only varied thing:

PHASE A   load 4.94 -> 8.51    6 runs   pass=6  fail=0
PHASE B   load 17.59 -> 23.37  6 runs   pass=1  fail=5

Phase B was 16 CPU spinners on 8 cores. The threshold is roughly 2x cores. Above it, six runs are
plenty; below it, forty prove nothing. So the honest version of my sentence is: sampling below the
threshold is a null experiment, not a weak one.

I also told you I ran 10 cold JVMs here, all green, and implied that meant the race would not
reproduce on this host. That was wrong for the same reason — this Mac was at load 2.10 on 12 cores.
Do not take those 10 green runs as evidence about anything.

Why the ticket still stands, unchanged

A deterministic test is still strictly better than the load recipe:

  • it fails on the first run, at any load, so it works in CI without a spinner harness
  • it does not depend on a threshold that may differ per host, per core count, or per JDK
  • it cannot rot into "this test is flaky, quarantine it", which is where load-dependent tests go

So build the test as briefed. The recipe below is not an alternative to it.

What the recipe gives you — a way to check your own test is honest

This is the useful part for you. Once your deterministic test exists, you have a cross-check
available that did not exist when I wrote the brief:

If your test is pinning the real defect, it must go red on exactly the code that goes red under
~2x-cores load. If it goes green where load goes red, your test is pinning something else.

That is a much stronger self-check than "it fails when I remove the barrier", because removing the
barrier is a change you chose. You are not required to run the load comparison — I will run it on
this host (12 cores, ~24 spinners) once you are finished, since loading the machine while you are
building would corrupt your results. But if your test passes when you expect it to fail, or you are
unsure whether you reproduced the right thing, say so in your reply rather than tuning the test
until it goes red. An unsure answer is more useful to me than a confident wrong one.

One detail from the load data that matters for acceptance criterion 4

Phase B counts red runs. The brief tells you the pre-fix failure mode is a false pass, and both
are true — they are different call sites. MessageServiceTest.java:1920 carries a comment saying its
own assertion happens to survive a late stamp (the clock is not advanced further before its sweep),
while :1955 is the one where a late stamp records the advanced time and hides a real eviction.

So when you answer criterion 4, say which call site you reproduced and which failure mode you
saw there. "It fails" is not specific enough to tell whether you hit the false-pass site or the red
site.

## Correction to this ticket's premise — a reproduction recipe now exists Posted after the brief went out, so **read this if you are working the ticket.** Nothing in the goal, the constraints or the acceptance criteria changes. What changes is one claim I made in the framing, and one new tool you can use to check your own work. ### What I got wrong above I wrote "a probabilistic test of a race needs ~20-40 runs to say anything." That was derived from runs taken **below the load threshold**, where the race essentially never fires. The fleet01 lead then ran the controlled A/B — one host, one commit, one command, load as the only varied thing: ``` PHASE A load 4.94 -> 8.51 6 runs pass=6 fail=0 PHASE B load 17.59 -> 23.37 6 runs pass=1 fail=5 ``` Phase B was 16 CPU spinners on 8 cores. **The threshold is roughly 2x cores.** Above it, six runs are plenty; below it, forty prove nothing. So the honest version of my sentence is: *sampling below the threshold is a null experiment, not a weak one.* I also told you I ran 10 cold JVMs here, all green, and implied that meant the race would not reproduce on this host. That was wrong for the same reason — this Mac was at load 2.10 on 12 cores. Do not take those 10 green runs as evidence about anything. ### Why the ticket still stands, unchanged A deterministic test is still strictly better than the load recipe: - it fails on the first run, at any load, so it works in CI without a spinner harness - it does not depend on a threshold that may differ per host, per core count, or per JDK - it cannot rot into "this test is flaky, quarantine it", which is where load-dependent tests go So build the test as briefed. The recipe below is not an alternative to it. ### What the recipe gives you — a way to check your own test is honest This is the useful part for you. Once your deterministic test exists, you have a cross-check available that did not exist when I wrote the brief: **If your test is pinning the real defect, it must go red on exactly the code that goes red under ~2x-cores load. If it goes green where load goes red, your test is pinning something else.** That is a much stronger self-check than "it fails when I remove the barrier", because removing the barrier is a change you chose. You are not required to run the load comparison — I will run it on this host (12 cores, ~24 spinners) once you are finished, since loading the machine while you are building would corrupt your results. But if your test passes when you expect it to fail, or you are unsure whether you reproduced the right thing, say so in your reply rather than tuning the test until it goes red. An unsure answer is more useful to me than a confident wrong one. ### One detail from the load data that matters for acceptance criterion 4 Phase B counts **red** runs. The brief tells you the pre-fix failure mode is a **false pass**, and both are true — they are different call sites. `MessageServiceTest.java:1920` carries a comment saying its own assertion happens to survive a late stamp (the clock is not advanced further before its sweep), while `:1955` is the one where a late stamp records the **advanced** time and hides a real eviction. So when you answer criterion 4, say **which call site** you reproduced and which failure mode you saw there. "It fails" is not specific enough to tell whether you hit the false-pass site or the red site.
Author
Owner

Merged as part of PR #414. Ruling on the contradiction the worker flagged: they were right, and the fault was in my brief.

The contradiction was mine, not a misreading

My ticket said two things that cannot both hold for one test:

  • the pre-fix failure mode is "a FALSE PASS, not a red test"
  • acceptance criterion 1: the test must literally fail without the barrier

Those describe two different test shapes, and I wrote them as if they described one.

A test that asserts survival cannot go red under this race. aTaskRunningLongerThanTheTtlStillKeepsItsReport asserts assertNotNull, so a late stamp leaves it green - it passes for the wrong reason. That is the false pass, and it is unfalsifiable by construction.

A test that asserts eviction is the only shape the race can turn red, because eviction is the direction a missing stamp blocks. So criterion 1 could only ever be met by the eviction shape.

The worker read the false-pass sentence as describing the sibling test, picked the eviction shape mirroring aFinishedTicketIsStillPrunedOnceTheTtlPassesSinceItFinished, and said so in the PR body in case they had misread my intent. They had not. My brief held a requirement and its own counter-example side by side.

What I checked myself before merging

I did not promote their "3/3" to a fact:

direction runs result
barrier present 2/2 Tests run: 83, Failures: 0
barrier line deleted 2/2 Failures: 1, only this test, identical assertion

I also checked the claim their comment asserts, in the code: pruneTerminalTickets has exactly one caller (sendAsync:1270) and poll never prunes. So between delayArmed.set(true) and the completion hook, no other nowNanos reader runs, and the one-shot delay cannot be consumed by the wrong call site. That claim was load-bearing - if another site ate the delay, the hook would stamp promptly, the barrier would become a no-op, and the test would go green while pinning nothing.

The green direction has no timing budget to lose: awaitCompletionStamped allows 3000ms against a 300ms sleep, and the test thread blocks there while the async thread sleeps. Only the manual red-direction experiment spends the 300ms window, and it needs microseconds of it.

Scope limit, recorded so nobody over-reads the test

This pins the test-harness invariant, not a production guarantee. Production deliberately leaves a done-but-unstamped ticket alone (MessageService.java:1369-1371 - "the next sweep collects it"). In the red direction the ticket survives because completedNanos was still null at the sweep, and the test runs no second sweep. So the test proves: a test that advances the clock and sweeps without waiting for the stamp gets a wrong answer. That is exactly what this ticket asked for. It is not evidence that production evicts correctly under a late stamp.

For my own future briefs

This is the sixth time a defect came from my own ticket text rather than the code. The specific error here: I described the failure mode and the acceptance criterion from two different test shapes without naming which shape each applied to. State the shape the criterion is about, or the worker has to guess which of my two sentences to obey - and a worker who guesses right still loses a turn asking.

Closing.

Merged as part of PR #414. Ruling on the contradiction the worker flagged: **they were right, and the fault was in my brief.** ## The contradiction was mine, not a misreading My ticket said two things that cannot both hold for one test: - the pre-fix failure mode is "a FALSE PASS, not a red test" - acceptance criterion 1: the test must literally fail without the barrier Those describe **two different test shapes**, and I wrote them as if they described one. A test that asserts **survival** cannot go red under this race. `aTaskRunningLongerThanTheTtlStillKeepsItsReport` asserts `assertNotNull`, so a late stamp leaves it green - it passes for the wrong reason. That is the false pass, and it is unfalsifiable by construction. A test that asserts **eviction** is the only shape the race can turn red, because eviction is the direction a missing stamp blocks. So criterion 1 could only ever be met by the eviction shape. The worker read the false-pass sentence as describing the sibling test, picked the eviction shape mirroring `aFinishedTicketIsStillPrunedOnceTheTtlPassesSinceItFinished`, and said so in the PR body in case they had misread my intent. They had not. My brief held a requirement and its own counter-example side by side. ## What I checked myself before merging I did not promote their "3/3" to a fact: | direction | runs | result | |---|---|---| | barrier present | 2/2 | `Tests run: 83, Failures: 0` | | barrier line deleted | 2/2 | `Failures: 1`, only this test, identical assertion | I also checked the claim their comment asserts, in the code: `pruneTerminalTickets` has exactly one caller (`sendAsync:1270`) and `poll` never prunes. So between `delayArmed.set(true)` and the completion hook, no other `nowNanos` reader runs, and the one-shot delay cannot be consumed by the wrong call site. That claim was load-bearing - if another site ate the delay, the hook would stamp promptly, the barrier would become a no-op, and the test would go green while pinning nothing. The green direction has no timing budget to lose: `awaitCompletionStamped` allows 3000ms against a 300ms sleep, and the test thread blocks there while the async thread sleeps. Only the manual red-direction experiment spends the 300ms window, and it needs microseconds of it. ## Scope limit, recorded so nobody over-reads the test This pins the **test-harness** invariant, not a production guarantee. Production deliberately leaves a done-but-unstamped ticket alone (`MessageService.java:1369-1371` - "the next sweep collects it"). In the red direction the ticket survives because `completedNanos` was still `null` at the sweep, and the test runs no second sweep. So the test proves: *a test that advances the clock and sweeps without waiting for the stamp gets a wrong answer.* That is exactly what this ticket asked for. It is not evidence that production evicts correctly under a late stamp. ## For my own future briefs This is the sixth time a defect came from my own ticket text rather than the code. The specific error here: I described the *failure mode* and the *acceptance criterion* from two different test shapes without naming which shape each applied to. State the shape the criterion is about, or the worker has to guess which of my two sentences to obey - and a worker who guesses right still loses a turn asking. Closing.
ltms closed this issue 2026-09-10 04:49:41 +02:00
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: fleet/fleetd#409