Production AI Observability

The Kitebase support bot from article 04 has been live for a few days. One morning two messages arrive. Finance asks why yesterday’s Anthropic bill for the bot was about 65% higher than the days before. And a customer says the bot’s answer “just stopped mid-sentence and took forever”. Your service dashboard is green: every request returned 200 OK, and the error rate is zero.

The HTTP logs say a request came in and a response went out. They don’t say which prompt ran, how many tokens it used, which help articles it read, or whether the model finished. An LLM feature fails quietly, inside a successful response.

What you’ll build: a thin wrapper around the Kitebase bot’s model call that writes one structured record per call (prompt version, model, tokens, cost, stop_reason, the chunks it read) as part of a trace, and a report that finds the cost jump in four days of logs and picks out the calls worth reading. It runs offline with a fake Claude client.

What observability means for an LLM feature

Observability means you can answer a new question about production (“why did this cost more?”) from data you already record, without shipping new code first. For a normal service that’s the request, the status code and the latency. For an LLM call it isn’t enough, because a 200 OK can hide three problems:

  • A wrong answer. The model invented a step, or retrieval handed it the wrong help article.
  • A cut-off answer. The model hit max_tokens, the output limit you set, and stopped mid-sentence.
  • An expensive answer. Normally $0.005, today $0.03, because the prompt or the answer grew.

So for every call you record what went in and what came back, in a shape you can query.

Step 1: Write one record per model call

A structured log is a log line that’s data, not a sentence: one JSON object per line, same field names every time, so you can filter, group and add it up. “Called Claude, took 1.8s” is a sentence. This is a record:

prompt            "support@v3"
prompt_fp         "13674be7"
model             "claude-opus-5"
chunk_ids         ["account-recovery#1", "recovery-email#1", "reset-password#1"]
input_tokens      412
output_tokens     118
stop_reason       "end_turn"
cost_usd          0.00501
duration_ms       1844

That’s the worked question from article 04, “How do I reset my password if I never set a recovery email?”, as it appears in the sample log that ships with the example, one field per line. Each field answers a question you’ll be asked:

  • prompt, prompt_fp: which prompt produced this answer, as a version name and a fingerprint (8 characters of a hash of the prompt text) from article 03. When answers change, this tells you whether the prompt did.
  • model: which model answered. Read it from the response, not your config, so a switch or a fallback shows up.
  • input_tokens, output_tokens: what you pay for. Tokens are the units models read and bill in, about 4 characters of English each (article 01).
  • cost_usd: the same in dollars, from step 2.
  • stop_reason: why the model stopped. "end_turn" means it finished, "max_tokens" that it was cut off, "refusal" that it declined.
  • chunk_ids: which help-center passages went into the prompt, so a wrong answer can be pinned on retrieval or on the model.
  • duration_ms: how long the call took.

The wrapper opens a span (step 3 explains that), makes the call as article 04 did, and copies the fields off the response:

def call_claude(client, trace: Trace, user_message: str, chunk_ids: list[str]):
    with trace.span("llm.call", prompt=PROMPT_ID, prompt_fp=PROMPT_FP,
                    model=MODEL, chunk_ids=chunk_ids) as rec:
        response = client.messages.create(
            model=MODEL,
            max_tokens=1024,
            system=SYSTEM_PROMPT,
            messages=[{"role": "user", "content": user_message}],
        )
        u = response.usage
        rec.update(
            model=response.model,  # what actually answered, not what you asked for
            message_id=response.id,
            input_tokens=u.input_tokens,
            output_tokens=u.output_tokens,
            cache_read_tokens=u.cache_read_input_tokens or 0,
            stop_reason=response.stop_reason,
        )
        rec["cost_usd"] = cost_usd(rec["model"], u.input_tokens, u.output_tokens,
                                   rec["cache_read_tokens"], u.cache_creation_input_tokens or 0)
        return response

message_id is the id Anthropic gives the response (msg_...). Include it when you ask their support about a specific call.

The question and answer text are missing on purpose: step 6 stores them somewhere else. The gotcha is logging too little. A field that isn’t in the record on the day something breaks can’t be added after the fact, so log stop_reason and the prompt version from day one, before you have a dashboard.

Step 2: Work out the cost when you write the record

The API response has token counts, not dollars. The price table on this site lists claude-opus-5 at $5 per million input tokens and $25 per million output tokens, so the worked call costs:

412 input tokens  × $5  / 1,000,000 = $0.00206
118 output tokens × $25 / 1,000,000 = $0.00295
                                      $0.00501

Output tokens cost five times as much as input, so long answers cost more than long questions. In code:

def cost_usd(model: str, input_tokens: int, output_tokens: int,
             cache_read_tokens: int = 0, cache_write_tokens: int = 0) -> float | None:
    price = PRICES.get(model)
    if price is None or cache_write_tokens:
        return None  # an unknown price, not $0
    total = (input_tokens * price["input"] + output_tokens * price["output"]
             + cache_read_tokens * price["cache_read"])
    return round(total / 1_000_000, 6)

Why now and not in the report? Prices change. A record that stores the cost at call time, plus the tokens behind it, stays right after the next price change.

The gotcha is the None. Add a model and forget the price table, and a function that defaults to $0 shows the cheapest day you’ve ever had. None lets the report count unpriced calls and say so. With prompt caching (article 10), cache reads cost a tenth of normal input ($0.50 per million here), but cache writes have their own price that isn’t in the table, so those calls come back unknown too.

Step 3: Tie retrieval and the model call together with a trace

The record from step 1 doesn’t say how long retrieval took or which user asked. Those belong to other steps of the same request, and when the customer from the opening complains, you want all of them, in order.

A trace is the record of one request as it moves through your code. It’s made of spans, one per step, each with a name, a duration and its own fields. Every span in a trace carries the same trace_id, and points to the span it ran inside through parent_id: a call stack written down with timings. For Kitebase, the root span support.answer covers the whole request, and retrieve and llm.call run inside it:

Trace 990f3ccb: one question, three spans "How do I reset my password if I never set a recovery email?" support.answer 1,990 ms retrieve 144 ms llm.call 1,844 ms 0 500 1,000 1,500 2,000 ms SUPPORT.ANSWER (ROOT) parent_id null user "u_07d1cbf11020" An HMAC of the login, not the email. RETRIEVE parent_id → support.answer k 3, top_score 0.61 account-recovery#1 recovery-email#1 reset-password#1 LLM.CALL: THE RECORD YOU DEBUG WITH prompt support@v3 13674be7 the exact prompt text model claude-opus-5 what actually answered input 412, output 118 tokens, what you pay for cost_usd 0.00501 412 × $5 + 118 × $25, /1M stop_reason end_turn finished, not cut off chunk_ids [3 ids] what it was given to read duration_ms 1844 93% of the wait trace_id, parent_id ties it to the other two
The worked question as it appears in the sample log. The model call is 93% of the wait.

The waterfall shows where the time went: the model call is almost all of it, which is typical, so latency work usually starts there. The example’s Trace class is about 20 lines. The part that matters:

@contextmanager
def span(self, name: str, **fields):
    record = {"trace_id": self.trace_id, "span_id": secrets.token_hex(8),
              "parent_id": self._open[-1] if self._open else None,
              "name": name, "status": "ok", **fields}
    self._open.append(record["span_id"])
    start = time.perf_counter()
    try:
        yield record  # the caller adds fields as it learns them
    except Exception as e:
        record.update(status="error", error=type(e).__name__)
        raise
    finally:  # write the span even when the call failed
        record["duration_ms"] = round((time.perf_counter() - start) * 1000)
        self._open.pop()
        self.sink(record)

self._open is a stack of running spans, so a span opened inside another gets it as its parent. sink is wherever finished records go: a JSON-lines file in the example, a list in the tests.

The gotcha is the finally. A span written only on success vanishes exactly when you need it: a timeout or rate-limit error would leave nothing. In finally, the failed call shows up with status: "error" and the exception’s name. Children also finish before their parent, so they’re written first; read traces by parent_id, not line order.

Should I use OpenTelemetry instead of writing my own?

In production, yes. OpenTelemetry is the open standard for traces, accepted by Datadog, Honeycomb, Grafana, and LLM tools like Langfuse and Phoenix. The shape is the same: tracer.start_as_current_span("llm.call") opens a span, one opened inside it becomes its child, and an exception marks it as an error.

It also names LLM fields, like gen_ai.usage.input_tokens, so tools chart them without setup. The Python package still marks those names experimental. The example’s otel_span.py writes the same spans with opentelemetry-sdk.

Step 4: Turn the records into a cost report and one alert

Back to finance’s question. The example ships data/sample_spans.jsonl: four made-up days of Kitebase traffic, 160 questions, in the format above. python report.py groups the llm.call spans by day:

day          calls     cost   $/call  p95 ms not ok
2026-09-20      40   $0.202  $0.0050   3,647      0
2026-09-21      40   $0.198  $0.0050   3,107      1
2026-09-22      40   $0.216  $0.0055   2,900      2
2026-09-23      40   $0.338  $0.0084   4,133      2

$/call is cost divided by priced calls. p95 ms is the 95th percentile latency: 95% of calls finished within it, and only the slowest 1 in 20 took longer. An average hides those slow ones. not ok counts calls that errored or didn’t end with "end_turn".

Cost per call jumped on the 23rd. The same records grouped by prompt version say why:

prompt       calls  avg in chunks   $/call
support@v3     128     417      3  $0.0052
support@v4      32   1,014     13  $0.0093

ALERT 2026-09-23: $0.0084 per call is 63% above the 3 days before ($0.0052).

Prompt v4 shipped at 09:00 on the 23rd, and every call since has sent all 13 chunks instead of the top 3. Someone set TOP_K = 13 while testing (article 04 suggests exactly that) and it shipped with the prompt change:

Cost per call, by day 160 questions from the sample log $0.0050 $0.0050 $0.0055 alert line for 09-23: $0.0052 + 30% = $0.0068 $0.0084 09-20 09-21 09-22 09-23 1 cut-off answer v4 ships at 09:00 ALERT 09-23: 63% above the 3 days before WHY: GROUP THE SAME LOG BY PROMPT support@v3: 128 calls 3 chunks, 417 tokens in, $0.0052 support@v4: 32 calls 13 chunks, 1,014 tokens in, $0.0093 v4 sends every chunk, not the top 3. 417 × $5 / 1M = $0.0021 1,014 × $5 / 1M = $0.0051 +$0.0030 a call from input alone; two cut-off answers add the rest. At 5,000 questions a day: $26 a day becomes $47.
The alert says something changed. The prompt and chunk fields say what.

The sample’s dollars are small because it’s 40 questions a day. At 5,000 a day, $26 becomes $47, every day, until someone notices. The alert rule:

for i, day in enumerate(names[1:], start=1):
    before = [days[d]["per_call"] for d in names[max(0, i - 7):i]]
    baseline = sum(before) / len(before)
    now = days[day]["per_call"]
    if baseline and now > baseline * (1 + jump):  # jump = 0.30
        alerts.append(f"ALERT {day}: ...")

Alert on cost per call, not total cost. Total cost also rises when more customers use the bot, which is good news. Per-call cost only moves when the calls changed. Start at 30%: tight enough to catch a prompt that doubled, loose enough that one long answer (the 22nd is 11% up from a single cut-off reply) doesn’t page anyone. An alert that fires every other day gets muted, and then catches nothing.

For the dashboard, start with five numbers per day: calls, cost per call, p95 latency, the share not ok, and the review fail rate from step 5. If the bot streams (article 02), add time to first token (TTFT), the wait before the first word appears, since that’s the delay users feel.

Step 5: Pick the calls a person should read

Numbers catch expensive and cut-off answers, not wrong ones. An answer saying the reset link lasts 24 hours, when the help article says 30 minutes, has normal tokens, normal cost and "end_turn". You find it by reading answers, and since you can’t read them all, you sample: pick a subset to read.

def pick_for_review(calls: list[dict], rate: float = REVIEW_RATE) -> list[dict]:
    return [c for c in calls if not_ok(c) or int(c["trace_id"][:8], 16) / 0xFFFFFFFF < rate]

That’s every call that went wrong, since each is rare and worth a look, plus about 5% of the normal ones. The 5% comes from the trace id, not random.random(), so re-runs pick the same calls and a trace is wholly in or out:

For review: 17 calls (5 didn't end normally, the rest are a 5% sample)
  2026-09-21T12:52  52e3f4b5  support@v3  refusal
  2026-09-22T12:18  8f40f198  support@v3  RateLimitError
  2026-09-23T10:34  e0d95f41  support@v4  max_tokens
  ...

e0d95f41 looks like the customer from the opening. Pull every span of that trace:

$ python report.py --trace e0d95f41
Trace e0d95f41, 2026-09-23T10:34:00+00:00
  support.answer     12,456 ms  u_4cb749ec5114
    retrieve            242 ms  k=13  top 0.35  account-recovery#1, account-recovery#2, ...
    llm.call         12,211 ms  support@v4  1,028 in / 1,024 out  max_tokens  $0.0307

The answer ran into the 1,024-token limit after 12 seconds, with 13 excerpts in its prompt. Both cut-off answers on the 23rd came from v4, so it’s most likely the same change as the cost spike, found from a different direction. Roll back to v3, and add this question to the eval set so the next prompt change is tested against it.

The normal 5% is the part people skip. Read them, or hand them to the judge from article 09 and track its fail rate daily. That rate is how you notice drift: quality slowly getting worse with no deploy to blame, because customers ask about something new or the help center changed. Each failure you find becomes a question in the golden set from article 08, the labelled questions your evals run on, so it can’t ship twice.

How big should the sample be?

Big enough to read. In the sample, 5% is 12 of 155 normal calls. At 5,000 questions a day it’s 250: too many for a person, about right for a judge.

A workable default: every not-ok call, every answer a user marked unhelpful, plus a fixed number of random ones per day (say 20 for a person, a few hundred for a judge), so the effort stays steady as traffic grows.

Step 6: Keep personal data out of the logs

Customers type personal data into support bots: “My login is sam@northwind.example and I’m locked out, call me on +31 6 1234 5678.” Log that raw and it’s copied into your log search, your vendor’s servers and every downloaded log file, for as long as logs live. Under GDPR, personal data in a log is still personal data, deletion requests included. The example follows three rules:

ANSWER_QUESTION writes two records user id, via hash_user() sam@northwind.example → u_daf0139f40bc text, via redact() sam@northwind.example → [email] SPANS.JSONL ids, tokens, cost, ms no question or answer keep 90 days TRANSCRIPTS.JSONL question + answer, redacted, by trace_id keep 7 days REPORT.PY $/call per day and per prompt p95 ms, not ok PICK FOR REVIEW every not-ok call + 5% by trace id 17 of 160 ALERT $/call more than 30% above the days before READ IT a person, or the judge from article 09 Delete text sooner than numbers: the numbers make the dashboard, the text is for debugging this week. Every failure you find becomes a golden-set question (article 08).
Delete text sooner than numbers: the numbers make the dashboard, the text is for debugging this week.

Hash user ids with a secret key. The spans need to know which calls came from the same user, not who that user is:

def hash_user(user_id: str) -> str:
    key = os.environ.get("LOG_HASH_KEY", "dev-only-not-secret").encode()
    return "u_" + hmac.new(key, user_id.encode(), hashlib.sha256).hexdigest()[:12]

An HMAC is a hash that needs a secret key. A plain SHA-256 of an email looks anonymous, but anyone can hash a list of known emails and match them. Without the key, u_daf0139f40bc can’t be traced to Sam; with it, you can still find Sam’s calls when Sam complains.

Redact the text you keep. Before the question and answer are stored, redact() swaps emails for [email] and long runs of digits (phone and card numbers) for [number].

Store text separately, and delete it sooner. Spans never hold question or answer text. The redacted text goes to transcripts.jsonl, keyed by trace_id so review can join the two. Keep spans 90 days and text 7: complaints about an answer arrive within days, cost trends need months. Real log stores set retention per index or bucket.

The gotcha: regex redaction misses anything that isn’t an obvious pattern. A name, an address or “my account number is four four one two” gets through. Redaction reduces risk; short retention and limited access to transcripts are the controls that hold.

Before you ship: evals in CI

Everything above happens after a change is live. The other half runs before: the eval harness from article 08, run in CI (the checks your repo runs on every pull request) whenever a change touches a prompt, retrieval settings or the model. It would have shown v4’s longer prompts and answers before a customer did. Observability catches what the eval set didn’t think to ask, and its failures go back into the eval set.

Try it yourself

The example is the wrapper, the trace, the report and the four-day sample log. It runs offline; ANTHROPIC_API_KEY makes main.py send one real call.

Download the runnable example (zip)

cd 11-production-ai-observability
python -m venv .venv && source .venv/bin/activate
pip install -r requirements.txt
python main.py        # one traced question, written to logs/
python report.py      # the four-day sample

Then try these:

  1. python main.py "My login is sam@northwind.example and I'm locked out", then open the last line of logs/transcripts.jsonl. The email is [email], and no span mentions it.
  2. Set ALERT_JUMP = 0.05 in report.py and run the report. The 22nd alerts too, because of one long answer. Put it back to 0.30.
  3. Change MODEL in main.py to a name that isn’t in PRICES, run python main.py, then python report.py logs/spans.jsonl. cost_usd is null, and the report says the call has no price instead of showing a cheap day.

pip install pytest && pytest -q runs the offline tests: record fields, cost maths, failed calls still logged, no email in either log, and the alert firing on the 23rd only.

Common beginner mistakes

  • Treating 200 OK as success. A cut-off, wrong or expensive answer is still a 200. Log stop_reason and cost, and read a sample.
  • Logging only “request in, response out”. Without chunk ids and a span per step, you can’t tell a retrieval problem from a model problem.
  • No prompt version in the log. When answers change, you can’t tell whether the prompt did.
  • Raw questions in long-lived logs. Hash user ids, redact text, and keep text for days, not months.

Questions you will face in production

“Hosted tool or our own logs?” If you already run Datadog, Honeycomb or Grafana, send OpenTelemetry spans there with the LLM fields. If not, a hosted LLM tool (LangSmith, Langfuse, Phoenix, Helicone) gives you a trace viewer on day one. The fields matter more than the tool: get the record right and you can switch later.

“Answers suddenly got worse. Where do I start?” Group the last few days by prompt version and model, and look for a change on the day it started. Then check top_score and chunk ids on the bad calls: wrong articles mean retrieval, right articles with a wrong answer mean the prompt or model. If nothing changed on your side, read 30 recent answers from the review sample.

“What should page someone at night?” Very little: error rate above normal for 10 minutes (the API is down or rate-limiting you) and cost per call far above normal (a runaway prompt). Drift and p95 creep go in a daily summary; nobody fixes those at 3am.

Check your understanding

Cost per call is flat, but the total bill doubled this month. Is something broken?

Probably not. Same cost per call and twice the bill means twice the calls: more customers using the bot, which isn’t a bug. That’s why the alert watches cost per call.

A customer says the bot told them the reset link lasts 24 hours. Which fields do you look at, and in what order?

Find their trace by hashed user id and time, then check chunk_ids on retrieve. If reset-password#1 (which says 30 minutes) wasn’t retrieved, it’s retrieval. If it was, the model misread it: note prompt and model and add the question to the eval set. The transcript shows what they saw, if it’s under 7 days old.

A teammate samples spans with random.random() < 0.05. What goes wrong?

Each span is sampled on its own, so you keep an llm.call without its retrieve, or the reverse. Sampling by trace id keeps traces whole and repeatable. Random-only sampling also drops most rare failures, which is why every not-ok call is kept on top.

You switch the bot to a new model and forget to add it to PRICES. What does the report show?

cost_usd is None for those calls and the report says how many have no price. With a $0 default, the day would look cheaper and nobody would notice until the invoice.

What to remember

  • A 200 OK proves nothing about an LLM answer. For every call, log prompt version and fingerprint, the model from the response, tokens, cost, stop_reason, chunk ids and latency.
  • A trace ties one request’s steps together with a shared trace_id and a parent_id per span. Write spans in finally, so failures are logged too.
  • Compute cost when you write the record. Unknown price means None, never $0. Alert on cost per call, not total spend.
  • Read every call that went wrong plus a small sample of normal ones, picked by trace id. Feed failures into the eval set.
  • Hash user ids with a key, redact text, and keep text for days while the numbers stay for months.

What to study next

You can now see what each call costs and why. Article 12: Cost Optimization in Production AI covers how to bring that number down: model routing, prompt caching and shorter outputs, each measured with the kind of per-call cost records you just built.

Further reading

Where this article comes from. This is a synthesis of common practice in AI engineering as of 2026, not a citation of any single paper. The sources above are where the broad mechanics and specific numbers come from. If you find an error or have a better source for a claim, the article gets fixed within a day, send me a note.


Auto-marks when you reach the end. Click to toggle.