[Bug][Reliability] Workers pass healthcheck with a DEAD RabbitMQ consumer → pipeline stages silently stall (image.description: 128 msgs/0 consumers) #698

Open
opened 2026-07-18 03:00:48 +00:00 by spikerj · 7 comments
Owner

Symptom

Book-upload processing silently stalls at a pipeline stage whose worker is up and healthy (HTTP healthcheck green) but has a dead RabbitMQ consumer. Requests published to that stage's queue pile up unconsumed; the upload-coordinator's staleness detector fires after 30 min and marks the workflow stalled. No quiz/embeddings result, no crash, no restart.

Evidence (2026-07-18)

Godot book upload 86bfade3-bbbd-480a-a2c2-9c5adb71b89b progressed (metadata → book created → file moved), then at 01:21:13 the coordinator published 128 image-description requests. RabbitMQ state:

image.description.requested   messages=128   consumers=0

The spikersoft-image-description worker (GPU container on node 4090; RabbitMQ on dreamstream7) had been Running 36h, healthcheck green, zero processing activity — no active consumer on the queue. Coordinator logged Staleness detected: Stage=ImageDescriptions, Elapsed=30.1min at 01:51:17Status: stalled, FailedStageError: "Processing timed out after 30 minutes — the ImageDescriptions service may be unavailable".

Not isolated — several dead-letter queues are also backed up, i.e. other workers dropping messages:

generation.process.dlq            5
keycloak.events.dlq               4
embeddings.process.dlq            2
metadata.extraction.requests.dlq  1

Root cause

  • The worker healthcheck only asserts HTTP liveness, not that the RabbitMQ consumer is actually subscribed/active. A worker whose consumer died (connection/channel drop, failed startup) stays "healthy", so Swarm never restarts it.
  • No evidence of consumer auto-reconnect when the connection/channel drops across the overlay (4090 ↔ dreamstream7).

Proposed fix (design needed — framework-level, touches EventHandlerHostBuilder healthchecks)

  1. Healthcheck asserts an active consumer on each expected queue (consumer count ≥ 1 / channel open), so a dead-consumer worker fails health → Swarm restarts it.
  2. Consumer auto-reconnect on connection/channel drop (re-declare + re-subscribe).
  3. Observability: alert on messages>0 && consumers==0 for any request queue; surface DLQ depth.

Impact

Silently blocks book processing (viewable book, but no image-descriptions → no embeddings → no quiz). Applies to any event-driven stage, not just image-description.

Immediate remediation

Restart the affected worker to re-establish its consumer and drain the queue. (A workflow already marked stalled may need a stage re-trigger or fresh upload after the worker is healthy.)

## Symptom Book-upload processing silently stalls at a pipeline stage whose worker is **up and healthy (HTTP healthcheck green) but has a dead RabbitMQ consumer**. Requests published to that stage's queue pile up unconsumed; the upload-coordinator's staleness detector fires after 30 min and marks the workflow `stalled`. No quiz/embeddings result, no crash, no restart. ## Evidence (2026-07-18) Godot book upload `86bfade3-bbbd-480a-a2c2-9c5adb71b89b` progressed (metadata → book created → file moved), then at `01:21:13` the coordinator published **128 image-description requests**. RabbitMQ state: ``` image.description.requested messages=128 consumers=0 ``` The `spikersoft-image-description` worker (GPU container on node 4090; RabbitMQ on dreamstream7) had been **Running 36h**, healthcheck green, **zero** processing activity — no active consumer on the queue. Coordinator logged `Staleness detected: Stage=ImageDescriptions, Elapsed=30.1min` at `01:51:17` → `Status: stalled`, `FailedStageError: "Processing timed out after 30 minutes — the ImageDescriptions service may be unavailable"`. Not isolated — several dead-letter queues are also backed up, i.e. other workers dropping messages: ``` generation.process.dlq 5 keycloak.events.dlq 4 embeddings.process.dlq 2 metadata.extraction.requests.dlq 1 ``` ## Root cause - The worker healthcheck only asserts **HTTP liveness**, not that the RabbitMQ **consumer is actually subscribed/active**. A worker whose consumer died (connection/channel drop, failed startup) stays "healthy", so Swarm never restarts it. - No evidence of consumer **auto-reconnect** when the connection/channel drops across the overlay (4090 ↔ dreamstream7). ## Proposed fix (design needed — framework-level, touches EventHandlerHostBuilder healthchecks) 1. **Healthcheck asserts an active consumer** on each expected queue (consumer count ≥ 1 / channel open), so a dead-consumer worker fails health → Swarm restarts it. 2. **Consumer auto-reconnect** on connection/channel drop (re-declare + re-subscribe). 3. **Observability:** alert on `messages>0 && consumers==0` for any request queue; surface DLQ depth. ## Impact Silently blocks book processing (viewable book, but no image-descriptions → no embeddings → no quiz). Applies to any event-driven stage, not just image-description. ## Immediate remediation Restart the affected worker to re-establish its consumer and drain the queue. (A workflow already marked `stalled` may need a stage re-trigger or fresh upload after the worker is healthy.)
Author
Owner

Additional evidence (read-only): RabbitMQ broker is healthy — 10 live connections, 81 active consumers system-wide, all running. Yet the image.description.requested queue still shows 128 messages / 0 consumers. So this is isolated to the image-description worker (not a broker outage): its consumer specifically is dead/absent while every other worker consumes normally. Implication: a worker restart should re-establish the connection + consumer and drain the 128 backlog. The durable fix (healthcheck must assert an active consumer, plus auto-reconnect) still stands — the worker stayed healthcheck-green for 36h with a dead consumer.

Additional evidence (read-only): RabbitMQ broker is healthy — 10 live connections, 81 active consumers system-wide, all running. Yet the image.description.requested queue still shows 128 messages / 0 consumers. So this is isolated to the image-description worker (not a broker outage): its consumer specifically is dead/absent while every other worker consumes normally. Implication: a worker restart should re-establish the connection + consumer and drain the 128 backlog. The durable fix (healthcheck must assert an active consumer, plus auto-reconnect) still stands — the worker stayed healthcheck-green for 36h with a dead consumer.
Author
Owner

Framework half fixed — backend PR #418. Verified the root-cause claim first: /healthz really ran zero checks (Predicate = _ => false in WebApplicationExtensions) — pure process liveness, exactly as this ticket diagnosed.

What #418 ships (all EventHandlerHostBuilder workers inherit automatically):

  1. Connection liveness/healthz goes Unhealthy (503 → curl -f fails → Swarm restart) when the shared IConnection is closed. The framework already enables AutomaticRecovery+TopologyRecovery, so a still-closed connection means recovery is stuck — the restart IS the reconnect, which largely covers proposed fix item 2 for .NET workers.
  2. Consumer registryIRabbitMqConsumerRegistry + liveness check for the finer consumer-dead-connection-alive case; probes adopt incrementally (zero probes = healthy, no behavior change until wired).

Remaining on this ticket:

  • The incident's actual worker is SpikerSoft.EventHandlers.ImageDescription.Pythonoutside this framework; it needs its own consumer-liveness healthcheck (same principle: fail health when the AMQP consumer is gone).
  • Per-consumer probe adoption across the .NET hosted services.
  • Broker-side alerting on messages>0 && consumers==0 + DLQ depth (the several backed-up DLQs in the evidence).
  • The running image-description container was deliberately not restarted (preserved specimen per standing instruction) — drain/restart remains an operator action.

Full unit suite green (30 projects); 8 new tests. Leaving the ticket open for the remaining items.

**Framework half fixed — backend PR [#418](https://git.spikersoft.com/spikerj/spikersoft-backend/pulls/418).** Verified the root-cause claim first: `/healthz` really ran **zero checks** (`Predicate = _ => false` in `WebApplicationExtensions`) — pure process liveness, exactly as this ticket diagnosed. What #418 ships (all `EventHandlerHostBuilder` workers inherit automatically): 1. **Connection liveness** — `/healthz` goes Unhealthy (503 → `curl -f` fails → Swarm restart) when the shared `IConnection` is closed. The framework already enables `AutomaticRecovery+TopologyRecovery`, so a still-closed connection means recovery is stuck — **the restart IS the reconnect**, which largely covers proposed fix item 2 for .NET workers. 2. **Consumer registry** — `IRabbitMqConsumerRegistry` + liveness check for the finer consumer-dead-connection-alive case; probes adopt incrementally (zero probes = healthy, no behavior change until wired). **Remaining on this ticket:** - The incident's actual worker is `SpikerSoft.EventHandlers.ImageDescription.Python` — *outside* this framework; it needs its own consumer-liveness healthcheck (same principle: fail health when the AMQP consumer is gone). - Per-consumer probe adoption across the .NET hosted services. - Broker-side alerting on `messages>0 && consumers==0` + DLQ depth (the several backed-up DLQs in the evidence). - The running image-description container was deliberately **not** restarted (preserved specimen per standing instruction) — drain/restart remains an operator action. Full unit suite green (30 projects); 8 new tests. Leaving the ticket open for the remaining items.
Author
Owner

Framework half merged — PR #418 is on master: every EventHandlerHostBuilder worker's /healthz now fails (→ Swarm restart) on a closed RabbitMQ connection, and the consumer-probe registry is available for the finer consumer-dead case. Remaining scope (this ticket stays open): Python image-description worker's own liveness check, per-consumer probe adoption in the .NET hosted services, broker-side messages>0 && consumers==0 + DLQ alerting, and the operator drain/restart of the preserved specimen worker.

Framework half **merged** — PR [#418](https://git.spikersoft.com/spikerj/spikersoft-backend/pulls/418) is on `master`: every `EventHandlerHostBuilder` worker's `/healthz` now fails (→ Swarm restart) on a closed RabbitMQ connection, and the consumer-probe registry is available for the finer consumer-dead case. Remaining scope (this ticket stays open): Python image-description worker's own liveness check, per-consumer probe adoption in the .NET hosted services, broker-side `messages>0 && consumers==0` + DLQ alerting, and the operator drain/restart of the preserved specimen worker.
Author
Owner

Recurred 2026-07-18, and the mechanism is now fully root-caused — it's a compound failure across the Python worker and the gpu-coordinator:

  1. 07:02Z swarm leader blip → both spikersoft-image-description and spikersoft-gpu-coordinator restarted.
  2. 07:03:00 the worker connected to RabbitMQ, logged "Starting to consume", then sent its GPU lease request (qwen3-vl-8b, 20000 MB).
  3. 07:03:21 the coordinator came up and logged: "Discarding stale lease request from ImageDescription ... requested at 07:03:00 — before coordinator started at 07:03:21" — discarded WITHOUT sending any rejection reply.
  4. The Python lease client has no timeout/retry on the RPC, so the worker blocked forever awaiting a reply. While blocked, its pika heartbeat starved → RabbitMQ closed the consumer. Process alive, healthcheck green, consumer dead — for 15h.
  5. Contrast: ArtPipeProcessor hit the same 07:03:21 discard but re-requested at 07:04:40 and got its lease — its client retries; image-description's doesn't.

Impact: image.description.requested grew to 954 msgs / 0 consumers; every book upload (incl. today's mathematics-game-development-collection.pdf, book 6a5bf73f) froze at ImageDescriptions, quizzes stuck Pending (quiz request rides embeddings, which follows). Remediated 2026-07-18 ~20:5xZ with docker service update --force (restart-to-drain).

Durable fixes this ticket should cover (the .NET healthz half merged today as backend dbc9cbc4 does NOT protect this Python worker):

  • gpu-coordinator: REPLY with a rejection when discarding a stale lease request (silent drop leaves clients hanging).
  • image-description lease client: timeout + re-request loop (mirror the ArtPipeProcessor client's behavior).
  • Python worker healthcheck: assert an ACTIVE RabbitMQ consumer (the original ask here), not just process liveness.
Recurred 2026-07-18, and the mechanism is now fully root-caused — it's a compound failure across the Python worker and the gpu-coordinator: 1. 07:02Z swarm leader blip → both `spikersoft-image-description` and `spikersoft-gpu-coordinator` restarted. 2. 07:03:00 the worker connected to RabbitMQ, logged "Starting to consume", then sent its GPU lease request (qwen3-vl-8b, 20000 MB). 3. 07:03:21 the coordinator came up and logged: "Discarding stale lease request from ImageDescription ... requested at 07:03:00 — before coordinator started at 07:03:21" — **discarded WITHOUT sending any rejection reply**. 4. The Python lease client has **no timeout/retry** on the RPC, so the worker blocked forever awaiting a reply. While blocked, its pika heartbeat starved → RabbitMQ closed the consumer. Process alive, healthcheck green, consumer dead — for 15h. 5. Contrast: ArtPipeProcessor hit the same 07:03:21 discard but **re-requested at 07:04:40 and got its lease** — its client retries; image-description's doesn't. Impact: `image.description.requested` grew to **954 msgs / 0 consumers**; every book upload (incl. today's `mathematics-game-development-collection.pdf`, book 6a5bf73f) froze at ImageDescriptions, quizzes stuck Pending (quiz request rides embeddings, which follows). Remediated 2026-07-18 ~20:5xZ with `docker service update --force` (restart-to-drain). Durable fixes this ticket should cover (the .NET healthz half merged today as backend dbc9cbc4 does NOT protect this Python worker): - gpu-coordinator: REPLY with a rejection when discarding a stale lease request (silent drop leaves clients hanging). - image-description lease client: timeout + re-request loop (mirror the ArtPipeProcessor client's behavior). - Python worker healthcheck: assert an ACTIVE RabbitMQ consumer (the original ask here), not just process liveness.
Author
Owner

Durable fixes are up as spikersoft-backend PR #420 (branch fix/698-lease-deadlock-durable): (1) coordinator replies GpuLeaseRejectMessage on stale discard instead of silently dropping; (2) Python acquire() bounded at 45s + reject-aware, both failure modes classified retryable so the #506 retry machinery re-requests with a fresh RequestedAt (mirrors the ArtPipeProcessor client's recovery behavior); .NET SharedGpuLeaseService made reject-aware too (a reject would otherwise parse as a grant with empty LeaseId); (3) container healthcheck now asserts the consumer loop is servicing events via a beat file + stdlib healthcheck.py — a deaf worker goes unhealthy in ~5-7 min and Swarm replaces it. 3 new xunit cases (first direct OnLeaseRequestReceived coverage), 1 new SharedGpuLeaseService case, 11 new pytest cases; all touched suites green. Worker half ships via the image-description CI deploy on merge; coordinator half rides the next backend fleet deploy.

Durable fixes are up as spikersoft-backend PR #420 (branch fix/698-lease-deadlock-durable): (1) coordinator replies GpuLeaseRejectMessage on stale discard instead of silently dropping; (2) Python acquire() bounded at 45s + reject-aware, both failure modes classified retryable so the #506 retry machinery re-requests with a fresh RequestedAt (mirrors the ArtPipeProcessor client's recovery behavior); .NET SharedGpuLeaseService made reject-aware too (a reject would otherwise parse as a grant with empty LeaseId); (3) container healthcheck now asserts the consumer loop is servicing events via a beat file + stdlib healthcheck.py — a deaf worker goes unhealthy in ~5-7 min and Swarm replaces it. 3 new xunit cases (first direct OnLeaseRequestReceived coverage), 1 new SharedGpuLeaseService case, 11 new pytest cases; all touched suites green. Worker half ships via the image-description CI deploy on merge; coordinator half rides the next backend fleet deploy.
Author
Owner

Sweep note: PR #420 fixed the gpu-lease slice (stale-request rejects, bounded Python acquire, consumer-aware healthcheck for the coordinator path). The ticket's broader claim — WORKERS generally passing healthchecks with dead RabbitMQ consumers — has no merged evidence of a fleet-wide fix. Leaving open, scoped to the remainder.

Sweep note: PR #420 fixed the gpu-lease slice (stale-request rejects, bounded Python acquire, consumer-aware healthcheck for the coordinator path). The ticket's broader claim — WORKERS generally passing healthchecks with dead RabbitMQ consumers — has no merged evidence of a fleet-wide fix. Leaving open, scoped to the remainder.
Author
Owner

Audited against origin/masterthe machinery shipped but is inert fleet-wide. Staying open. This is the important finding, so recording it precisely:

Landed:

  • EventHandlers.Infrastructure/HealthChecks/RabbitMqConsumerRegistry.cs + RabbitMqConsumerLivenessHealthCheck.cs, DI-registered at EventHandlers.Infrastructure/Extensions/ServiceCollectionExtensions.cs:437 (PR #418, dbc9cbc4).
  • GPU-lease slice (PR #420, b4637493): SpikerSoft.Common/Models/GpuLeaseMessages.cs (GpuLeaseReject), GpuCoordinator/Services/LeaseManagerService.cs, ImageDescription.Python/gpu_lease.py, Infrastructure/Services/SharedGpuLeaseService.cs, plus the ImageDescription.Python Dockerfile + healthcheck.py beat-file probe.

The consumer-liveness probe registers nothing. git grep -n 'registry.Register\|RegisterConsumer' origin/master returns only test files (RabbitMqLivenessHealthCheckTests.cs). No .NET hosted service ever registers a consumer with the registry. And RabbitMqConsumerLivenessHealthCheck.cs:19 reports Healthy when RegisteredCount == 0 — so on every worker in the fleet the check currently returns green by virtue of being empty.

That means the exact scenario this ticket describes — a worker passing its healthcheck while its RabbitMQ consumer is dead — is still possible on every .NET host. The health check that was built to catch it cannot fire.

Also missing: broker-side alerting. In spikersoft-infrastructure, git grep -rln 'consumers==0|consumer_count|messages_ready|dlq'zero hits; git grep -rln 'alert:|alerting_rules|rabbitmq_queue' → zero. prometheus/ contains only config/prometheus.yml and docker-stack.yml — no rules files and no RabbitMQ exporter. So the "128 msgs / 0 consumers" condition would still go unnoticed.

Remaining:

  1. Call registry.Register(...) from each consumer's startup path (or from EventHandlerHostBuilder, so all 26 hosts inherit it the way telemetry does).
  2. Decide whether RegisteredCount == 0 should be Healthy — as written, a host that forgets to register is indistinguishable from a healthy one, which is how this stayed invisible.
  3. Add the broker-side alert (consumers==0 with messages_ready>0), which needs a RabbitMQ exporter and a Prometheus rules file that don't currently exist.
  4. Operator drain/restart of the preserved specimen — not repo-provable.
Audited against `origin/master` — **the machinery shipped but is inert fleet-wide.** Staying open. This is the important finding, so recording it precisely: **Landed:** - `EventHandlers.Infrastructure/HealthChecks/RabbitMqConsumerRegistry.cs` + `RabbitMqConsumerLivenessHealthCheck.cs`, DI-registered at `EventHandlers.Infrastructure/Extensions/ServiceCollectionExtensions.cs:437` (PR #418, `dbc9cbc4`). - GPU-lease slice (PR #420, `b4637493`): `SpikerSoft.Common/Models/GpuLeaseMessages.cs` (`GpuLeaseReject`), `GpuCoordinator/Services/LeaseManagerService.cs`, `ImageDescription.Python/gpu_lease.py`, `Infrastructure/Services/SharedGpuLeaseService.cs`, plus the `ImageDescription.Python` Dockerfile + `healthcheck.py` beat-file probe. **The consumer-liveness probe registers nothing.** `git grep -n 'registry.Register\|RegisterConsumer' origin/master` returns **only test files** (`RabbitMqLivenessHealthCheckTests.cs`). No .NET hosted service ever registers a consumer with the registry. And `RabbitMqConsumerLivenessHealthCheck.cs:19` reports **Healthy when `RegisteredCount == 0`** — so on every worker in the fleet the check currently returns green by virtue of being empty. That means the exact scenario this ticket describes — a worker passing its healthcheck while its RabbitMQ consumer is dead — is still possible on every .NET host. The health check that was built to catch it cannot fire. **Also missing: broker-side alerting.** In spikersoft-infrastructure, `git grep -rln 'consumers==0|consumer_count|messages_ready|dlq'` → **zero hits**; `git grep -rln 'alert:|alerting_rules|rabbitmq_queue'` → zero. `prometheus/` contains only `config/prometheus.yml` and `docker-stack.yml` — no rules files and no RabbitMQ exporter. So the "128 msgs / 0 consumers" condition would still go unnoticed. **Remaining:** 1. Call `registry.Register(...)` from each consumer's startup path (or from `EventHandlerHostBuilder`, so all 26 hosts inherit it the way telemetry does). 2. Decide whether `RegisteredCount == 0` should be Healthy — as written, a host that forgets to register is indistinguishable from a healthy one, which is how this stayed invisible. 3. Add the broker-side alert (consumers==0 with messages_ready>0), which needs a RabbitMQ exporter and a Prometheus rules file that don't currently exist. 4. Operator drain/restart of the preserved specimen — not repo-provable.
Sign in to join this conversation.