How do you use distributed tracing to diagnose queueing, prefill, KV-transfer, and decode latency in LLM inference?

Distributed tracing follows one LLM inference request across services and GPU workers, recording *when each operation starts, how long it takes, and which other operations it depends on*. It helps explain why a particular user waited even when fleet-wide p95 charts look healthy. An inference trace might cross an API gateway, auth/rate limiter, tokenizer, KV-aware router, waiting queue, prefill GPU, optional KV-transfer network, decode GPU, and streaming response writer.

A metric answers “how much latency?”; a trace helps answer “which operation caused this request's latency?” This lesson continues Question 267 (Prometheus dashboards and alerts), while avoiding a repetition of Question 243 (the mechanics/trade-offs of disaggregated prefill/decode).

1. Understand the request timeline

For a typical disaggregated LLM:

1. Gateway and preprocessing: authenticate, validate input and apply chat template/tokenization.
2. Router: choose eligible prefill and decode workers, perhaps using prefix-cache locality and load.
3. Admission/queueing: wait for a compute slot, token budget and KV-cache space. Include router-side and engine-side queues separately.
4. Prefill: process input prompt tokens and construct the initial KV state. Prefill is often compute-intensive for long uncached prompts.
5. KV transfer: move computed KV blocks to a separate decode worker when disaggregated serving is enabled. This stage may include handshake, waiting, DMA and data movement.
6. Decode: iteratively generate new tokens with the evolving KV state. Track first-token production and subsequent inter-token gaps.
7. Stream delivery: flush output chunks to the gateway/client; network/proxy buffering may add delay even when GPU computation is fast.

Not every deployment has each stage. In a colocated engine, prefill and decode share the serving process/GPU and may have no inter-worker KV transfer at all. In multimodal serving, vision/audio encoding may introduce another stage.

2. Spans, traces and context propagation

• A trace is the end-to-end linked record for a logical request; a span represents an operation such as \inference.prefill\.
• Each span has a trace ID, span ID, parent relationship, start/end timestamps, status, and safe attributes such as \model.version\, prompt-token count, worker class and GPU device type.
• Use W3C Trace Context (for example, \traceparent\) for HTTP propagation and supported message/RPC headers for internal routing.
• Preserve trace context through asynchronous scheduling by attaching it to the queued request metadata and restoring the context inside the worker when work begins.
• If an operation is triggered asynchronously rather than being a nested synchronous call, use OpenTelemetry span links when parent-child structure would misrepresent causality.
• Instrument *both sides* of important RPC boundaries when possible; otherwise delays can be wrongly blamed on the destination worker.
• Keep \service.name\, model/version and region attributes consistent, without inserting raw prompts or user secrets into trace tags.

OpenTelemetry defines semantic conventions for GenAI inference operations, including latency and token usage. These conventions are evolving; prefer the instrumented library's documented stable/opt-in version and add clearly named internal stage spans when needed.

3. Beginner-friendly numerical example: one slow request

A hypothetical request has the following non-overlapping wall-clock stages, measured from a single end-to-end timeline:

• Gateway validation/tokenization: 20 ms.
• Router decision: 10 ms.
• Wait for a prefill slot: 280 ms.
• Actual prefill compute: 90 ms.
• KV transfer and handshake: 120 ms.
• Decode scheduling to first token: 30 ms.
• First-token production and delivery: 50 ms.

Total time to first delivered token (TTFT) in this simplified sequential trace:

\20 + 10 + 280 + 90 + 120 + 30 + 50 = 600 ms\.

• Prefill queue's share of TTFT = \280/600 × 100 ≈ 46.7%\.
• KV handoff's share = \120/600 × 100 = 20%\.
• Combined queue + KV handoff = \400/600 ≈ 66.7%\.

A team may incorrectly optimize attention kernels because the request is “slow on GPU.” The trace instead shows that waiting and handoff dominate first-token latency.

Now consider the output stream: if the next four token-delivery gaps are 40, 45, 110, and 45 ms, the average inter-token gap for those observations is \(40+45+110+45)/4 = 60 ms\. The 110-ms outlier warrants a decode-scheduler or network-flush investigation. The 600-ms TTFT does not include these later delivery gaps.

Important: these sums work only because the example deliberately uses non-overlapping sequential stages. Real systems overlap CPU work, GPU compute and asynchronous KV DMA. Never add all nested or overlapping span durations and call that end-to-end latency; examine the critical path, and align spans by request identity and causality.

4. Build the minimum useful trace tree

A practical shape is:

\\\text HTTP POST /v1/chat/completions (root, gateway) validate_and_tokenize route_request choose_prefill_worker choose_decode_worker inference_request prefill_wait prefill_compute kv_handoff kv_transfer_setup kv_transfer_wait kv_transfer_bytes decode_wait first_token_ready stream_tokens decode_step (sampled/aggregated) flush_to_client \\\

The exact tree varies by serving engine. For example, some systems create multiple worker/RPC spans, or implement a KV transfer overlapping the beginning of decode processing. Use span links if a single sequential parent-child tree would hide cross-worker timing.

Low-cardinality attributes: model revision, engine build, route class, prompt-length bucket, output-length bucket, streaming boolean, cache-hit bucket, region, worker class, error type, cancellation reason and sample decision. Prefer a request ID as a searchable trace identifier or log correlation value, not as a Prometheus metric label.

5. An implementation outline with OpenTelemetry

Here is minimal illustrative Python instrumentation around a serving pipeline. The imported functions represent your own engine integration; they are not built-in vLLM APIs:

\\\`python from opentelemetry import trace

tracer = trace.get_tracer("llm-serving")

async def handle_request(req): with tracer.start_as_current_span("llm.inference") as root: root.set_attribute("llm.model_revision", req.model_revision) root.set_attribute("llm.input_tokens", req.input_tokens)

with tracer.start_as_current_span("llm.route"): prefill_worker, decode_worker = await choose_workers(req)

with tracer.start_as_current_span("llm.prefill.queue"): await prefill_worker.wait_for_slot(req)

with tracer.start_as_current_span("llm.prefill.compute"): kv_handle = await prefill_worker.prefill(req)

with tracer.start_as_current_span("llm.kv_transfer"): await transfer_kv(kv_handle, decode_worker)

with tracer.start_as_current_span("llm.decode"): return await decode_worker.generate(req, kv_handle) \\\`

Production caveat: placing a Python span around an asynchronous CUDA launch may measure only enqueue time, not completed GPU execution. Add engine-provided timing or correctly synchronized GPU events where supported; synchronization itself can disturb performance. Likewise, a single \generate\ call may return a stream that completes *after* the function returns, so wrap the actual stream lifecycle, not only the initial coroutine. Propagate context across processes; in-process context alone does not create cross-node traces.

6. Trace streaming correctly

• Record request-arrival time, first model token-ready time, first chunk received by gateway, first byte/chunk observed at client, and stream finish/cancel/error time where each is observable.
• TTFT at the client may include gateway, proxy, network and flush delay; model-internal first-token timing does not.
• Record stream chunks in a bounded way. Full per-token spans on every request can overwhelm collectors and add CPU/GC overhead.
• Prefer sampled events or aggregates for token gaps, with additional detailed sampling only for anomalous requests.
• For HTTP server-sent events, ensure proxies do not buffer output unintentionally.
• Mark midstream cancellation and terminal status accurately; a response that started returning tokens but then disconnected is not a successful complete request.

7. Diagnose specific bottlenecks from trace shapes

• Large prefill queue span: too many long prompts, unfair scheduling, inadequate ready prefill capacity, token-budget limits or KV pressure. Check offered token-work rate and pending work.
• Long prefill compute span with small queue: prompt-length or cache-miss increase, an attention/kernel regression, GPU contention or an unexpected model/config change.
• Long KV transfer setup/wait: slow handshake, insufficient receive buffers, destination decode queue, backpressure or unavailable KV blocks.
• Long KV byte-transfer span: bandwidth saturation, network topology problems, GPU-direct transport fallback, retransmissions or too much uncompressed KV data.
• Long decode wait/steps: high active sequence count, KV pressure/preemption, poor batch scheduling, attention bandwidth or tensor-parallel communication.
• Fast engine but slow first client chunk: gateway buffering, TLS/network, overloaded reverse proxy or output serialization.
• One worker disproportionately slow: uneven routing, bad GPU/node health, co-tenancy, different build/version or faulty storage/network path.

Correlate the trace with Prometheus queue, KV occupancy, preemption, request rate and network/GPU telemetry. A span can show where the delay occurred, but causal attribution may still require a controlled experiment.

8. Tail sampling and overhead

• Head sampling: choose whether to trace near request entry; low overhead, but may miss rare slow requests.
• Tail sampling: keep traces after observing outcome/latency; excellent for rare slow, error or timeout cases, but needs memory, buffering and consistent routing through collectors.
• Consider policies to retain errors, timeouts, slow TTFT, long KV transfers, and a representative healthy baseline sample.
• Preserve enough examples for long-context or low-volume tenant classes without storing identifying text.
• Export tracing asynchronously with bounded buffers and backpressure; never let the collector outage block inference.
• Use trace-to-metrics exemplars when available so an engineer can jump from a p99 histogram observation to a representative slow trace.
• Check for clock skew across nodes. Compare durations from individual monotonic clocks and use synchronization for cross-host alignment; raw wall timestamps can produce misleading gaps.

9. Production incident: TTFT spikes despite healthy GPU utilization

Incident: A 70B disaggregated model receives long RAG requests. Users report p95 TTFT growing from 650 ms to 1.8 seconds, but prefill GPU utilization and kernel timings appear normal.

Debugging:

1. A slow trace shows 200 ms prefill compute, 150 ms admission wait, but 1.1 seconds in KV handoff.
2. Child spans reveal the majority of KV handoff delay is waiting for a decode destination to accept cache blocks, not actual network byte transfer.
3. Decode worker metrics show high KV occupancy, pending requests and repeated preemptions; the router sends traffic disproportionately to one group.
4. Compare cache transfer metrics and worker pool versions to rule out a network problem before increasing link bandwidth.

Root cause: Decode-side KV capacity/backpressure causes a handoff bottleneck, even though prefill GPUs remain busy and look healthy.

Engineering fix: rebalance compatible decode workers, tune admission/concurrency to KV capacity, scale decode capacity if needed and avoid routing to saturated workers. Verify that any disaggregated KV state remains correctly owned/isolated during retries or cancellations.

Prevention: instrument handoff wait separately from bytes-on-wire transfer, alert on KV occupancy *with* rising queue/TTFT, and replay mixed long-prompt burst traffic before rollout.

This scenario is illustrative, not a claim about an actual production incident.

10. Privacy, security and common mistakes

• Do not store raw prompts, outputs, retrieved private documents, authorization tokens, user IDs or full tool arguments in traces by default. Use explicit privacy review, appropriate redaction, access controls and short retention for any exceptional content capture.
• Keep trace context untrusted at public ingress: do not use client-provided baggage or trace IDs for authorization or cost attribution; sanitize them and apply sampling/rate limits to prevent telemetry abuse.
• Distinguish model token-ready from user-observed first token, as proxies and network add latency.
• Never blindly add nested spans or sum overlapping KV DMA and decode time.
• Don't use total request duration for requests that are still streaming or omit rejected/cancelled ones from operational reporting.
• Confirm vLLM/Dynamo/OTel version-specific instrumentation rather than assuming all stage spans exist automatically.
• Keep a controlled no-tracing benchmark: profiling and excessively detailed traces can change scheduling and tail latency.

11. Interview-ready answer

“I'd propagate OpenTelemetry context from the ingress through router, queues, prefill workers, KV handoff, decode workers and streaming response. I'd record queue wait, compute, KV-transfer setup versus bytes-on-wire, first-token-ready and client-visible TTFT as separate operations. For slow requests I'd inspect the critical path and correlate spans with KV occupancy, queue and network metrics, then validate with a controlled load test. I'd use bounded sampling and privacy-safe attributes, and avoid assuming GPU launch spans represent completed execution.”

References:

• NVIDIA Dynamo — Request Flow and Architecture
• NVIDIA Dynamo — Disaggregated Serving
• OpenTelemetry — Trace Semantic Conventions
• OpenTelemetry — GenAI Client Inference Conventions
• OpenTelemetry — Context Propagation