fix(test): /ws/stats tests slept 50 ms and hoped — poll the condition instead - #58
Merged
Merged
Conversation
… instead main is RED. `test (windows-2022, py3.14)` failed at be2fc08, the squash-merge of PR #56, whose own head was 33/33 green: assert harness.frames, "expected at least one stats frame before revocation" AssertionError: assert [] Not the merged change -- PR #56 touched TLS key-exchange policy, an OIDC settings validator and docs, none of which this route reaches. The test is defective, and this is deliberately NOT being treated as a flake to re-run: this repo has already mistaken a livelock for one, and no rerun or timeout ever fixed that. The defect: the first frame cannot be sent until `store.stats()` returns -- the route awaits it, builds the frame, then sends -- and the fixed 50 ms sleep had to cover that query PLUS scheduling the harness task, the handshake, and the handshake-time authorize. None of which these tests measure. It passes locally 3/3 in 10.06s, 12.33s and 3.89s, and that spread is the tell. Replaced the sleep with `_wait_for_first_frame`, a bounded poll on the ACTUAL asserted condition. This does not weaken the precondition: a frame is still required, and still required BEFORE the revocation. It also distinguishes a dead task from a slow one -- `task.result()` re-raises the real failure, because a route that blew up would otherwise be indistinguishable from a loaded runner, and "timed out waiting for a frame" is the least useful description of a traceback. A SECOND, quieter defect fixed at the same time. test_disabled_account_is_closed also slept 50 ms and asserts only `close_code == 1008` -- which BOTH the mid-stream revalidation and the pre-first-send re-check produce. So on a slow box the account was disabled before the first send, the close came from the wrong path, the assertion still held, and the test silently stopped covering what its comment claims while duplicating what test_revoke_before_first_send_yields_no_frames already owns. A coverage move with no symptom. It now waits for a frame, so "mid-stream" is a fact. New test_a_slow_first_stats_build_does_not_break_the_precondition makes the CI failure DETERMINISTIC: it stalls `store.stats()` to 0.4s, 8x the old budget, so the old form fails on any machine. That is the property the original failure never had -- it only reproduced on a loaded Windows runner, which is not something you can iterate against. Two mutations, and the second half of the first is the interesting one: M1 restore `await asyncio.sleep(0.05)` -> the slow-stats regression test RED (1 failed) -> and test_disabled_account_is_closed stays GREEN (1 passed), which is the silent-coverage-move demonstrated rather than argued M2 `_FIRST_FRAME_TIMEOUT = 0.0` -> 3 failed, so the wait is load-bearing and not decorative Timeouts: the first-frame wait is 10s and the harness budget is raised 5s -> 20s, because the harness must outlive the wait PLUS the close it then waits for, or it would time out mid-wait and the failure would point at the route instead of the clock. Both sit inside the 60s pytest timeout, which stays the real backstop against a hang. Full suite 9636 passed / 719 skipped; the one failure is the pre-existing environmental test_installed_metadata_matches_dunder_version (editable metadata 0.3.0 vs __version__ 0.3.2 -- its own comment names the case and the remedy).
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
mainis red.test (windows-2022, py3.14)failed atbe2fc08c— the squash-merge of #56, whose own head was 33/33 green:Not the merged change: #56 touched TLS key-exchange policy, an OIDC settings validator and docs, none of which this route reaches. The test is defective — and deliberately not treated as a flake to re-run, because this repo has already mistaken a livelock for one and no rerun or timeout ever fixed that.
The defect
The first frame cannot be sent until
store.stats()returns — the route awaits it, builds the frame, then sends. The fixed 50 ms sleep had to cover that query plus scheduling the harness task, the handshake, and the handshake-time authorize. None of which these tests measure. It passes locally 3/3, in 10.06s / 12.33s / 3.89s — and that spread is the tell.Replaced with
_wait_for_first_frame, a bounded poll on the condition actually being asserted. This does not weaken the precondition: a frame is still required, and still required before the revocation. It also separates a dead task from a slow one (task.result()re-raises the real failure), because a route that blew up would otherwise look identical to a loaded runner.A second, quieter defect
test_disabled_account_is_closedalso slept 50 ms, and asserts onlyclose_code == 1008— which both the mid-stream revalidation and the pre-first-send re-check produce. So on a slow box the account was disabled before the first send, the close came from the wrong path, the assertion still held, and the test silently stopped covering what its comment claims while duplicatingtest_revoke_before_first_send_yields_no_frames. A coverage move with no symptom. It now waits for a frame, so "mid-stream" is a fact.Making the CI failure reproducible
test_a_slow_first_stats_build_does_not_break_the_preconditionstallsstore.stats()to 0.4s — 8× the old budget — so the old form fails on any machine. That is the property the original failure never had: it only reproduced on a loaded Windows runner, which is not something you can iterate against.await asyncio.sleep(0.05)test_disabled_account_is_closedstays GREEN — the silent coverage move, demonstrated rather than argued_FIRST_FRAME_TIMEOUT = 0.0Timeouts
First-frame wait 10s; harness budget raised 5s → 20s, because the harness must outlive the wait plus the close it then waits for, or it times out mid-wait and the failure points at the route instead of the clock. Both sit inside the 60s pytest timeout, which stays the real backstop against a hang.
Verification
ruff check·ruff format --check·mypy --strict· full suite 9636 passed, 719 skipped. The one failure is the pre-existing environmentaltest_installed_metadata_matches_dunder_version(editable metadata0.3.0vs__version__0.3.2; its own comment names the case and the remedy).