Building Tracing Pipelines for LLM Apps

A retrieval-augmented chatbot has a latency distribution that makes no sense. The p50 is 900 ms. The p99 is 12.4 seconds. It is not one endpoint being slow and another fast — it is the same endpoint, the same model, the same customers. The logs record one line per request with a total duration and nothing else, so the investigation consists of staring at a histogram with two humps and guessing.

Someone adds tracing. The first slow request that gets captured looks like this:

POST /chat                                       12,412 ms  classify_intent                                    210 ms  agent.loop  iterations=4                        11,940 ms    tool.search   "refund policy"                  1,690 ms    llm.call      attempt=1                        1,240 ms    tool.search   "refund policy 2024"             1,710 ms    llm.call      attempt=2                        1,180 ms    tool.search   "refund policy exceptions"       1,720 ms    llm.call      attempt=3                        1,260 ms    tool.search   "how do refunds work"            1,680 ms    llm.call      attempt=4                        1,210 ms  format_response                                     52 ms

The model is not slow. The retrieval is not slow. The agent is looping — issuing near-identical searches, getting near-identical documents back, deciding it still lacks the answer, and going round again. Four search-plus-reason cycles at roughly 2.9 seconds each. The p99 hump is not a tail of the p50 distribution at all; it is a completely different behaviour hiding inside the same average.

No metric could have found that. A metric records that a request took 12.4 seconds. Only a trace records that it took 12.4 seconds because of four iterations of a loop. That causal structure — who called whom, in what order, for how long — is the entire product of a tracing pipeline, and getting one that actually works involves half a dozen decisions where the default is wrong.

The data model, precisely

Five concepts, and they are worth pinning down exactly because most tracing bugs are really misunderstandings of one of them.

A traceparent header looks like this, and reading it is occasionally the fastest way to debug a broken trace:

traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01             ^^ ^------------- trace id --------------^ ^-- span --^ ^^             |                                                        |          version                                             flags (01 = sampled)

That last byte matters more than it looks. 01 means an upstream service already decided this trace is being recorded. Downstream services must respect that decision, or you get traces where the front end is present and the back end is missing.

The pipeline, and the queue that silently drops your spans

Data flows: your code creates spans → a span processor buffers them → an exporter serialises and ships them → usually an OpenTelemetry Collector receives, processes, and forwards → a backend stores them.

1from opentelemetry import trace2from opentelemetry.sdk.resources import Resource3from opentelemetry.sdk.trace import TracerProvider4from opentelemetry.sdk.trace.export import BatchSpanProcessor5from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter67resource = Resource.create({8    "service.name": "chat-api",9    "service.version": "4.2.1",         # without this, no deploy attribution10    "deployment.environment.name": "production",11})1213provider = TracerProvider(resource=resource)14provider.add_span_processor(BatchSpanProcessor(15    OTLPSpanExporter(endpoint="http://otel-collector:4317", insecure=True),16    max_queue_size=8192,                # default 2048 - too small, see below17    schedule_delay_millis=1000,         # default 5000 - too slow, see below18    max_export_batch_size=1024,         # default 51219))20trace.set_tracer_provider(provider)21tracer = trace.get_tracer("chat-api")

Those three overridden numbers are not cosmetic, but the reason is often misunderstood. The default BatchSpanProcessor holds up to 2,048 spans in a queue. It does not simply wait 5 seconds between batches: as soon as 512 spans are queued it wakes up and exports batch after batch until the queue drains. The 5-second delay only matters in quiet periods. What limits throughput is how long each export takes, and the queue is what absorbs the gap while an export is in flight.

Now take a service handling 500,000 requests a day at 8 spans each. The daily average is modest:

500,000 / 86,400 = 5.8 requests/sec  x 8 spans = 46 spans/sec

A busy hour running ten times the daily mean gives 463 spans per second. While the Collector answers in a few milliseconds, that is easy. But suppose the Collector stalls — it restarts during a deploy, or the network drops packets. The OTLP exporter waits up to its timeout (10 seconds by default in the Python SDK) before giving up on a batch, and nothing leaves the queue while it waits:

2,048 / 463 = 4.4 seconds until the queue is fullafter that, every new span is dropped until the export returns

The symptom is maddening: traces are complete at 3 a.m. and full of holes at peak, which is exactly when you need them. Your requests see no error — the SDK drops spans rather than blocking your request path, and the only evidence is a "Queue full, dropping" warning in the application log. With max_queue_size=8192 the same stall takes 8,192 / 463 = 17.7 seconds to fill the queue, enough to ride out a short Collector restart. The shorter schedule_delay_millis gets quiet-period spans out within a second instead of five, and the larger batch halves the number of export calls at peak.

Check the dropped-span counter your SDK exposes. A tracing pipeline that quietly discards spans under load is worse than no tracing, because you will draw conclusions from data that is missing exactly the requests you care about.

Two related traps. SimpleSpanProcessor exports synchronously on every span end — fine in tests, catastrophic in production, where it adds a network round trip to every operation. And in serverless or short-lived processes you must call provider.shutdown() (or force_flush()) before exit, or the final batch dies with the process.

Naming things so that aggregation works

A trace you read by hand tolerates any naming. Aggregating across a million traces does not. The rule is that span names must be low cardinality — they are effectively a group-by key.

Attributes are where the high-cardinality detail goes, and OpenTelemetry publishes semantic conventions so that different libraries agree on key names. The generative-AI conventions now live in their own repository (open-telemetry/semantic-conventions-genai) and are still at Development status as of September 2026, so names can change: pin the version you target. They recommend naming an inference span {gen_ai.operation.name} {gen_ai.request.model}, for example chat claude-sonnet-5, and they cover the important attributes:

Following the convention rather than inventing my_model_name means vendor dashboards, the Collector's processors, and other people's instrumentation libraries all understand your spans without configuration.

Tracing an LLM call so the span is worth having

1import time2from opentelemetry.trace import Status, StatusCode34def call_llm(prompt: str, model: str = "claude-sonnet-5", max_attempts: int = 3):5    with tracer.start_as_current_span(f"chat {model}") as span:6        span.set_attribute("gen_ai.provider.name", "anthropic")7        span.set_attribute("gen_ai.operation.name", "chat")8        span.set_attribute("gen_ai.request.model", model)9        span.set_attribute("gen_ai.request.max_tokens", 1024)10        span.set_attribute("prompt.chars", len(prompt))11        span.set_attribute("prompt.sha256", sha256(prompt)[:16])   # not the text1213        for attempt in range(1, max_attempts + 1):14            started = time.perf_counter()15            first_token_at = None16            chunks = []17            try:18                stream = client.messages.stream(19                    model=model, max_tokens=1024,20                    messages=[{"role": "user", "content": prompt}],21                )22                with stream as s:23                    for text in s.text_stream:24                        if first_token_at is None:25                            first_token_at = time.perf_counter()26                            span.add_event("first_token", attributes={27                                "ttft_ms": round((first_token_at - started) * 1000, 1)})28                        chunks.append(text)29                    final = s.get_final_message()3031                total_ms = (time.perf_counter() - started) * 100032                gen_ms = total_ms - (first_token_at - started) * 100033                u = final.usage34                out_tok = u.output_tokens35                cached = (u.cache_read_input_tokens or 0) + (u.cache_creation_input_tokens or 0)3637                # Anthropic's input_tokens excludes cache; the convention's total includes it38                span.set_attribute("gen_ai.usage.input_tokens", u.input_tokens + cached)39                span.set_attribute("gen_ai.usage.cache_read.input_tokens",40                                   u.cache_read_input_tokens or 0)41                span.set_attribute("gen_ai.usage.output_tokens", out_tok)42                span.set_attribute("gen_ai.response.model", final.model)43                span.set_attribute("gen_ai.response.finish_reasons", [final.stop_reason])44                span.set_attribute("llm.ttft_ms", round((first_token_at - started) * 1000, 1))45                span.set_attribute("llm.output_tokens_per_sec",46                                   round(out_tok / (gen_ms / 1000), 1) if gen_ms > 0 else 0)47                span.set_attribute("llm.attempts_used", attempt)48                return "".join(chunks)4950            except (RateLimitError, APITimeoutError) as exc:51                span.add_event("retry", attributes={"attempt": attempt,52                                                    "error": type(exc).__name__})53                if attempt == max_attempts:54                    span.set_status(Status(StatusCode.ERROR, str(exc)))55                    span.record_exception(exc)56                    raise57                time.sleep(2 ** attempt * 0.5)

Three choices in there change what the span can tell you later.

Retries are events on one span, not sibling spans. Both designs are defensible, and this is the one the GenAI conventions recommend for automatic retries: one span for the whole logical call. It keeps llm.attempts_used on a single span, so the query "show me traces where the model needed a retry" is a simple attribute filter rather than a span-count aggregation. It also stops retries from inflating your span count and your bill.

Time to first token is separated from total duration. For streaming responses these are wildly different experiences. Suppose a call reports TTFT 380 ms and total 3,780 ms for 402 output tokens:

generation window = 3,780 - 380 = 3,400 ms = 3.4 sthroughput        = 402 / 3.4 = 118 output tokens/sec

Now those two numbers move independently and each means something specific. TTFT climbing while throughput holds means queueing or a longer prompt to process. Throughput collapsing from 118 to 45 tokens per second while TTFT is unchanged means provider-side capacity pressure. Total duration alone conflates them, and the user experience of "waited 380 ms then read along" is nothing like "waited 3.8 seconds then everything appeared".

The prompt hash, not the prompt. You get to answer "were these two requests identical?" and "how many distinct prompts hit this path?" without shipping user text to a trace backend.

Tracing retrieval and database work

Auto-instrumentation covers most of this — one line hooks your database driver, HTTP client, and web framework:

1from opentelemetry.instrumentation.psycopg2 import Psycopg2Instrumentor2from opentelemetry.instrumentation.requests import RequestsInstrumentor3from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor45Psycopg2Instrumentor().instrument()6RequestsInstrumentor().instrument()7FastAPIInstrumentor().instrument_app(app)

What it buys you is best shown by the failure it exposes. A trace of a "fast" endpoint:

GET /conversations/{id}                              441 ms  db.query  SELECT ... FROM conversations WHERE id=?    9 ms  db.query  SELECT ... FROM messages WHERE conv_id=?   14 ms  db.query  SELECT ... FROM users WHERE id=?            8 ms  db.query  SELECT ... FROM users WHERE id=?            8 ms  ... 45 more identical-shape queries ...  serialize                                            21 ms

Forty-seven single-row lookups at roughly 8 ms each:

47 x 8 ms = 376 ms of the 441 ms total = 85%replaced by one batched query at ~22 ms  ->  saves 354 ms, an 80% reduction

This is the classic N+1 query, and it is essentially invisible without tracing: each individual query is fast, the endpoint's average is unremarkable, and nothing errors. The trace makes it obvious in one glance because the shape of the problem — a long run of identical sibling spans — is visually distinctive.

For vector search specifically, add attributes that let you correlate latency with retrieval quality: retrieval.k, retrieval.hits, retrieval.top_score, retrieval.index_version. When answer quality drops, "top score fell from 0.81 to 0.52 the day the index was rebuilt" is the sort of finding you can only make if the numbers were on the spans.

Tracing chains and agents

Framework code makes many nested calls per request, which is precisely where a flat log becomes useless. LangChain exposes a callback interface, and OpenTelemetry instrumentation for it (the opentelemetry-instrumentation-langchain package) maps each chain, tool, and model call onto a span:

1from opentelemetry.instrumentation.langchain import LangchainInstrumentor2LangchainInstrumentor().instrument()34# agent = langchain.agents.create_agent(model, tools=[search, ...])5# Anything you write yourself just nests inside the current span:6def answer(question: str):7    with tracer.start_as_current_span("chat.answer") as root:8        root.set_attribute("input.chars", len(question))9        result = agent.invoke({"messages": [{"role": "user", "content": question}]})10        # counters that only make sense at the root11        turns = [m for m in result["messages"] if getattr(m, "tool_calls", None)]12        root.set_attribute("agent.iterations", len(turns))13        root.set_attribute("agent.tools_used",14                           sorted({tc["name"] for m in turns for tc in m.tool_calls}))15        return result["messages"][-1].content

agent.iterations on the root span is the attribute that would have solved the opening mystery on day one. With it, "p99 latency by iteration count" is a single query, and the answer — that traces with 4 iterations average 12 seconds while traces with 1 iteration average 900 ms — reframes the problem from "the model is slow" to "the agent does not know when to stop". Those have completely different fixes: the second one is a prompt change, a similarity check against previous queries, or a hard iteration cap.

Context propagation: where traces break

Context lives in thread-local or async-local storage. Anything that moves work to a different execution context loses it unless you carry it deliberately.

1from opentelemetry import context, propagate23# Producer: put the context into the message4headers = {}5propagate.inject(headers)6queue.publish(payload, headers=headers)78# Consumer: pull it back out and make it the parent9ctx = propagate.extract(message.headers)10with tracer.start_as_current_span("job.process", context=ctx) as span:11    span.set_attribute("messaging.message.id", message.id)12    handle(message)1314# Thread pool: capture and reattach15current = context.get_current()16def wrapped():17    token = context.attach(current)18    try:19        return work()20    finally:21        context.detach(token)22executor.submit(wrapped)

Sampling decisions must be consistent across services

If each service samples independently, traces come apart arithmetically. Say the front end samples at 10% and a downstream service at 1%, deciding separately:

both keep their spans   = 0.10 x 0.01 = 0.001  ->  0.1% of traces are completefront end only          = 0.10 x 0.99 = 0.099  ->  9.9% are partial and misleading

Ninety-nine out of every hundred sampled traces would show a request vanishing into a service that appears to do nothing. The fix is ParentBased sampling: the root makes one decision, encodes it in the traceparent flags, and every downstream service honours it. Set the rate at the entry point only.

from opentelemetry.sdk.trace.sampling import ParentBased, TraceIdRatioBasedprovider = TracerProvider(resource=resource,                          sampler=ParentBased(root=TraceIdRatioBased(0.1)))

Better still, sample at 100% in the SDK and let a Collector make the decision after the fact using what actually happened — keeping every error and every slow trace, and a small percentage of the rest.

From one trace to an answer

Reading individual traces is how you debug. Aggregating over span attributes is how you find things worth debugging. Both start with latency attribution.

POST /chat                              4,200 ms   root  embed_query                              40 ms    1.0%  vector_search                           180 ms    4.3%  rerank                                   95 ms    2.3%  llm.call (402 output tokens)           3,780 ms   90.0%  format_response                          25 ms    0.6%                        sum of children = 4,120 ms                        unaccounted     =    80 ms  1.9%

Two readings come out of this immediately.

The unaccounted 80 ms is the gap between the root duration and the sum of its children. Some of it is always framework overhead, but a large gap means there is real work happening in an uninstrumented region. If that number is 40% rather than 2%, stop optimising and go find the missing span.

The attribution decides what to work on, and it usually contradicts intuition. Retrieval feels like the complicated part, so it attracts the optimisation effort. Compare the two available moves:

Generation time is roughly linear in output tokens, so 3,780 × (250/402) = 2,351 ms, saving 1,429 ms of a 4,200 ms request. Two weeks of work on the vector index would have bought 2%. A sentence in the prompt buys a third of the latency. You cannot make that comparison without span-level attribution, and teams routinely spend the two weeks.

Once traces are flowing, the queries worth building are aggregate ones over span attributes:

A trace answers "where did the time go" for one request. Aggregating span attributes answers "which requests are like this, and how many", which is the question that justifies engineering time.

What this means when you build one

A tracing pipeline that helps during an incident differs from one that merely exists in a handful of specific ways, and none of them can be added later without re-instrumenting.

Put the trace ID on your log lines. This is the highest-return single change in the whole pipeline. A trace tells you which span is fat; the logs for that trace ID tell you why. Without the shared key, you have two disconnected systems and every incident starts with guesswork.

Decide what never leaves your network, and enforce it in the Collector. Prompts and completions are user-submitted personal data. Put an attribute-deletion processor in the Collector so that redaction happens once, centrally, before export — not in each service, where one team will forget.

Put the aggregate counters on the root span. agent.iterations, llm.attempts_used, retrieval.k, tools_used, total tokens. These turn "find the pathological traces" from a scan over child spans into a single attribute filter, and they are what makes trace data queryable at scale rather than only browsable.

Verify the pipeline under load, not at your desk. Run a load test and compare the number of traces the backend received against the number of requests you sent. If they do not match, your span processor is dropping and every conclusion you draw from that data is filtered through an invisible bias towards quiet periods.

Sample by keeping what is interesting. A tail sampler that retains 100% of errors, 100% of traces slower than your p99, and 1% of the remainder gives roughly 2.5% of the raw storage volume while never discarding a failure. Head sampling at 1% keeps 25 of your 2,500 daily errors, which is not a debugging loop.

The team with the looping agent had all their metrics in place before they added tracing. What they lacked was one attribute — the number of iterations — on one span. That single number turned an unexplained bimodal latency histogram into a fifteen-minute prompt fix.