Queues · beginner

How to verify queue visibility extension for slow jobs

Playbook for verifying that a Queues worker is correctly extending visibility (lock) for slow jobs, so that another instance cannot redeliver the same job mid-processing. Defines when extension is mandatory, what evidence proves it is happening, and how to detect duplicate work caused by stalled-job recovery.

The symptoms

  • Same job id appears twice in worker logs as completing, with timestamps separated by less than the configured lock duration
  • Job completes successfully in one worker process, yet the same job id is later picked up and reprocessed by another worker
  • Queue dashboard or metrics show a non-zero stalled counter incrementing while long-running jobs are active
  • Side effects of the job (emails, webhook calls, database writes) occur twice and downstream systems report duplicate processing for the same job id

Likely causes

  • Worker process is blocked or paused long enough that the BullMQ stalled-job interval fires before the worker has renewed its lock on the job
  • Visibility extension logic is present in worker code but is disabled by a feature flag, environment variable, or configuration default that prevents the renew call from running
  • Worker is using a vanilla Queue consumer pattern that does not call the BullMQ moveToDelayed / extend-lock mechanism, so the lock simply expires and the stalled job recovery requeues the work
  • Slow job duration regularly exceeds the configured lock duration, and the renew interval is not aligned with that lock duration, creating a window where the lock can expire before renewal

First ten minutes

  1. 01Confirm the bullmq stalled documentation page is the authority for the current contract on stalled jobs and lock renewal before drawing conclusions
  2. 02Identify the worker entry point and the exact handler that processes the slow job, and note whether the worker is registered as a Worker, a Queue consumer, or a custom polling loop
  3. 03Capture the configured lock duration, stalled-job check interval, and any visibility-extension interval from the worker configuration, in a single note alongside the observed job duration
  4. 04Inspect the worker's runtime for a stalled-counter increment, an unhandled promise rejection, or a process pause that coincides with the duplicate-completion event
  5. 05Establish a baseline: record one normal-duration job's lock-acquire and completion timestamps against the same metric for a known slow job, to compare whether extension is engaging

Evidence to collect

  • Job id, lock-acquire timestamp, observed processing duration, and completion timestamp for the duplicated job, from worker logs or queue history
  • The configured lockDuration, stalledInterval, and any delayed/renew mechanism interval from the worker startup configuration
  • The stalled-job counter or stalled event payload emitted by the queue while the slow job was running
  • Processor-side evidence of duplicate execution, including an idempotency key collision or a second downstream side effect recorded under the same job id

Where to look

  • Worker startup configuration object, where lockDuration and stalledInterval are set when the Worker instance is constructed
  • Queue event log boundary, where 'stalled', 'completed', and 'failed' events for the affected job id are emitted by the queue library
  • Processor handler boundary, where the slow work executes and where any per-job delayed/extend call would be invoked
  • Shared datastore or downstream system boundary, where the duplicate side effect is observable and attributable to the same job id

Diagnostic steps

  1. 01Compute the ratio of observed job duration to configured lockDuration for the affected job; if duration exceeds lockDuration, extension is required and any failure to extend is the leading cause
  2. 02Compare the timestamp of the 'stalled' event against the timestamp of the original 'active' event for the same job id to determine whether the lock expired before completion
  3. 03Trace the worker code path for the slow job to determine whether a renew or moveToDelayed call is wired in; absence of such a call rules out extension for jobs whose duration exceeds lockDuration
  4. 04Check the stalled event payload for the recovered job id; a recovered job with the same id running on a different worker pid is direct evidence of lock expiration rather than a queued retry
  5. 05Verify that the queue's stalled-check interval is not greater than the lock duration, since a longer interval can mask a stalled lock until it has already been requeued
  6. 06Decide between two causes: (a) the worker is not configured to extend the lock, or (b) the worker is configured to extend but the renew call is not firing due to a blocked event loop or a paused process

Common mistakes

  • Concluding that the queue is broken when the real cause is the worker exceeding the configured lockDuration without renewal, which is by design recovery behavior per the stalled jobs guide
  • Increasing lockDuration to mask the symptom without verifying that the renew or delayed mechanism is actually firing, which leaves duplicate work possible during long pauses
  • Equating a 'stalled' event with a job failure; stalled is a recovery signal, and the verification task is to confirm recovery is not needed because the lock was extended
  • Assuming the queue client renews the lock automatically on every operation; extension is an explicit step that must be present in the worker code path for slow jobs

Safe fixes

  • Conditional on evidence that duration exceeds lockDuration and no renew call exists: introduce an explicit per-job extension call in the slow processor, aligned with the queue's documented stalled recovery mechanism as the authoritative reference
  • Conditional on evidence that renew is present but not firing: identify the blocking condition (long synchronous loop, paused event loop, awaited network call without timeout) and bound the synchronous portion or move work off the critical path
  • Conditional on evidence that the same job id is being processed twice from a stale worker: ensure the worker handles the recovery case by treating the second pickup as a no-op where downstream side effects are concerned, using the job id as the idempotency key
  • Only after the above evidence is gathered: tune lockDuration and stalledInterval together so that the lock interval always exceeds the longest expected job duration and the stalled check interval is shorter than the lock duration

Prove the fix

  1. 01Run a slow job whose duration is deliberately greater than the previous lockDuration, and confirm that no 'stalled' event is emitted for that job id during processing
  2. 02Confirm that the slow job's 'completed' event is emitted exactly once and no second pickup of the same job id appears on any other worker pid during the run
  3. 03Confirm that the downstream side effect for the slow job id is recorded exactly once by the downstream system, matching the single 'completed' event
  4. 04Re-run the same scenario after a process pause exceeding the renew interval, and confirm that the renew mechanism still preserves the lock so that no duplicate processing occurs

Prevention and next steps

  • Set the worker lockDuration to a value strictly greater than the p99 observed processing duration for the slowest job class, and document the bound in the worker configuration
  • For any job expected to approach the lock boundary, write an explicit extension call in the processor and treat its absence as a code-review blocker rather than an optimization
  • Alert on the queue's stalled counter and on duplicate job id completions so that a missed extension is detected on the first occurrence rather than after downstream complaints
  • Make downstream side effects idempotent keyed by the queue job id, so that even a duplicate pickup caused by a missed extension cannot produce a duplicated external effect

Safe commands and checks

grep -nE 'lockDuration|stalledInterval' worker-startup.ts | sort
grep -nE 'moveToDelayed|extend|delay|renew' src/jobs/slow-job.ts
node -e 'process.env.NODE_ENV="inspect"; require("./dist/worker.js")' --max-old-space-size=512