Skip to content

test(interviews): the relay cancellation tests give cleanup one second and a slow runner misses it #152

Description

@L4XB

Problem

tests/test_voice_relay.py::test_cancel_closes_upstream_before_terminal_callback_and_retains_pending_cost
failed on a pull request that changes only src/sixsentences/cli.py,
tests/test_cli.py and CHANGELOG.md — nothing the relay imports.

E                   asyncio.exceptions.CancelledError
src/sixsentences_server/voice/relay.py:740: CancelledError
...
>               raise TimeoutError from exc_val
E               TimeoutError
/usr/lib/python3.12/asyncio/timeouts.py:115: TimeoutError
FAILED tests/test_voice_relay.py::test_cancel_closes_upstream_before_terminal_callback_and_retains_pending_cost
1 failed, 2902 passed, 2 skipped, 2 warnings in 605.46s (0:10:05)

Evidence: run 34963198097, job 104361421391, on PR #147. It passed on a
re-run of the same commit, and the same suite takes about five minutes locally
against the ten it took there — so the runner was roughly half speed for that
job.

Why it fails

The test cancels the relay task and then allows one second for everything that
follows:

task.cancel()
result = await asyncio.wait_for(task, 1)

What has to happen inside that second is not small. _Relay.run's finally
builds _close_and_persist, cancels four tasks and gathers them, optionally
drains a receipt, closes the provider under asyncio.wait_for(..., timeout=3),
runs conservative_finish, awaits on_closed, and closes the browser socket —
under asyncio.shield, so the outer cancellation cannot shorten it. The
traceback lands at relay.py:740, which is await asyncio.shield(cleanup): the
budget expired while the shielded cleanup was still running.

One second is not a property of the code under test. The test is about
ordering — the provider is closed before the terminal callback, and the
pending cost is retained — and nothing in it asserts that ordering happens
quickly. The timeout is only there so a hang fails instead of blocking forever,
and for that job a much larger number works equally well.

wait_for(task, 1) appears ten times in that file; wait_for(task, 2) appears
four more. The distinction between them does not look deliberate.

What to do

Raise the budget on the cancellation paths, or give the file one named constant
— something like TERMINAL_WAIT_SECONDS = 10 — so the intent reads as "fail
instead of hanging" rather than "this must finish within a second". Ten seconds
costs nothing when the test passes and still fails a genuine hang well inside
the job's thirty-minute limit.

Worth deciding at the same time: whether any of these timeouts is actually
asserting latency. If one is, it should say so in a comment and keep its tight
number; the rest should not inherit a number chosen for a different reason.

Not the fix

Retrying the test, or marking it flaky. It is not non-deterministic — it is a
deadline that a slow runner misses, and the deadline is measuring the wrong
thing.

Acceptance criteria

  • The cancellation tests no longer fail on a runner running at half speed
  • Any timeout that deliberately asserts latency says so and keeps its value
  • A genuine hang still fails the test rather than the job timeout

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    area:interviewsInterview, transcript, voice, and consent boundarieseffort:smallA few files, no system-wide knowledge neededgood first issueGood for newcomerstype:hardeningCorrectness, resilience, and adversarial-input hardening

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions