Queues · advanced
Worker acknowledges before commit: expose the loss window
A playbook for diagnosing the "ack-before-commit" failure pattern in queue workers, where a job is acknowledged, removed, or marked complete before its database writes or external side effects are durable. The loss window between ack and commit is exposed through stalled-job recovery, duplicate processing, and reconciliation drift. Engineers use BullMQ stalled-job telemetry and worker lock semantics as the authoritative anchor for this guide.
The symptoms
- •Jobs reappear in the "waiting" or "active" set after being reported as completed, often with the same job id and payload, indicating BullMQ stalled-job recovery moved work back into the queue.
- •Downstream records are missing, partial, or duplicated while the worker logs show the job as finished, signaling that the ack was sent before the side effect was committed.
- •Lock duration or stalledInterval warnings appear in worker logs because the job's critical section extended past the heartbeat window, a classic signal that a slow side effect straddled the ack.
- •Reconciliation jobs find rows that exist in the queue history but not in the system of record, or vice versa, surfacing the commit gap after the fact.
- •Error counters spike for "Job not found" or "Lock not acquired" retries, suggesting the worker believed it was the active owner but the lock had already been reclaimed.
Likely causes
- •The worker's success branch calls job.moveToCompleted or returns a resolved promise before the database transaction or external API call commits, leaving the ack on a non-durable side effect.
- •Side-effect work is performed before the BullMQ job is fetched, or after the lock has been considered "held," so a stall or worker crash causes BullMQ to reassign the job while the original worker still completes the write.
- •Lock renewal (extendLockTimer) is disabled, misconfigured, or shorter than the longest commit path, so BullMQ treats the job as stalled and re-enqueues it mid-transaction.
- •At-least-once semantics are misunderstood as exactly-once: the consumer implements no idempotency key, so the duplicate run that arrives after requeue causes divergent writes.
- •The "ack" is conflated with the application-level success callback, and the queue is configured with removeOnComplete but no delayed retry or dead-letter, hiding the failure path until a reconciliation sweep finds it.
First ten minutes
- 01Confirm scope: capture the BullMQ queue name, the worker concurrency, and the timestamp of the first observed duplicate or missing record to bound the loss window.
- 02Open the BullMQ stalled-job documentation reference to anchor terminology: stalled, lockDuration, maxStalledCount, and how BullMQ re-enqueues a stalled job back to "waiting."
- 03Grep worker logs for the exact strings "stalled", "lock duration", and "extend lock"; these are the direct signals that ack and commit were temporally decoupled.
- 04Compare the worker's reported completion timestamp against the database commit timestamp for the same job id; a negative delta is the smoking gun for an ack-before-commit.
- 05Inventory the worker's success path in code: identify the exact line where the promise resolves versus where the transaction commits, and check whether removeOnComplete is firing before the write is durable.
- 06Decide on evidence sufficiency: if the delta is negative and the success path resolves pre-commit, escalate to the diagnostic steps; otherwise widen the search to lock-renewal or external-call latency.
Evidence to collect
- •Worker log lines containing "stalled", "lock duration", or "extend lock" within the affected time window, with job id and queue name attached.
- •Database commit timestamps for rows the worker claims to have written, paired with the queue's "completed" event timestamp for the same job id.
- •Queue depth and state counters for "waiting", "active", "completed", and "failed" before and after the suspected window, to detect silent requeues.
- •BullMQ configuration values for lockDuration, stalledInterval, and maxStalledCount as actually loaded by the worker, not just the documented defaults.
- •Reconciliation report output listing job ids present in the queue history but absent in the system of record, and the inverse set.
- •External-system write receipts or response bodies that can prove whether the downstream API received and acknowledged the call before the queue ack.
Where to look
- •The boundary between the BullMQ worker process and the database transaction: this is where ack and commit are temporally separated and is the primary fault line.
- •The boundary between the BullMQ worker process and the external side-effect service (HTTP API, object store, payment processor), where a successful response can coexist with a non-durable local write.
- •The worker event bus: the "completed" and "failed" event handlers attached to the QueueEvents listener, since these are the last observable signals before BullMQ finalizes the job.
- •The stalled-job requeue path documented under docs.bullmq.io/guide/jobs/stalled, which describes how a job is moved from "active" back to "waiting" when its lock is considered lost.
- •The QueueOptions and WorkerOptions as instantiated in code, since removeOnComplete, lockDuration, and stalledInterval together define the loss window.
- •The idempotency layer, if any: the table, cache, or token store that the worker uses to deduplicate retries, which is the natural place to verify at-least-once handling.
Diagnostic steps
- 01Reconstruct the critical section: read the worker handler from entry to promise resolution, marking every await on a database transaction or external call, and note which step the queue's completion is fired from.
- 02Compute the commit-vs-ack delta: for each suspect job id, subtract the database commit timestamp from the queue "completed" event timestamp; a sustained negative delta across multiple jobs confirms the pattern.
- 03Audit lock renewal: verify that the worker either keeps lockDuration larger than the longest observed commit or actively extends the lock via the documented extendLockTimer mechanism; absence of either is a contributing cause.
- 04Cross-check stalled telemetry against maxStalledCount: jobs that exceed maxStalledCount are moved to "failed", so a stalled job that "completes" successfully anyway indicates the duplicate was processed by a second worker.
- 05Inspect the idempotency layer: simulate a duplicate delivery by re-running the same job id and observing whether the side effect is suppressed; if it executes twice, at-least-once is not handled and the loss window is exploitable.
- 06Distinguish from other causes: rule out network partitions at the queue boundary by checking the connection error log, rule out database deadlocks by checking the transaction retry log, and rule out consumer crashes by checking worker exit codes.
- 07Confirm scope: count distinct job ids affected; a single job points to a one-off race, while a sustained pattern across many job ids points to a structural ack-before-commit in the worker code.
Common mistakes
- •Treating a successful queue "completed" event as proof that the side effect was durable; the event fires on worker return, not on downstream commit.
- •Increasing lockDuration or stalledInterval without addressing the root cause; this only widens the loss window rather than eliminating it.
- •Assuming BullMQ's removeOnComplete provides exactly-once delivery; the documentation explicitly defines stalled-job recovery, which contradicts exactly-once assumptions.
- •Logging only inside the transaction without logging the queue completion timestamp, making it impossible to compute the commit-vs-ack delta post-incident.
- •Adding a retry on the downstream side effect without an idempotency key, converting a single loss into a duplicated write on the next delivery.
- •Conflating "the worker returned" with "the work is done", and alerting on the former, which masks the loss window until reconciliation runs.
Safe fixes
- •If the commit-vs-ack delta is negative on multiple job ids, restructure the worker to await the database transaction commit before resolving the job, and only then allow BullMQ to finalize the job state.
- •If lockDuration is shorter than the observed longest commit path, raise lockDuration to comfortably exceed the p99 commit latency, or enable active lock extension so a slow commit does not cause a stall mid-transaction.
- •If maxStalledCount is unbounded or zero-meaning, set it to a finite small integer and route exceeded-stall jobs to a "failed" listener so the loss is visible rather than silently requeued forever.
- •If the idempotency layer is missing, add a dedupe key keyed on the BullMQ job id (or a stable payload hash) at the side-effect target, and verify the duplicate path is suppressed before promoting the change.
- •If reconciliation drift is detected, run a one-time compensating job that re-derives system-of-record state from the queue history, and gate it on a flag so it cannot run concurrently with live workers.
- •If external API calls straddle the ack, switch the success branch to a two-phase pattern: stage the intent locally with an idempotency key, then commit and confirm, then resolve the job, so a stall before confirmation triggers a safe retry rather than a duplicate effect.
Prove the fix
- 01Inject a forced stall by stopping the worker mid-transaction and observing that the job is requeued, then re-processed exactly once at the side-effect target, confirming the duplicate path is suppressed.
- 02Replay a batch of historical job ids through the worker and verify the commit-vs-ack delta is non-negative for every job, demonstrating that the ack no longer precedes the commit.
- 03Run a continuous reconciliation job that compares queue history against the system of record for one hour; an empty diff at the end of the run proves the loss window has been closed under live traffic.
- 04Trigger an artificial commit slowdown (for example, a sleep on the database transaction) that exceeds the prior lockDuration, and confirm that the lock is extended rather than the job being marked stalled.
- 05Verify the failed-listener path: induce a stall that exceeds maxStalledCount and observe that the job lands in "failed" with the stalled-job event recorded, proving the silent-requeue path is no longer reachable.
- 06Confirm the idempotency layer empirically: deliver the same job id twice in rapid succession and observe a single side-effect record in the target system, proving at-least-once is now tolerated safely.
Prevention and next steps
- •Adopt a worker template that always awaits the downstream commit before resolving the BullMQ job, and enforce this with a lint or code-review checklist item.
- •Set lockDuration and stalledInterval from observed p99 commit latency plus a safety margin, and re-tune quarterly as commit paths evolve.
- •Require an idempotency key on every side-effect target that accepts writes from a queue worker, keyed on the job id, and reject writes that lack the key at the target boundary.
- •Run reconciliation as a scheduled job, not as an ad-hoc script, so commit-vs-ack drift is detected within hours rather than weeks.
- •Wire the failed-listener and stalled-event listener into the same alerting pipeline as application errors, so silent requeues cannot hide behind healthy-looking completion metrics.
Safe commands and checks
grep -nE "stalled|lock duration|extend lock" <worker-log-file> | head -n 100
grep -nE "jobId|completedAt|commitTimestamp" <worker-log-file> | head -n 200
awk -F'|' '$3 ~ /stalled/ {print $1, $2, $3}' <worker-log-file>
grep -nE "lockDuration|stalledInterval|maxStalledCount" <worker-source-file>
grep -nE "moveToCompleted|removeOnComplete|extendLockTimer" <worker-source-file>
ps -o pid,etime,cmd -C <worker-process-name>
tail -n 500 <worker-log-file> | grep -E "stalled|active|waiting"