Skip to content

fix(ci): give the unit suite a per-test timeout so a hang names itself (#2019) - #2021

Open
dolho wants to merge 1 commit into
devfrom
fix/2019-pytest-timeout
Open

fix(ci): give the unit suite a per-test timeout so a hang names itself (#2019)#2021
dolho wants to merge 1 commit into
devfrom
fix/2019-pytest-timeout

Conversation

@dolho

@dolho dolho commented Aug 5, 2026

Copy link
Copy Markdown
Contributor

Summary

The unit workflow installs pytest-timeout and never passed --timeout, so one stalled test consumed the whole 25-minute job budget, GitHub cancelled the job, the JUnit upload was skipped, and the failure surfaced as ##[error]The operation was canceled against whichever PR was running. Four occurrences in one day across all three seeds and both sides — the base side being plain dev, i.e. nothing to do with the PR it reddened.

The cost was never the lost minutes. It was that each occurrence had to be read out of a log by hand and produced no evidence about which test was responsible — which is why I misdiagnosed it once as a seed-specific ordering before a re-run of the same seed passed.

Both numbers in my own issue were wrong

300s, not the 60s I proposed. Measured from a green run's JUnit instead of guessed:

Test Time on CI
test_start_agent_skip_inject::test_injects_when_container_recreated_even_if_was_running 60.62s
test_start_agent_skip_inject::test_injects_when_container_was_stopped 60.57s
test_1083_result_callback::test_resend_drops_corrupt_file 39.90s
test_1083_result_callback::test_resend_delivers_and_deletes 26.58s

A 60s cap would have failed the top two on every PR — the fix would have become the outage. The cap also has to survive the runner variance that caused this issue (one shard ran 2.5× slower than its siblings), which puts a 60.6s test near 150s. 300s clears that and still turns a hang into a named failure: the observed stalls were minutes long and the budget fits ~5 of them.

signal, not the thread I recommended. thread dumps stacks and then kills the process — the run aborts, remaining tests never execute, JUnit is incomplete, so the diff job fails anyway, just with a named culprit in the log. signal raises inside the offending test and the suite continues, so the complete JUnit lets the diff job report the hang as an ordinary new failure by name.

The logs support that shape: #1952 kept making progress after its 3m37s gap, so these are stalls that release, not one permanent hang.

I had justified thread by saying SIGALRM cannot interrupt a blocked C call. Tested rather than repeated — a deliberate socket.connect to an unroutable address under --timeout-method=signal:

E       Failed: Timeout (>10.0s) from pytest-timeout.
unit/test_zz_tmp_hang.py:4: Failed
1 failed in 10.21s

It interrupts it fine.

Also

if: always() on the JUnit upload, so a partial artifact still reaches the diff job — which is deliberately fail-closed on a missing one, and that behaviour is worth keeping.

Test plan

  • tests/unit/test_2019_pytest_timeout_guard.py — 8 guards over the flag, the method, the value's lower and upper bound, if: always(), and the load-bearing || true (fix(tests): resolve 20 remaining unit test failures post-#589 #660 baseline)
  • Every assertion mutation-verified, including against the 60s I originally proposed: timeout=60 → 1 fail, timeout=1800 → 1 fail, thread → 1 fail, flag removed → 2 fails, if: always() removed → 1 fail, || true removed → 1 fail
  • Assertions read the step's command with YAML comments stripped. This is load-bearing: the step documents its own flags in prose, and an earlier draft stayed green with || true deleted because the comment still said it — the #1871 / ent#314 textual-scan trap, third occurrence. There is a test pinning the stripping itself.
  • The step slice is indentation-bounded after a name-bounded version ran past the last step and matched the diff job's own if: always() — caught by mutation-testing this file, not by review
  • 927 passed across 2019 / 1891 / workflow / ci; the flag smoke-tested on a real slice

Not included

backend-unit-nightly.yml carries the same 25-minute budget and wants the same two lines. PR #1952 is open against that file and conflicting with it would be a disservice — best applied there, or as a follow-up once it merges. Flagging rather than silently leaving it.

Closes #2019

#2019)

The workflow installs `pytest-timeout` and never used it, so a single stalled
test consumed the whole 25-minute job budget, GitHub cancelled the job, the
JUnit upload step was skipped, and the failure surfaced as
`##[error]The operation was canceled` on whichever PR happened to be running.
Four occurrences in one day across all three seeds and both sides — including
the base side, which is plain `dev` and has nothing to do with the PR it
reddened.

The cost was never the lost minutes; it was that every occurrence had to be
read out of a log by hand and produced no evidence about which test was
responsible. I misdiagnosed it once for exactly that reason.

Both numbers in my own issue were wrong, and measuring fixed them:

- **300s, not 60s.** Taken from a green run's JUnit rather than guessed:
  `test_start_agent_skip_inject`'s two retry cases legitimately run ~60.6s
  (three real connection retries), then 39.9s and 26.6s in
  `test_1083_result_callback`. A 60s cap would have failed those two on every
  PR — the fix would have become the outage. The cap must also survive the
  runner variance that caused this issue (one shard ran 2.5x slower than its
  siblings), which puts a 60.6s test near 150s.

- **signal, not thread.** `thread` dumps stacks and then kills the process, so
  the run aborts, the remaining tests never execute and the JUnit is
  incomplete — the diff job fails anyway, just with a named culprit in the log.
  `signal` raises inside the test and the suite continues, so the complete
  JUnit lets the diff job report the hang as an ordinary new failure by name.
  The logs support that shape: #1952 kept making progress after its 3m37s gap,
  so these are stalls that release, not one permanent hang.

I recommended `thread` on the grounds that SIGALRM cannot interrupt a blocked C
call. Tested rather than repeated: a deliberate `socket.connect` to an
unroutable address under `--timeout-method=signal` fails by name in 10.2s.

`if: always()` on the upload keeps a partial artifact reaching the diff job,
which is deliberately fail-closed on a missing one.

Scoped to `backend-unit-test.yml`. `backend-unit-nightly.yml` carries the same
25-minute budget and wants the same two lines, but PR #1952 is open against
that file and conflicting with it would be a disservice — noted on the PR.

8 guard tests, each mutation-verified (including against the 60s I first
proposed). Assertions read the step's command with comments stripped: the step
documents its own flags, and an earlier draft stayed green with `|| true`
deleted because the comment still mentioned it.

Closes #2019

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

@obasilakis obasilakis 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.

Approving. The central decision is correct and I verified both corrections independently rather than taking the comments on faith.

Verified

The 60s → 300s correction. Ran the cited module locally:

60.33s call  TestStartAgentSkipInject::test_injects_when_container_recreated_even_if_was_running
60.33s call  TestStartAgentSkipInject::test_injects_when_container_was_stopped
9 passed in 120.98s

Matches your 60.62/60.57 from CI closely enough to settle it — a 60s cap fails both on every PR.

The threadsignal correction. This is the load-bearing one, so I probed it with a deliberate 30s stall under a 3s cap:

thread : run aborted, 2nd test never executed, JUnit MISSING
signal : "1 failed, 1 passed in 3.14s", JUnit written, tests=2 failures=1

Worth stating plainly: --timeout-method=thread would have defeated AC #3 of the issue itself. With thread there is no XML at all, so the diff job's fail-closed check fires and you get exactly the second, differently-worded failure #2019 exists to remove. signal isn't a preference here, it's what makes the fix work.

The base side is covered. The side=base step switches only the working tree (git switch --detach FETCH_HEAD) while the workflow definition always comes from the PR ref — so --timeout applies to both sides, which is the case that was reddening innocent PRs.

The guard is not vacuous. Mutation-tested: drop both flags → 2 fails; thread → 1; timeout=60 → 1; drop if: always() → 1; drop || true → 1.

No config conflicts. No timeout in pytest config; @pytest.mark.timeout markers exist only in tests/ root files, outside the unit/ directory this workflow runs; zero signal.alarm/SIGALRM/setitimer users in tests/ or src/backend/, so the signal method can't collide.

Findings — none blocking

[1] The guard fails open on the space-form flag. test_2019_pytest_timeout_guard.py:127

assert "--timeout-method=thread" not in step

Mutating the workflow to --timeout-method thread leaves the guard green while thread is active — and pytest accepts that spelling (I ran it; same stack-dump-and-kill). This is a fourth variant of the textual-scan class your own docstring calls "third occurrence".

assert not re.search(r"--timeout-method[=\s]+thread", step)

The only change I'd suggest landing before merge.

[2] Closes #2019 closes an issue with an unmet AC. AC #4 — identifying the tests actually responsible — can't be satisfied by this diff; it needs post-merge observation. Worth amending the issue, downgrading to Refs, or opening the follow-up now, so the AC isn't silently dropped.

[3] The if: always() rationale slightly overstates. pytest writes JUnit at sessionfinish, so a killed process leaves nothing to upload — confirmed above, the thread run produced no file. What makes the XML exist is the signal method. With if-no-files-found: error the step now fails rather than being skipped on a true cancellation: equivalent outcome, different wording. Harmless, and the comment already hedges with "belt and braces" — just noting the prose promises more than the mechanism delivers.

[4] Budget math is marginal on a slow shard. ~7–8 min suite, 2–2.5× runner variance (~20 min), 25 min cap: one 300s stall on a slow shard lands right at the cliff. Holds for the observed incident (siblings ~10 min), not for the worst case. No change needed — the cap can come down once the culprit is named.

[5] The 300s floor is dictated by two tests that sleep through real retries. That module is 121s of every shard, ×6 shards. Out of scope here, but faking the retry clock would let the cap drop a long way. Follow-up candidate.

[6] The nightly keeps the bug. backend-unit-nightly.yml has the same timeout-minutes: 25 and two un-timed invocations (lines 147, 156) — the only remaining workflow without --timeout. Agreed with deferring it rather than conflicting with #1952; flagging so it stays tracked rather than resting in the PR description.

Nice call documenting both of your own numbers as wrong in the PR body — that's what made the review cheap to do.

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.

2 participants