Skip to content

fix(test): read the copy ordering before the worker is released - #9047

Merged
iamwhatever merged 1 commit into
mainfrom
fix/snapshot-copy-ordering-flake
Sep 6, 2026
Merged

fix(test): read the copy ordering before the worker is released#9047
iamwhatever merged 1 commit into
mainfrom
fix/snapshot-copy-ordering-flake

Conversation

@pepmach

@pepmach pepmach commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

What races

TestNotificationCopyWhenNoLiveFileExists has two ordering tests that both measured the
guarantee after _do_merge returned:

ran_during_copy.wait(timeout=1.0)   # inside the trigger, return value DISCARDED
...
self._merge(snap, home)
assert not ran_during_copy.is_set()  # <-- races correct behaviour

The property under test is that the snapshot copy and a concurrently delivered
notification are ordered, because both run on the single notif-io worker. The
copy occupies that worker; a queued append cannot start until the copy returns.

The trigger submits the append and then blocks the worker on wait(timeout=1.0). The
wait can only be satisfied by the append, and the append can only run on the worker the
wait is blocking — so it always times out. Then:

t worker thread main thread
0 dest O_CREAT open → trigger → submit(append_note)wait(1.0) blocks blocked in submit(work).result()
1.0 wait times out, copy finishes its 200 records, work returns .result() returns
1.0+ε picks up append_note, runs it, sets the event rest of _do_merge, then assert not is_set()

The append's post-copy run is correct — it is the ordering the test is asserting —
and it sets the very event the assertion reads. So the assertion was not measuring the
ordering at all; it was measuring whether the main thread finished _do_merge before the
worker drained one trivial job. Both happen at t≈1.0. On a contended shard the main
thread loses, and shard 4 reddened for PRs whose diffs never touch this path.

Why #8992 didn't close it

#8893/#8992 found a different cause in the same two tests: the trigger fired on the
first O_CREAT seen anywhere, and because the hook patches os.open process-wide, a
foreign thread's creating open could submit the append while the worker was still free.
36ffa67ea scoped both triggers to the copy's own destination path. That is correct and
is kept here — its diff touched only the two if conditions:

-            if flags & os.O_CREAT and not submitted:
+            if flags & os.O_CREAT and os.fspath(path) == dst and not submitted:

It left the observation point alone, so the second, independent cause survived. It
narrowed the flake rather than closing it.

Notably, #8992 already wrote the correct shape in the regression test it added,
test_the_ordering_trigger_ignores_a_foreign_O_CREAT_open, whose comment states the
reason exactly: "the ordering measurement is captured INSIDE the trigger — the wait's
return value, taken while the copy still holds the worker — where the append's legitimate
post-copy run cannot race it."
It simply was not retrofitted onto the two older tests.
This PR does that retrofit.

The fix

Capture the wait's own return value inside the trigger and assert on it:

ran_while_worker_held.append(ran_during_copy.wait(timeout=1.0))
...
assert ran_while_worker_held == [False]

In that window the worker is held by the copy, so only the defect can set the event.
Test-only: no retries, no longer timeouts, no weakened assertion.

Production is sound and unchanged

_copy_notifications wraps its whole body in
_serialise_with_notification_writes(lambda: _install_notifications(...)), so the
destination O_CREAT|O_EXCL|O_APPEND|O_NOFOLLOW open genuinely happens on the worker the
copy occupies. The serialisation, the acquire-don't-ask executor (#8576) and the locked
lazy init (#8788) are all correct. git diff origin/main..HEAD -- src/ is empty.

Reproduce + prove

Harness: 14 concurrent processes × 8 iterations, each running the class's three ordering
tests, on a 32-core host — the CPU contention of a loaded shard.

runs pass fail
base f4268fb56 (with #8992's cure) 112 85 27 (24%)
this branch 112 112 0

Both reported failures reproduced verbatim on base:

FAILED ...::test_a_note_delivered_during_the_copy_survives_the_READER
  AssertionError: the append ran while the copy was still writing, so the two are
  concurrent rather than ordered
FAILED ...::test_a_FRESH_gateway_still_orders_the_copy_against_a_delivery
  AssertionError: a delivery on a fresh gateway ran concurrently with the copy:
  'no pool' was read as 'no writer'

test_the_ordering_trigger_ignores_a_foreign_O_CREAT_open — the one test that already
used the in-trigger observation point — never failed once in those 112 base runs,
which is direct empirical isolation of the mechanism: same triggers, same contention,
same production code, only the observation point differs.

Assertion strength, not weakness. With the production serialisation removed
(submit(work).result()work()), all three tests fail on the new assertion:

E  AssertionError: the append ran while the copy was still writing, ...
E  assert [True] == [False]

Gates (touched file only)

black --check clean · isort --check-only clean · flake8 clean ·
mypy --platform linux via the CI-parity venv: error set identical to base
(2 pre-existing in this file, 0 new).

Why no screenshot: backend-only change, and test-only within that — two assertions and
their explanatory comments in test/test_snapshot.py. No dashboard, API, or rendered
surface is touched.

Pattern harvest

Rule candidate: When a test proves an ORDERING by blocking a single-worker pool and
checking that a queued job did not run, take the measurement INSIDE the blocking window
and assert on the blocking call's own return value. Reading the shared event/flag after
the operation returns races the queued job's LEGITIMATE post-release run, which sets the
same flag — so the assertion silently degrades into a footrace between the main thread
and the worker, and reddens under load while the guarantee is intact.

Rule candidate: When a flake recurs after a cure, check whether the cure's own new
regression test uses a different observation shape than the tests it was fixing. A cure
that adds a correctly-shaped test beside the old shape has usually fixed one cause and
left another; the fix is to retrofit the proven shape, and the cure's own comments
frequently already state why it is the right one.

Not generalizable: The 1.0s wait timeout, the 200-record archive sized to
_MAX_PERSISTED_NOTIFICATIONS, and the notif-io thread-name prefix are specific to the
notification-copy path and its positional reader cap.

Both notification-copy ordering tests measured the guarantee AFTER
`_do_merge` returned, with `assert not ran_during_copy.is_set()`. By
that point the copy has released the single `notif-io` worker and the
worker runs the queued append -- which is the CORRECT behaviour the
tests exist to prove, and it sets the same event. So the assertion was
really measuring whether the main thread reached it before that
legitimate run: a footrace between the main thread finishing `_do_merge`
and the worker draining one trivial job. On a contended shard the main
thread loses, and shard 4 reddened for PRs whose diffs never touch this
path.

#8893/#8992 found and fixed a different cause in the same two tests --
the trigger fired on the first `O_CREAT` seen anywhere, so a foreign
thread's open submitted the append while the worker was still free. That
scoping is correct and is kept. It narrowed the flake without closing it
because the observation point was left alone.

The fix is the shape #8992 already introduced in
`test_the_ordering_trigger_ignores_a_foreign_O_CREAT_open` and did not
retrofit: capture the wait's own return value INSIDE the trigger, while
the copy still holds the worker, and assert on that. In that window only
the defect can set the event, so the measurement no longer competes with
correct behaviour.

Production is unchanged and sound: `_copy_notifications` wraps its whole
body in `_serialise_with_notification_writes`, so the destination
`O_CREAT|O_EXCL` open genuinely happens on the worker the copy occupies.
The assertion is not weakened -- with the serialisation removed all
three tests fail `[True] == [False]`.
@pepmach
pepmach requested a review from a team as a code owner September 6, 2026 15:04
@pepmach
pepmach requested a review from dwu96 September 6, 2026 15:04
@github-actions github-actions Bot added the readiness: checking Automated validation is still running label Sep 6, 2026
@github-actions

github-actions Bot commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

Design Review (Fable 5) — ✅ PASS

Design-level review of 29310444b7126beab62d9e42266a3f1a17533f41 — updated in place on each push. A BLOCK verdict blocks PR readiness; PASS/CONCERNS are advisory.

Design-Verdict: PASS

Retrofits the already-proven in-trigger observation point onto the two remaining races, fixing the measurement's root cause with empirical falsification both ways.

[DESIGN-REVIEWED] 2931044

@github-actions

github-actions Bot commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

GPT 5.6 Review — ✅ no blocking findings

GPT 5.6 completed its review of 29310444b7126beab62d9e42266a3f1a17533f41 and found no blocking issues.

This comment is updated in place on each push.

Review details

No findings.
[GPT-REVIEWED] 2931044

False positive or not applicable? A repository writer can comment:
/ai-review override gpt 29310444b7126beab62d9e42266a3f1a17533f41: <one-sentence reason>

@github-actions

github-actions Bot commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

Opus 4.8 Review — ✅ no blocking findings

Reviewed 29310444b7126beab62d9e42266a3f1a17533f41 — this comment is updated in place on each push.

Review details

No findings.

[OPUS-REVIEWED] 2931044

Verdict parsed from the review's SHA-scoped output markers for commit 29310444b7126beab62d9e42266a3f1a17533f41.

False positive or not applicable? A repository writer can comment:
/ai-review override fable 29310444b7126beab62d9e42266a3f1a17533f41: <one-sentence reason>

@github-actions github-actions Bot added readiness: passed Eligible automated validation passed for the current revision and removed readiness: checking Automated validation is still running labels Sep 6, 2026
@iamwhatever
iamwhatever enabled auto-merge (squash) September 6, 2026 16:03

@iamwhatever iamwhatever left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tier 1 auto-approve: test (1 file). Criteria: no conflict, no requested changes, security path denylist clean, design-doc gate clean, SAST annotations clean, security checklist all-NO, AI reviewers green. Category: test-only change to test/test_snapshot.py -- moves the concurrency observation point inside the trigger window (records the wait() return value while the copy still holds the worker) instead of reading Event.is_set() after _merge, removing a footrace against the legitimate post-copy append; no production code touched.

@iamwhatever
iamwhatever merged commit d7fb9c5 into main Sep 6, 2026
64 checks passed
@iamwhatever
iamwhatever deleted the fix/snapshot-copy-ordering-flake branch September 6, 2026 16:03
@github-actions github-actions Bot removed the readiness: passed Eligible automated validation passed for the current revision label Sep 6, 2026

@dwu96 dwu96 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tier 1 auto-approve: test (1 file). Criteria: no conflict, no requested changes, security path denylist clean, design-doc gate clean, SAST annotations clean, security checklist all-NO, AI reviewers green. Category: test-only change to test/test_snapshot.py that moves the ordering observation point inside the trigger window, no runtime code touched.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants