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
- What we are measuring
- Architecture and prerequisites
- Implementation
- Diagnostic scenarios and traces
- Metrics and backlog analysis
- Concurrency benchmark
- Operational limits
- References
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 (
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
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): validatesPOST /jobsrequests, enqueues job batches atomically viaaddBulk, 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, andexhausted-failure. The scenario runner also dispatches a 20-job backlog burst. - SigNoz: receives OTLP/HTTP traces at
/v1/tracesand metrics at/v1/metricson port4318.
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
Select Node.js 24.21.0 and install the locked dependencies from
package-lock.json:
nvm use
npm ci
Copy the environment template and start Redis:
cp .env.example .env
docker compose up -d redis
Note:
docker compose up -d redisstarts 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=
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>
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
Start the worker in a second terminal:
npm run start:worker
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.
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:
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.tsconstructs the OpenTelemetryNodeSDKand OTLP HTTP exporters without starting them on import. -
src/bootstrap.tspreloads telemetry through--import ./src/bootstrap.tsbefore application modules load. -
src/app.tsdefines the Express application, payload validation, and error classification so route tests can importcreateApp()without binding a network port. -
src/server.tsstarts the HTTP server, pollsrecordJobCountsMetric(), 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,
});
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
1. What a slow worker looks like (slow-worker)
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)
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)
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 insrc/telemetry/job-age.tsand exported to SigNoz Metrics Explorer. - OpenTelemetry span attribute (
bullmq.job.age_at_attempt_ms): explicitly attached to active trace spans insrc/jobs/processor.tsusingsetAttributes(). Recording the histogram does not automatically create the trace attribute; the worker processor wires both using the value returned byrecordJobAgeAtAttempt().
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,
];
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;
}
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.timestampis stamped by the producer host andjob.processedOnby 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.idandrunIdstay on trace spans. The histogram usesbullmq.queue.name,bullmq.job.attempt_type(first_attemptorretry_attempt), and allowlistedbullmq.job.name. If queue names are dynamically generated per tenant, omitbullmq.queue.namefrom 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.
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])
)
)
P95 active worker execution duration per queue:
histogram_quantile(
0.95,
sum by (le, "bullmq.queue.name") (
rate({"bullmq.job.duration.bucket"}[5m])
)
)
Omitting "bullmq.queue.name" from sum by (...) aggregates buckets
across all queues into one combined series.
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
Opening the 20-job burst trace captured with a single worker slot
(npm run start:worker:constrained) reveals the backlog staircase.
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
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_msis 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 thebullmq.queue.jobswaiting 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), andsdk.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 to503 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
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
- Source code, tests, and benchmark artifacts
- BullMQ OpenTelemetry telemetry guide
- BullMQ telemetry metrics reference
- OpenTelemetry JavaScript documentation
- OpenTelemetry Tracing API specification
- OpenTelemetry Metrics SDK specification
- SigNoz: querying metrics and histogram quantiles
- SigNoz: PromQL syntax for dotted metric names
- SigNoz Cloud ingestion guide









Top comments (0)