diff --git a/internal/runner/llm_source_test.go b/internal/runner/llm_source_test.go index 1bd2a86..328ef41 100644 --- a/internal/runner/llm_source_test.go +++ b/internal/runner/llm_source_test.go @@ -752,6 +752,72 @@ func TestLLMSourceSkipsOnHTTPError(t *testing.T) { } } +// TestRunner_EveryModelCallFailingIsNotACleanRun drives the whole loop against a +// provider that answers every call with a rate limit. The picker hands back no +// action on every step, so the run observes the app, judges the same launch +// screen over and over and never touches it. Only llm-calls.jsonl used to know: +// the trace, the summary and the exit status were a healthy run's. +func TestRunner_EveryModelCallFailingIsNotACleanRun(t *testing.T) { + fake := newFakeOpenRouter(t) + fake.server.Config.Handler = http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusTooManyRequests) + }) + t.Setenv("OPENROUTER_API_KEY", "test-key") + t.Setenv("OPENROUTER_BASE_URL", fake.server.URL) + + state := newHarnessWithSpec(t, llmFixtureSpec) + state.mock.HierarchyJSON = llmTreeJSON + + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + defer cancel() + summary, err := Run(ctx, Options{ + Duration: 30 * time.Second, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 3, + Driver: state.mock, + Verifier: state.verifier, + TraceWriter: state.writer, + Generator: "llm", + LabelSource: verifier.LabelSourceVisibleText, + Logger: slog.New(slog.NewTextHandler(io.Discard, nil)), + }) + if err != nil { + t.Fatalf("Run: %v", err) + } + + calls := readLLMCalls(t, state.writer.Directory()) + if len(calls) != 3 { + t.Fatalf("recorded %d model calls, want 3", len(calls)) + } + for _, call := range calls { + if call.Outcome != trace.LLMOutcomeRequestFailed { + t.Fatalf("call at step %d ended %q, want %q: the fixture must fail every call", + call.Step, call.Outcome, trace.LLMOutcomeRequestFailed) + } + } + + if summary.DispatchedActions != 0 { + t.Fatalf("DispatchedActions = %d, want 0: every model call failed", + summary.DispatchedActions) + } + if got := summary.SkippedActions[string(actionSkippedNoActionProduced)]; got != 3 { + t.Errorf("summary counted %d step(s) as %q, want 3: %v", + got, actionSkippedNoActionProduced, summary.SkippedActions) + } + for _, line := range readTraceLines(t, state.writer.Directory()) { + if line.ActionSkipped != string(actionSkippedNoActionProduced) { + t.Errorf("step %d action_skipped = %q, want %q", + line.Step, line.ActionSkipped, actionSkippedNoActionProduced) + } + } + for _, action := range state.mock.Actions() { + switch action.Kind { + case mockdriver.ActionTap, mockdriver.ActionTapSelector, mockdriver.ActionInputText: + t.Errorf("the run drove the app with %v after every model call failed", action) + } + } +} + // llmSetupFixtureSpec drives the first action from setup, so the model is never // consulted for that step. const llmSetupFixtureSpec = ` diff --git a/internal/runner/runner.go b/internal/runner/runner.go index 7056fa6..fa8f907 100644 --- a/internal/runner/runner.go +++ b/internal/runner/runner.go @@ -75,6 +75,10 @@ type Summary struct { // all. Such a step verifies nothing, so a run that failed every observation // finishes with no violations and reads as a clean one. FailedObservations int + // DispatchedActions counts the steps whose chosen action reached the driver. + // A run at zero never touched the app, whatever its step count says, so its + // empty violation list is the reading of an instrument that measured nothing. + DispatchedActions int } type ViolationRecord struct { @@ -365,7 +369,14 @@ func Run(ctx context.Context, options Options) (Summary, error) { applySkipped := held var actionSkipped actionSkipReason - if nextErr == nil && !appIsForeground(ctx, options) { + if nextErr != nil && !held { + // The source was asked and handed nothing back. Recorded like every + // other non-action, because unrecorded it is the one that survives a + // whole run: a picker declining on all 200 steps leaves a trace, a + // summary and an exit status a run that exercised all 200 produces. + actionSkipped = actionSkippedNoActionProduced + lastAction = nil + } else if nextErr == nil && !appIsForeground(ctx, options) { // The app left the foreground between observe and apply (a prior // action's gesture settling late, or an async navigation). The // chosen action's coordinates reference a tree that no longer @@ -452,8 +463,6 @@ func Run(ctx context.Context, options Options) (Summary, error) { applied.Applied = true lastAction = &applied } - } else if !held { - lastAction = nil } // A held step leaves lastAction alone on purpose: nothing ran here, and // the action it points at is still the one the next verified step has to @@ -488,6 +497,9 @@ func Run(ctx context.Context, options Options) (Summary, error) { } summary.SkippedActions[string(actionSkipped)]++ } + if nextErr == nil && !applySkipped { + summary.DispatchedActions++ + } summary.Steps = stepIndex if len(violations) > 0 { summary.Violations = append(summary.Violations, violationRecords(violations, witnesses, stepIndex)...) @@ -1743,6 +1755,11 @@ const ( // the gesture was never dispatched. Recorded rather than counted as a // device fault: a run that acts on nothing has to say so. actionSkippedGestureUndelivered actionSkipReason = "gesture_undelivered" + // The step asked the action source for an action and was handed none: a + // generator with no candidate for this screen, or a model call that failed. + // The step then drives nothing, which is the one non-action a run can take + // on every one of its steps and still finish reporting a full step count. + actionSkippedNoActionProduced actionSkipReason = "no_action_produced" ) // maxConsecutiveApplyFailures bounds how many transient apply failures in a diff --git a/internal/runner/runner_test.go b/internal/runner/runner_test.go index 7826838..5d6e75c 100644 --- a/internal/runner/runner_test.go +++ b/internal/runner/runner_test.go @@ -57,6 +57,16 @@ globalThis.properties = { globalThis.actions = actions(() => [Tap({ on: "id:absent" })]); ` +// noActionSpec's generator offers nothing on any screen, so every step asks the +// source for an action and is handed none. +const noActionSpec = ` +import { actions, always } from "@sanderling/spec"; +globalThis.properties = { + alwaysHolds: always(() => true), +}; +globalThis.actions = actions(() => []); +` + const violationSpec = ` import { actions, always } from "@sanderling/spec"; globalThis.properties = { @@ -1429,12 +1439,101 @@ func TestRunner_DispatchedActionRecordsNoSkipReason(t *testing.T) { } } +// TestRunner_ASourceAskedAndHandedNothingSaysSo covers the run that touched the +// app zero times: every step asked the source for an action and got none, which +// is what a picker whose every model call fails does. Without a reason on the +// step the trace, the summary and the exit status of that run are the ones a run +// that exercised all three steps produces. +func TestRunner_ASourceAskedAndHandedNothingSaysSo(t *testing.T) { + state := newHarnessWithSpec(t, noActionSpec) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + summary, err := Run(ctx, Options{ + Duration: 5 * time.Second, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 3, + Driver: state.mock, + Verifier: state.verifier, + TraceWriter: state.writer, + }) + if err != nil { + t.Fatalf("Run: %v", err) + } + if summary.Steps != 3 { + t.Fatalf("Steps = %d, want 3", summary.Steps) + } + if summary.DispatchedActions != 0 { + t.Fatalf("DispatchedActions = %d, want 0: the fixture offers no action to dispatch", + summary.DispatchedActions) + } + if got := summary.SkippedActions[string(actionSkippedNoActionProduced)]; got != 3 { + t.Errorf("summary counted %d step(s) as %q, want 3: %v", + got, actionSkippedNoActionProduced, summary.SkippedActions) + } + for _, line := range readTraceLines(t, state.writer.Directory()) { + if line.NextAction != nil { + t.Errorf("step %d carries a next_action the source never produced", line.Step) + } + if line.ActionSkipped != string(actionSkippedNoActionProduced) { + t.Errorf("step %d action_skipped = %q, want %q", + line.Step, line.ActionSkipped, actionSkippedNoActionProduced) + } + if line.SkippedVerification { + t.Errorf("step %d reads as held; the source was asked on it", line.Step) + } + } + var rendered bytes.Buffer + RenderSummary(&rendered, summary, "android") + if !strings.Contains(rendered.String(), "3 action(s) never reached the app") { + t.Errorf("the run reports as a clean one:\n%s", rendered.String()) + } +} + +// The other half: a held step never asked the source for anything, so it must +// stay distinguishable from one that asked and was handed nothing. The fixture +// here has an action to offer, and no step of this run gets to hear it. +func TestRunner_AHeldStepIsNotRecordedAsASourceThatDeclined(t *testing.T) { + state := newHarness(t) + state.mock.Failures[mockdriver.ActionSnapshot] = errors.New("adb: device offline") + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + summary, err := Run(ctx, Options{ + Duration: 5 * time.Second, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 3, + Driver: state.mock, + Verifier: state.verifier, + TraceWriter: state.writer, + }) + if err != nil { + t.Fatalf("Run: %v", err) + } + if summary.SkippedVerification != 3 { + t.Fatalf("SkippedVerification = %d, want 3", summary.SkippedVerification) + } + if len(summary.SkippedActions) != 0 { + t.Errorf("held steps counted as skipped actions: %v", summary.SkippedActions) + } + for _, line := range readTraceLines(t, state.writer.Directory()) { + if !line.SkippedVerification { + t.Errorf("step %d was not recorded as held", line.Step) + } + if line.ActionSkipped != "" { + t.Errorf("step %d action_skipped = %q; the source was never asked", + line.Step, line.ActionSkipped) + } + } +} + type traceStepLine struct { - Step int `json:"step"` - NextAction *trace.Action `json:"next_action"` - ActionSkipped string `json:"action_skipped"` - Transitional bool `json:"transitional"` - ObservationError string `json:"observation_error"` + Step int `json:"step"` + NextAction *trace.Action `json:"next_action"` + ActionSkipped string `json:"action_skipped"` + Transitional bool `json:"transitional"` + ObservationError string `json:"observation_error"` + SkippedVerification bool `json:"skipped_verification"` } func readTraceLines(t *testing.T, directory string) []traceStepLine { diff --git a/internal/runner/testdata/violation-summary.txt b/internal/runner/testdata/violation-summary.txt index f042d62..4a4c2ae 100644 --- a/internal/runner/testdata/violation-summary.txt +++ b/internal/runner/testdata/violation-summary.txt @@ -2,3 +2,4 @@ run complete: 4 steps 1 violation record(s): step 1: [balanceNonNegative] +4 action(s) never reached the app: no_action_produced 4 diff --git a/internal/trace/writer.go b/internal/trace/writer.go index 2d1cdd0..066920c 100644 --- a/internal/trace/writer.go +++ b/internal/trace/writer.go @@ -48,9 +48,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 names why this step dispatched nothing: an action chosen and + // then thrown away, or a source that was asked and produced none. A count of + // executed actions cannot be inflated by either. Empty when the action ran, + // and empty on a held step, which never asked for one. ActionSkipped string `json:"action_skipped,omitempty"` // ObservationError names why this step's device read produced no tree, // empty when a tree was read. A screen with no elements on it is a tree,