Don't hang forever when cancelling a worker whose database connection is unresponsive - #1596
Don't hang forever when cancelling a worker whose database connection is unresponsive#1596tonycpsu wants to merge 3 commits into
Conversation
Cancelling run_worker_async() hangs forever if the worker's database connection has become unresponsive (e.g. half-open after a failover or proxy event): the shielded run loop task blocks in a database call that never returns and never observes the stop event, and run() waits for it unconditionally. With the new opt-in shutdown_timeout, run() waits up to that long for the run loop to stop, then cancels it, then abandons it, so cancelling the worker always terminates. unregister_worker() in _shutdown() gets the same bound: it is best effort, as a worker that could not unregister is eventually pruned through its stale heartbeat. Default (None) keeps today's behaviour exactly. Closes procrastinate-org#1513 Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
📝 WalkthroughWalkthroughAdds optional ChangesWorker shutdown timeout
Estimated code review effort: 3 (Moderate) | ~25 minutes Possibly related issues
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Actionable comments posted: 1
🧹 Nitpick comments (1)
procrastinate/worker.py (1)
34-104: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winConsider warning when
shutdown_timeout <= shutdown_graceful_timeout.Docs state
shutdown_timeout"should be greater thanshutdown_graceful_timeout" since the run loop waits for jobs to finish before exiting, but nothing validates this at construction time. A misconfigured pair (e.g. equal orshutdown_timeoutsmaller) silently aborts jobs before the graceful window elapses.♻️ Example validation
self.shutdown_graceful_timeout = shutdown_graceful_timeout self.shutdown_timeout = shutdown_timeout + if ( + shutdown_timeout is not None + and shutdown_graceful_timeout is not None + and shutdown_timeout <= shutdown_graceful_timeout + ): + self.logger.warning( + "shutdown_timeout should be greater than shutdown_graceful_timeout" + )🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@procrastinate/worker.py` around lines 34 - 104, In Worker.__init__, validate the configured shutdown_graceful_timeout and shutdown_timeout after assigning them: when both are set and shutdown_timeout is less than or equal to shutdown_graceful_timeout, emit a warning using the worker logger. Preserve valid configurations and None values without warning, and do not change shutdown behavior.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@procrastinate/worker.py`:
- Around line 467-508: The cancellation branch in the worker shutdown flow must
consume a completed loop_task after the second bounded wait, just as
unregister_task does. After the wait following loop_task.cancel(), check whether
the task is done and await it to retrieve any late exception, while preserving
the existing abandonment warning and non-blocking behavior when it remains
pending.
---
Nitpick comments:
In `@procrastinate/worker.py`:
- Around line 34-104: In Worker.__init__, validate the configured
shutdown_graceful_timeout and shutdown_timeout after assigning them: when both
are set and shutdown_timeout is less than or equal to shutdown_graceful_timeout,
emit a warning using the worker logger. Preserve valid configurations and None
values without warning, and do not change shutdown behavior.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: defaults
Review profile: CHILL
Plan: Pro
Run ID: 8d6dc9cd-fc69-4199-bdc6-8329e4d47fc1
📒 Files selected for processing (4)
docs/howto/advanced/shutdown.mdprocrastinate/app.pyprocrastinate/worker.pytests/unit/test_worker.py
|
For what it's worth, I was hoping to submit issues for psycopg as well but I think the author over there is a bit more hostile to AI-assisted fixes, which is why I'm starting here. |
…gured timeouts - The abandoned run loop task now gets the same late-failure consumption as the unregister task, so an exception raised while it unwinds in the background isn't logged as a never-retrieved task exception. - Warn at construction when shutdown_timeout <= shutdown_graceful_timeout, matching the documented constraint. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
|
Addressed both review items in 60dc4f7: the abandoned loop task's outcome is now consumed via a done callback (same pattern as the unregister task), and the worker warns at construction when |
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Closes #1513
The problem
run_worker_async()can never be cancelled if the worker's database connection stops responding. The worker keeps running, processes nothing, logs nothing, and the only way out is to kill the process.This is not theoretical: it caused a 7-hour silent stall in production, and the log evidence is unambiguous. A provider-side event on the managed-PostgreSQL connection path reset the server side of the worker's established connections — Postgres itself never restarted (its checkpoints run uninterrupted through the incident) but logged
could not receive data from client: Connection reset by peerat the event moment — while the worker's side of those sockets stayed open. From that instant the worker stopped fetching jobs entirely;run_worker_async()neither returned nor raised, and not a single procrastinate ERROR was logged for 7 hours. The process was otherwise alive the whole time — it kept serving HTTP and even kept deferring jobs successfully on fresh connections — it just never consumed the queue again, until the process was restarted. TCP keepalives andtcp_user_timeoutcannot catch this: the middlebox answers the probes, and nothing sent is left unacknowledged.Why it hangs
Worker.run()shields the run loop task and relies on the stop event for a graceful shutdown:stop()only sets_stop_event, and_fetch_and_process_jobs()only checks it between iterations. A fetch that never returns therefore never observes the stop event. Because the loop task is shielded, nothing ever cancels it either — soawait loop_taskwaits for a task that cannot finish, and the shutdown hangs forever.Observed against
main, with the worker parked exactly there:The change
Adds an opt-in
shutdown_timeout. Whenrun()is cancelled, the worker waits up toshutdown_timeoutfor the run loop to stop; if it hasn't, it cancels it; if it does not react to the cancellation either, it is abandoned and the cancellation is propagated regardless, so cancelling a worker always terminates.The same bound is applied to
unregister_worker()in_shutdown(): verified by stack traces, the run loop otherwise re-enters an unbounded database round-trip through a pool that may still hold dead connections, after surviving the fetch cancellation. Unregistering is best effort by design — a worker that could not unregister is eventually pruned through its stale heartbeat (prune_stalled_workers) — so on timeout it is cancelled and logged, not waited for. This is also what lets an abandoned run loop terminate on its own shortly after (observed: ~10s) instead of leaking for the life of the process, once the driver honors cancellation.Default is
None, which is exactly today's behavior (asyncio.wait(..., timeout=None)waits just likeawait loop_taskdid), so nothing changes for existing users unless they opt in.I deliberately did not reuse
shutdown_graceful_timeoutfor this. It bounds how long the worker waits for jobs, and it is consumed inside_shutdown(), which runs inside the run loop task. Using the same budget for the outer wait cancels the run loop while it is still legitimately aborting jobs — this breakstest_stopping_worker_aborts_job_after_timeout[cancel], which is how I found it. The two timeouts have to be separate;shutdown_timeoutshould be greater thanshutdown_graceful_timeout.What this does NOT fix (deliberate)
The root cause is in psycopg, not here. I localized it:
AsyncConnection.wait()(connection_async.py:520-529) catchesCancelledError, then re-enterswaiting.wait_async()on the same dead socket with no deadline, so the pendingCancelledErroris never re-raised. A task stayscancelling=1, cancelled=Falseforever. Verified with raw psycopg, no procrastinate and no pool involved, on psycopg 3.3.4 with both the binary (libpq 18) and pure-python (libpq 17) implementations. This is why the "did not react to cancellation" path exists at all; once psycopg bounds that wait, the cancellation lands promptly and the loop task unwinds cleanly. Reported upstream with a standalone reproduction: Async: task cancellation is never delivered when the server stops responding on an established connection psycopg/psycopg#1371.Abandoning the run loop leaks it. The abandoned task, its wedged connection, and the heartbeat side task stay wedged for the life of the process. This is a real cost, accepted deliberately: procrastinate cannot force an unresponsive round-trip to unwind, and hanging the caller forever is worse. It is bounded and logged rather than silent. (Concretely, the leaked backends hold
idle in transactionlocks server-side until the connection actually dies.)This abandon path is load-bearing, not a temporary workaround. I verified that a wedged
pool.connection()cannot be cancelled even with the psycopg core bug fixed, because there is a second, independent swallow in psycopg_pool: pool connections are not autocommit, socheck_connection()runstry: await conn.execute("")/finally: await conn.set_autocommit(False). Thefinallyperforms I/O on a connection that is by then dead, so it raises, and an exception raised in afinallyreplaces the in-flightCancelledError. The pool's_getconn_with_check_loopthen reads that as "this connection failed its check", discards it, and retries the next one — so the cancellation is lost and the caller eventually gets aPoolTimeoutrather thanCancelledError. Measured: a cancelledpool.connection()was still not cancelled 40s later. Until that is fixed too, procrastinate cannot rely on cancelling the loop task, and this timeout is the only thing that guarantees shutdown terminates.This does not fix Worker crashes on database connection loss during fetch loop #1523. That is a different failure mode — a
ConnectorExceptioncrashing out of the fetch loop when the outage exceeds the pool timeout, i.e. a crash, not a hang. This PR only addresses shutdown.It does not make the worker recover from a wedged connection. The fetch loop still stalls silently (no error, no fetch) until something cancels the worker. Bounding the fetch itself is impossible today: I verified that
pool.connection(timeout=N),asyncio.wait_for()andasyncio.timeout()all fail to fire on a half-open connection, because they all depend on the cancellation that psycopg swallows. Settingcheck=Noneon the pool doesn't help either — the hang just moves fromcheck_connectionto the query. Detecting the stall is left to the caller for now.Testing
test_cancelling_run_does_not_hang_on_stuck_loop_task. It models a fetch that never returns and does not honor the first cancellation, which is the essential property — a plainly cancellablesleeppasses even without the fix and would give false confidence. The test fails onmain(assertingrun()never returned) and passes with the fix. It usesasyncio.wait, neverwait_for, becausewait_forcancels only once and would itself hang on the swallowed cancellation rather than failing the test.Worker loop did not stop within shutdown_timeout. Cancelling itandWorker loop did not react to cancellation. Abandoning it.Disclosure: this change was written with the assistance of an LLM (Claude). The bug was reproduced, the root cause localized, and the fix verified end-to-end against a real half-open connection by a human-reviewed process; the reasoning and evidence are above.
🤖 Generated with Claude Code
Summary by CodeRabbit
shutdown_timeoutsetting to bound how long workers wait to stop during cancellation and cleanup.shutdown_graceful_timeoutvsshutdown_timeout.shutdown_timeoutis set incorrectly.