m/ImaGen
1
0
Fork 0
Code Issues 16 Pull Requests Actions Packages Projects Releases Wiki Activity

worker: reconnect on dropped DB connection instead of looping 'conn closed' forever (silent month-long outage) #17

New Issue
Open
opened 2026-07-06 10:35:27 +00:00 by mAi · 2 comments
mAi commented 2026-07-06 10:35:27 +00:00
Collaborator
Copy Link

Symptom

The imagen worker (systemd user unit imagen-worker.service on mRiver) stopped consuming imagen.jobs entirely. Every job submitted from /imagine since ~2026-06-07 sat at status='pending' with started_at=null — never claimed. No image ever came back and nothing surfaced the failure.

Root cause

The worker's Postgres connection (IMAGEN_WORKER_DATABASE_URL, direct over Tailscale to the pooler) dropped and the worker never re-established it. Instead its claim loop caught the error and spun forever, once every poll interval (5s):

worker: drain: claim: failed to deallocate cached statement(s): conn closed
worker: wait: conn closed (continuing)

The process stayed active (running) for ~28 days in this state, so systemd never restarted it and nothing alerted. A manual systemctl --user restart imagen-worker.service immediately fixed it — the worker reconnected and drained the backlog on the next poll.

Proposed fix

  1. Reconnect on a closed connection. When claim/wait detects conn closed (or any driver-level connection error), tear down and rebuild the pool / connection rather than looping continuing indefinitely. A pool with health-check + auto-reconnect (or pgx pool ping-before-use) would make this self-healing.
  2. Fail loud after N consecutive connection errors. If reconnect can't succeed, exit non-zero so systemd's restart policy kicks in — an always-active process that can do no work is worse than a crash-loop that's visible.
  3. Consider Restart=on-failure + a watchdog / WatchdogSec on the unit so a wedged worker is noticed.
  4. Optional: a cheap liveness signal (last-successful-claim timestamp) so a stuck worker is observable without reading journald.

Impact

This masked a real downstream problem (mGPUmanager can't evict ollama for image leases — separate m/mGPUmanager issue) for a month, because no job ever got far enough to hit the VRAM error. Self-healing reconnect + loud failure would have surfaced it in minutes.

Evidence

  • journalctl --user -u imagen-worker.service (mRiver) — the repeating conn closed (continuing) lines
  • worker had been up since 2026-06-07 16:03; restart on 2026-07-06 12:30 immediately claimed the stuck job.
## Symptom The `imagen worker` (systemd user unit `imagen-worker.service` on mRiver) stopped consuming `imagen.jobs` entirely. Every job submitted from `/imagine` since ~2026-06-07 sat at `status='pending'` with `started_at=null` — never claimed. No image ever came back and nothing surfaced the failure. ## Root cause The worker's Postgres connection (`IMAGEN_WORKER_DATABASE_URL`, direct over Tailscale to the pooler) dropped and the worker never re-established it. Instead its claim loop caught the error and spun forever, once every poll interval (5s): ``` worker: drain: claim: failed to deallocate cached statement(s): conn closed worker: wait: conn closed (continuing) ``` The process stayed `active (running)` for ~28 days in this state, so systemd never restarted it and nothing alerted. A manual `systemctl --user restart imagen-worker.service` immediately fixed it — the worker reconnected and drained the backlog on the next poll. ## Proposed fix 1. **Reconnect on a closed connection.** When claim/wait detects `conn closed` (or any driver-level connection error), tear down and rebuild the pool / connection rather than looping `continuing` indefinitely. A pool with health-check + auto-reconnect (or pgx pool ping-before-use) would make this self-healing. 2. **Fail loud after N consecutive connection errors.** If reconnect can't succeed, exit non-zero so systemd's restart policy kicks in — an always-`active` process that can do no work is worse than a crash-loop that's visible. 3. **Consider `Restart=on-failure` + a watchdog / `WatchdogSec`** on the unit so a wedged worker is noticed. 4. Optional: a cheap liveness signal (last-successful-claim timestamp) so a stuck worker is observable without reading journald. ## Impact This masked a real downstream problem (mGPUmanager can't evict ollama for image leases — separate m/mGPUmanager issue) for a month, because no job ever got far enough to hit the VRAM error. Self-healing reconnect + loud failure would have surfaced it in minutes. ## Evidence - `journalctl --user -u imagen-worker.service` (mRiver) — the repeating `conn closed (continuing)` lines - worker had been up since 2026-06-07 16:03; restart on 2026-07-06 12:30 immediately claimed the stuck job.
mAi self-assigned this 2026-07-06 10:35:27 +00:00
mAi commented 2026-07-06 10:49:02 +00:00
Author
Collaborator
Copy Link

Fixed: self-healing reconnect + fail-loud

Branch mai/zeus/issue-17-worker, commit d14498a. Root cause confirmed exactly as described: pgxQueue (cmd/imagen/worker.go) held a single *pgx.Conn with no reconnect path. Every method (ClaimNextPending, WaitForJob, MarkDone/Failed, ResetStaleRunning) used that one handle; once it dropped, every op returned conn closed forever, the loop logged continuing each poll, and the process stayed systemd-active so Restart=on-failure never fired.

What I changed

1. Reconnect on a closed connection (proposed fix #1) — pgxQueue is now self-healing:

  • ensureConn runs before every op. No-op when the handle is live; when it is missing or IsClosed(), it disposes the dead handle and redials + re-issues LISTEN imagen_jobs (re-establishing LISTEN is the non-obvious part — without it, NOTIFY wake-ups would be silently lost after a reconnect and the worker would degrade to poll-only latency).
  • afterOp force-closes the handle on a connection-class error so the next call rebuilds deterministically, even if pgx has not yet flipped IsClosed().
  • connBroken classifies purely by error: nil / context cancel+deadline / server-side *pgconn.PgError (the server answered → link healthy) stay healthy; everything else (closed conn, reset transport, EOF) is a broken link worth redialing.
  • A bounded 10s dial timeout stops a black-holed host from wedging the loop, and reconnect events (DB connection lost; reconnecting / established) log to stderr→journald so a flapping link is visible instead of swallowed.

2. Fail loud after N consecutive connection errors (proposed fix #2) — the DB-agnostic loop (internal/worker/worker.go) now counts cycles that made no DB progress at all (both the claim pass and the wait pass failed). After MaxConsecutiveDBErrors (default 12 ≈ 1 min at the 5s poll) it returns a fatal error; main exits non-zero → the unit's existing Restart=on-failure restarts it from a clean slate. Any successful claim or poll resets the streak, so a transient blip still costs only a log line (existing TestWorker_TransientClaimErrorDoesNotKillLoop still passes).

3. Restart=on-failure + watchdog (proposed fix #3) — scripts/imagen-worker.service already has Restart=on-failure + RestartSec=5; the fail-loud change is what finally makes it effective (before, the process never exited). I deliberately did not add WatchdogSec: it requires the binary to send sd_notify(WATCHDOG=1) pings, and adding WatchdogSec without that would make systemd kill a healthy worker. The observed failure mode (conn-closed spin) is now a visible crash-loop via fail-loud; a true silent hang is separately bounded by JobTimeout (pipeline) and the poll timeout (wait). If we want defence-in-depth against a wedged-but-alive process, Type=notify + WatchdogSec + an sd_notify pinger is a clean follow-up — say the word and I will open an issue.

4. Liveness signal (optional #4) — not added as a separate mechanism; the reconnect logs + fail-loud crash-loop already surface a stuck worker in journald without reading every line. A last-successful-claim timestamp would only help if we later add a metrics/health endpoint (imagen serve is still a stub) — better bundled with that work than bolted on now.

Tests (all green, go build/vet/test -race clean)

  • TestWorker_FailsLoudAfterConsecutiveDBErrors — both passes fail every cycle → Run returns fatal (the core regression).
  • TestWorker_HealthyWaitResetsErrorCounter — a working wait clears the streak so a failing claim alone never trips fail-loud.
  • TestConnBroken — table test over the classifier (ctx errors, wrapped PgError, EOF, the literal deallocate cached statement(s): conn closed).
  • TestWorker_Integration_ReconnectsAfterDrop (guarded by IMAGEN_WORKER_INTEGRATION=1) — kills the worker's backend via pg_terminate_backend, asserts the queue redials onto a fresh backend PID and that WaitForJob then wakes on a real NOTIFY (proving LISTEN was re-established).

Deploy note

This touches worker code, so the running daemon on mRiver needs the standard rebuild after merge: go build -o bin/imagen ./cmd/imagen && systemctl --user restart imagen-worker.service (the daemon runs a stale bin/imagen). No schema/config changes.

Commit: d14498a8e1

## Fixed: self-healing reconnect + fail-loud Branch `mai/zeus/issue-17-worker`, commit d14498a. Root cause confirmed exactly as described: `pgxQueue` (`cmd/imagen/worker.go`) held a single `*pgx.Conn` with **no reconnect path**. Every method (`ClaimNextPending`, `WaitForJob`, `MarkDone/Failed`, `ResetStaleRunning`) used that one handle; once it dropped, every op returned `conn closed` forever, the loop logged `continuing` each poll, and the process stayed systemd-`active` so `Restart=on-failure` never fired. ### What I changed **1. Reconnect on a closed connection** (proposed fix #1) — `pgxQueue` is now self-healing: - `ensureConn` runs before every op. No-op when the handle is live; when it is missing or `IsClosed()`, it disposes the dead handle and **redials + re-issues `LISTEN imagen_jobs`** (re-establishing LISTEN is the non-obvious part — without it, NOTIFY wake-ups would be silently lost after a reconnect and the worker would degrade to poll-only latency). - `afterOp` force-closes the handle on a connection-class error so the next call rebuilds deterministically, even if pgx has not yet flipped `IsClosed()`. - `connBroken` classifies purely by error: `nil` / context cancel+deadline / server-side `*pgconn.PgError` (the server answered → link healthy) stay healthy; everything else (closed conn, reset transport, EOF) is a broken link worth redialing. - A **bounded 10s dial timeout** stops a black-holed host from wedging the loop, and reconnect events (`DB connection lost; reconnecting` / `established`) log to stderr→journald so a flapping link is **visible** instead of swallowed. **2. Fail loud after N consecutive connection errors** (proposed fix #2) — the DB-agnostic loop (`internal/worker/worker.go`) now counts cycles that made **no DB progress at all** (both the claim pass and the wait pass failed). After `MaxConsecutiveDBErrors` (default **12** ≈ 1 min at the 5s poll) it returns a fatal error; `main` exits non-zero → the unit's existing `Restart=on-failure` restarts it from a clean slate. Any successful claim or poll resets the streak, so a transient blip still costs only a log line (existing `TestWorker_TransientClaimErrorDoesNotKillLoop` still passes). **3. `Restart=on-failure` + watchdog** (proposed fix #3) — `scripts/imagen-worker.service` **already** has `Restart=on-failure` + `RestartSec=5`; the fail-loud change is what finally makes it effective (before, the process never exited). I deliberately did **not** add `WatchdogSec`: it requires the binary to send `sd_notify(WATCHDOG=1)` pings, and adding `WatchdogSec` without that would make systemd kill a *healthy* worker. The observed failure mode (conn-closed spin) is now a visible crash-loop via fail-loud; a true silent hang is separately bounded by `JobTimeout` (pipeline) and the poll timeout (wait). If we want defence-in-depth against a wedged-but-alive process, `Type=notify` + `WatchdogSec` + an sd_notify pinger is a clean follow-up — say the word and I will open an issue. **4. Liveness signal** (optional #4) — not added as a separate mechanism; the reconnect logs + fail-loud crash-loop already surface a stuck worker in journald without reading every line. A last-successful-claim timestamp would only help if we later add a metrics/health endpoint (`imagen serve` is still a stub) — better bundled with that work than bolted on now. ### Tests (all green, `go build`/`vet`/`test -race` clean) - `TestWorker_FailsLoudAfterConsecutiveDBErrors` — both passes fail every cycle → `Run` returns fatal (the core regression). - `TestWorker_HealthyWaitResetsErrorCounter` — a working wait clears the streak so a failing claim alone never trips fail-loud. - `TestConnBroken` — table test over the classifier (ctx errors, wrapped `PgError`, EOF, the literal `deallocate cached statement(s): conn closed`). - `TestWorker_Integration_ReconnectsAfterDrop` (guarded by `IMAGEN_WORKER_INTEGRATION=1`) — kills the worker's backend via `pg_terminate_backend`, asserts the queue redials onto a **fresh** backend PID and that `WaitForJob` then wakes on a real NOTIFY (proving LISTEN was re-established). ### Deploy note This touches worker code, so the running daemon on mRiver needs the standard rebuild after merge: `go build -o bin/imagen ./cmd/imagen && systemctl --user restart imagen-worker.service` (the daemon runs a stale `bin/imagen`). No schema/config changes. Commit: https://mgit.msbls.de/m/ImaGen/commit/d14498a8e1b3fd72ffebeefca35e7861246bb20d
mAi added the
done
 label 2026-07-06 10:49:11 +00:00
mAi commented 2026-07-06 10:51:42 +00:00
Author
Collaborator
Copy Link

Merged + deployed live

Head review passed — go build / go vet / go test ./... all clean on the branch. Merged --no-ff into main as db9c91a and pushed.

Deploy note actioned (this is on mRiver, where the daemon runs):

  • go build -o bin/imagen ./cmd/imagen ✓
  • systemctl --user restart imagen-worker.service ✓ — now active (running), PID 459013, imagen worker: ready. No conn closed loop.

The self-healing reconnect + fail-loud path is now the running code, replacing the binary that had been wedged since 2026-06-07.

Merge commit: https://mgit.msbls.de/m/ImaGen/commit/db9c91a

Downstream, for the record: as #17's own impact note called out, this outage masked the mGPUmanager eviction gap for a month — no job ran far enough to hit the VRAM error. With the worker now failing loud, that m/mGPUmanager lease-resource gap (ImaGen #15 is code-complete but prod-blocked on it) will resurface as soon as a real restyle job runs. Tracked separately on the mGPUmanager side.

### Merged + deployed live Head review passed — `go build` / `go vet` / `go test ./...` all clean on the branch. Merged `--no-ff` into `main` as **db9c91a** and pushed. Deploy note actioned (this is on mRiver, where the daemon runs): - `go build -o bin/imagen ./cmd/imagen` ✓ - `systemctl --user restart imagen-worker.service` ✓ — now `active (running)`, PID 459013, `imagen worker: ready`. No `conn closed` loop. The self-healing reconnect + fail-loud path is now the running code, replacing the binary that had been wedged since 2026-06-07. Merge commit: https://mgit.msbls.de/m/ImaGen/commit/db9c91a **Downstream, for the record:** as #17's own impact note called out, this outage masked the mGPUmanager eviction gap for a month — no job ran far enough to hit the VRAM error. With the worker now failing loud, that `m/mGPUmanager` lease-resource gap (ImaGen #15 is code-complete but prod-blocked on it) will resurface as soon as a real restyle job runs. Tracked separately on the mGPUmanager side.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
done
Work complete, awaiting m close
needs-review
Awaiting m review
needs-smoke
Code merged; real-API smoke still pending
No Label
done
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
mAi m
No Assignees mAi
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: m/ImaGen#17
No description provided.
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?