Test suite kills its own process mid-run and exits 0, hiding later failures #149

New Issue

2026-10-27T09:35:30+01:00

adam commented

2026-10-27 09:35:30 +01:00

Summary

The test suite kills its own process part way through, and exits 0 while doing it — so a run that never finished reports as success, and any failure after that point is silently lost.

What happens

RepeaterDaemon._shutdown arms an exit watchdog: a threading.Timer that calls os._exit(0) after SHUTDOWN_EXIT_GRACE_S (5 s). Correct in production — it guarantees SIGTERM is honoured.

tests/test_main_py_more.py::test_run_starts_http_and_handles_dispatcher_cancelled_gracefully awaits daemon.run(), whose finally reaches _shutdown(). It arms a real watchdog and returns without patching it. Five seconds later the timer fires and takes pytest down.

Why it is worth fixing rather than tolerating

Three things make it costly out of proportion to the one-line cause:

It exits 0. No summary line, truncated progress bar. CI reads that as green. On this run the suite reported 1580 passed only after the fix — before it, the last thing printed was [ 77%] and pytest returned success.
Everything after the kill point is invisible. The 3 genuine pre-existing failures on dev were not visible until the process survived to the end.
It misattributes itself. The test blamed is whichever happened to be running 5 s later. Across two runs here it was test_route_login_server_companion_only_skips_login_helper and then test_route_login_server_hash_collision_offers_to_both — neither related to shutdown. Finding the real cause needed wrapping _arm_exit_watchdog to log which test armed it.

Reproduce

python -m pytest tests/ -q

Observe: progress stops mid-run, no summary, echo $? → 0.

To see the cause, wrap the arming:

orig = RepeaterDaemon._arm_exit_watchdog
def wrapped(self):
    print("ARMED by", current_test_nodeid, "grace", self.SHUTDOWN_EXIT_GRACE_S)
    return orig(self)
RepeaterDaemon._arm_exit_watchdog = wrapped

→ ARMED by tests/test_main_py_more.py::test_run_starts_http_and_handles_dispatcher_cancelled_gracefully (grace=5.0)

Fix

PR to follow:

Patch _arm_exit_watchdog for that test, matching the guard the shutdown tests in test_main_py_coverage.py already use.
Add tests/conftest.py with an autouse fixture that fails any test leaving a live shutdown-watchdog timer, and cancels it — so this blames the responsible test at the moment it leaks, instead of an unrelated one five seconds later. Verified it catches the original bug when the one-line fix is reverted.

test_exit_watchdog_is_a_daemon_timer_that_forces_exit is unaffected: it uses a 0.05 s grace and asserts on a patched os._exit before returning.

Environment: Raspberry Pi 4, Python 3.13.5, dev at efc5616.

### Summary The test suite kills its own process part way through, and exits **0** while doing it — so a run that never finished reports as success, and any failure after that point is silently lost. ### What happens `RepeaterDaemon._shutdown` arms an exit watchdog: a `threading.Timer` that calls `os._exit(0)` after `SHUTDOWN_EXIT_GRACE_S` (5 s). Correct in production — it guarantees SIGTERM is honoured. `tests/test_main_py_more.py::test_run_starts_http_and_handles_dispatcher_cancelled_gracefully` awaits `daemon.run()`, whose `finally` reaches `_shutdown()`. It arms a real watchdog and returns without patching it. Five seconds later the timer fires and takes pytest down. ### Why it is worth fixing rather than tolerating Three things make it costly out of proportion to the one-line cause: 1. **It exits 0.** No summary line, truncated progress bar. CI reads that as green. On this run the suite reported `1580 passed` only *after* the fix — before it, the last thing printed was `[ 77%]` and pytest returned success. 2. **Everything after the kill point is invisible.** The 3 genuine pre-existing failures on `dev` were not visible until the process survived to the end. 3. **It misattributes itself.** The test blamed is whichever happened to be running 5 s later. Across two runs here it was `test_route_login_server_companion_only_skips_login_helper` and then `test_route_login_server_hash_collision_offers_to_both` — neither related to shutdown. Finding the real cause needed wrapping `_arm_exit_watchdog` to log which test armed it. ### Reproduce ``` python -m pytest tests/ -q ``` Observe: progress stops mid-run, no summary, `echo $?` → `0`. To see the cause, wrap the arming: ```python orig = RepeaterDaemon._arm_exit_watchdog def wrapped(self): print("ARMED by", current_test_nodeid, "grace", self.SHUTDOWN_EXIT_GRACE_S) return orig(self) RepeaterDaemon._arm_exit_watchdog = wrapped ``` → `ARMED by tests/test_main_py_more.py::test_run_starts_http_and_handles_dispatcher_cancelled_gracefully (grace=5.0)` ### Fix PR to follow: - Patch `_arm_exit_watchdog` for that test, matching the guard the shutdown tests in `test_main_py_coverage.py` already use. - Add `tests/conftest.py` with an autouse fixture that fails any test leaving a live `shutdown-watchdog` timer, and cancels it — so this blames the responsible test at the moment it leaks, instead of an unrelated one five seconds later. Verified it catches the original bug when the one-line fix is reverted. `test_exit_watchdog_is_a_daemon_timer_that_forces_exit` is unaffected: it uses a 0.05 s grace and asserts on a patched `os._exit` before returning. Environment: Raspberry Pi 4, Python 3.13.5, `dev` at `efc5616`.

adam closed this issue

2026-10-27 09:35:30 +01:00

adam commented

2026-10-27 09:35:31 +01:00

fixed in dev branch.

thanks

fixed in dev branch. thanks

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: adam/pyMC_Repeater#149