Queues · advanced
Queue jobs disappear after acknowledgement timeout: trace ownership
Queue jobs vanish from the visible worker set after an acknowledgement timeout, leaving no clear owner. The playbook traces the handoff from pickup to ack, isolating whether the job was stalled, double-locked, or evicted by a watchdog, and shows how to prove ownership before changing retry logic.
The symptoms
- •Job appears in the queue under a worker, runs for some duration, then the same job id is picked up again by a different worker instance, and the original instance never reports a completion or failure event in metrics.
- •Dashboard or logs show a stalled-job or lock-lost event aligned with the disappearance, often coinciding with a worker process restart, a deploy rollout, or a heartbeat that stopped incrementing while the job was still running.
- •Metrics count the job as completed exactly once even though two workers executed the payload, which suggests an idempotency layer silently absorbed the duplicate rather than the queue reconciling ownership.
- •Side effects (database writes, outbound HTTP calls) occur for a job whose queue state moved back to waiting before any failure event was emitted, indicating ack happened after lock loss.
- •Throughput drops while the visible job count is normal, because workers spend their lock window retrying jobs that another instance is also processing, and the job never reaches an acknowledged terminal state within the heartbeat interval.
Likely causes
- •Worker heartbeat fell below the lock duration threshold (CPU starvation, GC pause, event loop saturation), so the broker moved the job back to wait while the original handler still held it, producing a double-execution window.
- •Lock duration was set shorter than the realistic worst-case duration of the job, so the lock expired before the worker finished, and the second pickup raced the first handler's completion path.
- •Process death during graceful shutdown lost the in-flight acknowledgement, and the broker only marked the job stalled after a full lock-renewal cycle rather than on disconnect.
- •Network partition between worker and broker prevented lock renewal RPCs from reaching the broker even though the worker kept processing, so the broker reassigned ownership to a different consumer.
- •Misconfigured stalled-job checker cadence or stalled interval left jobs in a limbo state where ownership reassignment lagged, masking the real reassignment timestamp in audit logs.
First ten minutes
- 01Freeze new deployments so the reproducing state is preserved, and capture the worker process tree plus the exact version and lock duration settings in use at the time of disappearance.
- 02Pull the broker queue metrics around the disappearance window: counts of waiting, active, completed, failed, delayed, and stalled states, and the per-state transition timestamps for the affected job id.
- 03Grep worker logs for the job id across all instances ordered by timestamp, and tag each line with whether the worker emitted a heartbeat, a stalled event, or a completion event for that job.
- 04Compare the broker's lock-renewal log timestamps with the worker's last in-process log line on the same job id; the gap between them is the candidate ownership-loss window.
- 05Decide between two competing hypotheses before any code change: (a) the worker failed to renew the lock in time, or (b) the lock was renewed but the ack never reached the broker due to a network or process lifecycle event.
Evidence to collect
- •Per-job event timeline from the broker including waiting→active→completed/failed/stalled transitions with their timestamps and the consumer identifier at each transition.
- •Worker-side log lines for the same job id covering start, last heartbeat, last db write, and any exception or shutdown signal, time-synchronized to broker timestamps via a shared NTP reference.
- •Resource metrics for the worker host covering the disappearance window: CPU, memory, GC or event-loop lag, and network reachability to the broker endpoint.
- •Configuration snapshot of lock duration, lock renewal interval, stalled job check cadence, and stalled interval compared with p95 and p99 observed job processing time.
- •Side-effect audit showing whether outbound calls, database rows, or message publishes occurred for the job once, twice, or zero times across the competing worker instances.
Where to look
- •At the broker boundary, inspecting the queue's stalled-job detection path and the per-job lock-renewal audit log to see when ownership was reassigned.
- •At the worker boundary, inspecting the connection lifecycle, graceful shutdown handler, and the heartbeat emitter to see whether renewal stopped before work stopped.
- •At the application boundary, inspecting idempotency keys, dedupe tables, and downstream sinks to see whether a duplicate execution was absorbed or produced conflicting writes.
- •At the platform boundary, inspecting kernel or container signals (SIGTERM during deploys, cgroup throttling, DNS resolver behavior) that align with the lock-loss timestamp.
Diagnostic steps
- 01Reproduce under controlled load by replaying a representative job while disabling worker concurrency to one and capturing every broker↔worker message with timing, so the lock-loss boundary is observable.
- 02Set lock duration to a value strictly greater than observed p99 processing time plus a safety margin, then watch whether disappearance rate drops; if it persists, the boundary is at ack or network, not renewal latency.
- 03Instrument the worker to log a monotonic counter on every heartbeat tick and compare with the broker's renewal timestamps; a divergence larger than one interval confirms a renewal miss rather than an ack miss.
- 04Inject a forced graceful shutdown during job execution and inspect whether the broker recorded a stalled transition or the job stayed active past the shutdown deadline, which distinguishes signal-based loss from renewal-based loss.
- 05Enable verbose broker audit for the affected queue and isolate the exact RPC that moved the job from active back to waiting; cross-reference the worker log to determine whether the worker was alive at that moment.
- 06Cross-check idempotency tables for the affected job id to confirm whether duplicate execution happened or was deduplicated; this narrows whether the loss is visible (double side effect) or silent (absorbed dedupe).
Common mistakes
- •Increasing lock duration without first measuring observed p99 processing time, which masks the symptom only until the next slow tail and obscures the real renewal-miss cause.
- •Assuming a stalled event in the dashboard means the worker died; the worker may still be running and merely unable to renew on schedule, so killing the worker first destroys the evidence needed to confirm the boundary.
- •Treating duplicate side effects as proof of double execution without checking idempotency keys, leading to a missed class where the queue reports a single completion while downstream sees two writes.
- •Rerunning failed jobs from a poisoned-pill list without inspecting the lock-loss trail, which can re-stall the same job under a new worker and repeat the disappearance pattern.
- •Pointing log search at the wrong queue name prefix when multiple environments share the broker, so the timeline is anchored to a different job id and the ownership boundary is misattributed.
Safe fixes
- •If p99 processing time exceeds lock duration, raise lock duration to at least p99 plus a documented margin, and add an alert when observed processing time approaches the lock so future regressions surface before disappearance.
- •If heartbeats stop during long jobs, increase the worker's lock-renewal frequency so each renewal lands inside a smaller slice of the lock duration, and verify broker audit shows renewal ticks until completion.
- •If graceful shutdown loses in-flight acks, route completion through an idempotent sink that the worker writes before the ack, so a reassigned job retries a safe operation rather than a destructive duplicate.
- •If network partitions cause lock-loss, add a readiness signal that pauses new pickup whenever renewal RPCs start failing, instead of letting the worker keep processing a job whose lock is already lost.
- •If the stalled checker cadence hides the reassignment timestamp, shorten the stalled interval and the check cadence so the audit log records the boundary within a known bounded window.
Prove the fix
- 01Re-run the same job shape under the same load profile and confirm the broker records exactly one waiting→active→completed transition per job id, with no stalled or reactivated transitions.
- 02Compare lock-renewal timestamps against worker heartbeat timestamps across a full job lifecycle and confirm the maximum skew stays under one renewal interval for the entire run.
- 03Verify that downstream side-effect counters show exactly one execution per job id by replaying a tagged sample batch and counting external calls or DB rows.
- 04Inject a forced worker shutdown during a synthetic job and confirm either a stalled transition with retrievable evidence or a clean completion-then-acked sequence, with no silent loss of ownership.
- 05Hold the new configuration for at least two consecutive deploy windows at production-equivalent load, and confirm the disappearance rate and the double-execution rate both stay at zero.
Prevention and next steps
- •Pin lock duration, lock renewal interval, and stalled-job configuration as code-reviewed values tied to measured p99 processing time, with an alert that fires if processing time approaches the lock threshold.
- •Require jobs to write to an idempotent sink before emitting the acknowledgement, so the boundary between work-done and ack-delivered is auditable per job id.
- •Add a canary that runs a synthetic long-running job per deploy and asserts that exactly one completion event is recorded, so renewal-miss regressions are caught before user traffic is affected.
- •Centralize worker graceful-shutdown logic so in-flight jobs either reach the broker-side ack or trigger a controlled stalled transition, and treat any other path as an incident signal.
- •Audit the stalled-job check cadence and stalled interval at every queue-config change, since the cadence determines how quickly ownership loss is visible in the audit trail.
Safe commands and checks
bullmq-cli stalled --queue <queue-name> --limit 50 bullmq-cli jobs list --queue <queue-name> --states active waiting stalled --limit 50 redis-cli -h <broker-host> -p <port> ZRANGE <queue-name>:stalled 0 49 WITHSCORES redis-cli -h <broker-host> -p <port> ZRANGE <queue-name>:active 0 49 WITHSCORES redis-cli -h <broker-host> -p <port> HGETALL bull:<job-id>:lock redis-cli -h <broker-host> -p <port> HGETALL bull:<job-id>:logs grep -n "<job-id>" <worker-log-path> | sort -k1,2 journalctl --since "<timestamp>" --until "<timestamp>" -u <worker-service> --no-pager | grep -E "<job-id>|heartbeat|stalled"