`agent_trace level:"error"` cannot express a failed tool call — the ❌ is written at `info`, so the documented "just failures" read is three days stale

[serge-ivo]

agent_trace level:"error" cannot express a failed tool call — the ❌ is written at info, so the documented "just failures" read is three days stale

What a debugger sees

agent_trace is billed as the first thing to call:

Reconstruct the complete, time-ordered timeline of what an agent instance DID — chat turns (chat.in/tool.call/chat.out), apply steps/handoffs/outcomes (apply.*), and failures (level=error), interleaved. This is the primary tool for debugging or improving an agent.
— workers/mcp/src/instance-tools/observability.ts:111

and SERVER_INSTRUCTIONS (workers/mcp/src/tool-metadata.ts:25) sends every host there first: "To debug what an agent did, call agent_trace first".

Measured, production, instance bd43f4de-ef35-4051-bdec-43f8571414a1, 2026-08-15:

• agent_trace(level:"error") → 4 events, all 2026-08-08, all AI request timed out (25s).

• agent_trace(source:"chat", limit:40) over 2026-08-11 22:43 → 2026-08-12 07:43 → zero error-level events, and these, all at level: "info", event: "tool.call":

  2026-08-11 23:05:57  ❌ **start_work** apps/chess-academy is already being worked on
  2026-08-12 03:22:34  ❌ **repo_find** This machine's runner is too old to search t
  2026-08-12 03:23:28  ❌ **repo_find** … ❌ **repo_find** …
  2026-08-12 04:03:31  ❌ **repo_grep** … ❌ **repo_grep** …
  

• instance_activity for the same period carries repo_grep / repo_find / start_work with success: false, and instance_board shows two Failed cards from 08-11.

Someone who follows the tool's own instruction concludes the last failure on this agent was three days before the ones that actually broke the session.

Mechanism — two decisions, both locally reasonable

1. The write path has no level and no success flag. workers/api/src/routes/instances-chat.ts:121:

if (tools) await logEvent(c.env, { source: "chat", event: "tool.call", message: tools.replace(/\s+/g, " ").slice(0, 200), userId: session.uid, instanceId, traceId: turnId, ts: now });

logEvent defaults it (workers/api/src/lib/events.ts:62): e.level ?? "info".

tools is the DO's toolMessage.content — a single string of ALL the round's tool lines concatenated (agent-do.ts:587, toolCalls.join("\n")), each already formatted by lib/tool-result-cap.ts:95-99:

export function toolLogLine(name: string, content: string, success: boolean): string {
	if (success) return `✅ **${name}** ${text.slice(0, TOOL_LOG_MAX_CHARS)}`;
	…
	return `❌ **${name}** ${shown}`;
}

So by the time the route logs it, the per-tool success boolean is gone — flattened into an emoji inside one string. The route cannot classify what it is handed. This is verified, not inferred: grep -rn '"tool\.call"' workers/ returns exactly this one call site.

2. A mixed round collapses into one row. The 08-11 23:05 event above is literally ✅ **check_work** … ❌ **start_work** … in a single info message, truncated at 200 chars. There is no shape in which that row can carry one level honestly.

Second defect in the same tool: level is an equality filter, not the documented one

observability.ts:117 describes it as:

"Minimum-interest filter — e.g. "error" for just failures."

workers/api/src/lib/events.ts:118-120 implements equality:

if (opts.level) {
	binds.push(opts.level);
	where.push(`level = ?${binds.length}`);
}

level:"error" happens to be right because error is the top of the ladder. level:"warn" silently drops every error — on this instance that means asking for warnings hides the 4 timeouts, which is the opposite of "minimum-interest". Same tool, same call, worth fixing in the same change.

What to do — cheapest first

1. Log one tool.call event per tool, with its own level. The success flag exists at agent-do.ts where toolLogLine is called; carry it. A failed call writes level: "warn" (or "error" — see the open question) with context: { tool, success: false }; a successful one stays info. This also fixes the 200-char truncation swallowing the remedy text that TOOL_LOG_FAILURE_MAX_CHARS = 600 deliberately preserved for the model (tool-result-cap.ts:83) — the trace currently keeps 200 of it.

2. Make level a floor. WHERE level IN (…) over the tail of ["debug","info","warn","error"], or drop the word "minimum-interest" from the description. Either is fine; the two disagreeing is not.

3. If (1) is too invasive for now, the one-line stopgap is to set level: "warn" on the tool.call write when the flattened string contains ❌. Ugly (it parses a display string) and explicitly not the recommended fix — recorded only so a partial can ship.

Open question for the owner

Is a failed tool call warn or error? A repo_find refusal is a real failure the agent could not work around, but it is also routine and self-explanatory. I would use warn and reserve error for a turn that could not complete — which is what the existing 4 rows are — and then fix the description to say so, because the current text promises error covers "failures" generically. Going the other way (everything failed is error) is defensible but will bury the turn-level failures under tool noise.

Alternatives considered and rejected

• Read failures from instance_activity instead. That is where they are today, and it is why this is a defect: the trace is the documented entry point and the activity log is a second surface with no trace/turn correlation. Telling debuggers to check two places is the state we are in.
• Derive the level in listEvents at read time. Would require parsing ❌ out of the message on every read, and leaves the stored row wrong for anything else that consumes it.

Acceptance criteria

• agent_trace(instance_id, level:"error") (or "warn", per the decision above) returns the 08-11/08-12 tool failures on bd43f4de-…, not only the 08-08 timeouts.
• A turn with one succeeding and one failing tool produces two distinguishable events, not one info row.
• agent_trace(level:"warn") includes error rows, or the description no longer calls it a minimum-interest filter.
• A failed tool's message in the trace is not cut shorter than what TOOL_LOG_FAILURE_MAX_CHARS preserves.

Regression risk

Splitting one row into N multiplies agent_events writes per turn on tool-heavy agents; the table has an opportunistic 1%-of-writes 14-day prune (events.ts:69-76) and no cron, so a large increase in insert volume is a real cost to weigh. Bound it — cap events per turn, or write one row per tool only when success === false and keep the single info summary otherwise. The test to have: a mixed round asserts one info and one warn, and a 3-round all-success turn asserts the write count did not change.

Related: #527 (a finished coding run is unauditable over MCP) — same underlying complaint from the other side.

[serge-ivo]

Both defects fixed, in two commits on main (API worker deployed, CI green).

20b64fd — level is a floor. listEvents builds level IN (…) over the tail of ["debug","info","warn","error"] instead of level = ?. The floor won rather than the doc being edited down to match the code: the documented behaviour is the contract a caller may already have written against, and it stays correct as bands are added below error.

Every caller was traced before changing it — listEvents has exactly one production caller (the /trace route); the console reads /trace with trace_id only and never level; routes/admin-trace.ts keeps its own equality builder deliberately and is untouched, because "exactly the warns" is the question there. An unrecognised level is matched exactly rather than expanded — a filter nobody can parse must return nothing, never everything.

2fc3f90 — a failed tool call writes its own warn row. Verified live: agent_trace(level:"error") → 7 rows; agent_trace(level:"warn") → 43, containing all 7 error rows by id, including the four 2026-08-08 AI request timed out (25s) ones. Before this, asking for warnings returned zero errors.

On your open question — warn, and it stopped being a dilemma. With level as a floor, level:"warn" returns tool failures and the turn-level errors above them, so the worry about burying turn-level failures under tool noise is answered by the ordering rather than by a judgement call. error keeps meaning "the turn or run could not complete". The description no longer promises that error covers failures generically.

Shape: one row per FAILURE, not per tool — the issue's own acceptance criteria already described this. The route's single info summary row stays, so nothing reading it today changes, and a warn row is added per failed tool carrying the full 600 characters TOOL_LOG_FAILURE_MAX_CHARS preserves rather than the 200 the summary cuts to. Write amplification is bounded by the failure rate, not the tool-call rate — which matters against a table whose only retention is an opportunistic 1%-of-writes prune.

The issue misattributes one call site. toolLogLine is called at agent-think.ts:1114, not in agent-do.ts — agent-do.ts:587 only receives the already-flattened toolCalls: string[]. That is why the fix lives in agent-think.ts.

Honest limit. This is a write-path fix. Rows already stored at info are not reclassified, so the 08-11/08-12 failures still will not appear under warn — only failures from this deploy forward. Confirmed live: those rows are still level:"info", and no post-deploy tool failure has occurred yet, so the new row has not been observed in production. The floor half proved itself immediately on existing data.

Guards: a mixed round asserts one info and one warn; a 3-round all-success turn asserts the write count did not change, and asserts the fixture actually ran 3 successful tools first so it cannot pass vacuously. Proven in both directions — deleting the failure row fails two arms, and widening it to one row per tool fails the other two.

Closing.