feat(server): observability primitives — build identity, turn outcomes, transcript degradation#55
Conversation
An engineer burned 30 minutes today suspecting a stale box binary because /health only ever echoed the config Version string (0.1.0-dev), which never changes across deploys. /health now also returns vcs_revision and vcs_time, read from runtime/debug.ReadBuildInfo's VCS settings, so a live process can be matched to an exact commit. Both fields are always present (never omitted) and empty when build info carries no VCS settings, which is the ordinary case for a go test binary.
…shable from idle-because-died
Three plain-prompt turns died mid-stream today (final assistant message
reasoning-only, no text, no tool call) and every monitor had to infer death
from message part shapes. Journal a durable turn.end record — outcome
'completed' or 'error' plus a sanitized (never credentials/request bodies)
error string on failure — whenever a prompt (prompt_async) or a goal-worker
loop (POST /session/{id}/goal) finishes. It reaches /event like any other
durable record and is mirrored as Session.last_turn and each /session/status
entry's last_turn, so a poller can read the outcome directly instead of
reverse-engineering it from transcript content. A deliberate abort still
emits only session.aborted/goal.cleared, exactly as before — turn.end covers
completion and failure, not cancellation. No goal semantics changed; the
goal loop's state machine, retries, and events are untouched.
…r 500 wholesale
Today GET /session/{id}/message 500'd entirely because one resident message
failed json.Marshal ('json: error calling MarshalJSON for type
message.Parts'), taking down the whole transcript view exactly when it was
most needed to diagnose the death (ses_01kx453ewfedqrg7p3c64f8sca,
ses_01kx453ev9ejattygpf7rbzptw). The handler now marshals each message
independently and substitutes a {id, role, marshal_error} MessagePlaceholder
for any message that fails, returning 200 with every other message intact.
The regression test builds the poison directly: message.Normalize only
scrubs a ZERO-length Reasoning.ProviderData entry (mirroring the
ToolCall.Arguments guard), never a present-but-invalid one, so a scripted
provider's assistant message carrying a non-empty-but-truncated
ProviderData entry sails through ingest untouched and reproduces the exact
production failure.
📦 Previous Review (superseded by newer review)Claude finished @andybons's task in 4m 38s —— View job Review: observability primitives (PR #55)
Built clean, 🔴
|
PR #55 review finding: runGoal recorded turn.end{outcome:"completed"} whenever PursueGoal returned a nil error, but PursueGoal returns a NIL error with Achieved:false in two cases that are not completions: - MaxTurns exhausted without the evaluator ever returning MET (Reason "max turns") — the goal gave up, it did not finish. Now recorded as its own outcome, max_turns_exceeded (added to the openapi enum and documented), never "completed". - ClearGoal winning a race against an in-flight worker retry or evaluator call (Reason "goal cleared"), reached without the loop's context ever being cancelled. This is a clear, same as the existing context.Canceled path — no turn.end is emitted at all, matching the documented "DELETE /session/{id}/goal does not emit turn.end" contract. Both paths previously surfaced as last_turn={completed}, recreating the exact idle-because-done-vs-idle-because-it-died-or-gave-up ambiguity this primitive exists to remove. Red-first tests cover both: a max-turns exhaustion asserting a non-completed outcome, and a goal cleared while an evaluator call is deliberately blocked in flight (bypassing DELETE, which would otherwise take the already-correct context.Canceled path) asserting turn.end is suppressed entirely.
…s a restart PR #55 review finding: reconcile()/loadJournal() already replay events.jsonl on boot to rebuild the seen-message index, but did nothing with turn.end records — so last_turn, a field whose entire purpose is answering "did the last turn finish cleanly" for an orchestrator reconnecting after this process restarts, was silently lost across exactly the restart it needs to survive: the durable record stayed on disk while the in-memory field it drives reset to absent. loadJournal now folds each turn.end record into Server.lastTurn as it replays the journal in file order, so the last one seen for a session is, by construction, its most recent — no sequence-number bookkeeping needed. Red-first test builds a Server, drives one prompt to completion, closes it, and opens a second Server over the same session directory (simulating a process restart), asserting GET /session/{id} and /session/status still carry last_turn.
PR #55 review finding (cosmetic): the handler sets MessagePlaceholder.Role from string(m.Role) verbatim — a degraded-path fallback for a message the server couldn't even marshal — but the openapi schema constrained it to the Message.role enum [user, assistant, tool], which can drift the moment message.Role gains a variant this schema isn't updated to match, on exactly the failure path that must never itself risk being rejected by a stricter consumer. Schema only; handler behavior is unchanged.
|
Claude finished @andybons's task in 3m 53s —— View job Review: observability primitives (PR #55) — re-review after fixes
Built clean; Prior findings — confirmed resolved🔴 (blocking) case err == nil && res.Achieved:
s.recordTurnEnd(id, "completed", nil)
case err == nil && res.Reason == "goal cleared":
// cleared in flight: no turn.end (matches DELETE contract)
case err == nil:
s.recordTurnEnd(id, outcomeMaxTurnsExceeded, nil) // "max_turns_exceeded"
(minor) (cosmetic) One minor, non-blocking noteString coupling on Not an issue — just noting for context: Verdict: LGTM. The blocking finding is fully addressed with an incident-shaped, red-first test; the two minor notes are resolved; openapi tracks every surface change. Ship it. |
Three primitives from today's incident review, each converting a debugging blind spot into a self-announcing signal. Companion to the docs in #54; motivation details in each commit.
4076e6e— GET /health returnsvcs_revision/vcs_time(fromruntime/debug.ReadBuildInfo; empty when unavailable). "Is this binary stale?" becomes one curl — today that question cost a forensics dispatch.061cf69— durableturn.endrecords +last_turn: {outcome, error}on GET /session/{id} and /session/status, flowing through the /event stream like other durable records. "Idle because done" and "idle because the stream died mid-turn" are now different, queryable states — replacing the monitor heuristic of sniffing reasoning-only message tails (three silent plain-prompt deaths today).7f742d2— GET /session/{id}/message degrades per-message: an unmarshalable resident message yields a{id, role, marshal_error}placeholder instead of 500ing the entire transcript. During today's poisoning incident the transcript view died exactly when it was most needed; post-fix(message,engine): truncated ToolCall.Arguments must never poison history #52 this class shouldn't recur, but the observability layer must never again be a casualty of the thing it exists to observe.All red-first with incident-shaped tests; openapi.yaml updated for every surface change.
🤖 Generated with Claude Code
https://claude.ai/code/session_013B9pwUYhT4o8se9skmS5PP