Tracing Celery Tasks End to End

Instrument both the producer and the worker, let the context ride in the message headers, and make the task a linked root rather than a child once the delay between queue and execution exceeds a few seconds — a task that inherits a parent it outlives by minutes produces a trace whose duration is meaningless.

Context and when it matters

A request enqueues a task and returns in 40 ms. The task runs eleven seconds later, takes four seconds, fails, retries twice with exponential backoff, and finally succeeds three minutes after the user clicked the button. Ask the trace what happened and, without deliberate instrumentation, you get either a 40 ms request with no visible consequence, or a single trace spanning three minutes in which the user’s request appears to have taken three minutes.

Neither is useful. The first hides the work entirely; the second corrupts every latency percentile the endpoint contributes to. Getting this right means being explicit about a distinction that synchronous tracing never forces you to make: the difference between what caused this work and what the user waited for.

Inheriting versus linking across a broker Two timelines. In the inherit model, the HTTP request span appears to last three minutes because the task and its retries are nested children. In the link model, the request span ends at forty milliseconds and the task is a separate root span linked back to it, with its own duration and retry spans. Same work, two very different stories about latency inherit — misleading POST /orders — reported as 3 min 04 s enqueue · 6 ms task attempt 1 (fail) …retries land here, minutes later link — honest POST /orders — 40 ms task root · own trace span link — navigable both ways Use inheritance when the task runs within a second or two; use links when the queue delay is unbounded.

Implementation

Both sides, instrumented

# Producer and worker both need this; the worker also needs the worker_process_init
# hook, because Celery forks and a provider created before the fork is not usable.
from celery.signals import worker_process_init
from opentelemetry.instrumentation.celery import CeleryInstrumentor

@worker_process_init.connect(weak=False)
def init_tracing(*args, **kwargs):
    CeleryInstrumentor().instrument()

Forgetting the fork hook is the classic Celery tracing bug: the producer emits spans, the worker emits nothing, and the configuration looks identical on both sides.

Carrying context in the message

Celery’s own instrumentation puts the context in the message headers automatically. Doing it by hand is worth understanding, because it is what you fall back to for a custom broker or a task submitted from another language:

from opentelemetry import trace
from opentelemetry.propagate import inject, extract
from opentelemetry.trace import Link, SpanKind

# Producer — attach the current context to the task's headers.
def enqueue_order_email(order_id):
    carrier = {}
    inject(carrier)                          # writes traceparent (+ baggage)
    process_order_email.apply_async(
        args=[order_id],
        headers={"otel": carrier, "enqueued_at": time.time()},
    )

# Worker — extract, then decide what to do with it.
@app.task(bind=True, max_retries=3)
def process_order_email(self, order_id):
    carrier = (self.request.headers or {}).get("otel", {})
    parent_ctx = extract(carrier)
    parent_sc = trace.get_current_span(parent_ctx).get_span_context()

    enqueued_at = (self.request.headers or {}).get("enqueued_at")
    queue_wait = time.time() - enqueued_at if enqueued_at else None

    # Long queue delay → link, not inherit. The threshold is a judgement call;
    # a few seconds is the usual boundary between "the user is waiting" and not.
    use_link = queue_wait is not None and queue_wait > 2.0
    links = [Link(parent_sc)] if (use_link and parent_sc.is_valid) else []
    ctx = None if use_link else parent_ctx

    with tracer.start_as_current_span(
            "process_order_email", context=ctx, links=links,
            kind=SpanKind.CONSUMER) as span:
        span.set_attribute("messaging.system", "rabbitmq")
        span.set_attribute("messaging.operation.name", "process")
        span.set_attribute("messaging.destination.name", self.request.delivery_info.get("routing_key", ""))
        # The measurement that explains most "the task was slow" reports.
        if queue_wait is not None:
            span.set_attribute("messaging.queue.wait_time_ms", int(queue_wait * 1000))
        span.set_attribute("celery.task.retries", self.request.retries)
        send_email(order_id)

Queue wait is the number that matters

Task duration is usually the least interesting measurement in a queue system. What users experience is end-to-end delay: enqueue to completion, of which broker wait is frequently ninety percent.

Where the time goes between enqueue and completion A stacked bar of a 79 second end-to-end task. Queue wait accounts for 11 seconds, the first execution attempt 4 seconds, retry backoff 60 seconds, and the successful attempt 4 seconds. Execution is only ten percent of the total. 79 s from enqueue to success · 8 s of it is execution queue 11 s 4 s retry backoff 60 s 4 s worker saturation attempt 1 nothing is running attempt 2 Tuning the task's own code targets 10% of the problem; adding workers or fixing the failure targets the other 90%. Record messaging.queue.wait_time_ms on every task span and the distinction is one query away. Without it, a saturated worker pool and a slow task look identical from the outside.

Retries and chains

Each retry is a separate execution and deserves its own span. Linking each attempt to the original request keeps them navigable, and celery.task.retries makes “how many attempts did this take” a query rather than a manual count.

@app.task(bind=True, max_retries=3, autoretry_for=(TransientError,),
          retry_backoff=True)
def process_order_email(self, order_id):
    span = trace.get_current_span()
    span.set_attribute("celery.task.retries", self.request.retries)
    # Mark the final attempt so alerting can distinguish "retried" from "gave up".
    span.set_attribute("celery.task.is_final_attempt",
                       self.request.retries >= self.max_retries)

For chains and groups, each task keeps its own root and links back to the task that scheduled it. That produces a navigable chain of short traces rather than one trace whose duration is the sum of every step’s queue delay — the same reasoning as span links for batch and fan-out workloads.

Verification

# From a producer trace, find the linked task trace
curl -s "http://tempo:3200/api/traces/${REQUEST_TRACE_ID}" \
  | jq -r '.batches[].scopeSpans[].spans[] | select(.links != null)
           | .links[].traceId' | sort -u

# Then confirm the task trace carries queue wait and retry count
curl -s "http://tempo:3200/api/traces/${TASK_TRACE_ID}" \
  | jq -r '.batches[].scopeSpans[].spans[].attributes[]
           | select(.key | test("queue.wait_time_ms|celery.task.retries"))'

Check three things: the producer span ends when the HTTP response was sent, the task span exists and is reachable from it, and the queue wait attribute is present on every task span.

Making the worker pool itself visible

Task-level spans explain individual executions. Most Celery incidents, though, are pool-level: every task is fine and the queue is thirty thousand deep because a slow task type is occupying every worker.

Three measurements turn that from a guess into a diagnosis. The first is queue wait, recorded per task as shown above — rising wait across all task types means the pool is saturated, while rising wait for one type means that queue’s consumers are starved specifically. The second is concurrency, recorded as an attribute on each task span: knowing that a worker was running with a concurrency of four when a task took eleven seconds distinguishes a slow task from a contended one. The third is the identity of the worker itself, so a single bad host — a node with a failing disk, a pod that never finished warming up — is visible rather than smeared across the average.

span.set_attribute("celery.worker.hostname", self.request.hostname)
span.set_attribute("celery.worker.concurrency", app.conf.worker_concurrency)
span.set_attribute("messaging.destination.name", self.request.delivery_info.get("routing_key", ""))

With those three attributes present, the routine questions become queries rather than investigations: which queue is backed up, which task type is consuming the pool, and whether the problem is one worker or all of them.

The related design decision is queue separation. A single default queue means a slow task type can starve everything else, and no amount of instrumentation fixes that — it only makes it visible faster. Separating long-running tasks onto their own queue with their own workers turns a fleet-wide symptom into a contained one, and the queue-wait attribute is what tells you when a queue has outgrown its worker allocation.

Finally, watch the result backend. Tasks that store results in Redis or a database do work after the task body returns, and if the backend is slow that time is invisible in a task span that ends too early. Instrument the result write, or accept that a portion of end-to-end latency is unaccounted for.

Celery-specific failure points provider created before fork worker emits nothing *use worker_process_init inherit across a long delay endpoint latency corrupted link instead no enqueue timestamp queue wait unmeasurable *record it in headers one span for all retries attempt detail lost span per attempt result backend uninstrumented tail latency invisible wrap the write Celery-specific failure points cause symptom fix provider created before fork worker emits nothing use worker_process_init inherit across a long delay endpoint latency corrupted link instead no enqueue timestamp queue wait unmeasurable record it in headers one span for all retries attempt detail lost span per attempt result backend uninstrumented tail latency invisible wrap the write The first row accounts for most 'Celery tracing does not work' reports.

Common pitfalls

  • No worker_process_init hook. Celery’s prefork model means instrumentation set up before the fork does not apply in the worker; producer spans appear, worker spans do not.
  • Inheriting across a long queue delay. Every endpoint that enqueues work then reports task latency as its own, destroying its percentiles.
  • Not recording enqueue time. Without it, queue wait cannot be computed and the most important number in the system is unavailable.
  • One span for all retries. The attempts have different outcomes and durations; collapsing them hides the pattern that explains the failure.
  • Ignoring the result backend. A task that writes its result to Redis or a database is doing work after the “task” span ends; instrument it or the tail of the latency is invisible.

The same reasoning applies to scheduled beat tasks: they have no producer at all, so they are always roots, and their spans need a deliberate name and a schedule attribute if they are to be distinguishable from user-triggered work.

Related

↑ Back to Handling Async Boundaries in Node.js and Python