Skip to content

Three deadline tests fire the real deadline inside the held operation, not on wall time (BACKLOG #3871) - #2439

Merged
wshallwshall merged 3 commits into
mainfrom
b3871-sibling-deflake
Oct 20, 2026
Merged

wshallwshall merged 3 commits into
mainfrom
b3871-sibling-deflake

Conversation

@wshallwshall

Copy link
Copy Markdown
Collaborator

Vault BACKLOG #3871, the remainder: the last three tests on the row that raced a wall-clock request deadline, plus a fourth case found in review. Together with engine PR 2438 (test_ui_dr_outlive), this closes the row. Test-only; production code is unchanged.

The race (the same in every case)

The deadline was wall time from the start of the request. When the auth dependencies, the body read, or the file save outlasted it, the 503 fired before the route reached OutlivingOperations.run, so the test asserted on state the code never reached. The merge-queue failure of test_upload_api.py::test_a_deadline_during_the_create_row_still_writes_it ("ValueError: not enough values to unpack (expected 1, got 0)", run 39177122501) is this race: the deadline fired before or during us.save, which removes its pair on cancellation (#2262). That is correct product behaviour.

What changed

  • New tests/_deadline_capture.py (registered for assert rewriting in tests/conftest.py):
    • capture_deadlines(monkeypatch, app) records the middleware's real asyncio.Timeout, set to a 15 s deadline that never fires on its own.
    • The held operation awaits capture.cut_off(), which reschedules that deadline to now, so the middleware's own 503 lands mid-operation.
    • async with capture.held(): releases the operation and waits with OutlivingOperations.drain, asserting nothing was cancelled.
    • expect_cut_off asserts the exact 503 body.
    • A bad fire (zero deadlines, more than one, already disarmed, or a refused reschedule) never deadlocks: it records the reason and releases.
  • test_dr_outlive_deadline.py:
    • The release test cuts off after park_intake, with the box active and intake unbound. All original end-state assertions are kept, plus inflight == ["DR release"].
    • The activation test cuts off in _activate_profile, with the original assertions kept.
  • test_reload_cancellation.py: cuts off in reload_detail. It asserts inflight == ["config reload"] and no row while held, then that the row is written after the caller left and there is no interrupted row. The dead deadline parameter and the _wait helper are removed.
  • test_upload_api.py:
    • The create and delete tests cut off inside the parked audit write; mid-cut, the create test asserts one stored file.
    • The mid-sweep test, added in review, fires the deadline from the sweep thread via call_soon_threadsafe.
    • _settle is removed.
  • PR 2438's web console copy is untouched; that PR owns its file.

Proof

Arm Before After
serial, 200 runs of each of the six 0 failed 0 failed
parallel: the three files x50, -n auto (3000 tests) 3000 passed 3000 passed
slowed arm (OutlivingOperations.run delayed 0.7 s before registering), five tests 25 of 25 failed 25 of 25 and 15 of 15 passed
slowed arm 2.5 s, mid-sweep 3 of 3 failed 3 of 3 passed

Plain loops do not reproduce the flake on this box; the slowed arm does, and it reproduces the exact CI failure. Mutations, each reverted:

  • OutlivingOperations.run as a plain await: five tests red, also confirmed independently by the code-review skill.
  • drained hard-coded True: the release test red.
  • Sweep on_cancel=lambda: None: the mid-sweep test red.

Checks

  • ruff and format: clean.
  • mypy linux 361, win32 342, tests 1393: all clean, re-run on the final code.
  • pytest: the three files give 60 passed; the related request-timeout, DR, reload, dual-control, upload and web console DR suites give 421 passed at -n auto.
  • Not run: the full suite, and the Postgres and SQL Server legs.
  • The Builder's git merge-tree --write-tree origin/main eaccaab9b exited 0 at main d61284d, with a self-merge control at 0.

Open findings (code review at xhigh, 2 rounds; no correctness defect in what the tests prove)

  1. The mid-sweep test keeps 5 s wall-clock safety bounds, the sweep thread's abort wait and the route's ledger cancel wait. That is far looser than the old 2.0 s race, but not zero.
  2. _admin_client in test_dr_outlive_deadline keeps a dead deadline parameter; two other test files import it.
  3. The seam depends on how the middleware imports asyncio. A change there fails loudly, not silently; a first-class seam would be a production change.
  4. held() cannot report the operation's own exception, because OutlivingOperations exposes no task results. The outcome-row assertions cover it instead.
  5. Two copies of the stand-in exist: PR 2438's web console one, with fewer checks, and this helper. They could be consolidated after both land.
  6. expect_cut_off pins the 503 body literal, as test_api_request_timeout.py does.

Proposed banner

SHIPPED -- all four tests on the row (test_ui_dr_outlive in PR 2438; test_dr_outlive_deadline, test_reload_cancellation and test_upload_api here) fire the middleware's real deadline inside the held operation instead of racing wall time (BACKLOG #3871).

…, not on wall time (BACKLOG #3871)

test_dr_outlive_deadline (activation and release), test_reload_cancellation and
test_upload_api (create row and delete row) set the request deadline to a
fraction of a second. It counts from the start of the request, so on a loaded
runner the auth dependencies, the body read or the file save outlasted it: the
503 came before the route started its outliving operation, and the test failed
on a state the code never reached (the merge-queue failure of 2026-10-19,
"not enough values to unpack (expected 1, got 0)", is the create test's form).

A new tests/_deadline_capture.py, the same stand-in engine PR 2438 uses in the
web console, records the middleware's own asyncio.Timeout under a 30 s deadline.
The held operation fires it to now and is held until the 503 is in; the test
then waits on OutlivingOperations.drain instead of polling a clock.

Ledger banner: #3871 remainder done -- the three sibling tests fire the deadline
inside the held operation; test_upload_api's mid-sweep test (2.0 s) is not covered.
… upload test fires it too (BACKLOG #3871)

Code-review round 1. fire() records a miscount or an already-started response
on the capture instead of raising on the operation's task, where the DR
coordinator would catch it and write abort rows; expect_cut_off asserts it.
The middleware module sees only timeout() (no Any-typed __getattr__), the
deadline attribute is set through monkeypatch so it is undone, held() takes
the app's OutlivingOperations from the capture, the generous deadline drops to
15 s so a failing run still ends inside the per-test timeout, and the
rationale lives once, in tests/_deadline_capture.py.

test_a_deadline_mid_sweep_still_writes_a_prune_row_per_deleted_file raced a
2.0 s wall-clock deadline the same way; its parked sweep thread now fires the
captured deadline through call_soon_threadsafe.

Proposed PR title: Three deadline tests fire the real deadline inside the held operation, not on wall time (BACKLOG #3871)
Ledger banner: #3871 remainder done -- test_dr_outlive_deadline, test_reload_cancellation and test_upload_api (create, delete and mid-sweep) fire the deadline inside the held operation.
… deadlocks (BACKLOG #3871)

Code-review round 2. When fire() finds no deadline, a second one, a disarmed
one, or one reschedule refuses, it fires nothing, records the reason and lets
the hold go, so the request ends and expect_cut_off reports the reason (also
when the request raised). fired now means a deadline really was expired. The
helper is registered for assert rewriting in conftest, as tests._content_free
is. The mid-sweep test checks that its sweep parked before it reads the
response, as it did before.

Proposed PR title: Three deadline tests fire the real deadline inside the held operation, not on wall time (BACKLOG #3871)
Ledger banner: #3871 remainder done -- test_dr_outlive_deadline, test_reload_cancellation and test_upload_api (create, delete and mid-sweep) fire the deadline inside the held operation.
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

QA for head eaccaab (the Builder's line, posted by the Manager): QA -- korus roles/BUILDER.md step 11 / Level: xhigh, from the brief. Tag: none printed (findings list only, both rounds). / Rounds: 2. Findings: round 1 raised 13, round 2 raised 13, all diagnostic, robustness or cleanup, none a correctness defect in what the tests prove; most fixed in 55f7dae and eaccaab; 6 open, listed in the PR body.

@wshallwshall wshallwshall added the qa Builder QA record posted; not a merge gate label Oct 20, 2026
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Lander: enqueued at eaccaab, pinned.

  • Review: the QA line names this head (code-review at xhigh, 2 rounds, no correctness defect).
  • This PR changes tests only.
  • Its 6 open findings are on vault #3871, now on main through pass 10 (vault PR 2547). Closing step 5 carries findings 1 and 5 to a new row when #3871 closes. Graded non-blocking: no product behaviour changes and no control is weakened. That grade is a Lander decision under the owner's Driver delegation, not an owner ruling.
  • All 9 live required contexts are SUCCESS on this head.

@wshallwshall
wshallwshall added this pull request to the merge queue Oct 20, 2026
Merged via the queue into main with commit f6b805c Oct 20, 2026
51 checks passed
@wshallwshall
wshallwshall deleted the b3871-sibling-deflake branch October 20, 2026 02:11
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

qa Builder QA record posted; not a merge gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant