From 226f5805aa4de5319b9a05d1a6bfff378c4d05cc Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:37:52 +0530 Subject: [PATCH 01/10] feat(spec): let the runner install state.logs in the page Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- pkg/spec/src/web-runtime.ts | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/pkg/spec/src/web-runtime.ts b/pkg/spec/src/web-runtime.ts index a607758..c28f4aa 100644 --- a/pkg/spec/src/web-runtime.ts +++ b/pkg/spec/src/web-runtime.ts @@ -445,6 +445,15 @@ if (typeof globalThis.addEventListener === "function") { // that reads state.lastAction vacuously true on web. let lastAction: unknown = null; +// logs is what the driver captured between the previous step and this one, +// pushed in by the Go runner (via __sanderlingSetLogs__) before each extractor +// evaluation, in the shape internal/verifier/marshal.go builds for goja. The +// page cannot derive it: console output reaches the runner over CDP and nothing +// in the page reads it back. Hardcoding [] here, as this file used to, makes +// every spec property that reads state.logs vacuously true on web, the default +// noLogcatErrors included, because the page's reading is the one that wins. +let logs: unknown[] = []; + function buildState(): unknown { return { snapshots: {}, @@ -453,7 +462,7 @@ function buildState(): unknown { window, lastAction, time: 0, - logs: [], + logs, exceptions: capturedExceptions.slice(), }; } @@ -502,6 +511,11 @@ defineLockedGlobal("__sanderlingSetLastAction__", (value: unknown) => { lastAction = value ?? null; }); +// The host calls this once per step too, alongside __sanderlingSetLastAction__. +defineLockedGlobal("__sanderlingSetLogs__", (value: unknown) => { + logs = Array.isArray(value) ? value : []; +}); + // writable:false stops a page script from shadowing the runtime via plain // assignment (the realistic in-page threat). configurable:true is required so // unit tests sharing one process can reinstall a fake via defineProperty; a From e18dafeba96bb3976b7a2699fbedc268e27baeda Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:38:42 +0530 Subject: [PATCH 02/10] feat(verifier): encode state.logs for the web host Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/verifier/marshal.go | 37 ++++++++++++++++++++---- internal/verifier/marshal_test.go | 47 +++++++++++++++++++++++++++++++ 2 files changed, 78 insertions(+), 6 deletions(-) diff --git a/internal/verifier/marshal.go b/internal/verifier/marshal.go index 18b2ac6..31c9e99 100644 --- a/internal/verifier/marshal.go +++ b/internal/verifier/marshal.go @@ -468,19 +468,44 @@ func runtimeMillis(stepTime, runStart time.Time) int64 { return stepTime.Sub(runStart).Milliseconds() } +// logFields is the ONE description of a state.logs entry, for the same reason +// lastActionFields is: the goja host turns it into a JS object (logsArray) and +// the web host receives the same fields as JSON (EncodeLogs), so a property +// counting error-level lines cannot read one shape on native and another on web. +func logFields(entry LogEntry) []actionField { + return []actionField{ + {key: "unixMillis", value: entry.UnixMillis}, + {key: "level", value: entry.Level}, + {key: "tag", value: entry.Tag}, + {key: "message", value: entry.Message}, + } +} + func logsArray(runtime *goja.Runtime, logs []LogEntry) *goja.Object { array := runtime.NewArray() for index, entry := range logs { - item := runtime.NewObject() - _ = item.Set("unixMillis", entry.UnixMillis) - _ = item.Set("level", entry.Level) - _ = item.Set("tag", entry.Tag) - _ = item.Set("message", entry.Message) - _ = array.Set(fmt.Sprintf("%d", index), item) + _ = array.Set(fmt.Sprintf("%d", index), objectFromFields(runtime, logFields(entry))) } return array } +// EncodeLogs renders this step's log entries for the web host, which has no +// Go-side state object to read: the runner pushes this JSON into the page +// before each extractor evaluation. No entries encodes as an empty array, the +// same value the goja host reports for a step whose log fetch found nothing. +func EncodeLogs(logs []LogEntry) json.RawMessage { + var buffer bytes.Buffer + buffer.WriteByte('[') + for index, entry := range logs { + if index > 0 { + buffer.WriteByte(',') + } + buffer.Write(encodeFields(logFields(entry))) + } + buffer.WriteByte(']') + return buffer.Bytes() +} + func exceptionsArray(runtime *goja.Runtime, exceptions []Exception) *goja.Object { array := runtime.NewArray() for index, exception := range exceptions { diff --git a/internal/verifier/marshal_test.go b/internal/verifier/marshal_test.go index b3a1a56..942aec0 100644 --- a/internal/verifier/marshal_test.go +++ b/internal/verifier/marshal_test.go @@ -282,3 +282,50 @@ func TestLastAction_ReportsARelaunchSeparatelyFromTheDispatch(t *testing.T) { }) } } + +// TestLogs_WebJSONMatchesTheGojaObject pins state.logs to ONE shape across the +// two hosts, for the same reason lastAction is pinned. On web the page's +// reading of every extractor replaces the host's, so state.logs is whatever +// EncodeLogs put in the page: a field this side renames or cases differently +// leaves the default noLogcatErrors counting nothing on web while it counts on +// native, with nothing reporting that it never saw an entry. +func TestLogs_WebJSONMatchesTheGojaObject(t *testing.T) { + verifier := newVerifier(t) + mustLoad(t, verifier, ` + globalThis.lines = __sanderling__.extract(state => JSON.stringify(state.logs)); + `) + + for _, testCase := range []struct { + name string + logs []LogEntry + }{ + {"none", nil}, + {"empty", []LogEntry{}}, + { + "one error", + []LogEntry{{UnixMillis: 1700000000123, Level: "E", Tag: "console", Message: "boom from the page"}}, + }, + { + "mixed levels", + []LogEntry{ + {UnixMillis: 1, Level: "E", Tag: "console", Message: `say "hi" & co`}, + {UnixMillis: 2, Level: "W", Tag: "AndroidRuntime", Message: "a warning"}, + }, + }, + } { + t.Run(testCase.name, func(t *testing.T) { + if err := verifier.PushSnapshot(SnapshotInput{ + Snapshots: Snapshots{}, + Logs: testCase.logs, + }); err != nil { + t.Fatal(err) + } + handle := verifier.runtime.GlobalObject().Get("lines").ToObject(verifier.runtime) + goja := handle.Get("current").String() + web := string(EncodeLogs(testCase.logs)) + if goja != web { + t.Errorf("the two hosts disagree on state.logs\n goja: %s\n web: %s", goja, web) + } + }) + } +} From 6d72410f559b128e67ba088142aa4dbd26403d3c Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:39:17 +0530 Subject: [PATCH 03/10] feat(chrome): install the step's logs in the page Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/driver/chrome/driver.go | 24 ++++++++++++++ internal/driver/chrome/driver_test.go | 48 +++++++++++++++++++++++++++ 2 files changed, 72 insertions(+) diff --git a/internal/driver/chrome/driver.go b/internal/driver/chrome/driver.go index db51c01..06914bd 100644 --- a/internal/driver/chrome/driver.go +++ b/internal/driver/chrome/driver.go @@ -887,6 +887,30 @@ func (d *Driver) SetLastAction(ctx context.Context, encoded json.RawMessage) err return nil } +// SetLogs installs the entries this step's log fetch returned as state.logs +// inside the page runtime. The page cannot derive them: console output reaches +// the driver over CDP and nothing in the page reads it back. Without this call +// every web state.logs is empty, and since the page's reading of an extractor +// replaces the host's, the default noLogcatErrors then reports green on a run +// whose console was full of errors. +// +// Unguarded for the same reason as SetLastAction: on a page with no setter, +// "the page cannot accept logs" has to fail the run rather than be reported as +// a successful install. +func (d *Driver) SetLogs(ctx context.Context, encoded json.RawMessage) error { + payload := strings.TrimSpace(string(encoded)) + if payload == "" { + payload = "[]" + } + script := fmt.Sprintf(`window.__sanderlingSetLogs__(%s)`, payload) + runCtx, cancel := d.runCtx(ctx) + defer cancel() + if err := chromedp.Run(runCtx, chromedp.Evaluate(script, nil)); err != nil { + return fmt.Errorf("set logs: %w", err) + } + return nil +} + // extractorScript resolves the extractor table once the page is not mid route // transition, giving up on that wait after %d ms. // diff --git a/internal/driver/chrome/driver_test.go b/internal/driver/chrome/driver_test.go index 36ef3fb..a0708a4 100644 --- a/internal/driver/chrome/driver_test.go +++ b/internal/driver/chrome/driver_test.go @@ -860,6 +860,54 @@ func TestSetLastAction_ReportsAPageThatCannotTakeIt(t *testing.T) { } } +// TestSetLogs_ReportsAPageThatCannotTakeThem is the same install on the channel +// the log properties hang off. The driver holding a console error changes +// nothing on web: the page's reading of every extractor replaces the host's, so +// unless the entries are put back into the page, noLogcatErrors counts an empty +// array and stays green through a run full of errors. +func TestSetLogs_ReportsAPageThatCannotTakeThem(t *testing.T) { + const withSetter = `` + const withoutSetter = `
no sanderling runtime here
` + pages := map[string]string{"/with": withSetter, "/without": withoutSetter} + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "text/html") + _, _ = w.Write([]byte(pages[r.URL.Path])) + })) + defer server.Close() + + d := New() + defer d.Terminate(context.Background()) + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + defer cancel() + + if err := d.Launch(ctx, server.URL+"/with", false, nil); err != nil { + t.Fatalf("Launch: %v", err) + } + logs := json.RawMessage(`[{"unixMillis":1,"level":"E","tag":"console","message":"boom"}]`) + if err := d.SetLogs(ctx, logs); err != nil { + t.Fatalf("SetLogs on a page that defines the setter: %v", err) + } + var seen []map[string]any + if err := chromedp.Run(d.tabCtx, + chromedp.Evaluate(`window.__logsSeen`, &seen)); err != nil { + t.Fatalf("read installed logs: %v", err) + } + if len(seen) != 1 || seen[0]["level"] != "E" || seen[0]["message"] != "boom" { + t.Errorf("the page received %v, want the error-level entry the driver captured", seen) + } + + if err := d.Launch(ctx, server.URL+"/without", false, nil); err != nil { + t.Fatalf("Launch: %v", err) + } + if err := d.SetLogs(ctx, logs); err == nil { + t.Error("SetLogs reported success on a page with no setter; " + + "a runtime that cannot take the step's logs is indistinguishable from one that did") + } +} + // TestEvaluateExtractors_ReportsAMissingTable is the same failure on the other // sampler. An empty override map is what a spec with no extractors returns, so // treating a missing table as {} makes "this page has no sanderling runtime" From 3dfd5df5115027ffa15d73e6c71fb25a5a6f662e Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:41:06 +0530 Subject: [PATCH 04/10] test(runner): teach the web fakes to take the step's logs Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/runner/web_carrier_test.go | 4 ++++ internal/runner/web_extractor_trace_test.go | 2 ++ internal/runner/web_last_action_test.go | 8 +++++++- 3 files changed, 13 insertions(+), 1 deletion(-) diff --git a/internal/runner/web_carrier_test.go b/internal/runner/web_carrier_test.go index c5cb169..96b5f9d 100644 --- a/internal/runner/web_carrier_test.go +++ b/internal/runner/web_carrier_test.go @@ -75,6 +75,8 @@ func (d *carrierWebDriver) NextActionFromV8(context.Context) (json.RawMessage, e func (d *carrierWebDriver) SetLastAction(context.Context, json.RawMessage) error { return nil } +func (d *carrierWebDriver) SetLogs(context.Context, json.RawMessage) error { return nil } + // TestRunner_TransitionalStepNeverAdvancesThePageCarrier pins the ordering the // web path depends on. The page-side extractors must run only on steps the // verifier accepts: their getters advance spec state every time they evaluate, @@ -172,6 +174,8 @@ func (d *installFailsWebDriver) SetLastAction(context.Context, json.RawMessage) return errors.New("__sanderlingSetLastAction__ is not a function") } +func (d *installFailsWebDriver) SetLogs(context.Context, json.RawMessage) error { return nil } + // TestRunner_LastActionInstallFailureFailsTheRun covers the other half of the // same trust boundary. A run that cannot install lastAction in the page cannot // apply the page's extractor values either, so the step keeps goja's diff --git a/internal/runner/web_extractor_trace_test.go b/internal/runner/web_extractor_trace_test.go index b31733e..d2c54e4 100644 --- a/internal/runner/web_extractor_trace_test.go +++ b/internal/runner/web_extractor_trace_test.go @@ -47,6 +47,8 @@ func (d *webMockDriver) NextActionFromV8(context.Context) (json.RawMessage, erro func (d *webMockDriver) SetLastAction(context.Context, json.RawMessage) error { return nil } +func (d *webMockDriver) SetLogs(context.Context, json.RawMessage) error { return nil } + // TestRunner_TraceRecordsTheValueTheVerdictUsed fails if the trace and the // verdict disagree about an extractor. A witness is only an explanation of a // violation if it holds the state the violated property was evaluated against. diff --git a/internal/runner/web_last_action_test.go b/internal/runner/web_last_action_test.go index 10ce20e..a50c706 100644 --- a/internal/runner/web_last_action_test.go +++ b/internal/runner/web_last_action_test.go @@ -26,7 +26,8 @@ globalThis.properties = {}; // control, so the runner has a real applied action to report on the next step. type tappingWebDriver struct { *mockdriver.Driver - installed []string + installed []string + installedLogs []string } func (d *tappingWebDriver) InstallBundle(context.Context, []byte) error { return nil } @@ -44,6 +45,11 @@ func (d *tappingWebDriver) SetLastAction(_ context.Context, encoded json.RawMess return nil } +func (d *tappingWebDriver) SetLogs(_ context.Context, encoded json.RawMessage) error { + d.installedLogs = append(d.installedLogs, string(encoded)) + return nil +} + func TestRunner_WebInstallsLastActionInThePage(t *testing.T) { state := newHarnessWithSpec(t, lastActionSpec) web := &tappingWebDriver{Driver: state.mock} From 78d57bf94fee1c45df99d627f7c6d8c8ee17d62b Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:41:10 +0530 Subject: [PATCH 05/10] fix(runner): install the step's logs before the page extracts On web every extractor reading is replaced by the one the page computed, and the page answered logs: [], so noLogcatErrors counted an empty array however full of errors the console was. Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/runner/runner.go | 7 ++++--- internal/runner/source.go | 42 +++++++++++++++++++++++++++++---------- 2 files changed, 35 insertions(+), 14 deletions(-) diff --git a/internal/runner/runner.go b/internal/runner/runner.go index 478907c..5496da9 100644 --- a/internal/runner/runner.go +++ b/internal/runner/runner.go @@ -222,9 +222,10 @@ func Run(ctx context.Context, options Options) (Summary, error) { // behind the hierarchy fetch; the fetch is what decides whether this // step counts at all, so it has to go first. // - // lastAction is the same value PushSnapshot hands the goja state - // below: the two engines evaluate this step against one action. - v8Overrides, overridesErr := extractorSource.ExtractorOverrides(ctx, lastAction) + // lastAction and logs are the same values PushSnapshot hands the + // goja state below: the two engines evaluate this step against one + // action and one set of log entries. + v8Overrides, overridesErr := extractorSource.ExtractorOverrides(ctx, lastAction, logs) if overridesErr != nil { // Not a warning. Without the page's values this step's // extractors keep goja's dump-derived readings while the diff --git a/internal/runner/source.go b/internal/runner/source.go index 513a8ab..f8f4c66 100644 --- a/internal/runner/source.go +++ b/internal/runner/source.go @@ -24,14 +24,15 @@ type ActionSource interface { // PushSnapshot. The mobile path has none (returns nil); the web path returns the // values its extractors computed in V8 against the real DOM. // -// lastAction is the action the previous step actually applied, the same value -// PushSnapshot hands the goja state. The web path has to install it in the page -// before its extractors run: a spec extractor reading state.lastAction runs in -// V8 there, and V8 has no way to know what the runner dispatched. +// lastAction and logs are what PushSnapshot hands the goja state. The web path +// has to install both in the page before its extractors run: a spec extractor +// reading state.lastAction or state.logs runs in V8 there, and V8 knows neither +// what the runner dispatched nor what the driver's log fetch returned. type ExtractorSource interface { ExtractorOverrides( ctx context.Context, lastAction *verifier.Action, + logs []verifier.LogEntry, ) (map[int]json.RawMessage, error) } @@ -42,6 +43,13 @@ type lastActionInstaller interface { SetLastAction(ctx context.Context, encoded json.RawMessage) error } +// logInstaller is the same channel for the entries this step's log fetch +// returned. Console output reaches the driver over CDP, so the page can only +// learn about it from the runner. +type logInstaller interface { + SetLogs(ctx context.Context, encoded json.RawMessage) error +} + // gojaSource drives both action selection and (trivially) extractor overrides // for the mobile path, where the goja-bundled picker runs in-process and no V8 // extractor values exist. @@ -56,6 +64,7 @@ func (s gojaSource) NextAction(context.Context) (verifier.Action, error) { func (gojaSource) ExtractorOverrides( context.Context, *verifier.Action, + []verifier.LogEntry, ) (map[int]json.RawMessage, error) { return nil, nil } @@ -77,24 +86,35 @@ func (s webSource) NextAction(ctx context.Context) (verifier.Action, error) { return verifier.DecodeAction(raw) } -// ExtractorOverrides installs the previous step's action in the page, then -// reads back what the spec's extractors computed against the live DOM. The -// install is not best-effort: a web driver that cannot take it leaves -// state.lastAction null in V8, which silently turns every action-gated -// property vacuously true, so it is reported as an error instead. +// ExtractorOverrides installs the previous step's action and this step's log +// entries in the page, then reads back what the spec's extractors computed +// against the live DOM. Neither install is best-effort: a web driver that +// cannot take them leaves state.lastAction null and state.logs empty in V8, +// which silently turns every action-gated property and every log property +// vacuously true, so both are reported as errors instead. func (s webSource) ExtractorOverrides( ctx context.Context, lastAction *verifier.Action, + logs []verifier.LogEntry, ) (map[int]json.RawMessage, error) { - installer, ok := s.web.(lastActionInstaller) + actions, ok := s.web.(lastActionInstaller) if !ok { return nil, fmt.Errorf( "web driver %T cannot install state.lastAction; every property gated "+ "on the last action would be vacuously true", s.web) } - if err := installer.SetLastAction(ctx, verifier.EncodeLastAction(lastAction)); err != nil { + if err := actions.SetLastAction(ctx, verifier.EncodeLastAction(lastAction)); err != nil { return nil, fmt.Errorf("install last action: %w", err) } + entries, ok := s.web.(logInstaller) + if !ok { + return nil, fmt.Errorf( + "web driver %T cannot install state.logs; every property reading the "+ + "log stream would be vacuously true", s.web) + } + if err := entries.SetLogs(ctx, verifier.EncodeLogs(logs)); err != nil { + return nil, fmt.Errorf("install logs: %w", err) + } return s.web.EvaluateExtractors(ctx) } From cbf2c313ec749ef51f7e2ce67adcef1c89db8fce Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:42:16 +0530 Subject: [PATCH 06/10] test(runner): cover the logs reaching the page and failing to Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/runner/web_carrier_test.go | 46 +++++++++++++++++++++++++ internal/runner/web_last_action_test.go | 37 ++++++++++++++++++++ 2 files changed, 83 insertions(+) diff --git a/internal/runner/web_carrier_test.go b/internal/runner/web_carrier_test.go index 96b5f9d..e47a8fb 100644 --- a/internal/runner/web_carrier_test.go +++ b/internal/runner/web_carrier_test.go @@ -204,3 +204,49 @@ func TestRunner_LastActionInstallFailureFailsTheRun(t *testing.T) { t.Errorf("Run error = %v, want it to name the failed lastAction install", err) } } + +// logInstallFailsWebDriver takes lastAction and refuses the logs, the shape a +// page carrying an older published @sanderling/spec runtime has: it knows the +// action setter and not the log one. +type logInstallFailsWebDriver struct { + *installFailsWebDriver +} + +func (d *logInstallFailsWebDriver) SetLastAction(context.Context, json.RawMessage) error { + return nil +} + +func (d *logInstallFailsWebDriver) SetLogs(context.Context, json.RawMessage) error { + return errors.New("__sanderlingSetLogs__ is not a function") +} + +// TestRunner_LogInstallFailureFailsTheRun holds the log channel to the same +// standard as the action one. The driver having the console errors decides +// nothing on web: the page's reading of every extractor replaces the host's, so +// a run that cannot put the entries back into the page evaluates noLogcatErrors +// against an empty array and reports green on a console full of errors. +// Continuing past this is the vacuity the whole install exists to prevent. +func TestRunner_LogInstallFailureFailsTheRun(t *testing.T) { + state := newHarnessWithSpec(t, carrierSpec) + web := &logInstallFailsWebDriver{ + installFailsWebDriver: &installFailsWebDriver{Driver: state.mock}, + } + + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + _, err := Run(ctx, Options{ + Duration: 2 * time.Second, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 3, + Driver: web, + Verifier: state.verifier, + TraceWriter: state.writer, + }) + if err == nil { + t.Fatal("Run succeeded with a page that cannot take the step's logs; " + + "every property reading the log stream ran against an empty array") + } + if !bytes.Contains([]byte(err.Error()), []byte("install logs")) { + t.Errorf("Run error = %v, want it to name the failed log install", err) + } +} diff --git a/internal/runner/web_last_action_test.go b/internal/runner/web_last_action_test.go index a50c706..34a247c 100644 --- a/internal/runner/web_last_action_test.go +++ b/internal/runner/web_last_action_test.go @@ -7,6 +7,7 @@ import ( "testing" "time" + "github.com/priyanshujain/sanderling/internal/driver" mockdriver "github.com/priyanshujain/sanderling/internal/driver/mock" ) @@ -84,6 +85,42 @@ func TestRunner_WebInstallsLastActionInThePage(t *testing.T) { } } +// The same hole on the other channel: state.logs was hardcoded [] in +// pkg/spec/src/web-runtime.ts, and because the page's reading of an extractor +// replaces the host's on web, the driver's error-level entries never reached a +// property. The default noLogcatErrors counted an empty array on every run. +func TestRunner_WebInstallsTheStepsLogsInThePage(t *testing.T) { + state := newHarnessWithSpec(t, lastActionSpec) + state.mock.LogEntries = []driver.LogEntry{ + {UnixMillis: 1700000000123, Level: "E", Tag: "console", Message: "boom from the page"}, + } + web := &tappingWebDriver{Driver: state.mock} + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if _, err := Run(ctx, Options{ + Duration: time.Hour, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 2, + Driver: web, + Verifier: state.verifier, + TraceWriter: state.writer, + }); err != nil { + t.Fatalf("Run: %v", err) + } + + if len(web.installedLogs) == 0 { + t.Fatal("the page was never handed the step's logs; every property reading " + + "state.logs evaluated against the empty array the page starts with") + } + // The shape is the goja host's (internal/verifier/marshal.go logFields), + // pinned against it by TestLogs_WebJSONMatchesTheGojaObject. + const want = `[{"unixMillis":1700000000123,"level":"E","tag":"console","message":"boom from the page"}]` + if web.installedLogs[0] != want { + t.Errorf("step 1 installed %s, want %s", web.installedLogs[0], want) + } +} + // failingTapWebDriver dispatches the tap and then fails the call, the shape an // RPC deadline takes: the page has the click, the runner has an error. type failingTapWebDriver struct { From 3bab5c3f5c57a990b1d7060c23ee24f1fb795aee Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:42:46 +0530 Subject: [PATCH 07/10] test(spec): cover the host pushing state.logs into the page Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- pkg/spec/test/web-runtime.test.ts | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/pkg/spec/test/web-runtime.test.ts b/pkg/spec/test/web-runtime.test.ts index 0d96434..95a9432 100644 --- a/pkg/spec/test/web-runtime.test.ts +++ b/pkg/spec/test/web-runtime.test.ts @@ -365,6 +365,35 @@ test("state.lastAction is null when the host pushed nothing", () => { assert.equal(lastActionSeenByASpec(null), null); }); +// state.logs is the same kind of hole. Console output reaches the runner over +// CDP, so the page cannot read it back, and while the web runtime hardcoded [] +// there the default noLogcatErrors counted an empty array on every web run: a +// page whose console was full of errors went green having checked nothing. +function logsSeenByASpec(pushed: unknown): unknown { + const setLogs = (globalThis as Record).__sanderlingSetLogs__ as ( + value: unknown, + ) => void; + __testing__.extractors.length = 0; + __testing__.runtime.extract((state) => (state as { logs: unknown }).logs); + let out: Record = {}; + withState(() => { + setLogs(pushed); + out = __testing__.evaluateExtractors(); + }); + return readingOf(out, 0); +} + +test("state.logs carries the entries the host pushed", () => { + const entries = [ + { unixMillis: 1700000000123, level: "E", tag: "console", message: "boom from the page" }, + ]; + assert.deepEqual(logsSeenByASpec(entries), entries); +}); + +test("state.logs is empty when the host pushed no entries", () => { + assert.deepEqual(logsSeenByASpec([]), []); +}); + // sanitize runs over every extractor's return value before it leaves the // runtime. A user extractor that returns a page object reachable from // document/window can be self-referential, carry functions, or nest deeply; From a6b3ccee58014b7d6c3c70ede703593e5ed968b4 Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:42:50 +0530 Subject: [PATCH 08/10] test(browser): drive console.error through to a fired property Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- test/browser/console_levels_test.go | 27 +++++++++++++++++++ .../browser/testdata/console-quiet/index.html | 23 ++++++++++++++++ test/browser/testdata/console-quiet/spec.ts | 15 +++++++++++ 3 files changed, 65 insertions(+) create mode 100644 test/browser/testdata/console-quiet/index.html create mode 100644 test/browser/testdata/console-quiet/spec.ts diff --git a/test/browser/console_levels_test.go b/test/browser/console_levels_test.go index a1b81de..f977dc9 100644 --- a/test/browser/console_levels_test.go +++ b/test/browser/console_levels_test.go @@ -81,6 +81,33 @@ func TestBrowserConsoleErrorReachesTheSpec(t *testing.T) { } } +// TestBrowserConsoleErrorFiresTheLogProperty drives the same page through the +// whole bundle -> run -> verify pipeline instead of hand-assembling a snapshot. +// The driver holding the entry is not enough on web: every extractor reading is +// replaced by the one the page computed, so state.logs is whatever the page +// says it is, and a page that answers "no logs" leaves noLogcatErrors green on +// a run whose console was full of errors. +func TestBrowserConsoleErrorFiresTheLogProperty(t *testing.T) { + violations := runFixture(t, "console-levels") + if !slices.Contains(violations, "noLogcatErrors") { + t.Fatalf("a page calling console.error ran a whole run without noLogcatErrors firing; violations=%v", violations) + } +} + +// TestBrowserQuietPageKeepsTheLogPropertySatisfied is the other half: a page +// whose console never reaches the error level must leave noLogcatErrors alone, +// so the property is reporting what the page logged rather than being on +// whenever the run is web. +func TestBrowserQuietPageKeepsTheLogPropertySatisfied(t *testing.T) { + violations := runFixture(t, "console-quiet") + if slices.Contains(violations, "noLogcatErrors") { + t.Errorf("noLogcatErrors fired on a page that logged nothing at error level; violations=%v", violations) + } + if !slices.Contains(violations, "counterNeverMoves") { + t.Fatalf("nothing was ever pressed, so the run proves nothing about a property that can fire; violations=%v", violations) + } +} + // TestBrowserConsoleLevelsMapToTheLogcatScale pins what each console verb // becomes once it crosses the driver. driver.LogEntry.Level is the single-letter // logcat scale on every platform, so a spec asking for warnings or debug lines diff --git a/test/browser/testdata/console-quiet/index.html b/test/browser/testdata/console-quiet/index.html new file mode 100644 index 0000000..2020cf6 --- /dev/null +++ b/test/browser/testdata/console-quiet/index.html @@ -0,0 +1,23 @@ + + + + + console-quiet + + + +
0
+ + + diff --git a/test/browser/testdata/console-quiet/spec.ts b/test/browser/testdata/console-quiet/spec.ts new file mode 100644 index 0000000..842a8f4 --- /dev/null +++ b/test/browser/testdata/console-quiet/spec.ts @@ -0,0 +1,15 @@ +import { always, extract, taps } from "@sanderling/spec"; +import { noLogcatErrors } from "@sanderling/spec/defaults/properties"; + +const presses = extract((s) => { + const el = s.ax.find({ id: "count" }); + return el ? parseInt(el.text, 10) || 0 : 0; +}).named("presses"); + +// The run has to actually be driving the page, or noLogcatErrors staying +// satisfied says nothing about whether it can fire at all. +const counterNeverMoves = always(() => presses.current === 0); + +export const properties = { noLogcatErrors, counterNeverMoves }; + +export const actionsRoot = taps; From 0cfda3fa18ba7549abfdda375cf34a3f60e5529a Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:46:11 +0530 Subject: [PATCH 09/10] fix(runner): report a log fetch the driver could not make The comment claimed the failure was warned about; nothing warned, so a device whose log fetch failed every step held noLogcatErrors on evidence nobody collected. Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/runner/runner.go | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) diff --git a/internal/runner/runner.go b/internal/runner/runner.go index 5496da9..d89b8cf 100644 --- a/internal/runner/runner.go +++ b/internal/runner/runner.go @@ -163,7 +163,7 @@ func Run(ctx context.Context, options Options) (Summary, error) { }) logSince := lastLogTime g.Go(func() error { - logs = collectLogs(gctx, options.Driver, logSince) + logs = collectLogs(gctx, options.Driver, logger, si, logSince) return nil }) // All goroutines write to local variables and return nil, so the Wait @@ -824,11 +824,23 @@ func applyAction(ctx context.Context, drv driver.DeviceDriver, action verifier.A } // collectLogs pulls recent error-level log entries from the driver since the -// previous fetch. A failure is warned-on but not fatal: log capture is a -// best-effort observability channel, not a correctness dependency. -func collectLogs(ctx context.Context, drv driver.DeviceDriver, since time.Time) []verifier.LogEntry { +// previous fetch. A failure is warned-on but not fatal: one unreadable fetch on +// a flaky device should not end a run. It is not free either. This fetch is the +// whole evidence base for state.logs, so a step that could not make it leaves +// every log property (the default noLogcatErrors included) holding on an empty +// slice, and that has to be visible in the run's output rather than read as the +// app having logged nothing. +func collectLogs( + ctx context.Context, + drv driver.DeviceDriver, + logger *slog.Logger, + step int, + since time.Time, +) []verifier.LogEntry { entries, err := drv.RecentLogs(ctx, since, "E") if err != nil { + logger.Warn("log fetch failed; log properties hold vacuously this step", + "step", step, "err", err) return nil } result := make([]verifier.LogEntry, 0, len(entries)) From 217ea590c523b7b85cbbede628bb410af089d69f Mon Sep 17 00:00:00 2001 From: PJ Date: Sun, 16 Aug 2026 01:46:11 +0530 Subject: [PATCH 10/10] test(runner): cover the silently dropped log fetch Claude-Session: https://claude.ai/code/session_01ShuAy8q8ZfPi8KHxwc8JpQ --- internal/runner/web_last_action_test.go | 34 +++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/internal/runner/web_last_action_test.go b/internal/runner/web_last_action_test.go index 34a247c..6f66304 100644 --- a/internal/runner/web_last_action_test.go +++ b/internal/runner/web_last_action_test.go @@ -1,9 +1,12 @@ package runner import ( + "bytes" "context" "encoding/json" "errors" + "log/slog" + "strings" "testing" "time" @@ -121,6 +124,37 @@ func TestRunner_WebInstallsTheStepsLogsInThePage(t *testing.T) { } } +// A log fetch that fails decides the verdict of every log property: they all +// evaluate against an empty slice and hold. That is not a fact about the app, +// so the step it happened on has to be visible in the run's output. It used to +// be dropped in silence, under a comment claiming it was warned about. +func TestRunner_ReportsALogFetchItCouldNotMake(t *testing.T) { + state := newHarnessWithSpec(t, lastActionSpec) + state.mock.Failures[mockdriver.ActionRecentLogs] = errors.New("adb: device offline") + + var buffer bytes.Buffer + logger := slog.New(slog.NewTextHandler(&buffer, &slog.HandlerOptions{Level: slog.LevelWarn})) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if _, err := Run(ctx, Options{ + Duration: time.Hour, + IdleTimeout: 20 * time.Millisecond, + MaxSteps: 2, + Driver: state.mock, + Verifier: state.verifier, + TraceWriter: state.writer, + Logger: logger, + }); err != nil { + t.Fatalf("Run: %v", err) + } + + if !strings.Contains(buffer.String(), "adb: device offline") { + t.Errorf("the run never reported the failed log fetch, so noLogcatErrors "+ + "held on evidence nobody collected; log was %q", buffer.String()) + } +} + // failingTapWebDriver dispatches the tap and then fails the call, the shape an // RPC deadline takes: the page has the click, the runner has an error. type failingTapWebDriver struct {