diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index daf9d54e..0c77dcdc 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -93,6 +93,18 @@ jobs: CAIRN_MCP_ENTRY: ${{ runner.temp }}/cairn-document-tools/node_modules/chrome-devtools-mcp/build/src/bin/chrome-devtools-mcp.js CAIRN_NETWORK_REPORT: ${{ runner.temp }}/network-evidence.json run: npm run test:network-evidence + - name: Skeleton readiness, polling exclusions and deterministic replay + env: + CAIRN_MCP_ENTRY: ${{ runner.temp }}/cairn-document-tools/node_modules/chrome-devtools-mcp/build/src/bin/chrome-devtools-mcp.js + run: npm run test:settle -- --out "${{ runner.temp }}/settle.json" + - name: Preserve settle results + if: ${{ always() }} + uses: actions/upload-artifact@v4 + with: + name: settle + path: ${{ runner.temp }}/settle.json + if-no-files-found: warn + retention-days: 14 - name: Preserve network evidence results if: ${{ always() }} uses: actions/upload-artifact@v4 diff --git a/bench/local/README.md b/bench/local/README.md index 921e7f06..6fd146a5 100644 --- a/bench/local/README.md +++ b/bench/local/README.md @@ -11,6 +11,19 @@ For a short, human-authored description of the stateful fixture, see the [shop app-context proposal example](../../docs/examples/shop-app-context.md). It is not a supported configuration file; the engine does not load it. +## Readiness regression (#175) + +`npm run build -w cairn-engine && node bench/local/settle.mjs --out bench/results/settle.json` +runs public-driver checks in real isolated Chrome without model calls. It holds a single +fetch behind a skeleton, checks deferred rendering, compares ordinary and explicitly excluded +continuous polling, retains excluded HTTP failures for `no-failed-requests`, caps continuous DOM +mutation, and replays a load-and-commit scenario with page and server assertions. The report path +must be new. `CAIRN_MCP_ENTRY` optionally selects an installed MCP entry point. + +Add `--baseline-engine /absolute/path/to/old/dist/index.js` to first reproduce the original +pending-fetch and DOM-quiet defects and the absence of polling exclusions using the same fixtures. +This script uses public driver methods and reports observed timings; it does not patch transport. + ## Run a small scripted smoke Install the lockfile dependencies with `npm ci`, and install Chrome. The runner diff --git a/bench/local/settle.mjs b/bench/local/settle.mjs new file mode 100644 index 00000000..1d41f048 --- /dev/null +++ b/bench/local/settle.mjs @@ -0,0 +1,181 @@ +// #175: real Chrome readiness, polling exclusions and deterministic replay; no hosted model. +// npm run build -w cairn-engine && node bench/local/settle.mjs [--out report.json] +// Add --baseline-engine /absolute/path/to/old/dist/index.js to reproduce the original defects. +import assert from 'node:assert/strict'; +import { readFileSync } from 'node:fs'; +import { access, mkdir, writeFile } from 'node:fs/promises'; +import { createServer } from 'node:http'; +import { dirname, resolve } from 'node:path'; +import { pathToFileURL } from 'node:url'; + +const args = process.argv.slice(2); +const value = flag => { + const index = args.indexOf(flag); + if (index < 0) return undefined; + assert.ok(args[index + 1] && !args[index + 1].startsWith('--'), `${flag} requires a path`); + return resolve(args[index + 1]); +}; +const baselinePath = value('--baseline-engine'); +const out = value('--out'); +assert.equal(args.length, (baselinePath ? 2 : 0) + (out ? 2 : 0), 'Unknown arguments'); +if (out) { + await access(out).then(() => { throw new Error(`Report already exists: ${out}`); }, error => { + assert.equal(error.code, 'ENOENT'); + }); + await mkdir(dirname(out), { recursive: true }); +} +const engines = []; +if (baselinePath) engines.push({ name: 'baseline', api: await import(pathToFileURL(baselinePath)) }); +engines.push({ name: 'patched', api: await import('../../packages/harness/dist/index.js') }); +const mcp = process.env.CAIRN_MCP_ENTRY; +const flags = ['--isolated', '--headless', '--no-page-id-routing', '--no-usage-statistics']; +const transport = mcp ? { command: process.execPath, args: [mcp, ...flags] } + : { command: 'npx', args: ['-y', 'chrome-devtools-mcp@1.8.0', ...flags] }; +const settle = { idleMs: 400, timeoutMs: 2200, pollMs: 40 }; +const html = readFileSync(new URL('../../packages/harness/test/fixtures/probe/settle.html', import.meta.url), 'utf8'); +const report = []; +let modelCalls = 0; +const forbidden = { id: 'no-model', async complete() { modelCalls++; throw new Error('Unexpected model call'); } }; + +async function fixture(mode, autoData = false) { + const state = { dataCount: 0, pollCount: 0, commitCount: 0 }; + const timers = new Set(); + const pendingData = new Set(); + const later = (fn, ms) => { + const timer = setTimeout(() => { timers.delete(timer); fn(); }, ms); + timers.add(timer); + }; + const sendData = res => { pendingData.delete(res); res.end('Loaded content'); }; + const server = createServer((req, res) => { + if (req.url === '/favicon.ico') { res.writeHead(204); res.end(); return; } + if (req.url === '/api/data') { + state.dataCount++; + pendingData.add(res); + if (autoData) later(() => sendData(res), 800); + return; + } + if (req.url === '/api/poll' || req.url === '/api/poll/failing') { + state.pollCount++; + // Failed excluded traffic must remain ordinary assertion evidence. + const status = req.url === '/api/poll/failing' ? 503 : 200; + later(() => { res.writeHead(status); res.end('poll'); }, 120); + return; + } + if (req.url === '/api/commit' && req.method === 'POST') { + state.commitCount++; + res.end('Committed'); + return; + } + res.setHeader('content-type', 'text/html; charset=utf-8'); + res.end(html); + }); + await new Promise((resolve, reject) => { server.once('error', reject); server.listen(0, '127.0.0.1', resolve); }); + return { + origin: `http://127.0.0.1:${server.address().port}/?mode=${mode}`, + snapshot: () => ({ ...state }), + releaseData: () => { for (const res of pendingData) sendData(res); }, + async close() { + for (const timer of timers) clearTimeout(timer); + for (const res of pendingData) res.end(); + server.closeAllConnections(); + await new Promise(resolve => server.close(resolve)); + }, + }; +} + +async function withBrowser(engine, mode, options, run, autoData = false) { + const server = await fixture(mode, autoData); + const driver = new engine.api.ChromeDevToolsDriver({ ...transport, settle: options }); + try { return await run(driver, server); } + finally { await driver.close(); await server.close(); } +} + +async function measuredSettle(driver, options) { + const started = performance.now(); + await driver.settle(options); + return Math.round(performance.now() - started); +} + +for (const engine of engines) { + await withBrowser(engine, 'skeleton', settle, async (driver, server) => { + await driver.goto(server.origin); + assert.equal(server.snapshot().dataCount, 1, 'The page starts one slow fetch'); + // Hold it past the idle window: counting new requests cannot distinguish pending from idle. + const release = setTimeout(() => server.releaseData(), 1500); + try { + const elapsedMs = await measuredSettle(driver, { ...settle, timeoutMs: 6000 }); + const evidence = await driver.observe(); + const request = evidence.logic.requests.find(r => r.url.endsWith('/api/data')); + assert.ok(request); + if (engine.name === 'baseline') { + assert.equal(request.status, 0, 'The original settle returns while the single fetch is pending'); + assert.ok(elapsedMs < 1500, `Baseline unexpectedly waited for completion: ${elapsedMs}ms`); + } else { + assert.equal(request.status, 200); + assert.ok(elapsedMs >= 1500 + 650 + settle.idleMs, 'Deferred rendering gets its own quiet window'); + const after = await driver.snapshot(); + assert.ok(after.some(row => row.name === 'Loaded content')); + assert.ok(!after.some(row => row.name === 'Loading data')); + } + report.push({ engine: engine.name, phase: 'single-fetch-skeleton', elapsedMs, request, oracle: server.snapshot() }); + } finally { clearTimeout(release); } + }); + + for (const ignored of [false, true]) { + const options = { ...settle, ...(ignored ? { ignoreRequests: ['/api/poll'] } : {}) }; + await withBrowser(engine, 'polling', options, async (driver, server) => { + await driver.goto(server.origin); + const elapsedMs = await measuredSettle(driver, options); + const evidence = await driver.observe(); + const requests = evidence.logic.requests.filter(r => r.url.includes('/api/poll')); + assert.ok(server.snapshot().pollCount >= 4, 'Polling remains active during settle'); + assert.ok(requests.some(r => r.status === 503), 'Excluded failures remain in evidence'); + if (!ignored || engine.name === 'baseline') { + assert.ok(elapsedMs >= settle.timeoutMs, `Continuous polling must reach the cap: ${elapsedMs}ms`); + } else { + assert.ok(elapsedMs < settle.timeoutMs - settle.idleMs, `Declared background polling should not burn the cap: ${elapsedMs}ms`); + // No extra adapter or benign rule: the built-in guard sees exactly the driver's evidence. + const result = await engine.api.runScenario({ name: 'Excluded polling failures remain failures', steps: [], + assertions: [{ kind: 'no-failed-requests' }] }, { driver, llm: forbidden, reporter: { async emit() {} } }); + assert.equal(result.result.verdict.passed, false); + assert.equal(result.result.verdict.results[0].passed, false); + assert.ok(result.result.evidence.logic.requests.some(r => r.url.endsWith('/api/poll/failing') && r.status === 503)); + assert.equal(result.result.usage.llmCalls, 0); + } + report.push({ engine: engine.name, phase: ignored ? 'excluded-polling' : 'ordinary-polling', elapsedMs, + requestCount: requests.length, failures: requests.filter(r => r.status === 503).length, oracle: server.snapshot() }); + }); + } + + await withBrowser(engine, 'mutating', settle, async (driver, server) => { + await driver.goto(server.origin); + const elapsedMs = await measuredSettle(driver, settle); + if (engine.name === 'baseline') assert.ok(elapsedMs < settle.timeoutMs - settle.idleMs); + else assert.ok(elapsedMs >= settle.timeoutMs, `Continuous DOM mutation must reach the cap: ${elapsedMs}ms`); + const rows = await driver.snapshot(); + const counter = rows.find(row => /^Counter [1-9]\d*$/.test(row.name)); + assert.ok(counter, 'The real page continued to mutate'); + report.push({ engine: engine.name, phase: 'continuous-dom', elapsedMs, counter: counter.name }); + }); + + if (engine.name === 'patched') await withBrowser(engine, 'skeleton', settle, async (driver, server) => { + const result = await engine.api.runScenario({ name: 'Load and commit the rendered content', steps: [ + { kind: 'goto', url: server.origin }, + { kind: 'waitFor', until: { text: 'Loaded content' }, timeoutMs: 4000 }, + { kind: 'click', target: { text: 'Commit', role: 'button' } }, + ], assertions: [ + { kind: 'request-status', urlIncludes: '/api/commit', method: 'POST', status: 200, origin: 'user' }, + { kind: 'no-failed-requests' }, + ] }, { driver, llm: forbidden, reporter: { async emit() {} } }); + assert.equal(result.result.verdict.passed, true, JSON.stringify(result.result)); + assert.equal(result.result.usage.llmCalls, 0); + assert.equal(server.snapshot().commitCount, 1, 'Replay commits exactly once'); + const rows = await driver.snapshot(); + assert.ok(rows.some(row => row.name === 'Committed'), 'Deferred post-submit rendering is visible'); + report.push({ engine: engine.name, phase: 'replay', llmCalls: result.result.usage.llmCalls, + oracle: server.snapshot(), verdict: result.result.verdict }); + }, true); +} +assert.equal(modelCalls, 0); +console.log(JSON.stringify(report, null, 2)); +if (out) await writeFile(out, JSON.stringify(report, null, 2) + '\n', { flag: 'wx' }); diff --git a/docs/custom-driver.md b/docs/custom-driver.md index d4fb4305..acb1e96b 100644 --- a/docs/custom-driver.md +++ b/docs/custom-driver.md @@ -77,6 +77,29 @@ heuristic and best-effort: it is time-bounded and must not throw if the wait its not prove that a step succeeded. Deterministic readiness comes from a step's `expect` post-condition or an explicit `waitFor`, which the engine polls against `observe()` and `snapshot()`. +The Chrome Driver waits for both network and DOM activity to quiet down. A single pending +request or a new document mutation keeps the wait active, up to the configured timeout. +Declare an application's background polling explicitly through the Driver's wait defaults: + +```ts +import { ChromeDevToolsDriver, runScenario } from "cairn-engine"; + +const driver = new ChromeDevToolsDriver({ + settle: { ignoreRequests: ["/api/notification-count", "/api/keepalive"] }, +}); +try { + await runScenario(scenario, { driver }); +} finally { + await driver.close(); +} +``` + +These defaults also apply to discovery and waits inside `type`/`select`. A direct call such +as `driver.settle({ timeoutMs: 2_000 })` overrides that field and retains the exclusions; +`ignoreRequests: []` clears them. Matching uses URL substrings, so choose patterns that do +not also match the flow's important requests. Excluded requests still appear in evidence +and can fail assertions. This option does not mark a failure `benign`. + When a Driver throws during a step, it can attach the structured `kind` from the existing [`StepErrorKind`](../packages/harness/src/core/types.ts) contract. Create one with [`stepError`](../packages/harness/src/core/errors.ts), or set the same plain `kind` property on diff --git a/package.json b/package.json index 2f113454..6fa54136 100644 --- a/package.json +++ b/package.json @@ -23,6 +23,7 @@ "test:compatibility": "node bench/ci-smoke.mjs", "test:document-refs": "node scripts/test-document-refs.mjs", "test:network-evidence": "node scripts/test-network-evidence.mjs", + "test:settle": "node bench/local/settle.mjs", "check:language": "node scripts/check-language.mjs", "journal:status": "node scripts/journal.mjs status", "journal:check": "node scripts/journal.mjs check", diff --git a/packages/harness/src/adapters/drivers/chrome-network.ts b/packages/harness/src/adapters/drivers/chrome-network.ts index 334901c9..f25c6c3e 100644 --- a/packages/harness/src/adapters/drivers/chrome-network.ts +++ b/packages/harness/src/adapters/drivers/chrome-network.ts @@ -2,11 +2,11 @@ import { stepError } from "../../core/errors.js"; import type { NetworkRequest } from "../../core/types.js"; /** MCP request IDs are stable across navigations, but local to a page's collector. */ -export function networkRows(text: string): { id: string; request: NetworkRequest }[] { - const rows: { id: string; request: NetworkRequest }[] = []; +export function networkRows(text: string): { id: string; pending: boolean; request: NetworkRequest }[] { + const rows: { id: string; pending: boolean; request: NetworkRequest }[] = []; for (const line of text.split("\n")) { const m = line.match(/^reqid=(\d+)\s+(\w+)\s+(\S+)\s+\[([^\]]+)\]/); - if (m) rows.push({ id: m[1]!, request: { + if (m) rows.push({ id: m[1]!, pending: m[4] === "pending", request: { method: m[2]!, url: m[3]!, status: /^\d+$/.test(m[4]!) ? Number(m[4]) : 0, } }); } diff --git a/packages/harness/src/adapters/drivers/chrome.ts b/packages/harness/src/adapters/drivers/chrome.ts index cded461f..9b2c2778 100644 --- a/packages/harness/src/adapters/drivers/chrome.ts +++ b/packages/harness/src/adapters/drivers/chrome.ts @@ -155,6 +155,9 @@ export interface ChromeDriverOptions { * legacy snapshots promote matching StaticText listing roles to button. False disables * those hints and legacy promotion; other perception facts and exact refs remain available. */ promoteClickables?: boolean; + /** Defaults for every settle, including waits inside type/select and engine replay. + * Per-call SettleOptions override these fields. */ + settle?: SettleOptions; } /** @@ -192,6 +195,7 @@ export class ChromeDevToolsDriver implements Driver { private lastClickable?: Set; // labels of roleless clickable regions, keyed by that raw private readonly driverId = ++nextDriverId; private observationVersion = 0; + private settleVersion = 0; private observedRows: SnapshotRow[] = []; private documentObservation?: ChromeDocumentObservation; private observedPage?: string; @@ -735,34 +739,74 @@ export class ChromeDevToolsDriver implements Driver { // Chrome defers low-priority resources (favicon, web fonts) past the usual 500ms // "network-idle" window, so the idle threshold is generous — missing a late request // would mean missing a real failure. Tune via SettleOptions. - const idleMs = options.idleMs ?? 1_000; - const timeoutMs = options.timeoutMs ?? 10_000; - const pollMs = options.pollMs ?? 250; - // Tolerate a trickle of background traffic (analytics beacons, polling, websockets) so - // those sites reach "idle" instead of always burning the full timeout; a real load - // burst (>1 new request in the window) still resets the wait. - const tolerance = 1; + const config = { ...this.opts.settle, ...options }; + const duration = (value: number | undefined, fallback: number) => + value !== undefined && Number.isFinite(value) && value >= 0 ? value : fallback; + const idleMs = duration(config.idleMs, 1_000); + const timeoutMs = duration(config.timeoutMs, 10_000); + const pollMs = Math.max(1, duration(config.pollMs, 250)); + const ignore = config.ignoreRequests ?? []; const deadline = Date.now() + timeoutMs; let windowStart = Date.now(); - let windowBase = -1; + let previous: string | undefined; + const probe = this.settleProbe(++this.settleVersion, timeoutMs); + // A late render may invalidate the lookup cache even though no action ran. + this.snapshotCache = undefined; try { - const pages = await this.call("list_pages"); while (Date.now() < deadline) { - await this.collectNetwork(pages); - const count = this.network.size; - if (windowBase < 0 || count - windowBase > tolerance) { - windowBase = count; + const [pages, network, dom] = await this.withTimeout(Promise.all([ + this.call("list_pages"), + this.call("list_network_requests", { includePreservedRequests: true }), + this.call("evaluate_script", { function: probe }, "observation").catch(() => ""), + ]), Math.max(0, deadline - Date.now()), "settle"); + this.network.collect(pages, network); + // Only the current listing gates readiness. Evicted pending rows stay unknown in + // cumulative evidence, and a failed fetch (also status 0) is no longer in flight. + const rows = networkRows(network).filter(({ request }) => !ignore.some(url => request.url.includes(url))); + const state = extractFirstJsonObject(dom) as Record | undefined; + const signature = JSON.stringify([ + pages.match(/^\s*\d+:[^\n]*\[selected\](?:\s|$)/m)?.[0], + rows.map(({ id, pending, request }) => [id, request.status, pending]), + state?.documentEpoch, state?.revision, state?.ready, + ]); + if (signature !== previous || rows.some(row => row.pending) || state?.ready === false) { + previous = signature; windowStart = Date.now(); } else if (Date.now() - windowStart >= idleMs) { - return; // at most a trickle over idleMs — treat as network-idle + return; } - await delay(pollMs); + await delay(Math.min(pollMs, Math.max(0, deadline - Date.now()))); } } catch { // best-effort: settling must never fail a run (port contract). + } finally { + this.snapshotCache = undefined; } } + /** Separate from exact-reference guards: retain only a revision, never nodes or records. + * The page timer cleans up even if a tool hangs or the host stops waiting. */ + private settleProbe(version: number, timeoutMs: number): string { + return `() => { + const key = Symbol.for(${JSON.stringify(`cairn:settle:${this.driverId}`)}); + const sessions = globalThis[key] ??= new Map(); + let state = sessions.get(${version}); + if (!state) { + state = { revision: 0 }; + state.observer = new MutationObserver(() => state.revision++); + state.observer.observe(document, { subtree: true, childList: true, characterData: true, attributes: true }); + state.timer = setTimeout(() => { + state.observer.disconnect(); + sessions.delete(${version}); + if (!sessions.size && globalThis[key] === sessions) delete globalThis[key]; + }, ${Math.max(1, timeoutMs)}); + sessions.set(${version}, state); + } + if (state.observer.takeRecords().length) state.revision++; + return { ready: document.readyState !== "loading", revision: state.revision, documentEpoch: performance.timeOrigin }; + }`; + } + async observe(): Promise { const [pages, network, console] = await Promise.all([ this.call("list_pages"), diff --git a/packages/harness/src/core/types.ts b/packages/harness/src/core/types.ts index 8b823bfa..893e1589 100644 --- a/packages/harness/src/core/types.ts +++ b/packages/harness/src/core/types.ts @@ -173,6 +173,9 @@ export interface SettleOptions { idleMs?: number; timeoutMs?: number; pollMs?: number; + /** URL substrings excluded only from the network-idle wait. Requests remain in evidence + * and assertions; this is separate from the product's benign failure policy. */ + ignoreRequests?: readonly string[]; } export interface NetworkRequest { diff --git a/packages/harness/src/index.ts b/packages/harness/src/index.ts index 11f61bd1..b97c16dc 100644 --- a/packages/harness/src/index.ts +++ b/packages/harness/src/index.ts @@ -39,6 +39,7 @@ export { ConsoleReporter } from "./adapters/reporters/console.js"; export { JsonReporter } from "./adapters/reporters/json.js"; export { FakeDriver } from "./adapters/drivers/fake.js"; export { ChromeDevToolsDriver } from "./adapters/drivers/chrome.js"; +export type { ChromeDriverOptions } from "./adapters/drivers/chrome.js"; export { SelfHealingDriver, parseHealChoice } from "./adapters/drivers/self-heal.js"; export type { Heal, SelfHealOptions } from "./adapters/drivers/self-heal.js"; export { createTargetChoiceRepair } from "./adapters/drivers/target-choice.js"; diff --git a/packages/harness/test/adapters/drivers/chrome-network.test.ts b/packages/harness/test/adapters/drivers/chrome-network.test.ts index c441da93..15e94150 100644 --- a/packages/harness/test/adapters/drivers/chrome-network.test.ts +++ b/packages/harness/test/adapters/drivers/chrome-network.test.ts @@ -1,22 +1,24 @@ -import { expect, it, vi } from "vitest"; +import { afterEach, expect, it, vi } from "vitest"; import { ChromeDevToolsDriver } from "../../../src/adapters/drivers/chrome.js"; import { conditionMet } from "../../../src/core/steps.js"; // MCP 1.8.0's actual list format: page-local reqids, numeric/pending/error statuses. const listing = (...rows: string[]) => `# list_network_requests response\n## Network requests\nShowing 1-${rows.length} of ${rows.length} (Page 1 of 1).\n${rows.join("\n")}`; -function browser() { +function browser(options?: ConstructorParameters[0]) { const wire = { pages: "0: https://app/start [selected]", network: listing(), error: false }; const client = { close: vi.fn(async () => {}), callTool: vi.fn(async ({ name }: { name: string; arguments: Record }) => { if (name === "list_network_requests" && wire.error) throw new Error("network collection failed"); const text = name === "list_pages" ? wire.pages : name === "list_network_requests" ? wire.network : ""; return { content: [{ type: "text", text }] }; }) }; - const driver = new ChromeDevToolsDriver(); + const driver = new ChromeDevToolsDriver(options); // Inject the SDK transport boundary, retaining the real driver's collection and parsing. (driver as unknown as { client: unknown }).client = client; return { driver, wire, client }; } +afterEach(() => vi.useRealTimers()); + it("retains evicted requests and their positions after repeated document navigations", async () => { const { driver, wire, client } = browser(); wire.network = listing("reqid=1 POST https://app/api/order [200]"); @@ -88,6 +90,86 @@ it("does not fabricate completion for an evicted pending request or a failed fet await driver.close(); }); +it("ignores configured polling for readiness while retaining its pending and failed evidence", async () => { + vi.useFakeTimers(); + const { driver, wire } = browser({ settle: { idleMs: 200, pollMs: 50, ignoreRequests: ["/poll"] } }); + const rows = ["reqid=1 POST https://app/api/order [200]", "reqid=2 GET https://app/poll [pending]"]; + wire.network = listing(...rows); + let done = false; + const p = driver.settle().then(() => (done = true)); + await vi.advanceTimersByTimeAsync(100); + rows.push("reqid=3 GET https://app/poll [net::ERR_FAILED]"); + wire.network = listing(...rows); + await vi.advanceTimersByTimeAsync(100); + await p; + expect(done).toBe(true); + expect((await driver.observe()).logic.requests).toEqual([ + { method: "POST", url: "https://app/api/order", status: 200 }, + { method: "GET", url: "https://app/poll", status: 0 }, + { method: "GET", url: "https://app/poll", status: 0 }, + ]); + + // A per-call empty list overrides the driver's ignore list, so this pending poll gates readiness. + done = false; + const override = driver.settle({ ignoreRequests: [], timeoutMs: 400 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(300); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(100); + await override; + await driver.close(); +}); + +it("does not gate readiness on evicted pending evidence or a current failed fetch", async () => { + vi.useFakeTimers(); + const { driver, wire } = browser(); + wire.network = listing("reqid=1 POST https://app/api/order [pending]"); + await driver.observe(); + wire.network = listing("reqid=2 GET https://app/lost [net::ERR_FAILED]"); + let done = false; + const p = driver.settle({ idleMs: 200, pollMs: 50, timeoutMs: 1_000 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(200); + await p; + expect(done).toBe(true); + expect((await driver.observe()).logic.requests.map(r => r.status)).toEqual([0, 0]); + await driver.close(); +}); + +it("restarts readiness after switching selected pages even when their request rows match", async () => { + vi.useFakeTimers(); + const { driver, wire } = browser(); + wire.network = listing("reqid=1 GET https://app/shared [200]"); + let done = false; + const p = driver.settle({ idleMs: 200, pollMs: 50 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(100); + // The URLs also match: selected page identity alone must restart the quiet window. + wire.pages = "0: https://app/start\n1: https://app/start [selected]"; + await vi.advanceTimersByTimeAsync(100); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(150); + await p; + expect((await driver.observe()).logic.requests).toHaveLength(2); + await driver.close(); +}); + +it.each(["list_pages", "list_network_requests", "evaluate_script"])( + "bounds a hung %s call by the settle deadline and resolves without throwing", async hungTool => { + vi.useFakeTimers(); + const { driver, client } = browser({ timeoutMs: 30_000 }); + client.callTool.mockImplementation(async ({ name }) => { + if (name === hungTool) return new Promise(() => {}); + return { content: [{ type: "text", text: name === "list_pages" ? "0: https://app/start [selected]" : "" }] }; + }); + let done = false; + const p = driver.settle({ timeoutMs: 125 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(124); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(1); + await p; + expect(done).toBe(true); + await driver.close(); + }, +); + it("rejects rows without page identity and conflicting reused IDs instead of mixing evidence", async () => { const { driver, wire } = browser(); wire.pages = ""; diff --git a/packages/harness/test/adapters/drivers/chrome.test.ts b/packages/harness/test/adapters/drivers/chrome.test.ts index abd76d2c..cf98b095 100644 --- a/packages/harness/test/adapters/drivers/chrome.test.ts +++ b/packages/harness/test/adapters/drivers/chrome.test.ts @@ -725,7 +725,8 @@ describe("ChromeDevToolsDriver audit coverage", () => { const calls: Array<{ name: string; args: Record }> = []; (driver as unknown as { call: unknown }).call = async (name: string, args: Record = {}) => { calls.push({ name, args }); - const r = responses[name] ?? (name === "list_pages" ? "0: https://x/ [selected]" : undefined); + const r = responses[name] ?? (name === "list_pages" ? "0: https://x/ [selected]" : + name === "evaluate_script" ? 'Script ran on page and returned:\n```json\n{"ready":true,"revision":0,"documentEpoch":1}\n```' : undefined); if (r === undefined) return ""; return typeof r === "function" ? r(args) : r; }; @@ -1369,35 +1370,168 @@ describe("ChromeDevToolsDriver audit coverage", () => { }); } - // chrome-settle-tolerates-one-background-request.test.ts + // Readiness regressions (#175): every request and DOM change restarts the quiet window. { describe("chrome settle", () => { afterEach(() => vi.useRealTimers()); - it("chromeSettleToleratesOneBackgroundRequest: one new request inside the window does not reset it, two do", async () => { + it("restarts the idle window for a single new request", async () => { vi.useFakeTimers(); let count = 5; const { driver } = stubbedDriver({ list_network_requests: () => net(count) }); - // one trickle beacon at 250ms → still idle at ~1s let done = false; const p = driver.settle().then(() => (done = true)); - await vi.advanceTimersByTimeAsync(200); + await vi.advanceTimersByTimeAsync(400); count = 6; + await vi.advanceTimersByTimeAsync(700); // the new request was seen at 500ms + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(500); + await p; + expect(done).toBe(true); + }); + + it("waits for a lone pending request and then for the response's idle window", async () => { + vi.useFakeTimers(); + let status = "pending"; + const { driver } = stubbedDriver({ + list_network_requests: () => `reqid=1 POST https://x/api/order [${status}]`, + }); + let done = false; + const p = driver.settle().then(() => (done = true)); await vi.advanceTimersByTimeAsync(1_100); + expect(done).toBe(false); + status = "200"; + await vi.advanceTimersByTimeAsync(750); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(500); await p; expect(done).toBe(true); + }); - // a burst of two resets the window: not idle at 1.1s, idle by ~1.6s - count = 10; - let done2 = false; - const p2 = driver.settle().then(() => (done2 = true)); + it.each([ + ["DOM revision", { ready: true, revision: 1, documentEpoch: 1 }], + ["document replacement", { ready: true, revision: 0, documentEpoch: 2 }], + ])("restarts the idle window after %s with no new network requests", async (_name, changed) => { + vi.useFakeTimers(); + let dom = { ready: true, revision: 0, documentEpoch: 1 }; + const { driver } = stubbedDriver({ + list_network_requests: net(1), + evaluate_script: () => `Script ran on page and returned:\n\`\`\`json\n${JSON.stringify(dom)}\n\`\`\``, + }); + let done = false; + const p = driver.settle().then(() => (done = true)); await vi.advanceTimersByTimeAsync(400); - count = 12; // seen on the poll at 500ms → reset - await vi.advanceTimersByTimeAsync(700); // t=1.1s - expect(done2).toBe(false); - await vi.advanceTimersByTimeAsync(600); // t=1.7s - await p2; - expect(done2).toBe(true); + dom = changed; + await vi.advanceTimersByTimeAsync(700); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(500); + await p; + expect(done).toBe(true); + }); + + it("does not count a loading document as idle", async () => { + vi.useFakeTimers(); + let ready = false; + const { driver } = stubbedDriver({ + evaluate_script: () => `Script ran on page and returned:\n\`\`\`json\n${JSON.stringify({ ready, revision: 0, documentEpoch: 1 })}\n\`\`\``, + }); + let done = false; + const p = driver.settle({ idleMs: 200, pollMs: 100 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(500); + expect(done).toBe(false); + ready = true; + await vi.advanceTimersByTimeAsync(200); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(100); + await p; + expect(done).toBe(true); + }); + + it("bounds continuous DOM activity by the overall deadline and clips the final poll", async () => { + vi.useFakeTimers(); + let revision = 0; + const { driver } = stubbedDriver({ + evaluate_script: () => `Script ran on page and returned:\n\`\`\`json\n${JSON.stringify({ ready: true, revision: revision++, documentEpoch: 1 })}\n\`\`\``, + }); + let done = false; + const p = driver.settle({ idleMs: 200, pollMs: 250, timeoutMs: 1_100 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(1_099); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(1); + await p; + expect(done).toBe(true); + }); + + it("merges per-call settle options over driver defaults", async () => { + vi.useFakeTimers(); + const { driver } = stubbedDriver({}, { settle: { idleMs: 200, pollMs: 50, timeoutMs: 500 } }); + let done = false; + const p = driver.settle().then(() => (done = true)); + await vi.advanceTimersByTimeAsync(199); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(1); + await p; + + done = false; + const override = driver.settle({ idleMs: 350 }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(349); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(1); + await override; + expect(done).toBe(true); + }); + + it("falls back to bounded defaults for invalid timings without emitting invalid script literals", async () => { + vi.useFakeTimers(); + const { driver, calls } = stubbedDriver({}); + let done = false; + const p = driver.settle({ idleMs: Infinity, pollMs: -1, timeoutMs: NaN }).then(() => (done = true)); + await vi.advanceTimersByTimeAsync(999); + expect(done).toBe(false); + await vi.advanceTimersByTimeAsync(1); + await p; + expect(done).toBe(true); + const scripts = calls.filter(call => call.name === "evaluate_script").map(call => String(call.args.function)); + expect(scripts.length).toBeGreaterThan(0); + expect(scripts.every(script => !/Infinity|NaN/.test(script))).toBe(true); + }); + + it("uses negotiated fast observation while preserving the guard that rejects an earlier stale ref", async () => { + vi.useFakeTimers(); + let connected = true; + const { driver, client } = withClient(async ({ name, arguments: args }) => { + let text = ""; + if (name === "list_pages") text = "0: https://x/ [selected]"; + if (name === "take_snapshot") text = 'uid=1_1 button "Save"'; + if (name === "evaluate_script") { + const script = String(args.function); + if (script.includes("cairn:settle:")) text = JSON.stringify({ ready: true, revision: 1, documentEpoch: 1 }); + else if (script.includes("const connected =")) text = JSON.stringify({ connected, revision: 1 }); + else if (script.includes("const ids =")) text = JSON.stringify({ "1_1": { referenceReady: true } }); + else text = "{}"; + } + return { content: [{ type: "text", text }] }; + }, { promoteClickables: false }); + // Capability state after negotiation; the injected client retains real argument preparation. + (driver as unknown as { observationWaitOverride: boolean }).observationWaitOverride = true; + const ref = (await driver.snapshot({ perception: true }))[0]!.ref!; + expect(ref).toBeTypeOf("string"); + const references = (driver as unknown as { references: Map }).references; + const captured = references.get(ref); + connected = false; + client.callTool.mockClear(); + const p = driver.settle({ idleMs: 100, pollMs: 50 }); + await vi.advanceTimersByTimeAsync(100); + await p; + const evaluations = client.callTool.mock.calls.map(([req]) => req).filter(req => req.name === "evaluate_script"); + expect(evaluations.length).toBeGreaterThan(0); + expect(evaluations.every(req => req.arguments.waitForStableDom === false)).toBe(true); + expect(evaluations.every(req => !String(req.arguments.function).includes("cairn-observation-guard"))).toBe(true); + expect(client.callTool.mock.calls.some(([req]) => req.name === "take_snapshot")).toBe(false); + expect(references.get(ref)).toBe(captured); + await expect(driver.click({ text: "Save", role: "button" }, ref)).rejects.toThrow(/ref|expired|detached/i); + expect(client.callTool.mock.calls.some(([req]) => req.name === "click")).toBe(false); + await driver.close(); }); }); } diff --git a/packages/harness/test/fixtures/probe/README.md b/packages/harness/test/fixtures/probe/README.md index 0c2a933f..7bddf903 100644 --- a/packages/harness/test/fixtures/probe/README.md +++ b/packages/harness/test/fixtures/probe/README.md @@ -11,7 +11,10 @@ only pin the script's *text*, which is how three real bugs shipped past green te candidate's own centre sat); - a `position: fixed` modal read as clipped by an ancestor whose overflow it escapes. -Each file is one layout, and the expectation lives next to it in `probe.browser.test.ts`. Every +Each reachability file is one layout, and the expectation lives next to it in `probe.browser.test.ts`. Every element that matters is named "Continue", because the probe's whole job is telling same-named elements apart. Add a fixture when a review turns up a layout the probe gets wrong — the file is the report, and the test is the fix's proof. + +`settle.html` supplies skeleton rendering, background polling and continuous DOM mutation for +the public Chrome Driver regression in `bench/local/settle.mjs` (#175). diff --git a/packages/harness/test/fixtures/probe/settle.html b/packages/harness/test/fixtures/probe/settle.html new file mode 100644 index 00000000..420a532f --- /dev/null +++ b/packages/harness/test/fixtures/probe/settle.html @@ -0,0 +1,42 @@ + + + +Settle fixture + +

Loading data

+ + diff --git a/spec/core/perception.md b/spec/core/perception.md index 3a6bbe46..ccb6992e 100644 --- a/spec/core/perception.md +++ b/spec/core/perception.md @@ -164,6 +164,22 @@ require a fresh observation or cause a ref to be refused. Fast guard/facts/valid retain navigation detection. Scroll, native inputs, legacy probes and other evaluations keep ordinary waiting. Negotiation caching never caches a node validation. +Chrome `settle()` uses one bounded quiet window for current network activity and document +mutations (#175). A single nonexcluded request, an in-flight `[pending]` row, or a changed +document/revision restarts the window. Failed fetches and evicted pending evidence do not +stand in for active requests. A separate, expiring DOM observer retains only a revision; +it never clears or reuses exact-reference guards. Its probes use the negotiated fast +evaluation mode where available; a missing DOM measurement falls back to network waiting. +The wait clears the lookup snapshot cache so late rendering is visible to subsequent lookup. + +`ChromeDriverOptions.settle` supplies defaults for engine and internal waits; per-call +`SettleOptions` override individual fields. `ignoreRequests` declares URL substrings that +do not count toward network idle. It neither removes evidence nor changes assertions or +the product's `benign` policy. Polling knowledge belongs to the consumer, not a universal +traffic heuristic. Both waits remain best-effort: a deadline or probe failure is not proof +of readiness. CSS-only animation, shadow/frame rendering and work scheduled after the +quiet window still require a step `expect` or explicit `waitFor`. + Opt-in Chrome capture requests the full MCP accessibility tree because compact snapshots can omit listbox options. It excludes virtual `InlineTextBox` runs, which can share non-actionable UIDs; the owning text row remains. Ordinary no-options snapshots keep their existing shape. diff --git a/spec/journal/entries/2026-10-06-175-settle-readiness.md b/spec/journal/entries/2026-10-06-175-settle-readiness.md new file mode 100644 index 00000000..6110fbba --- /dev/null +++ b/spec/journal/entries/2026-10-06-175-settle-readiness.md @@ -0,0 +1,31 @@ +--- +issue: 175 +pr: 281 +status: in-progress +summary: Wait for network and DOM quiet with explicit background request exclusions +next: Review PR 281 and confirm CI before merging into develop +--- + +Chrome settling now measures current MCP request identities, response transitions and literal +pending rows alongside document mutations. A separate expiring observer retains only a revision +and leaves exact-reference guards intact. The same deadline bounds tool calls and sleep. Evicted +pending evidence stays unknown without holding the current wait open indefinitely. + +Application-specific polling arrives through `ChromeDriverOptions.settle.ignoreRequests`, with +per-call overrides. These URL substrings affect idle accounting only: excluded requests remain +cumulative evidence and can still fail assertions. They do not become benign failures. Snapshot +lookup caches are cleared after waiting so deferred rendering is visible to later lookup. + +The committed public-driver fixture reproduces the original pending-fetch and DOM races and +checks polling exclusions, an unrecovered 503, the mutation cap and a server-verified zero-call +replay. On one local comparison against develop 31cfed0, with a 400ms quiet interval, baseline +settle returned in 423ms while the fetch was pending; the fix waited 2764ms through the response +and deferred rendering. Excluded polling took 543ms versus 2212ms. These are fixture observations, +not population latency estimates. Reproduce with `npm run build && npm run test:settle` and the +runner's optional `--baseline-engine` argument. CI preserves the fixture's JSON result. + +Typecheck, build, full tests, boundaries, language and diff checks passed, as did all 30 Chromium +probe/reference tests and the real MCP 1.8.0 document-reference and cumulative-network regressions. +No hosted model was used. Settling remains a bounded heuristic; missing DOM measurements fall +back to network waiting, and response headers do not prove body completion. CSS-only, frame or +shadow rendering and work scheduled beyond the quiet window still require `expect` or `waitFor`.