Distributed Tracing

When P99 TTFT spikes from 1.5s to 8s, metrics tell you something is slow. Distributed tracing tells you exactly where: was it the gateway auth check (5ms), the scheduler queue (3s wait), the prefill (2s), or a slow KV cache transfer? Tracing follows a single request through every component, creating a waterfall timeline.

---

1. Trace Structure for LLM Serving

[Trace: req-abc123] ─────────────────────────────────────────────── 4,250ms total
│
├─ [Gateway] ──────────────────── 15ms
│   ├─ auth_check                  3ms
│   ├─ rate_limit_check            2ms
│   └─ route_selection             5ms
│
├─ [Queue Wait] ───────────────── 1,200ms  ← bottleneck!
│   └─ scheduler_queue_wait     1,200ms
│
├─ [Prefill] ──────────────────── 800ms
│   ├─ kv_cache_prefix_lookup     10ms (hit: 2000/3000 tokens cached)
│   ├─ prefill_compute            780ms (1000 new tokens)
│   └─ kv_cache_store              10ms
│
├─ [Decode] ───────────────────── 2,200ms (110 tokens × 20ms/token)
│   ├─ decode_iteration ×110      20ms avg per token
│   └─ sampling                    <1ms per token
│
└─ [Response] ─────────────────── 35ms
    ├─ detokenize                  5ms
    └─ stream_to_client           30ms

The 1,200ms queue wait is the problem — the scheduler had too many active requests. Without tracing, you’d only see the 4.25s total latency.

---

2. OpenTelemetry Instrumentation

Gateway Spans

from opentelemetry import trace
from opentelemetry.trace import SpanKind

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

@app.post("/v1/chat/completions")
async def chat_completions(request: Request):
    with tracer.start_as_current_span("gateway.request", kind=SpanKind.SERVER) as span:
        # Add request attributes
        span.set_attribute("llm.model", request.model)
        span.set_attribute("llm.input_tokens", count_tokens(request.messages))
        span.set_attribute("llm.max_tokens", request.max_tokens or 4096)
        span.set_attribute("tenant.id", request.tenant_id)
        
        # Auth
        with tracer.start_as_current_span("gateway.auth"):
            tenant = await authenticate(request)
        
        # Rate limiting
        with tracer.start_as_current_span("gateway.rate_limit"):
            await check_rate_limit(tenant)
        
        # Route selection
        with tracer.start_as_current_span("gateway.route") as route_span:
            backend = await select_backend(request)
            route_span.set_attribute("backend.instance", backend.id)
            route_span.set_attribute("backend.queue_depth", backend.queue_depth)
        
        # Forward to inference engine (propagates trace context)
        with tracer.start_as_current_span("gateway.proxy", kind=SpanKind.CLIENT):
            response = await backend.forward(request)
            span.set_attribute("llm.output_tokens", response.output_tokens)
            span.set_attribute("llm.ttft_ms", response.ttft_ms)
        
        return response

Inference Engine Spans

# Inside vLLM/SGLang — instrument the scheduler and model runner
tracer = trace.get_tracer("llm-engine")

class InstrumentedScheduler:
    async def schedule(self, request):
        with tracer.start_as_current_span("engine.queue_wait") as span:
            queued_at = time.monotonic()
            slot = await self.wait_for_slot(request)
            wait_ms = (time.monotonic() - queued_at) * 1000
            span.set_attribute("queue.wait_ms", wait_ms)
            span.set_attribute("queue.depth_at_arrival", self.queue_depth)
        
        with tracer.start_as_current_span("engine.prefill") as span:
            span.set_attribute("prefill.tokens", request.prompt_tokens)
            span.set_attribute("prefill.prefix_cache_hit", prefix_hit_tokens)
            span.set_attribute("prefill.new_tokens", request.prompt_tokens - prefix_hit_tokens)
            result = await self.run_prefill(request)
        
        return result

Trace Context Propagation

Pass trace context between services via HTTP headers:

# Inject trace context into outgoing request
from opentelemetry.propagate import inject

headers = {}
inject(headers)  # Adds traceparent header
response = await httpx.post(backend_url, headers=headers, json=request)

# Extract trace context in receiving service
from opentelemetry.propagate import extract

@app.post("/v1/generate")
async def generate(request: Request):
    context = extract(request.headers)
    with tracer.start_as_current_span("engine.generate", context=context):
        ...

---

3. LLM-Specific Trace Attributes

Standard web tracing attributes don’t capture LLM-specific information:

# Semantic conventions for LLM traces
LLM_TRACE_ATTRIBUTES = {
    # Request
    "llm.model": "meta-llama/Llama-3.1-70B",
    "llm.input_tokens": 3500,
    "llm.max_tokens": 4096,
    "llm.temperature": 0.7,
    "llm.quantization": "int4",
    "llm.tensor_parallel_size": 4,
    
    # Scheduling
    "scheduler.queue_depth": 15,
    "scheduler.queue_wait_ms": 1200,
    "scheduler.batch_size": 32,
    
    # Prefill
    "prefill.tokens": 3500,
    "prefill.prefix_cache_hit_tokens": 2000,
    "prefill.compute_ms": 780,
    
    # Decode
    "decode.tokens": 110,
    "decode.avg_tpot_ms": 20,
    "decode.total_ms": 2200,
    
    # Result
    "llm.output_tokens": 110,
    "llm.ttft_ms": 2015,
    "llm.total_ms": 4250,
    "llm.finish_reason": "stop",
}

---

4. Collection & Visualization

# OpenTelemetry Collector configuration
receivers:
  otlp:
    protocols:
      grpc:
        endpoint: "0.0.0.0:4317"
      http:
        endpoint: "0.0.0.0:4318"

processors:
  batch:
    send_batch_size: 1024
    timeout: 5s

exporters:
  jaeger:
    endpoint: "jaeger:14250"
  
  # Also export to analytics for LLM-specific analysis
  clickhouse:
    endpoint: "clickhouse:9000"
    database: "llm_traces"

service:
  pipelines:
    traces:
      receivers: [otlp]
      processors: [batch]
      exporters: [jaeger, clickhouse]

Useful Queries

-- Find requests where queue wait > 50% of total latency
SELECT 
    trace_id,
    queue_wait_ms,
    total_ms,
    queue_wait_ms::float / total_ms AS queue_pct
FROM llm_traces
WHERE queue_wait_ms::float / total_ms > 0.5
ORDER BY total_ms DESC
LIMIT 20;

-- Average TTFT breakdown by component
SELECT 
    date_trunc('hour', timestamp) AS hour,
    avg(auth_ms) AS avg_auth,
    avg(queue_wait_ms) AS avg_queue,
    avg(prefill_ms) AS avg_prefill,
    percentile_cont(0.99) WITHIN GROUP (ORDER BY queue_wait_ms) AS p99_queue
FROM llm_traces
WHERE timestamp > now() - interval '24 hours'
GROUP BY hour
ORDER BY hour;

---

5. Sampling Strategy

Tracing every request is expensive at high throughput. Use intelligent sampling:

from opentelemetry.sdk.trace.sampling import TraceIdRatioBased, ParentBased

# Sample 5% of normal requests
base_sampler = TraceIdRatioBased(0.05)

# But always sample slow requests and errors
class AdaptiveSampler:
    def should_sample(self, context, trace_id, name, attributes):
        # Always sample errors
        if attributes.get("error"):
            return RECORD_AND_SAMPLE
        
        # Always sample slow requests (detected by parent span)
        if attributes.get("llm.ttft_ms", 0) > 5000:
            return RECORD_AND_SAMPLE
        
        # Base rate: 5%
        return base_sampler.should_sample(context, trace_id, name, attributes)

---

Self-Check

• Design a trace structure for an LLM request showing gateway, scheduler, prefill, and decode spans
• Instrument an LLM gateway with OpenTelemetry, including LLM-specific attributes
• Propagate trace context between gateway and inference engine
• Write a query to find requests where queue wait dominates total latency
• Implement adaptive sampling that always captures slow requests

---

References

• OpenTelemetry Documentation
• Jaeger Tracing
• OpenLLMetry: OpenTelemetry for LLMs
• For metrics, see Metrics