Observability and tracing

The eval says how a feature does on 200 cases you chose. The trace says what it did on the 20,000 tasks it ran yesterday: one record per task holding every model call, every tool call, the token and cache counters, the latency of each step, and which stop condition ended the loop. Without it, "the agent was slow on Tuesday" and "cost per ticket went up" are complaints. With it, they are queries.

The mistake: a log line per call

The first version almost everyone ships writes one log line per API call — timestamp, model, input tokens, output tokens, duration. It answers "how many tokens did we use today" and nothing else. It cannot say what one task cost, because nothing ties the four calls of a task together. It cannot say which step was slow, because tool calls are not in it. It cannot say why a task failed, because the stop reason, the checks and the loop's exit live somewhere else or nowhere.

The fix is the structure distributed systems already use: a trace per task with a task id, and a span per step inside it, each span carrying its own counters and timings. The monitoring lesson explains why traces cost more than metrics and earn it. For a model feature, the trace is the only record in which cost, latency and correctness meet.

What one trace holds

trace   task_id · feature · prompt_version · model_version · status
        status ∈ done | turn_cap | token_cap | no_progress | error
        turns · input · output · cache_read · cache_write · cost_units · wall_ms
span    model call: turn · input · output · cache_read · cache_write
                    ttft_ms · total_ms · stop_reason · checks (schema, invariants, provenance)
span    tool call:  name · args_hash · ms · ok | error · result_tokens
span    gate:       which gate · verdict · ms

Status comes first: it is the field agent loops and stop conditions says every run must record. The prompt and model versions turn "it got worse on Tuesday" into a suspect. The four counters come straight from the usage block of each response, and cost is computed from them rather than estimated: input × P_in + cache reads × C_r × P_in + cache writes × C_w × P_in + output × P_out. The check results from reading the response and the gate verdicts from the guardrails lesson are spans too, so a failed task shows which check stopped it.

Reading one trace

Expand

A support-agent task that took 13.4 s against a 10 s budget: three model calls take about 9 s, a knowledge-base search takes 4.2 s, and an order lookup 0.4 s100%−+FitSVG (opens in a new tab)CloseEsc

Pinch to zoom · drag to panScroll to zoom · drag or arrow keys to pan · 0 fits · Esc closes

The trace above is one support-agent task that took 13.4 seconds against a 10-second p95 budget. Left to right: the first call read its prefix from cache and decoded 60 tokens in about a second; a knowledge-base search took 4.2 seconds; a second call was quick; an order lookup took 0.4 seconds; the answer decoded 250 tokens in 5 seconds. The model accounts for about 9 of the 13 seconds and the search for 4. Without tool spans, the obvious fixes are a smaller model or a shorter answer. With them, the first fix is an index and a timeout on the search, which costs no quality at all.

The aggregate view is the same fields grouped. Share of tasks by status: "3% ended in no_progress, all on search_kb" is a tool-description bug. Cost per task by prompt version. p95 by span name. Cache hit rate by day, against what prompt caching says the layout should give.

What it costs to keep

Metadata is small: a few hundred bytes a span, perhaps 2 KB for a four-call task. Payloads — the prompts and outputs themselves — are not. A task that reads 10k tokens in total carries about 40 KB of text at 4 characters a token. At 20,000 tasks a day that is 800 MB a day, about 24 GB a month, of text that contains your customers' tickets.

So keep metadata for every task and payloads for a sample: every task that ended in anything but done, every task that failed a check or drew a complaint, and a random 5% of the rest. If 3% of tasks fall in the first group, payloads drop to about 8% of tasks, roughly 2 GB a month. Redact personal data before the payload is written, set a retention period, and keep a hash of each input so a task whose payload was dropped can still be matched to a golden case.

Sampling traces back into the golden set

The trace store is where the golden set gets new cases. Once a week, pull a sample: at 3% of 20,000 tasks a day, over 4,000 tasks a week fail a check, end in a cap or draw a user flag, so take 30 of them spread across the status values, and 20 random done tasks — a confident wrong answer looks like success in every metric, and only a person reading it finds it. Label them; at a minute each, 50 items is under an hour. A failure of a kind the set does not already cover becomes a case, with the trace id as its source, entering the dev set first and the golden set once reviewed.

That loop keeps the set resembling the traffic. A golden set that never takes cases from production measures last quarter's traffic, and its pass rate stays flat while the feature degrades on inputs it has never seen.

Alerts on cost per task and p95

Alert on rates per task, not on totals. Daily spend rises with traffic, and that is good news; cost per task rising is a change in behaviour. Four alerts cover most incidents:

• cost per task, daily median, more than 25% above its seven-day baseline
• p95 task latency over the budget for an hour
• share of tasks ending in a cap or no_progress above 2%
• cache hit rate below what the request layout predicts

Each catches a specific incident. A deploy that puts a timestamp at the top of the system prompt sends the cache-read counter to zero; cost per task jumps by the cached share of input times 1 − C_r, the alert fires within the hour, and the prompt version on the trace names the deploy. A tool whose backing API slows down moves p95 while the model spans stay flat. A model update that makes the agent repeat a call moves the no_progress share. Use burn-rate alerting, from the monitoring lesson, for the latency alert, so a five-minute blip pages nobody.

For an automation that runs with nobody watching, the same signals become drift alarms and a weekly review, taught in what working means and drift and silent failure.

In an interview

The usual question is "the agent's cost tripled last week; how do you find out why?", and what is tested is whether your system can answer it. Say: "one trace per task, a span per call, tool and gate; status first, then prompt and model version, then the four usage counters with cost computed from them; payloads sampled, every failure kept." Then answer from the trace: cost per task by prompt version, cache hit rate by day, calls per task by status.

The mistake that loses points is "we log every request" — per-call logs with no task id, which can total the bill and explain none of it. Second: alerting on daily spend, which pages on growth and sleeps through a cache that stopped hitting.

Check yourself

1. 50,000 tasks a day, each carrying about 12k tokens of prompts and outputs. What do you keep, and how much storage is that a month?

Full payloads are 12k × 4 characters ≈ 48 KB a task, 2.4 GB a day, 72 GB a month. Keep metadata for all of it — about 100 MB a day — and payloads for failures, flags and a 5% sample; if 3% of tasks fail, that is 8% of tasks, about 6 GB a month. Redact before writing.

2. Cost per task rose 40% overnight. Input tokens per call and calls per task are flat, and the cache-read counter dropped to zero. Cause and fix?

The cached prefix changed, so every call pays full P_in on input it used to read at C_r × P_in. The prompt version on the trace names the deploy. Diff the prompt for anything per-request near the top — a timestamp, a user name, tools in a new order — and move it below the stable prefix.

3. p95 went from 8 to 14 seconds while the model spans' prefill and decode times are unchanged. Where do you look, and what bounds it?

At the spans that are not model calls: tool latency and the gaps between spans. Compare p95 by span name for the weeks before and after; a tool whose p95 went from 0.5 to 6 seconds is the cause. A timeout a little above that tool's normal p99, with the error returned to the model as a result, bounds the task while the tool is fixed.