Stop silent permanent failures after a broker outage

Summary

Three defects turned a transient broker error into a permanently half-dead process that looked healthy to every external signal — heartbeat file fresh, zero restarts — so no orchestrator ever restarted it. Reported by @tobias-dev in #6 (closed) (a 3.5-day scheduler outage) and #7 (closed) (2h20m of accepted-but-invisible events on a batched queue).

Tests land in the first commit and fail; the fix lands in the second and turns them green.

What was wrong

Scheduler.run() died permanently on a transient error. acquire_lock and get_metadata sat outside the loop's only try, so one ConnectionError ended the coroutine for the life of the process while the queue consumers on the same connection logged, backed off, and recovered. The loop body is now guarded per iteration, the way Worker.consume_queue already was. CancelledError re-raises so cancellation semantics are unchanged.

Nothing supervised the long-lived tasks. runworker and the embedded ASGI app both held their asyncio.Task objects for the whole process lifetime and only awaited them at shutdown, so asyncio's "Task exception was never retrieved" never fired and the traceback sat in the Task unread. Any unhandled exception in Worker.run() or Scheduler.run() became a silent half-outage. Crashes are now logged with their traceback; runworker also stops so an orchestrator restarts it. The embedded app additionally retains the Task references, which it was discarding entirely — a garbage-collection hazard independent of the logging.

fetch_batch reported broker failures as an empty queue. A bare except Exception: break returned [], exactly what an idle queue returns, so the error never reached consume_queue's handler and a batch queue could fail every fetch for hours without a single log line. Failures now propagate.

One deliberate deviation from the fix proposed in #7 (closed): a failure after some tasks were already collected returns the partial batch and logs a warning instead of raising. BLMPOP has already removed those tasks from the queue and they exist only in that list, so raising would lose them outright.

Verification

Reproduced against a real Valkey before and after, not just in the suite.

	before	after
scheduler across broker stop/start	22 ticks → 22, dead forever, 0 log lines	11 → 23, resumed, 2 Scheduler loop failed, retrying
Consumer error logs, default vs batch queue	8 vs 0	2 vs 2
SIGTERM shutdown	clean	clean, 0 false crash reports

The supervision callback ignores tasks that finish while stop_event is already set, so a normal shutdown is not reported as a crash — checked against a live SIGTERM, not just in the tests.

Suite: 185 tests green including the valkey-tagged ones. The new tests use fakes only, so they run in every CI job including test-sqlite, which has no broker service. Each was also re-checked against a reverted fix to confirm it still catches the regression.

Also folded in

chore(deps): django-vcache 3.1.1 — lockfile only. The pyproject.toml floor stays at >=3.0.0 since 3.1.1 is a pyo3 0.29 and dependency refresh with no API change.

Not addressed

The stall case. A blocking fetch has no wall-clock bound, so a broker that stops responding without closing the connection still parks both consumers silently. Reproduced with docker pause. Fixing it needs a decision on the timeout: BLOCKING_TIMEOUT defaults to 1s but batch queues carry their own (GlitchTip's ingest uses 2.0s), so the bound has to derive from the per-queue value plus slack rather than a constant.

#7 (closed)'s permanence is still unexplained. This MR fixes the silence on the batch path, which is reproducible. It does not explain why the reporter's batch consumer never recovered even against a healthy broker — a clean broker restart and a broker stall both recovered here. Leaving #7 (closed) open for that reason.

Heartbeat liveness. /tmp/worker_health still reflects only the heartbeat loop, not the subsystems. Less pressing now that crashes are fatal under runworker, but it is still what lets a half-dead embedded process pass a liveness probe.

Closes #6 (closed). Refs #7 (closed) — partially addressed, see above.

---

Update (rebased and picked back up)

Rebased onto current main. The branch was 25 days stale and its last green pipeline was on Django 6.0.6; main has since moved to 6.1 via !28 (merged). The rebase is clean, and the chore(deps): django-vcache 3.1.1 commit was automatically dropped as already upstream in that refresh — so the branch no longer touches uv.lock or .gitlab-ci.yml at all and is purely the fix. Re-verified on 6.1: 196 tests OK on Postgres 18 + Valkey, 179 OK on SQLite, ruff clean on the CI-gated scope.

Two commits that existed only locally are now pushed — including fix: don't report a graceful embedded shutdown as a crash, which was the real reason this looked abandoned. Without it, every clean deploy logs two spurious exited unexpectedly ERRORs plus a ValueError: I/O operation on closed file.

Added: the consumer gets the same retry backoff as the scheduler. The scheduler half of this branch replaced its flat 1s retry with exponential backoff and a traceback-once rule, and its own comment explains why — a 34-minute outage emitted ~2000 tracebacks into the deployment's own error tracker. consume_queue had the identical flat retry and did not get the same treatment, and there it runs per queue, so the same outage produced that flood multiplied by the queue count. It had received the run_once guard but not the backoff, which read as the fix stopping halfway. It now mirrors the scheduler, including resetting the moment a fetch succeeds so a recovered broker returns to normal cadence. Both new tests fail against the unfixed loop with the intervals flat at [1, 1, 1].

Independent evidence on #7 (closed), and it supports leaving it open. The fault-injection harness in !30 (merged) now runs a batch queue and a normal queue under load simultaneously and asserts per queue, since #7 (closed)'s signature is one queue dying while its sibling recovers. Against main — with fetch_batch still swallowing errors — a broker stop/start recovered fully (both queues 100%), and so did a scenario that starts a worker only after the broker is already healthy, which is the specific case the reporter could not explain. So the swallowing produces the reported silence but not, in any shape reproduced so far, the reported permanence. Refs #7 rather than Closes #7 is the right call.

AI disclosure: Claude Code (Opus 5) wrote the tests, the fix, the changelog entry, and this description, working from the two issue reports. Direction, scoping, and review are mine. The live before/after reproduction against a real Valkey was run and its output inspected, not asserted from reading the code. The rebase, the consumer-backoff commit, and the #7 (closed) harness evidence in this update were also done with Claude Code, and re-verified on Django 6.1.