DEV Community

Cover image for Diagnosing BullMQ Jobs with OpenTelemetry and SigNoz
Hunter
Hunter

Posted on AI-assisted

Diagnosing BullMQ Jobs with OpenTelemetry and SigNoz

Imagine a user clicks "Generate Invoice" in your application. Your
Express API validates the request, pushes a job into Redis, and responds
in under 10 milliseconds with 202 Accepted.

In reality, the user waits two full seconds for the invoice to finish,
or longer during traffic spikes. When users report the delay, you check
your observability dashboard expecting to find a slow database query or
a bogged-down worker. Instead, every chart looks healthy. The API
responds in a few milliseconds, and the worker reports that every job
finishes in 100 milliseconds.

If the API takes 6 milliseconds and the worker takes 100 milliseconds,
where did the other 1,900 milliseconds go?

Most of that time passed before the worker ever started the job. When a
burst of jobs arrives and worker concurrency is saturated, jobs sit in
Redis waiting for an available worker slot. Retries and exponential
backoff delays add another layer of waiting. Standard job duration
metrics only start measuring when a worker picks up a job, which leaves
pre-execution waiting invisible.

In this guide, we will instrument a Node.js and TypeScript BullMQ
pipeline with OpenTelemetry and SigNoz. We will inspect what generic
Node.js auto-instrumentation misses, enable BullMQ's bullmq-otel
integration to trace retries across services, build a bounded
job_age_at_attempt_ms histogram alongside a
bullmq.job.age_at_attempt_ms span attribute, and run a 10-trial
concurrency benchmark to separate slow worker code from queue waiting
time.

The complete source code, 50-test suite, OTLP export smoke test, and
benchmark CSV artifacts are available in the GitHub
repository
.

In this article

GitHub logo Hunter-debug00 / otel-bullmq-signoz-tracing

Why a 100 ms BullMQ job still feels slow: measure enqueue-to-attempt age vs. worker runtime using OpenTelemetry, distributed traces, histograms, and a reproducible concurrency benchmark.

BullMQ Distributed Tracing & Job Age Telemetry with SigNoz

In asynchronous queues, a worker pool can appear healthy while jobs sit waiting in Redis for seconds. The standard bullmq.job.duration metric only starts when a worker begins executing the job handler, so it completely misses queue waiting time.

This repository demonstrates how to instrument BullMQ with OpenTelemetry and export signals to SigNoz over OTLP/HTTP. It adds a custom histogram, job_age_at_attempt_ms, to measure the elapsed time from job enqueue to the start of each attempt. Two services (order-api and order-worker) propagate distributed W3C trace contexts so producer HTTP requests and worker job executions appear in a single trace waterfall.


What the Benchmark Shows

The included experiment runs 20 jobs of 100 ms simulated work across two conditions: baseline concurrency ($c=5$) and constrained concurrency ($c=1$). Each condition ran 5 trials on a 2-CPU Linux host using…

What we are measuring (and why these tools fit together)

To separate slow worker execution from pre-execution waiting, we need
two distinct measurements:

  • Worker execution duration (bullmq.job.duration): how long the worker handler spends executing an attempt once picked up.
  • Enqueue-to-attempt age (job_age_at_attempt_ms): elapsed wall-clock time from when the job was originally created (job.timestamp) until the current processing attempt starts (job.processedOn).

For a first attempt on a job that is eligible to run immediately,
enqueue-to-attempt age reflects initial queue wait time. It is not pure
Redis queue wait in every scenario. If a job is scheduled with an
intentional delay, that delay is part of the elapsed time. If a job is
on a retry attempt, its age measures cumulative elapsed time since
initial creation, including earlier attempts, prior queue waits, and
retry backoff.

Three open-source tools form our diagnostic stack:

  • BullMQ: offloads background work such as PDF generation or webhook delivery into Redis with built-in retries, exponential backoff, and concurrency controls.
  • OpenTelemetry: provides a vendor-neutral SDK and protocol (OTLP) so traces and histograms are exported from one standard instrumentation layer.
  • SigNoz: ingests OTLP traces and histograms into a unified backend, letting us correlate histogram quantiles with distributed trace waterfalls in the same interface.

Architecture and runtime specifications

architecture diagram showing the Express API, Redis, BullMQ workers, and SigNoz OTLP exports

Figure 1. The Express API enqueues jobs in Redis, BullMQ workers process them, and OpenTelemetry exports traces and metrics to SigNoz over OTLP/HTTP.

The application is intentionally compact so the measurement problem is
easy to reproduce. It runs four components:

  • order-api (src/app.ts, src/server.ts): validates POST /jobs requests, enqueues job batches atomically via addBulk, and polls queue state counts every five seconds.
  • Redis (redis:7.4-alpine): stores the BullMQ queue and serialized W3C trace context.
  • order-worker (src/worker.ts, src/jobs/processor.ts): processes jobs across four core scenarios: success, slow-worker, transient-retry, and exhausted-failure. The scenario runner also dispatches a 20-job backlog burst.
  • SigNoz: receives OTLP/HTTP traces at /v1/traces and metrics at /v1/metrics on port 4318.

Tested environment and prerequisites

The benchmark data and telemetry captures should be interpreted
alongside the locked dependency versions in
results/sample-manifest.json.

Component Tested version Notes
Node.js 24.21.0 (.nvmrc) Benchmark tested on a 2-vCPU Linux environment with 8 GB RAM.
BullMQ and Redis client bullmq 6.3.15, bullmq-otel 2.0.1, ioredis 6.0.0 Installed reproducibly with npm ci.
OpenTelemetry SDK @opentelemetry/sdk-node 0.223.0 Includes @opentelemetry/resources 2.12.0.
Redis container redis:7.4-alpine Started with Docker Compose on port 6379.
SigNoz backend SigNoz Cloud or local SigNoz A self-hosted installation needs sufficient Docker memory; use SigNoz Cloud on smaller environments.

Implementation

Step 1: Clone the repository and start the services

Clone the repository and move into the project directory:

git clone https://github.com/Hunter-debug00/otel-bullmq-signoz-tracing.git
cd otel-bullmq-signoz-tracing
Enter fullscreen mode Exit fullscreen mode

Select Node.js 24.21.0 and install the locked dependencies from
package-lock.json:

nvm use
npm ci
Enter fullscreen mode Exit fullscreen mode

Copy the environment template and start Redis:

cp .env.example .env
docker compose up -d redis
Enter fullscreen mode Exit fullscreen mode

Note: docker compose up -d redis starts Redis only; it does not
deploy a full local SigNoz stack. Run a separate local SigNoz
installation
or configure
SigNoz Cloud.

Open .env to verify the OTLP endpoint settings. By default, it points
to a local SigNoz receiver on port 4318:

PORT=3000
HOST=127.0.0.1
REDIS_URL=redis://localhost:6379
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318
OTEL_EXPORTER_OTLP_HEADERS=
Enter fullscreen mode Exit fullscreen mode

The application's exporters append /v1/traces and /v1/metrics to
OTEL_EXPORTER_OTLP_ENDPOINT, so do not append /v1/traces in .env.
For SigNoz Cloud, use your regional ingestion URL and the
signoz-ingestion-key header (see the SigNoz Cloud ingestion
guide
):

OTEL_EXPORTER_OTLP_ENDPOINT=https://ingest.<region>.signoz.cloud:443
OTEL_EXPORTER_OTLP_HEADERS=signoz-ingestion-key=<your-signoz-ingestion-key>
Enter fullscreen mode Exit fullscreen mode

Keep the real SigNoz ingestion key in your local .env file; do not commit it or include it in screenshots.

Start the API in one terminal:

npm run start:api
Enter fullscreen mode Exit fullscreen mode

Start the worker in a second terminal:

npm run start:worker
Enter fullscreen mode Exit fullscreen mode

The npm scripts set OTEL_SERVICE_NAME (order-api and order-worker)
and configure worker concurrency. The explicit script setting takes
precedence over .env where applicable.

Step 2: The trap of relying on generic auto-instrumentation alone

A common mistake when adding OpenTelemetry to a Node.js service is
enabling only @opentelemetry/auto-instrumentations-node. The
historical baseline captures below were recorded before bullmq-otel
and job-level metrics were wired into the worker.

baseline SigNoz service table showing low-level worker operations before BullMQ job instrumentation

Figure 2. In the baseline run before job-level instrumentation, the service table reports fast low-level operations (34.65 ms P99 on order-worker) and misses the BullMQ job lifecycle.

Opening a worker trace from that baseline run shows what generic
auto-instrumentation actually captures:

baseline worker trace showing Redis evalsha and moveStalledJobsToWait spans without a BullMQ job-attempt span

Figure 3. Baseline trace showing a 1.21 ms Redis evalsha span and moveStalledJobsToWait spans, with no parent HTTP link or job-attempt span.

Generic auto-instrumentation wraps low-level HTTP, Express, and ioredis
calls. It sees the fast Redis Lua scripts that poll the queue, but it
has no concept of BullMQ job attempts, retry backoffs, or enqueue
timestamps.

Step 3: Initialize OpenTelemetry and enable bullmq-otel

To keep unit tests fast and free of import-time side effects, the
repository separates telemetry SDK construction from process startup:

  • src/instrumentation.ts constructs the OpenTelemetry NodeSDK and OTLP HTTP exporters without starting them on import.
  • src/bootstrap.ts preloads telemetry through --import ./src/bootstrap.ts before application modules load.
  • src/app.ts defines the Express application, payload validation, and error classification so route tests can import createApp() without binding a network port.
  • src/server.ts starts the HTTP server, polls recordJobCountsMetric(), and handles graceful shutdown.

The SDK factory in src/instrumentation.ts normalizes the OTLP base URL
and wires both exporters. The following excerpt reflects the current
repository's service-name fallback and exporter configuration:

const serviceName =
  options.serviceName ?? process.env.OTEL_SERVICE_NAME ?? 'bullmq-diagnostics';
const baseUrl = normalizeOtlpBaseUrl(
  options.otlpEndpoint ?? process.env.OTEL_EXPORTER_OTLP_ENDPOINT
);
const headers =
  options.otlpHeaders ?? parseOtlpHeaders(process.env.OTEL_EXPORTER_OTLP_HEADERS);
const timeoutMillis =
  options.timeoutMillis ??
  (process.env.OTEL_EXPORTER_OTLP_TIMEOUT
    ? Number(process.env.OTEL_EXPORTER_OTLP_TIMEOUT)
    : 5000);

const traceExporter = new OTLPTraceExporter({
  url: `${baseUrl}/v1/traces`,
  headers,
  timeoutMillis,
});

const metricExporter = new OTLPMetricExporter({
  url: `${baseUrl}/v1/metrics`,
  headers,
  timeoutMillis,
});
Enter fullscreen mode Exit fullscreen mode

One configuration detail in createTelemetrySdk avoids a subtle trap.
In @opentelemetry/sdk-node 0.223.0, supplying a spanProcessors array
takes precedence over the top-level traceExporter option. If you
configure an InMemorySpanExporter in spanProcessors and leave it in
the production configuration, metrics can still reach SigNoz through
metricReader while traces are captured only in memory. Production
startup omits this test-only override; tests/otlp-export.smoke.test.ts
verifies real OTLP delivery to an ephemeral HTTP server.

The queue module wires BullMQOtel into both the producer queue and the
worker. When order-api enqueues jobs with addBulk(), bullmq-otel
injects the active W3C trace context into job metadata in Redis. When
order-worker processes the job, it extracts that context so worker
attempts appear in the originating POST /jobs trace.

Step 4: Run the diagnostic scenarios and inspect the traces

The scenario runner sends four core scenarios, waits for retry and
slow-worker work to finish, and then dispatches a backlog burst:

Scenario Behavior
success Standard 50 ms job completing on attempt 1 in the scenario runner.
slow-worker Simulated handler work of approximately 2,000 ms.
transient-retry Fails on attempt 1, waits through exponential backoff (1,500 ms base delay), and succeeds on attempt 2.
exhausted-failure Fails all three configured attempts across exponential backoff delays.
Backlog burst Enqueues 20 jobs with 100 ms of simulated work each to expose queue backlog.

With order-api and order-worker running, trigger the scenarios from
a third terminal:

npm run scenarios
Enter fullscreen mode Exit fullscreen mode

1. What a slow worker looks like (slow-worker)

slow-worker trace comparing a 2-second worker span with 6 milliseconds of enqueue-to-attempt age

Figure 4. The selected worker span (execute_scenario.slow-worker) lasts 2.00 seconds while bullmq.job.age_at_attempt_ms is 6 ms. In this single diagnostic capture, the job started almost immediately and the delay was inside the worker handler.

Because the job waited only 6 ms before processing began, scaling worker
concurrency would not speed up this operation; inspect the code or
downstream service inside the worker. This capture represents a single
trace observation, not a statistical estimate of production P99 latency.

2. What a transient retry looks like (transient-retry)

transient-retry trace showing the HTTP request, failed first attempt, backoff, and successful second attempt

Figure 5. The HTTP request returns 202 Accepted quickly. The asynchronous trace continues through a failed first attempt, a retry delay, and a 50.38 ms second attempt across a 1.67-second trace horizon.

A common misreading is assuming the Express HTTP handler stayed open for
1.67 seconds. In fact, the root HTTP span ends as soon as 202 Accepted
is returned. The trace can still span the later worker activity because
the BullMQ consumer spans are represented as children in the trace.

3. What an exhausted failure looks like (exhausted-failure)

exhausted-failure trace showing three failed attempts and retry backoff

Figure 6. All three configured attempts fail (one initial attempt and two retries). The final attempt (bullmq.job.attempt_number: 3) lasts 49.89 ms, while the full trace spans 3.27 seconds including earlier attempts and backoff.

Selecting the third attempt shows the exception, a 49.89 ms handler
duration, and a cumulative bullmq.job.age_at_attempt_ms of 3,209 ms.

Step 5: Build the job_age_at_attempt_ms histogram and span attribute

To measure enqueue-to-attempt age in both the metrics pipeline and
individual traces, the code records two distinct telemetry signals:

  • OpenTelemetry histogram metric (job_age_at_attempt_ms): defined in src/telemetry/job-age.ts and exported to SigNoz Metrics Explorer.
  • OpenTelemetry span attribute (bullmq.job.age_at_attempt_ms): explicitly attached to active trace spans in src/jobs/processor.ts using setAttributes(). Recording the histogram does not automatically create the trace attribute; the worker processor wires both using the value returned by recordJobAgeAtAttempt().

The metric uses explicit bucket boundaries:

export const JOB_AGE_BUCKET_BOUNDARIES = [
  5, 10, 25, 50, 100, 150, 250, 500, 750, 1000, 1500, 2000, 3000, 5000, 10000,
];
Enter fullscreen mode Exit fullscreen mode

The calculation helper rejects invalid or non-positive timestamps and
returns null rather than manufacturing an age value:

export function calculateEnqueueToAttemptAgeMs(
  enqueueTimestamp: number,
  processedOnTimestamp: number | undefined
): number | null {
  if (
    typeof enqueueTimestamp !== 'number' ||
    !Number.isFinite(enqueueTimestamp) ||
    enqueueTimestamp <= 0
  ) {
    return null;
  }
  if (
    processedOnTimestamp === undefined ||
    typeof processedOnTimestamp !== 'number' ||
    !Number.isFinite(processedOnTimestamp) ||
    processedOnTimestamp <= 0
  ) {
    return null;
  }
  const diff = processedOnTimestamp - enqueueTimestamp;
  if (diff < 0) {
    warnRateLimited(
      'negative_clock_skew',
      `Negative clock skew detected: processedOn (${processedOnTimestamp}) < enqueueTimestamp (${enqueueTimestamp}). Skipping metric recording.`
    );
    return null;
  }
  return diff;
}
Enter fullscreen mode Exit fullscreen mode

recordJobAgeAtAttempt() separately classifies invalid enqueue
timestamps and missing or invalid processing timestamps before calling
the helper. A genuine negative delta is classified as
negative_clock_skew; invalid observations are skipped rather than
clamped to zero. Warnings are rate-limited to once per reason per
minute.

Key design safeguards and limitations

  • Clock-skew directionality: job.timestamp is stamped by the producer host and job.processedOn by the worker host. A worker clock that lags behind the producer can produce a negative delta, which is dropped. If the worker clock is ahead, the age can be artificially high while still positive. Synchronized host clocks remain essential.
  • Bounded metric cardinality: high-cardinality identifiers such as job.id and runId stay on trace spans. The histogram uses bullmq.queue.name, bullmq.job.attempt_type (first_attempt or retry_attempt), and allowlisted bullmq.job.name. If queue names are dynamically generated per tenant, omit bullmq.queue.name from metric attributes.
  • Explicit bucket boundaries: OpenTelemetry's default histogram buckets jump from 100 to 250 ms. In the tested workload, 100 ms timers completed around 100.3 to 101.6 ms, which places observations above the 100 ms boundary. The custom boundaries provide finer resolution for sub-10-second ages.

Step 6: Compare both histograms and inspect the backlog in SigNoz

Visual query builder

Open Metrics → Explorer in SigNoz to compare enqueue-to-attempt age
with active worker duration. Select job_age_at_attempt_ms for Query A
and bullmq.job.duration for Query B, choose P95, and group by
bullmq.queue.name.

SigNoz visual query builder with enqueue-to-attempt age and worker duration queries grouped by queue

Figure 7. Query A (job_age_at_attempt_ms) and Query B (bullmq.job.duration) configured for P95 and grouped by queue name in the visual query builder.

Raw PromQL in a dashboard panel

For raw PromQL, open Dashboards, create or edit a panel, and select
the PromQL editor. SigNoz uses quoted metric and label names for dotted
names.

P95 enqueue-to-attempt age per queue:

histogram_quantile(
  0.95,
  sum by (le, "bullmq.queue.name") (
    rate({"job_age_at_attempt_ms.bucket"}[5m])
  )
)
Enter fullscreen mode Exit fullscreen mode

P95 active worker execution duration per queue:

histogram_quantile(
  0.95,
  sum by (le, "bullmq.queue.name") (
    rate({"bullmq.job.duration.bucket"}[5m])
  )
)
Enter fullscreen mode Exit fullscreen mode

Omitting "bullmq.queue.name" from sum by (...) aggregates buckets
across all queues into one combined series.

SigNoz P95 comparison showing enqueue-to-attempt age and worker execution duration

Figure 8. In the interactive diagnostic run, P95 enqueue-to-attempt age reaches 2.93 seconds while P95 worker execution duration is 248.5 ms. These observations come from the mixed scenario run, separate from the controlled benchmark.

SigNoz estimates histogram percentiles via bucket interpolation across
aggregated bucket counts. This differs from exact nearest-rank
percentiles calculated over discrete per-job observations.

Inspecting a single backlog job in Trace Explorer

To jump from a metric spike to the underlying traces, open Traces
Explorer
and filter by the span attribute:

service.name = 'order-worker' AND bullmq.job.age_at_attempt_ms > 500
Enter fullscreen mode Exit fullscreen mode

Opening the 20-job burst trace captured with a single worker slot
(npm run start:worker:constrained) reveals the backlog staircase.

single-worker backlog trace showing the twentieth job waiting before execution

Figure 9. In this interactive burst trace (2.06-second horizon), the selected twentieth job executes in 100.5 ms after an enqueue-to-attempt age of 1,957 ms.

The selected span finishes in 100.5 ms, while its
bullmq.job.age_at_attempt_ms attribute is 1,957 ms. Because the single
worker processes jobs sequentially, the twentieth job waits behind the
first 19 jobs before starting.

Step 7: Reproduce the 10-trial controlled concurrency benchmark

To evaluate concurrency saturation in an isolated experiment without
retry noise or histogram bucket interpolation, run:

npm run experiment
Enter fullscreen mode Exit fullscreen mode

The script runs five trials at concurrency 5 and five at concurrency
1, alternating trial order so neither condition always runs on a cold
process. Each trial creates a dedicated queue, pauses the worker,
enqueues 20 jobs with 100 ms simulated work in one addBulk() call,
resumes processing for a synchronized burst, validates that returned
ages are finite and non-negative, and cleans up Redis resources.

The run writes three artifacts to results/ and overwrites the
committed samples:

  • results/sample-trial-summary.csv: per-trial P50 and P95 summaries across all 10 trials.
  • results/sample-job-observations.csv: all 200 individual job observations.
  • results/sample-manifest.json: runtime specifications, locked package versions, workload settings, and the nearest-rank percentile formula.

If you want to restore the committed sample dataset after running the
experiment, use git checkout results/.

Benchmark results

The table reports mean batch-enqueue latency across the five trials and
the median of the five per-trial nearest-rank percentiles (rather than
pooling all 100 observations together):

Measurement Concurrency 5 Concurrency 1
Mean enqueue-batch latency (20 jobs) 6.53 ms 3.93 ms
Processor elapsed P50 (median of 5 trials) 100.6 ms 100.3 ms
Processor elapsed P95 (median of 5 trials) 101.6 ms 100.9 ms
Enqueue-to-attempt age P50 (median of 5 trials) 118 ms 923 ms
Enqueue-to-attempt age P95 (median of 5 trials) 328 ms 1,844 ms

At concurrency 5, 20 jobs of 100 ms complete in four waves of five. At
concurrency 1, the twentieth job waits behind the first 19
jobs (approximately 1.9 seconds under idealized sequential processing), while the full batch takes approximately 2 seconds to
drain. The median per-trial P95 processor elapsed time stays near 101 ms
in both conditions, while the median per-trial P95 enqueue-to-attempt
age rises from 328 ms to 1,844 ms (about 5.6 times higher in this
workload).

The benchmark's processor_elapsed_ms values come from a local
performance.now() timer inside processDiagnosticJob(). They are not
calculated from the exported bullmq.job.duration histogram, which is
the separate metric examined in SigNoz.

This 5.6× ratio is a measurement of this specific 20-job, 100 ms burst
workload on a single worker process, not a general constant that will
hold across arbitrary production traffic. Production queue latency
varies with arrival rate, job duration variance, scheduling delays,
retries, and worker fleet size. What the experiment shows is that
plotting job_age_at_attempt_ms alongside bullmq.job.duration helps
separate queue waiting from handler execution time.

Screenshot chronology: the screenshots are representative captures from separate diagnostic runs. Baseline captures predate job-level instrumentation, while interactive trace and Metrics Explorer captures are separate from the automated 10-trial CSV benchmark.

Operational limits and production diagnostic guide

Keep three operational details in mind when running this instrumentation
in production:

  • Idle or dead workers emit no job-age samples: because job_age_at_attempt_ms is recorded only when a worker starts an attempt, a queue whose workers have all crashed will stop emitting histogram observations. Pair alerts on job age with an alert on the bullmq.queue.jobs waiting gauge.
  • Collector timeouts on shutdown: when the OTLP collector is unreachable, the API and worker can continue processing jobs while telemetry export fails. Exporter requests time out according to OTEL_EXPORTER_OTLP_TIMEOUT (default 5,000 ms), and sdk.shutdown() waits for in-flight requests. Configure container termination grace periods accordingly.
  • API hardening: the demo API enforces a 16 KB payload limit (413 Payload Too Large), rejects malformed input (400 Bad Request), and maps Redis connection errors to 503 Service Unavailable. It includes no authentication or rate limiting and should not be exposed directly to the public internet.

Use this diagnostic matrix when triaging latency in SigNoz:

bullmq.job.duration job_age_at_attempt_ms (first attempt) job_age_at_attempt_ms (retry attempt) Likely cause and next step
High Low Low Slow worker handler or downstream call: jobs start immediately, but active execution is slow. Inspect child spans inside the worker trace.
Low High Low Queue backlog or scheduled delay: handler execution is fast, but jobs wait before starting. Check waiting counts and increase concurrency or worker instances if appropriate.
Low Low High Retry and backoff accumulation: failures and backoff inflate age on retry attempts. Filter Trace Explorer by service.name = 'order-worker' AND has_error = true.

Run the TypeScript check, 50-test suite, and build locally with Redis
running:

npm run typecheck
npm test
npm run build
Enter fullscreen mode Exit fullscreen mode

The GitHub Actions
workflow

provides the latest CI result.

Conclusion

You have instrumented a BullMQ pipeline with OpenTelemetry to compare enqueue-to-attempt age with active worker execution time. The controlled benchmark shows why both measurements matter: under this 20-job workload, median per-trial P95 enqueue-to-attempt age rose from 328 ms at concurrency 5 to 1,844 ms at concurrency 1, while processor elapsed P95 stayed near 101 ms.

For a production rollout, start in staging, keep producer and worker clocks synchronized, and pair job-age observations with queue-waiting and worker-health alerts. Then use the traces to decide whether the bottleneck is handler execution, queue backlog, or retry backoff before changing concurrency. The SigNoz query and ingestion references below provide the next steps for adapting the dashboards to your environment.

References

Top comments (0)