Part IV · Applied concepts · Chapter 45

Observability, tracing and cost

When an answer is slow, wrong or expensive, you need to see what happened inside it: which model ran with which prompt, what it read, which tools it called, how long each step took and what each call cost. This chapter covers what to record for every model call, traces and spans for runs with many steps, the OpenTelemetry conventions, keeping personal data out of logs, sampling, latency percentiles, cost from token counts, budgets that stop spending at a cap, and alerts on quality as well as errors.

What to record for every model call

One record per call, written when the call ends, whether it succeeded or not:

Most of these come back with the reply: the token counts, the stop reason, the model id and the tool calls are part of every response. The rest you add. As one line of JSON, for a help desk assistant that answers library members' questions:

{"trace_id": "t-2f9c", "span_id": "s-07", "parent_id": "s-01", "name": "chat claude-haiku-5-5",
 "prompt_version": "support_answer_v7", "model": "claude-haiku-5-5",
 "input_tokens": 4200, "output_tokens": 350, "latency_s": 1.42, "cost_usd": 0.000595,
 "stop_reason": "end", "tool_calls": [], "retrieved_ids": ["loans-policy#renewals"], "error": null}

Watch the stop reason in particular. Current Claude models think before they answer, and the thinking counts toward max_tokens. Set max_tokens too low and some replies stop with max_tokens after thinking, with little or no answer text. A rise in max_tokens stops after a change is the record telling you so.

Traces and spans

One request often makes several calls: retrieve passages, ask the model to plan, run a tool, ask the model to answer, check the output. A log line per call cannot show how they fit together. A trace can. It is a tree of spans: each span is one piece of work with a name, a start time, an end time, some attributes, and a parent, the span that started it. The root span is the whole request.

answer                                   2.81 s   $0.001115
├─ retrieve      (embed and search)      0.21 s
├─ chat claude-haiku-5-5   (plan)        0.94 s   $0.000520   3,000 in   440 out
├─ tool lookup_loans                     0.12 s
├─ chat claude-haiku-5-5   (answer)      1.42 s   $0.000595   4,200 in   350 out
└─ check         (citations, schema)     0.03 s

Read it top down. The children took 2.72 s together; the other 0.09 s of the root went between steps. The answer call is the slowest step and the most expensive, so that is where to look first.

• Roll costs up. As each model span finishes, add its cost and tokens to its parent's sum, and write the sum on the parent when it ends. Then every span shows what everything under it cost, and the root shows the whole request: $0.000520 + $0.000595 = $0.001115 here. See cost rollup.
• Find the parent from the context. Each new span takes the current span as its parent. In Python the current span lives in a context variable, which tasks started inside it inherit, so parallel branches land under the right parent and two users' requests never mix.
• Give background work its own trace. Work that runs after the answer has been sent, such as judging a sample of answers (chapter 44), starts in a fresh context. Give it a trace of its own and store the answer's trace id on it, so you can go from one to the other.
• Never block the answer. Send spans in the background, in batches. If the tracing backend is down, drop the spans and count the drops; tracing must never slow or break a request.

You need no service to start. A file with one JSON line per span, carrying its trace id and parent id, is a trace store you can search with grep and turn back into a tree with a few lines of code.

OpenTelemetry and the GenAI conventions

OpenTelemetry is an open standard, with SDKs for most languages, for producing traces, metrics and logs and sending them to any backend that accepts its wire format, OTLP. Instrument your code once and you can change backends without touching it.

Its GenAI semantic conventions name the attributes of a model call, so different tools read the same fields. Among them:

The conventions are still marked as in development, so names can change between versions: check the current specification before you depend on one. Prompt versions, costs and retrieved ids have no standard name yet, so put them under a prefix of your own.

Several tools are built for model applications. Langfuse and Arize Phoenix are open source and can run on your own machines; others are hosted services. They accept OpenTelemetry spans and add views a general tracing tool lacks: the prompt and reply of each call, token counts and costs, scores from judges and users, and test sets built from saved traces. A general OpenTelemetry backend such as Jaeger shows the same spans as a timeline. Choose by where the data may live and who may see it (below), not by features alone.

Personal data in logs

Traces copy prompts and replies, and prompts carry whatever users typed: names, email addresses, account numbers, health details. A trace store that keeps them is a second copy of your users' data, often with wider access and a longer life than the first. Four rules:

1. Mask before logging, not when displaying. Replace personal data with placeholders before a span leaves the process (chapter 34). Masking in the viewer leaves the raw data in the store. If the model already saw a masked copy, log that copy.
2. Mask structured fields by key name. A tool result such as {"name": …, "email": …, "loans": 3} can be masked by the names of its keys, which is exact; free text needs a detector, which is not. Never log secrets: API keys, tokens, passwords, cookies.
3. Log references where you can. Ids, counts, versions and amounts are enough for most debugging. A span that says "retrieved 4 passages" with their ids needs no passage text.
4. Set retention and access. Decide how long traces live, for example 30 days for full prompts and replies, and delete them on schedule. Cost and count records hold no personal data and can live longer. Limit who can open traces. A hosted tracing service processes your users' data, with the obligations that brings (chapter 43).

Sampling

At low volume, keep every trace. At high volume, full traces with prompt text cost storage and money, and nobody reads most of them. Sampling keeps some:

• Head sampling decides when the request starts: keep 10%, say. It is simple, but it throws away errors as readily as successes.
• Tail sampling decides when the request ends, so it can keep every error, every slow request and every answer a judge or a user marked down, plus a share of the rest. It has to hold the spans until the request finishes.

Worked: 200,000 calls a day, 1% of them errors. Keep every error and 10% of the rest: 2,000 + 10% × 198,000 = 2,000 + 19,800 = 21,800 traces a day, about 10.9% of the calls, with no error lost.

Sample the payloads, never the counters. Every call's tokens and cost must be recorded, sampled or not, or your cost totals and budget checks are wrong.

Latency percentiles

Chapter 42 explains why you watch percentiles rather than the average. Here is how they are computed. A percentile pN is the value that N% of the measurements are at or below.

Worked: twenty calls took these times, in seconds, sorted:

• Mean: the sum is 43.4, so 43.4 / 20 = 2.17 s. Two slow calls pull it up, and it describes no real call.
• p50, the median, by the nearest-rank method: rank = ⌈0.50 × 20⌉ = 10, and the 10th value is 1.5 s.
• p95: rank = ⌈0.95 × 20⌉ = 19, and the 19th value is 6.8 s. One call in twenty waits about that long or longer.

Tools differ in method: many interpolate between neighbours, and NumPy's default gives 6.915 s for this p95. With twenty values a p95 rests on one or two calls, so wait for a few hundred before you trust it, and know which method your dashboard uses.

Two habits help. Record percentiles per step as well as for the whole request, to find which step is slow. And compute the request's percentile from whole-request times: the p95s of the steps do not add up to the p95 of the request, because the slow calls of different steps rarely land on the same request. For streamed answers, track time to first token too; it is what the user feels first.

Cost from token counts

Providers bill by tokens, with separate prices per million input and output tokens:

cost = (input tokens × input price + output tokens × output price) / 1,000,000

Worked: a help desk answer sends 4,200 input tokens (system prompt, four retrieved passages and the question) and gets 350 output tokens back. With the prices per million tokens of Claude Haiku 5.5 ($0.10 input, $0.50 output), Sonnet 5.5 ($2, $10) and Opus 5.5 ($4, $20):

Three things make real costs bigger than one call suggests:

• Thinking is output. Current Claude models think before they answer. Those tokens are billed at the output price and appear in the output count.
• Loops resend the conversation. In an agent loop (chapter 29) each round sends everything so far again. Worked on Sonnet 5.5: the first round sends 3,000 tokens; each round adds 600 (the model's 150-token tool call and a 450-token tool result); the fourth round writes a 400-token answer. Input per round is 3,000, 3,600, 4,200 and 4,800, 15,600 in all; output is 150 + 150 + 150 + 400 = 850. Cost: (15,600 × 2 + 850 × 10) / 10⁶ = $0.0397, against $0.0075 for the first round alone.
• Requests make many calls. The root span holds the sum of its calls, and that sum per request is the number to watch.

Prompt caching cuts the cost of a repeated prefix (chapter 42). Prices change, so keep the price table in one place with the date you checked it, and store the computed cost with each call, so old records keep the price they were made at. Keep money out of floating point when you add up many records: store whole millionths of a dollar or use a decimal type, and round each call's cost up, so the meter never undercounts.

Budgets and spend caps

A spend guard refuses a paid call that could push spending past a cap. Caps belong at several levels: per run (one agent task, one eval run), per user per day, and for the whole application per month. The guard works in three steps:

1. Reserve. Before the call, work out the most it could cost: its input tokens at the input price plus max_tokens at the output price. If spent + already reserved + this worst case reaches the cap, refuse the call.
2. Call. If the call fails, release the reservation.
3. Settle. Price the real tokens, add them to the amount spent, and release the reservation.

Worked, on Sonnet 5.5 with a cap of $0.05: each call sends 3,000 tokens, allows max_tokens = 1,024 and writes 400. A call really costs (3,000 × 2 + 400 × 10) / 10⁶ = $0.010, and its worst case is (3,000 × 2 + 1,024 × 10) / 10⁶ = $0.01624. Calls 1 to 4 go ahead, leaving $0.040 spent. Call 5 needs 0.040 + 0.01624 = $0.05624, which passes the cap, so it is refused, although its real cost would just have fitted. Planning for the worst case costs a little headroom, and it is what makes the cap a cap.

The guard must fail closed. If it cannot read its meter, it refuses every paid call; if it cannot record a cost, it keeps the reservation counted as spent and makes no further paid call. A guard that lets calls through when it is unsure is not a guard. Set the provider's own spending limit on the API key as well, as a backstop: it catches what your code does not count, such as calls made by other programs with the same key.

Alerting on quality as well as errors

Errors and slowness announce themselves. Quality does not: a model update or a prompt change can make answers worse while every request still succeeds. Alert on both kinds of signal:

Alert on change against a baseline, and allow for sample size, or the alerts will cry wolf. Worked: last week the judge passed 1,288 of 1,400 sampled answers (92%; 95% Wilson interval 90.5% to 93.3%). Today it passed 126 of 150 (84%; interval 77.3% to 89.0%). The intervals do not overlap, so this is a real drop, not noise. Filter today's traces by prompt version and model id: if the drop starts with a new version, you have your suspect.