Worker stop request is lost (deadlock) when cancellation lands during startup
## Symptom
`test_stop_worker_aborts_sync_jobs_past_shutdown_graceful_timeout` failed on main in CI ([run](https://github.com/procrastinate-org/procrastinate/actions/runs/27297387907/job/80633639248)):
```
assert fast_job_status == Status.SUCCEEDED
E AssertionError: assert <Status.TODO: 'todo'> == <Status.SUCCEEDED: 'succeeded'>
```
Investigating the flake surfaced a more serious underlying bug: a stop request (or task cancellation) landing in the worker's startup window is silently erased, leaving the worker unstoppable — and, with a sync job waiting on `should_abort()`, deadlocked.
## Bug 1: `_run_loop`'s `_stop_event.clear()` erases an early stop request
`Worker._run_loop` starts with `self._stop_event.clear()`. The fatal interleaving:
1. `run()` creates `loop_task = asyncio.create_task(self._run_loop())` — scheduled, not yet started
2. Cancellation hits `run()` at `await asyncio.shield(loop_task)`; the `except CancelledError` handler calls `self.stop()`, which sets `_stop_event`
3. `run()` proceeds to `await loop_task`; only now does `_run_loop` get its first slot — and its first statement clears the just-set event
4. The worker runs as if no stop was requested: graceful shutdown (and the abort it would issue) never begins. A sync job polling `context.should_abort()` spins forever, and `await run_task` never returns
Reproduced by shrinking the pre-cancel `asyncio.sleep(0.05)` in the test above to `0.001`: the test hangs instead of failing. py-spy of the hung process shows the event loop idle and `slow_job` spinning in its worker thread waiting for an abort that never comes.
## Bug 2 (the flake actually seen in CI): fixed 50 ms sleep races worker startup
The `*_past_shutdown_graceful_timeout` tests sleep a fixed `0.05s` between starting the worker and cancelling it. In that time the worker must prune stalled workers, register itself, start the run loop and side tasks, fetch and run the fast job, and fetch the slow job — several DB roundtrips. On a loaded CI runner the cancel wins the race: graceful shutdown finds no running job and exits cleanly, the jobs were never fetched, hence `TODO`. (When the cancel lands slightly later, you get the bug-1 hang instead.)
## Fix
Branch `fix-worker-stop-race` (PR to follow):
- Move the `_stop_event.clear()` out of `_run_loop` to the top of `run()`, before the first await, so no stop requested after `run()` has started can be erased. Behavior is otherwise unchanged (a stop requested before `run()` is still discarded, worker instances stay reusable).
- Deterministic regression test for the lost-stop window.
- De-flake the four shutdown acceptance tests by polling for the slow job reaching `doing` (new `wait_for_job_status` helper) instead of sleeping a fixed 50 ms.
The `ValueError: I/O operation on closed file` logging tracebacks in the CI output are pytest capture noise around the failure, not a procrastinate bug.
关闭于 2026-06-13 1 条评论