feat(trace): record one typed outcome per model-driven step

llm-calls.jsonl carries the prompts as sent, the candidate list as the model
saw it, the screenshot reference, the raw response, tokens, latency and how the
step ended. It sits beside trace.jsonl rather than inside it because every trace
line already carries a full hierarchy and both the replay server and the
campaign summarizer scan all of them; folding prompts in would grow the lines
those readers parse for data neither reads.

Claude-Session: https://claude.ai/code/session_01A5KmftdEJ49A9z5mF5ESrX
This commit is contained in:
pj committed 2026-08-12 22:56:58 +05:30
1 parent b9cdf7a571
commit ec5872ac6e
3 files changed
+293 -4

No files matched your search

+129
View File
@@ -0,0 +1,129 @@
package trace
import (
"encoding/json"
"fmt"
"os"
"path/filepath"
"time"
)
// LLMCallFileName is the run-directory file model-call records are appended to,
// one JSON object per line, in step order.
//
// These records live beside trace.jsonl rather than inside it because the two
// have different readers. Every trace line already carries a full accessibility
// hierarchy, and both the replay server and the campaign summarizer scan every
// line of it; folding prompts, candidate lists and raw responses in would grow
// the lines those readers parse by several KB each for data neither one reads.
// The join is by Step, which is the step field of the trace line whose
// next_action the call produced.
const LLMCallFileName = "llm-calls.jsonl"
// Outcomes of one step's action selection. Exactly one is recorded per step of
// a model-driven run, so a step the guard threw away is never confused with one
// where the picker legitimately had nothing to do.
const (
// LLMOutcomeSelected: the model picked a candidate and the action ran.
LLMOutcomeSelected = "selected"
// LLMOutcomeSetupAction: the spec's setup generator drove the step, so the
// model was not consulted.
LLMOutcomeSetupAction = "setup_action"
// LLMOutcomeSetupFailed: the setup generator itself errored, which aborts
// the run.
LLMOutcomeSetupFailed = "setup_failed"
// LLMOutcomeNoCandidates: the action tree yielded nothing on this screen, so
// no call was made.
LLMOutcomeNoCandidates = "no_candidates"
// LLMOutcomeRequestFailed: the provider call failed (transport, timeout,
// non-2xx).
LLMOutcomeRequestFailed = "request_failed"
// LLMOutcomeNoChoices: a 2xx response carrying an empty choices array.
LLMOutcomeNoChoices = "no_choices"
// LLMOutcomeUnparsableResponse: the content was empty, not JSON, or carried
// no choice.
LLMOutcomeUnparsableResponse = "unparsable_response"
// LLMOutcomeChoiceOutOfRange: the number picked is not in 1..len(candidates).
LLMOutcomeChoiceOutOfRange = "choice_out_of_range"
// LLMOutcomeEchoMismatch: the echoed chosen_action disagrees with the
// numbered entry, so the pick is discarded.
LLMOutcomeEchoMismatch = "echo_mismatch"
// LLMOutcomeActionBuildFailed: the chosen candidate could not be turned into
// an executable action (e.g. the input sampler was unavailable).
LLMOutcomeActionBuildFailed = "action_build_failed"
)
// LLMCall is one step's action-selection record: what was sent, what came back,
// what it cost, and how the step ended.
type LLMCall struct {
// Step joins this record to the trace line of the same step index.
Step int `json:"step"`
Timestamp time.Time `json:"timestamp"`
Outcome string `json:"outcome"`
// Model is the requested model id; ServedModel is the one the provider
// reported serving, which a router may vary per call.
Model string `json:"model,omitempty"`
ServedModel string `json:"served_model,omitempty"`
// SystemPrompt and UserPrompt are the text parts as sent, not the templates
// they were assembled from.
SystemPrompt string `json:"system_prompt,omitempty"`
UserPrompt string `json:"user_prompt,omitempty"`
// Candidates is the numbered list the prompt rendered, so an experiment that
// varies candidate labelling can recover the labels this call actually saw.
Candidates []LLMCandidate `json:"candidates,omitempty"`
// Screenshot is the run-relative path of the image sent with the call. It
// names the step the image was captured at, which lags Step when the runner
// skipped a transitional observation.
Screenshot string `json:"screenshot,omitempty"`
// RawResponse is the assistant content before parsing.
RawResponse string `json:"raw_response,omitempty"`
PromptTokens int `json:"prompt_tokens,omitempty"`
CompletionTokens int `json:"completion_tokens,omitempty"`
TotalTokens int `json:"total_tokens,omitempty"`
LatencyMillis int64 `json:"latency_millis,omitempty"`
// Choice, EchoedAction and Reasoning are the parsed output, recorded
// whenever parsing succeeded and so present on the outcomes that then
// discarded the pick. EchoedAction is verbatim, including the weight
// annotation models copy along with the line; on an echo_mismatch it is what
// disagreed with Candidates[Choice-1].
Choice int `json:"choice,omitempty"`
EchoedAction string `json:"echoed_action,omitempty"`
Reasoning string `json:"reasoning,omitempty"`
Error string `json:"error,omitempty"`
}
// LLMCandidate is one numbered line of the candidate list as the model saw it.
type LLMCandidate struct {
Index int `json:"index"`
Kind string `json:"kind,omitempty"`
// Description is the rendered line the model echoes back; Label is the
// target's visible text the description was built from.
Description string `json:"description"`
Label string `json:"label,omitempty"`
// Weight is the percentage annotation shown on the line, 0 when the spec's
// action tree declared no weights and none was shown.
Weight int `json:"weight,omitempty"`
}
// WriteLLMCall appends one record to llm-calls.jsonl, creating the file on the
// first call.
func (w *Writer) WriteLLMCall(call LLMCall) error {
w.mutex.Lock()
defer w.mutex.Unlock()
if w.file == nil {
return fmt.Errorf("trace: writer is closed")
}
if w.llmCallEncoder == nil {
file, err := os.OpenFile(
filepath.Join(w.directory, LLMCallFileName),
os.O_CREATE|os.O_WRONLY|os.O_APPEND,
0o644,
)
if err != nil {
return fmt.Errorf("open %s: %w", LLMCallFileName, err)
}
w.llmCallFile = file
w.llmCallEncoder = json.NewEncoder(file)
}
return w.llmCallEncoder.Encode(call)
}
+131
View File
@@ -0,0 +1,131 @@
package trace
import (
"encoding/json"
"os"
"path/filepath"
"reflect"
"strings"
"testing"
"time"
)
func TestWriteLLMCall_RoundTrip(t *testing.T) {
directory := t.TempDir()
writer, err := NewWriter(directory)
if err != nil {
t.Fatal(err)
}
call := LLMCall{
Step: 4,
Timestamp: time.Date(2026, 8, 12, 9, 30, 0, 0, time.UTC),
Outcome: LLMOutcomeSelected,
Model: "vendor/model",
ServedModel: "vendor/model-2026-05",
SystemPrompt: "You are exercising a UI to find bugs.\n\n" +
"hunt for double submits",
UserPrompt: "Actions available on the current screen:\n1. Tap \"Submit\" (w60)\n",
Candidates: []LLMCandidate{
{Index: 1, Kind: "tap", Description: `Tap "Submit"`, Label: "Submit", Weight: 60},
{Index: 2, Kind: "inputText", Description: `Type into "Name"`, Label: "Name", Weight: 40},
},
Screenshot: ScreenshotReference(4),
RawResponse: `{"reasoning":"submit twice","choice":1,"chosen_action":"Tap \"Submit\"","text":""}`,
PromptTokens: 1200,
CompletionTokens: 34,
TotalTokens: 1234,
LatencyMillis: 812,
Choice: 1,
EchoedAction: `Tap "Submit"`,
Reasoning: "submit twice",
}
if err := writer.WriteLLMCall(call); err != nil {
t.Fatal(err)
}
if err := writer.WriteLLMCall(LLMCall{
Step: 5,
Timestamp: call.Timestamp.Add(time.Second),
Outcome: LLMOutcomeNoCandidates,
}); err != nil {
t.Fatal(err)
}
if err := writer.Close(); err != nil {
t.Fatal(err)
}
body, err := os.ReadFile(filepath.Join(directory, LLMCallFileName))
if err != nil {
t.Fatal(err)
}
lines := strings.Split(strings.TrimSpace(string(body)), "\n")
if len(lines) != 2 {
t.Fatalf("wrote %d lines, want 2", len(lines))
}
var got LLMCall
if err := json.Unmarshal([]byte(lines[0]), &got); err != nil {
t.Fatalf("%s line 1 is not valid JSON: %v", LLMCallFileName, err)
}
if !reflect.DeepEqual(got, call) {
t.Errorf("round-trip mismatch:\n got: %+v\nwant: %+v", got, call)
}
var declined LLMCall
if err := json.Unmarshal([]byte(lines[1]), &declined); err != nil {
t.Fatal(err)
}
if declined.Step != 5 || declined.Outcome != LLMOutcomeNoCandidates {
t.Errorf("second record = %+v, want step 5 with outcome %q", declined, LLMOutcomeNoCandidates)
}
}
// TestWriteLLMCall_FileAbsentWithoutCalls keeps a seeded run's directory free of
// model-call output, so its presence alone identifies a model-driven run.
func TestWriteLLMCall_FileAbsentWithoutCalls(t *testing.T) {
directory := t.TempDir()
writer, err := NewWriter(directory)
if err != nil {
t.Fatal(err)
}
if err := writer.WriteStep(Step{Index: 1, Timestamp: time.Now()}); err != nil {
t.Fatal(err)
}
if err := writer.Close(); err != nil {
t.Fatal(err)
}
if _, err := os.Stat(filepath.Join(directory, LLMCallFileName)); !os.IsNotExist(err) {
t.Errorf("stat %s = %v, want the file never to be created", LLMCallFileName, err)
}
}
// TestScreenshotReferenceMatchesWrittenFile pins the reference records point at
// to the path WriteScreenshot actually writes.
func TestScreenshotReferenceMatchesWrittenFile(t *testing.T) {
directory := t.TempDir()
writer, err := NewWriter(directory)
if err != nil {
t.Fatal(err)
}
defer writer.Close()
if err := writer.WriteScreenshot(12, []byte("not really a png")); err != nil {
t.Fatal(err)
}
if _, err := os.Stat(filepath.Join(directory, ScreenshotReference(12))); err != nil {
t.Errorf("stat %s: %v", ScreenshotReference(12), err)
}
}
func TestWriteLLMCall_AfterCloseErrors(t *testing.T) {
directory := t.TempDir()
writer, err := NewWriter(directory)
if err != nil {
t.Fatal(err)
}
if err := writer.Close(); err != nil {
t.Fatal(err)
}
if err := writer.WriteLLMCall(LLMCall{Step: 1}); err == nil {
t.Error("expected an error writing to a closed writer")
}
}
+33 -4
View File
@@ -31,6 +31,10 @@ type Step struct {
// retry budget. The verifier is skipped for these steps so transient
// state does not poison the previous/current extractor advance.
Transitional bool `json:"transitional,omitempty"`
// ActionSkipped names why NextAction was chosen but never dispatched, so a
// count of executed actions cannot be inflated by steps whose action the
// runner threw away. Empty when the action ran (or when none was chosen).
ActionSkipped string `json:"action_skipped,omitempty"`
// SkippedVerification is set true exactly when the verifier was skipped
// for this step, so downstream tooling can tell a deliberately-skipped
// step from one that was verified and came back clean.
@@ -151,6 +155,10 @@ type Writer struct {
mutex sync.Mutex
file io.WriteCloser
encoder *json.Encoder
// llmCallFile is opened on the first WriteLLMCall, so a run whose picker
// never called a model leaves no llm-calls.jsonl behind at all.
llmCallFile io.WriteCloser
llmCallEncoder *json.Encoder
}
// NewWriter ensures `directory` exists and opens trace.jsonl for append.
@@ -194,14 +202,27 @@ func (w *Writer) WriteStep(step Step) error {
// file via os.WriteFile and touches no field of Writer, so concurrent calls
// never contend.
func (w *Writer) WriteScreenshot(stepIndex int, png []byte) error {
return w.writePNG(fmt.Sprintf("step-%05d.png", stepIndex), png)
return w.writePNG(screenshotName(stepIndex), png)
}
func screenshotName(stepIndex int) string {
return fmt.Sprintf("step-%05d.png", stepIndex)
}
// ScreenshotReference is the run-relative path WriteScreenshot puts a step's
// screenshot at. Records that describe an image point at it instead of copying
// the bytes.
func ScreenshotReference(stepIndex int) string {
return screenshotDirectory + "/" + screenshotName(stepIndex)
}
const screenshotDirectory = "screenshots"
func (w *Writer) writePNG(name string, png []byte) error {
if len(png) == 0 {
return nil
}
directory := filepath.Join(w.directory, "screenshots")
directory := filepath.Join(w.directory, screenshotDirectory)
if err := os.MkdirAll(directory, 0o755); err != nil {
return fmt.Errorf("mkdir screenshots: %w", err)
}
@@ -211,10 +232,18 @@ func (w *Writer) writePNG(name string, png []byte) error {
func (w *Writer) Close() error {
w.mutex.Lock()
defer w.mutex.Unlock()
var err error
if w.llmCallFile != nil {
err = w.llmCallFile.Close()
w.llmCallFile = nil
w.llmCallEncoder = nil
}
if w.file == nil {
return nil
return err
}
if closeErr := w.file.Close(); closeErr != nil {
err = closeErr
}
err := w.file.Close()
w.file = nil
return err
}