Day 142 · Flight recorders

Tracing LLM Applications

You will be able to

Describe the anatomy of a trace: trace ID, spans, parent-child links, attributes, status
Instrument a multi-step LLM pipeline with nested spans in plain Python
Decide what to record on LLM spans (model, tokens, cost, doc IDs) and what to redact
Choose a sampling strategy that keeps costs sane without losing the failures

Today's ~120 minutes

Spaced-rep warm-up + review yesterday's gate design	10 min
ELI5 + tech read: span anatomy, OTel mapping, sampling	20 min
Guided: build the tracer + the trace viewer	40 min
Practice: redaction before the recorder	15 min
Project: instrument the capstone end-to-end	25 min
Quiz + flashcards	10 min

Builds on: Day 16 — Logging, config & CLI ergonomics · Day 113 — RAG architecture · Day 140 — Capstone eval harness

The analogy

🧸 ELI5⚙ Tech

When a plane lands badly, investigators do not interview the pilot's feelings — they pull the flight recorder: a timestamped record of every instrument, control input, and system state for the whole flight. The crash makes sense in minutes because the evidence was captured *while it happened*, not reconstructed afterwards.

A trace is a flight recorder for one request through your system. The user asks "what's the refund policy?" and that single flight touches five subsystems: query rewriting, retrieval, reranking, the LLM call, citation checking. A trace records each leg as a span — when it started, how long it took, what it was given, what it returned, whether it errored — and links them into a tree under one trace ID. When a user reports "it gave a wrong answer at 2:14pm", you pull that flight's recording and see immediately: retrieval returned the wrong document, or retrieval was fine and the model ignored it. Without the recorder, every bug report starts a guessing game; with it, debugging is reading.

Why this matters on the job

RAG and agent bugs are *pipeline* bugs: the final answer is wrong, but the cause is three steps upstream. Logs that only capture the final answer cannot distinguish "retrieval failed" from "generation ignored good context" — the single most important diagnostic split in RAG debugging (Day 136 made you measure them separately; tracing lets you see them separately in production). For an FDE, traces are also the customer-facing debugging tool: when the client says "your bot was wrong yesterday", you answer with the trace, not a shrug. Day 172 (production debugging with customers) leans entirely on what you build today.

Watch it happen

The flight recorder — one RAG request, span by span

step 1 / 5

trace 4f2c-91 · total 3,840 ms

POST /ask ································ 3840 ms

A user reports: "the app felt slow and the answer had no citations." Without tracing, that is a shrug. With tracing, every request leaves a tree of timed spans. Here is that request's recording.

🎯 Predict modespeed1×

Guided practice

guided 1

Build a flight recorder in 50 lines

25 min

Create tracer.py from the starter code and read it line by line — the contextvars stack is the whole trick: entering a span makes it "current"; any span opened inside becomes its child.
Create demo_pipeline.py with the fake RAG pipeline below and run it: terminal: python demo_pipeline.py.
Open traces.jsonl. Verify: all spans share one trace_id; retrieve and llm.generate have the root span's ID as parent_id; durations nest sensibly.
Add a rerank step between retrieve and generate with its own span. Rerun and confirm the tree grew.
Make generate raise an exception on one run and confirm the span records status: error with the exception message — the recorder must survive the crash.

🐍 python — editable, runs in your browser

# tracer.py — a minimal flight recorder in plain Python
import contextvars, json, time, uuid
from contextlib import contextmanager

_current = contextvars.ContextVar("current_span", default=None)

class Tracer:
    def __init__(self, path="traces.jsonl"):
        self.path = path

@contextmanager
    def span(self, name, **attributes):
        parent = _current.get()
        s = {
            "trace_id": parent["trace_id"] if parent else uuid.uuid4().hex,
            "span_id": uuid.uuid4().hex[:16],
            "parent_id": parent["span_id"] if parent else None,
            "name": name,
            "start": time.time(),
            "attributes": dict(attributes),
            "status": "ok",
        }
        token = _current.set(s)
        try:
            yield s                      # caller may add attributes mid-flight
        except Exception as e:
            s["status"] = "error"
            s["attributes"]["error"] = repr(e)
            raise
        finally:
            s["end"] = time.time()
            s["duration_ms"] = round((s["end"] - s["start"]) * 1000, 1)
            _current.reset(token)
            with open(self.path, "a") as f:
                f.write(json.dumps(s) + "
")

tracer = Tracer()

# ---- demo_pipeline.py ----
# from tracer import tracer
import random

def retrieve(q):
    with tracer.span("retrieve", k=8) as s:
        time.sleep(random.uniform(0.05, 0.2))
        docs = ["doc-14", "doc-02", "doc-31"]
        s["attributes"]["doc_ids"] = docs
        return docs

def generate(q, docs):
    with tracer.span("llm.generate", model="claude-sonnet-4-5", doc_ids=docs) as s:
        time.sleep(random.uniform(0.3, 0.8))
        s["attributes"].update(input_tokens=1200, output_tokens=250,
                               cost_usd=0.0071, stop_reason="end_turn")
        return "The refund window is 30 days [doc-14]."

def answer(q):
    with tracer.span("request", route="/ask") as s:
        docs = retrieve(q)
        out = generate(q, docs)
        s["attributes"]["answer_len"] = len(out)
        return out

if __name__ == "__main__":
    print(answer("What is the refund policy?"))

Ctrl/⌘+Enter runs · Tab indents · numpy/pandas/sklearn auto-load on import (torch and network calls need a local run)

guided 2

A trace viewer: reconstruct the tree

15 min

Write trace_view.py: load traces.jsonl, group spans by trace_id, link children to parents, and print each trace as an indented waterfall — name, duration, key attributes, and a red flag on error status.
Run it against the demo output; you should see request at the root with children indented beneath.
Add a --slowest flag that sorts traces by root duration and shows the worst one — the "which flight was bad?" query you will run constantly in production.

🐍 python — editable, runs in your browser

# trace_view.py
import json, sys
from collections import defaultdict

spans = [json.loads(l) for l in open("traces.jsonl")]
by_trace = defaultdict(list)
for s in spans:
    by_trace[s["trace_id"]].append(s)

def show(trace):
    kids = defaultdict(list)
    root = None
    for s in trace:
        if s["parent_id"] is None:
            root = s
        else:
            kids[s["parent_id"]].append(s)
    def walk(s, depth):
        flag = " [ERROR]" if s["status"] == "error" else ""
        attrs = {k: v for k, v in s["attributes"].items()
                 if k in ("model", "doc_ids", "cost_usd", "input_tokens", "error")}
        print("  " * depth + f"{s['name']:<14} {s['duration_ms']:>7.1f} ms {attrs}{flag}")
        for c in sorted(kids[s["span_id"]], key=lambda x: x["start"]):
            walk(c, depth + 1)
    if root:
        walk(root, 0)

traces = sorted(by_trace.values(), key=lambda t: max(s["duration_ms"] for s in t))
if "--slowest" in sys.argv:
    traces = traces[-1:]
for t in traces:
    show(t)
    print("-" * 60)

Ctrl/⌘+Enter runs · Tab indents · numpy/pandas/sklearn auto-load on import (torch and network calls need a local run)

On your own

Redaction before the recorder

15 min

Users will type emails, ticket numbers, and names into your docs-QA box, and your tracer currently writes queries verbatim. Add a redact(text) function applied to every attribute value before a span is written: mask email addresses, long digit runs, and anything matching your company's employee-ID pattern, replacing each with a typed placeholder like [EMAIL]. Prove it works by tracing a request containing an email and a phone number, then grepping traces.jsonl for them — zero hits allowed.

Hints: Day 13's regexes do the work; walk the attributes dict recursively (values may be lists); redact at write time inside the tracer, not at call sites, so nobody can forget.

Ship before you stop

Instrument the capstone end-to-end

Bring the flight recorder into your real docs-QA service. Add tracer.py (with redaction) to the capstone, then wrap: the request handler (root span with route and request ID), query transformation if you have it, retrieval (doc IDs + scores), reranking, the LLM call (model, tokens, cost, stop reason, prompt hash), and citation post-processing. Return the trace ID to the client in an X-Trace-ID response header so a bug report can name its flight. Run 10 varied queries, then use trace_view.py to answer in writing: where does the p95 request spend its time, and what fraction of total latency is the LLM call vs retrieval?

Rubric — check what you completed (0/6)

Every request produces exactly one trace with a single root span and correctly parented childrenLLM spans record model ID, token counts, computed cost, and stop reasonRetrieval spans record doc IDs and scores, not full document textRedaction verified: a query containing an email yields no raw email in traces.jsonlX-Trace-ID returned on responses and resolvable to a stored traceWritten latency breakdown for 10 queries identifies the dominant span

Common mistakes & misconceptions

Logging only the final answer. Pipeline bugs live between steps; without spans for retrieval and generation separately you cannot tell which failed — the Day-136 split, lost.
Storing full documents and full prompts on every span. Traces balloon and become a PII liability; store doc IDs, hashes, and versions, and fetch content on demand.
Using thread-locals for the current span. They break under asyncio because many requests share a thread — contextvars exist precisely for this (Day 40).
Head-sampling 10% uniformly and losing 90% of your errors. Tail-bias the sampling: keep all errors, slow requests, and negative-feedback flights.
Treating tracing as a production-only tool. Run it in dev too — the trace viewer is a better debugger for pipelines than print statements.
Forgetting to end spans on exceptions. A recorder that dies with the plane is useless; the try/finally in the context manager is the whole point.

Knowledge check

Q1. What structurally distinguishes a trace from ordinary structured logs?

Q2. Your service keeps 10% of traces via random head sampling. What is the biggest risk for an LLM app?

Q3. Why record retrieved doc IDs on the retrieval span instead of full chunk text?

Go deeper — curated resources

docsOpenTelemetry — Traces concepts ↗20 min docsOpenTelemetry — Python getting started ↗25 min docsLangSmith — Evaluation & tracing concepts ↗15 min

If you have a third hour

Swap your tracer for the OTel SDK ↗ — Re-instrument the demo pipeline with the real SDK and an OTLP console exporter — notice your span() maps 1:1 to start_as_current_span().

Done means

Demo pipeline produces correctly nested traces, including on exceptions
Capstone requests each emit one trace and return X-Trace-ID
Redaction test passes (no raw email/phone in traces.jsonl)
Written latency breakdown identifies the dominant span
Quiz ≥ 2/3

How this connects

← Back: This is Day 16's flight-recorder analogy graduating from flat logs to trees, using Day 40's contextvars, and making Day 136's retrieval-vs-generation split visible per request in production.

Forward →: Day 143 mines these traces for eval cases and joins them to user feedback; Day 146's dashboard aggregates their latency and cost fields; Day 172 uses them to debug in front of a customer.

Unlocks: D143 Logging, Feedback & the Data Flywheel · D146 Quality & Cost Dashboards · D147 Observability Complete · D157 Monitoring & SLOs