Skip to content

feat(turn): log what each one-shot model call sent and got back - #727

Open
andybons wants to merge 1 commit into
mainfrom
feat/oneshot-call-log
Open

andybons wants to merge 1 commit into
mainfrom
feat/oneshot-call-log

Conversation

@andybons

Copy link
Copy Markdown
Contributor

Problem

A boxes box was auto-named "Dinner plans for two in the city tonight?" from a first prompt that asked to find and wake another box. The title call (claude-code/haiku) succeeded, so harness logged nothing. No record holds the system prompt that the backend sent or the raw answer of the model, so the cause could not be found. 178 reruns of the same call, with the same request shape and another box's prompt, all gave a correct title.

Design

ask in internal/turn/compact.go is the one path of every model call with no tools on every backend: the title call, a compaction summary, a goal evaluation, and a plugin model call. It now writes one oneshot_call INFO line beside turn_metrics (docs/architecture.md, the turn_metrics paragraph of the turn section). The system text is what the backend reports through Request.Sent. Claude Code reports the instructions plus the append_system_prompt entries; a model API backend reports none, so the line uses the request instructions, which is what it sends. Backend.Run is synchronous, so Sent fires before the line is written.

serve already writes JSON logs on stderr, and the boxes log collector ships them to BetterStack, so boxes needs only a pin bump.

turn now imports toolresult for Mask, the masker of turn errors and child reports. toolresult imports only protocol. The turn-seam depguard list and the spec's import sentence (docs/architecture.md, the frozen-graph paragraph) add it. Andy approved this dependency.

Semantic change

  • One new INFO line oneshot_call per one-shot call, after its last attempt, also on failure.
  • Keys: session_id, turn_id, model, duration_ms, input_tokens, output_tokens, system_bytes, system, messages_count, messages (role, text), answer (raw, before the caller cleans it), and error on failure.
  • Every text is masked with toolresult.Mask, then capped: system 32 KiB, messages 32 KiB in total and 64 messages, answer 8 KiB, error 1 KiB. That is about 73 KiB of text per line, under the 900 KB batch of the boxes log collector even at worst-case JSON escaping.
  • The line holds prompt text, by Andy's decision for this single-tenant deployment. A secret that the mask does not recognize can stay in it; the spec says so.
  • No event, request, result, or existing log line changes.

Verification

  • TestContractOneShotCallLineOfATitleCall (new, e2e/) has three rows: a model API title model, a model API title call that fails, and claude-code over fakeclaude. It failed before the change (no oneshot_call line) and passes after it.
  • The claude-code row checks that the line holds the append_system_prompt entry; the model API row checks that it does not, because that backend does not send it.
  • The failure row puts Authorization: Bearer sk-live-… in the provider error and checks that the logged error holds no token. It was red before the mask.
  • go test -race ./... passes locally. golangci-lint is not installed in this box, so CI runs depguard.

Review

Cross-provider review by codex/gpt-6.1-sol (applied AGENTS.md, architecture-review, harness-architecture-review, go-guide):

  • Blocker, raw errors could log credentials: fixed. Every text goes through toolresult.Mask, and a contract row covers it.
  • Should-fix, the per-field caps did not bound the line: fixed with the caps above and a 64-message limit. The reviewer agreed that no separate size test is needed.
  • Blocker, turn may not import toolresult: fixed by allowing the dependency in .golangci.yml and the spec, as Andy decided.
  • The reviewer verified that Request.Sent is sequenced before the line, that every caller passes Limits.Log, and that ACP still logs to stderr only.

A box was auto-named "Dinner plans for two in the city tonight?" from a
first prompt that asked to find and wake another box. The title call
succeeded, so harness logged nothing: no record holds the system prompt
that the backend sent or the raw answer of the model, and the cause
could not be found. 178 reruns of the same call with another box's
prompt all gave a correct title.

Design: ask is the one path of every model call with no tools (title,
compaction summary, goal evaluation, plugin model call) on every
backend, so it owns one oneshot_call INFO line, beside turn_metrics. The
system text is what the backend reports through Request.Sent (Claude
Code sends the instructions plus the append_system_prompt entries),
else the request instructions (a model API backend sends those alone).
serve already writes JSON on stderr, which the boxes log collector
ships to BetterStack. turn now imports toolresult for Mask, the masker
of turn errors and child reports; toolresult imports only protocol, so
the turn-seam depguard list and the spec import sentence add it.

Semantic change: one new INFO line per one-shot call, after its last
attempt, also on failure: session_id, turn_id, model, duration_ms,
input_tokens, output_tokens, system_bytes, system, messages_count,
messages (role and text), answer, and error on failure. Each text is
masked with toolresult.Mask, so a provider error that echoes an
Authorization header logs "***", then capped: system 32 KiB, messages
32 KiB and 64 messages, answer 8 KiB, error 1 KiB, about 73 KiB of text
per line, under the 900 KB batch of the boxes log collector. The line
holds prompt text. No event, request, or result changes.

Verification: TestContractOneShotCallLineOfATitleCall fails without the
change (no oneshot_call line) and passes with it, on a model API title
model and on claude-code over fakeclaude. It checks that the Claude Code
line holds the append_system_prompt entry and the model API line does
not. A failure row checks that a bearer token in the provider error is
masked; it was red before the mask. go test -race ./... passes.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant