From dd2de7f676af743d8e36a5373a80a331d9712e9f Mon Sep 17 00:00:00 2001 From: meetsu <96637888+klNuno@users.noreply.github.com> Date: Mon, 19 Oct 2026 17:41:34 +0200 Subject: [PATCH 1/5] test(core): date the attended use before the news with a still clock --- packages/core/test/push.test.ts | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/packages/core/test/push.test.ts b/packages/core/test/push.test.ts index 4b605b938..82907e4ef 100644 --- a/packages/core/test/push.test.ts +++ b/packages/core/test/push.test.ts @@ -206,19 +206,22 @@ test('no push about a thread someone is looking at and uses, on the PC or the ph finish(threadId); await delivered(3); // Looking away without having used the thread since sends what waited. + // The core dates a use at the report's arrival minus its idleMs, so any + // margin the test picks loses to a slow enough trip to the core, which then + // drops the news as seen. A still clock dates the use 1 ms before the news. + setSystemTime(new Date()); await desktop.call('threads.focus', { threadId, attentive: true, idleMs: 0 }); - const heldFrom = Date.now(); finish(threadId); - await Bun.sleep(5); - // The last use is dated before the news, however long the runner took to - // get here: a fixed 20 ms fell after it on a slow runner and dropped it as seen. - await desktop.call('threads.focus', { threadId, attentive: true, idleMs: Date.now() - heldFrom + 20 }); + // The report takes its time to arrive, as on a loaded runner. + await Bun.sleep(40); + await desktop.call('threads.focus', { threadId, attentive: true, idleMs: 1 }); + setSystemTime(); await delivered(3); desktop.close(); await delivered(4); await expect(phone.call('threads.focus', { threadId, attentive: 'yes' as never })).rejects.toThrow('attentive'); await expect(phone.call('threads.focus', { threadId, idleMs: -1 })).rejects.toThrow('idleMs'); - } finally { phone.close(); } + } finally { setSystemTime(); phone.close(); } }); test('questions and permissions push immediately even when their thread is attended', async () => { const paired = session(); From dbd43c018d72b37f4ccd7d24c2e73c7ae6d61541 Mon Sep 17 00:00:00 2001 From: meetsu <96637888+klNuno@users.noreply.github.com> Date: Mon, 19 Oct 2026 17:41:34 +0200 Subject: [PATCH 2/5] test(core): check each keepalive hold by running the ping timer's callback --- packages/core/test/cache-keepalive.test.ts | 58 +++++++++++++++------- 1 file changed, 39 insertions(+), 19 deletions(-) diff --git a/packages/core/test/cache-keepalive.test.ts b/packages/core/test/cache-keepalive.test.ts index 97051ea98..8aa4bb5f6 100644 --- a/packages/core/test/cache-keepalive.test.ts +++ b/packages/core/test/cache-keepalive.test.ts @@ -1,4 +1,4 @@ -import { afterEach, beforeEach, describe, expect, test } from 'bun:test'; +import { afterEach, beforeEach, describe, expect, spyOn, test } from 'bun:test'; import { DEFAULT_DELEGATION_CONFIG, checkSettingsPatch, type Turn, type Usage } from '@boite/contracts'; import type { CoreClient } from '../src/client.ts'; import { SHORT_ANSWERS } from '../src/agent-guide.ts'; @@ -210,42 +210,62 @@ describe('cache keepalive', () => { test('turning the setting off, archiving and a user turn each hold the ping', async () => { const s = await setup(h); try { - // The ping is due 1 s after the last request, 900 ms after a turn ends: each hold below lands well - // before it, and each wait outlasts it. At 200 ms, a Linux arm64 run archived too late (#635). - CACHE_KEEPALIVE.marginMs = 300_000 - 1_000; - // Off before the ping comes. + // The timer is set a minute after the last request, past the end of the test, so none + // races a hold. Each check makes the ping due and runs the timer's own callback once the + // hold is done. A ping 200 ms, then 900 ms, after the turn lost to a late archive on a + // loaded runner (#639). + const later = 300_000 - 60_000; + CACHE_KEEPALIVE.marginMs = later; + const keepalive = h.core.threads.cacheKeepalive as unknown as { waits: Map; fire(threadId: string): void }; + const settled = spyOn(h.core.threads.cacheKeepalive, 'turnFinished'); + const turn = async () => { const before = settled.mock.calls.length; await s.turn(); await waitFor(() => settled.mock.calls.length > before); }; + const armed = () => keepalive.waits.get(s.threadId)?.timer != null; + const fire = async () => { + CACHE_KEEPALIVE.marginMs = 300_000; + try { keepalive.fire(s.threadId); } finally { CACHE_KEEPALIVE.marginMs = later; } + return (await s.pings()).length; + }; + + // Nothing held, the timer's call sends the ping. await s.client.call('settings.set', { cacheKeepalive: { hours: 12 } }); await s.spawn(); - await s.turn(); + await turn(); + expect(armed()).toBe(true); + const pinged = s.client.next('turn.finished', t => t.threadId === s.threadId && t.execution?.operation === 'keepalive'); + expect(await fire()).toBe(1); + expect((await pinged).status).toBe('done'); + await waitFor(armed); + + // Off before the ping comes. await s.client.call('settings.set', { cacheKeepalive: null }); - await pause(1_200); - expect(await s.pings()).toEqual([]); + expect(await fire()).toBe(1); // Off from the start: nothing is planned. - await s.turn(); - await pause(1_200); - expect(await s.pings()).toEqual([]); + await turn(); + expect(armed()).toBe(false); + expect(await fire()).toBe(1); // A user turn that runs past the ping's time: no ping while it runs. await s.client.call('settings.set', { cacheKeepalive: { hours: 12 } }); - await s.turn(); + await turn(); + expect(armed()).toBe(true); s.state.holdParent = true; const started = s.client.next('turn.started', t => t.threadId === s.threadId && !t.execution?.operation); await s.client.call('turns.start', { threadId: s.threadId, prompt: 'long' }); await started; - await pause(1_200); - expect(await s.pings()).toEqual([]); + expect(await fire()).toBe(1); s.state.holdParent = false; - const ended = s.client.next('turn.finished', t => t.threadId === s.threadId && !t.execution?.operation); + const ended = settled.mock.calls.length; s.held.get(s.threadId)!(); - await ended; + await waitFor(() => settled.mock.calls.length > ended); + expect(armed()).toBe(true); // Archived before the ping comes. await s.client.call('threads.archive', { threadId: s.threadId, archived: true }); - await pause(1_200); - expect(await s.pings()).toEqual([]); + expect(await fire()).toBe(1); + expect(armed()).toBe(false); } finally { s.restore(); } - }, 10_000); + }); test('a child result that comes in during a ping stops it and is delivered', async () => { const s = await setup(h); From 1810db77904ee733f7c2bd43297d3865cff3543d Mon Sep 17 00:00:00 2001 From: meetsu <96637888+klNuno@users.noreply.github.com> Date: Mon, 19 Oct 2026 17:41:35 +0200 Subject: [PATCH 3/5] test(core): compare checkpoint inodes exactly on NTFS --- packages/core/test/rewind-files.test.ts | 24 +++++++++++++++--------- 1 file changed, 15 insertions(+), 9 deletions(-) diff --git a/packages/core/test/rewind-files.test.ts b/packages/core/test/rewind-files.test.ts index f28812af0..36da7c07c 100644 --- a/packages/core/test/rewind-files.test.ts +++ b/packages/core/test/rewind-files.test.ts @@ -434,6 +434,12 @@ test('an external edit to an affected file refuses the rewind without truncating }); const hashOf = (text: string) => createHash('sha256').update(text).digest('hex'); +/** + * A file's inode, exact. NTFS ids carry a sequence number in their top 16 bits + * and pass 2^53; near 2^55 a number keeps one id in 8, so two private copies written + * one after the other read as one inode on a Windows runner (job 118081174911). + */ +const inodeOf = async (path: string) => (await stat(path, { bigint: true })).ino; test('threads on one folder share each blob, and a discarded thread\'s blobs are collected while the other still rewinds', async () => { await mkdir(join(cwd, 'src', 'deep'), { recursive: true }); @@ -448,8 +454,8 @@ test('threads on one folder share each blob, and a discarded thread\'s blobs are const messageId = await run('second'); const shared = join(h.dataDir, 'checkpoints', 'objects'); for (const text of ['initial', 'agent']) { - const blob = await stat(sharedBlob(shared, hashOf(text))); - for (const thread of [first, threadId]) expect((await stat(join(h.dataDir, 'checkpoints', thread, 'objects', hashOf(text)))).ino).toBe(blob.ino); + const blob = await inodeOf(sharedBlob(shared, hashOf(text))); + for (const thread of [first, threadId]) expect(await inodeOf(join(h.dataDir, 'checkpoints', thread, 'objects', hashOf(text)))).toBe(blob); } await h.core.threads.codeCheckpoints.discard([first]); @@ -483,7 +489,7 @@ test('a thread saved before the shared store still rewinds, and its next snapsho expect(await readFile(join(cwd, 'app.ts'), 'utf8')).toBe('initial'); expect((await stat(join(objects, hashOf('initial')))).nlink).toBe(1); await run('again'); - expect((await stat(join(objects, hashOf('initial')))).ino).toBe((await stat(sharedBlob(join(h.dataDir, 'checkpoints', 'objects'), hashOf('initial')))).ino); + expect(await inodeOf(join(objects, hashOf('initial')))).toBe(await inodeOf(sharedBlob(join(h.dataDir, 'checkpoints', 'objects'), hashOf('initial')))); }); test('a short shared blob left by a crash is replaced instead of linked', async () => { @@ -525,14 +531,14 @@ test('private copies from before the shared store are adopted once, end as one c await privateCopies(second); await rm(join(h.dataDir, 'checkpoints', 'objects'), { recursive: true }); const named = (thread: string, text: string) => join(h.dataDir, 'checkpoints', thread, 'objects', hashOf(text)); - expect((await stat(named(first, initial))).ino).not.toBe((await stat(named(second, initial))).ino); + expect(await inodeOf(named(first, initial))).not.toBe(await inodeOf(named(second, initial))); await h.core.threads.codeCheckpoints.maintain(); const shared = join(h.dataDir, 'checkpoints', 'objects'); for (const text of [initial, agent]) { - const blob = await stat(sharedBlob(shared, hashOf(text))); - expect(blob.nlink).toBe(3); - for (const thread of [first, second]) expect((await stat(named(thread, text))).ino).toBe(blob.ino); + const blob = await stat(sharedBlob(shared, hashOf(text)), { bigint: true }); + expect(blob.nlink).toBe(3n); + for (const thread of [first, second]) expect(await inodeOf(named(thread, text))).toBe(blob.ino); // Adopted into the store as a frame: the name stays the hash of the original bytes. const stored = await readFile(sharedBlob(shared, hashOf(text))); expect(stored.subarray(0, 4)).toEqual(ZSTD_MAGIC); @@ -568,7 +574,7 @@ test('a copy that does not match its name is left alone, and the rest of the fol const shared = join(h.dataDir, 'checkpoints', 'objects'); expect(await readFile(join(objects, hashOf(text)), 'utf8')).toBe('damaged'); await expect(stat(sharedBlob(shared, hashOf(text)))).rejects.toMatchObject({ code: 'ENOENT' }); - expect((await stat(join(objects, hashOf(other)))).ino).toBe((await stat(sharedBlob(shared, hashOf(other)))).ino); + expect(await inodeOf(join(objects, hashOf(other)))).toBe(await inodeOf(sharedBlob(shared, hashOf(other)))); }); test('compressed and raw blobs, framed and plain manifests all restore byte for byte', async () => { @@ -658,7 +664,7 @@ test('a damaged shared frame of the right size is linked without reading it, and await writeFile(path, damaged); const objects = join(h.dataDir, 'checkpoints', threadId, 'objects'); const before = await snapshot(h.core, threadId, cwd, objects, undefined, shared); - expect((await stat(join(objects, hash))).ino).toBe((await stat(path)).ino); + expect(await inodeOf(join(objects, hash))).toBe(await inodeOf(path)); await writeFile(join(cwd, 'app.ts'), 'agent'); const after = await snapshot(h.core, threadId, cwd, objects, undefined, shared); await expect(restoreFiles(cwd, objects, [{ name: 'app.ts', before: before['app.ts'], after: after['app.ts'] }])).rejects.toThrow('app.ts is missing or corrupt'); From a9eb0e3a1957fc4d29a0d3cbad18ea9dacb3b831 Mon Sep 17 00:00:00 2001 From: meetsu <96637888+klNuno@users.noreply.github.com> Date: Mon, 19 Oct 2026 17:41:36 +0200 Subject: [PATCH 4/5] fix(browser): say whether the browser or the page stalled when a sleeping tab misses a step --- docs/browser.md | 13 +++++- packages/core/src/browser.ts | 5 +++ packages/core/src/browser/sleep.ts | 51 +++++++++++++++++++++--- packages/core/test/browser-sleep.test.ts | 32 +++++++++++++++ packages/core/test/browser/fixture.ts | 3 +- 5 files changed, 96 insertions(+), 8 deletions(-) diff --git a/docs/browser.md b/docs/browser.md index 979656c60..6050867a9 100644 --- a/docs/browser.md +++ b/docs/browser.md @@ -168,6 +168,15 @@ then runs, and the page is visible and focused again when it does. A tab closed while asleep is woken first, and a freeze that fails is tried again after the wait. A page asleep keeps its state; its timers resume where they stopped, and a page that reads the clock sees the time pass. +Each call of a freeze or a wake has 5 seconds. A frozen page still answers +DevTools at once (measured on Windows on 2026-10-19), so a call that misses +them met a stalled renderer or browser, not a frozen page: a wake that fails +fails the command that asked for it, the tab stays asleep and the next use +wakes it again. The error says whether the browser itself still answered +(`Target.getTargetInfo` for the tab), and a `browser.sleep-late` warning in +the logs says when the page answered after, or that it never did within 30 +seconds. + A tab the desktop app hosts gets the same calls through the relay: `Page` and `Emulation` are among the domains an agent webview takes. The desktop's own pages, the ones the user browses, are suspended once hidden @@ -417,8 +426,8 @@ read back, a recording discarded at the end of a turn, a page that sleeps once nobody uses it and meets the next command and viewer awake and focused, one kept awake by `browser.remoteWatch`, and a machine without a browser. `browser-sleep.test.ts` checks, with the page stubbed, that a command arriving during a freeze runs after the wake, and that -a held or closed tab never sleeps, and that a running turn holds an unused -tab only 5 minutes. `AgentBrowserSurface.test.ts` checks that the desktop app +a held or closed tab never sleeps, that a running turn holds an unused +tab only 5 minutes, and that a wake call that misses its time names who stalled. `AgentBrowserSurface.test.ts` checks that the desktop app reports a hosted tab it shows, only while its window is visible. `browser-cli.test.ts` checks the CLI's files with the browser stubbed. `tests/e2e/agent-browser-core.test.ts` runs the whole path on a real core: the owner's desktop at 1280 × 900 and a paired phone at 390 × 844 see the cover, diff --git a/packages/core/src/browser.ts b/packages/core/src/browser.ts index 8a2785313..1166febff 100644 --- a/packages/core/src/browser.ts +++ b/packages/core/src/browser.ts @@ -93,6 +93,11 @@ export class AgentBrowser { constructor(core: Core, private findBrowser = findChromium) { this.#core = core; + // A freeze or wake step that missed its time: the browser process answers its own targets without the page's renderer. + this.#sleep.browserAnswers = tab => tab.engine.cdp.send('Target.getTargetInfo', { targetId: tab.targetId }); + this.#sleep.lateAnswer = (tab, method, after) => core.logs.record('warn', typeof after === 'number' + ? `A sleeping tab's page answered ${method} ${after} ms after it was sent` + : `A sleeping tab's page never answered ${method}: ${after.message}`, { source: 'browser', event: 'browser.sleep-late', threadId: tab.threadId, data: { method } }); this.#downloads = new BrowserDownloads(() => core.dataDir, message => core.log('warn', message)); this.#engines = new BrowserEngines(core, this.#host, () => this.findBrowser(), this.#machine, BROWSER_SCOPE, engine => this.#targets(engine), id => this.#drop(id), this.#downloads); diff --git a/packages/core/src/browser/sleep.ts b/packages/core/src/browser/sleep.ts index daf7996c7..a44cb7874 100644 --- a/packages/core/src/browser/sleep.ts +++ b/packages/core/src/browser/sleep.ts @@ -42,8 +42,23 @@ export function sleepState(): SleepState { } const STEP_MS = 5000; +/** How long a step that missed its time is still listened to, so the log says whether its answer came late or not at all. */ +const LATE_MS = 30_000; +/** What the browser gets to answer for itself once a step missed its time: the command that waits pays for it. */ +const PROBE_MS = 1000; export class TabSleep { + /** What each DevTools call of a freeze or a wake may take; tests shorten it. */ + stepMs = STEP_MS; + /** + * Asked of the browser itself when a step of a tab misses its time: an + * answer puts the stall in that page's renderer, none in the browser or + * its connection. + */ + browserAnswers: (tab: T) => Promise = () => Promise.resolve(); + /** Hears when a step that missed its time got its answer, in ms after it was sent, or why none came. */ + lateAnswer: (tab: T, method: string, after: number | Error) => void = () => {}; + /** * `held` says whether something keeps the tab awake without a use running: * a viewer, a recording. `turning` says whether its agent's turn runs, which @@ -72,8 +87,8 @@ export class TabSleep { wake(tab: T): Promise { return this.#queue(tab, async () => { if (!tab.sleep.asleep) return; - await tab.page.send('Page.setWebLifecycleState', { state: 'active' }, STEP_MS); - await tab.page.send('Emulation.setFocusEmulationEnabled', { enabled: true }, STEP_MS); + await this.#step(tab, 'Page.setWebLifecycleState', { state: 'active' }); + await this.#step(tab, 'Emulation.setFocusEmulationEnabled', { enabled: true }); tab.sleep.asleep = false; }); } @@ -119,21 +134,47 @@ export class TabSleep { return this.#queue(tab, async () => { if (tab.sleep.asleep || tab.sleep.dropped || tab.sleep.uses > 0 || this.#held(tab) || this.#turnHolds(tab)) return; try { - await tab.page.send('Emulation.setFocusEmulationEnabled', { enabled: false }, STEP_MS); - await tab.page.send('Page.setWebLifecycleState', { state: 'frozen' }, STEP_MS); + await this.#step(tab, 'Emulation.setFocusEmulationEnabled', { enabled: false }); + await this.#step(tab, 'Page.setWebLifecycleState', { state: 'frozen' }); tab.sleep.asleep = true; } catch { // A page that cannot freeze stays as it was and tries again after the wait; one that is gone is dropped by its tab. - await tab.page.send('Emulation.setFocusEmulationEnabled', { enabled: true }, STEP_MS).catch(() => {}); + await this.#step(tab, 'Emulation.setFocusEmulationEnabled', { enabled: true }).catch(() => {}); tab.sleep.heldAt = Date.now(); this.schedule(tab); } }); } + /** + * One DevTools call of a freeze or a wake, given `stepMs`. A frozen page + * answers at once (measured on 2026-10-19), so a call that misses its time + * met a stalled renderer or browser: the error says whether the browser + * itself still answered, and the late answer is still awaited for the log. + */ + async #step(tab: T, method: string, params: Record): Promise { + const sent = performance.now(); + const answer = tab.page.send(method, params, LATE_MS); + if (await within(answer.then(() => true), this.stepMs) !== null) return; + void answer.then(() => this.lateAnswer(tab, method, Math.round(performance.now() - sent)), (error: Error) => this.lateAnswer(tab, method, error)); + const probed = performance.now(); + const browser = await within(Promise.resolve(this.browserAnswers(tab)).then(() => true, () => null), Math.min(PROBE_MS, this.stepMs)) === null + ? 'the browser itself did not answer either' + : `the browser itself answered in ${Math.round(performance.now() - probed)} ms`; + throw new Error(`the browser did not answer ${method} within ${this.stepMs / 1000} seconds; ${browser}`); + } + #queue(tab: T, run: () => Promise): Promise { const next = tab.sleep.turn.then(run); tab.sleep.turn = next.catch(() => {}); return next; } } + +/** What `promise` gives within `ms`, or null; its rejection passes through. */ +async function within(promise: Promise, ms: number): Promise { + let timer: ReturnType | undefined; + try { + return await Promise.race([promise, new Promise(resolve => { timer = setTimeout(() => resolve(null), ms); })]); + } finally { clearTimeout(timer); } +} diff --git a/packages/core/test/browser-sleep.test.ts b/packages/core/test/browser-sleep.test.ts index 33470aed4..495e9a9a8 100644 --- a/packages/core/test/browser-sleep.test.ts +++ b/packages/core/test/browser-sleep.test.ts @@ -115,6 +115,38 @@ test('a wake that fails leaves the tab asleep, and the next use wakes it', async sleep.drop(tab); }); +// A wake step that gets no answer in time failed a command on a macOS runner +// with only "did not answer Emulation.setFocusEmulationEnabled within 5 +// seconds" (job 118094995614). A frozen page answers at once, so the error +// says whether the browser itself still answered, and the log hears when, or +// whether, the page answered after. +test('a wake step that misses its time says whether the browser answered, and when the page did', async () => { + const { tab, calls, holdNext, release, held } = fakeTab(); + const sleep = new TabSleep(() => false, () => false, 20); + sleep.stepMs = 50; + const late: Array<[string, number | string]> = []; + sleep.lateAnswer = (_tab, method, after) => late.push([method, typeof after === 'number' ? after : after.message]); + sleep.schedule(tab); + await until(() => tab.sleep.asleep); + holdNext('Emulation.setFocusEmulationEnabled'); + await expect(sleep.use(tab, async () => { calls.push('first'); })).rejects.toThrow('the browser did not answer Emulation.setFocusEmulationEnabled within 0.05 seconds; the browser itself answered in'); + expect(tab.sleep.asleep).toBe(true); + expect(late).toEqual([]); + release('Emulation.setFocusEmulationEnabled'); + await until(() => late.length === 1); + expect(late[0]![0]).toBe('Emulation.setFocusEmulationEnabled'); + expect(late[0]![1]).toBeGreaterThanOrEqual(50); + // A browser that does not answer its own targets either is named so. + sleep.browserAnswers = () => new Promise(() => {}); + holdNext('Page.setWebLifecycleState'); + await expect(sleep.use(tab, async () => {})).rejects.toThrow('within 0.05 seconds; the browser itself did not answer either'); + release('Page.setWebLifecycleState'); + await sleep.use(tab, async () => { calls.push('second'); }); + expect(calls.at(-1)).toBe('second'); + expect(held('Page.setWebLifecycleState')).toBe(false); + sleep.drop(tab); +}); + // A turn that runs for half an hour without touching its tab must not keep // it awake throughout: the turn holds it only for a while after its last use, // and the next command wakes it. The hold is measured from the use to the diff --git a/packages/core/test/browser/fixture.ts b/packages/core/test/browser/fixture.ts index 403b600c0..1530e288e 100644 --- a/packages/core/test/browser/fixture.ts +++ b/packages/core/test/browser/fixture.ts @@ -86,7 +86,8 @@ export function createBrowserFixture() { opened.harness = harness = await startTestCore(); const record = harness.core.logs.record.bind(harness.core.logs); harness.core.logs.record = (level, message, context = {}, at) => { - if (context.event === 'rpc.failed') failures.push(message); + // A sleeping tab's late answer explains a wake that failed (`browser/sleep.ts`). + if (context.event === 'rpc.failed' || context.event === 'browser.sleep-late') failures.push(message); record(level, message, context, at); }; opened.owner = owner = await harness.connect(); From eaff6b1c2aa336069e396876bba661444a05c900 Mon Sep 17 00:00:00 2001 From: meetsu <96637888+klNuno@users.noreply.github.com> Date: Mon, 19 Oct 2026 18:29:04 +0200 Subject: [PATCH 5/5] fix(browser): fail a missed sleep step at its time and probe the browser after --- docs/browser.md | 11 +++++---- packages/core/src/browser.ts | 5 +++- packages/core/src/browser/sleep.ts | 25 ++++++++++--------- packages/core/test/browser-sleep.test.ts | 31 +++++++++++++++++------- packages/core/test/browser/fixture.ts | 4 +-- 5 files changed, 47 insertions(+), 29 deletions(-) diff --git a/docs/browser.md b/docs/browser.md index 6050867a9..d5752e92e 100644 --- a/docs/browser.md +++ b/docs/browser.md @@ -172,10 +172,11 @@ Each call of a freeze or a wake has 5 seconds. A frozen page still answers DevTools at once (measured on Windows on 2026-10-19), so a call that misses them met a stalled renderer or browser, not a frozen page: a wake that fails fails the command that asked for it, the tab stays asleep and the next use -wakes it again. The error says whether the browser itself still answered -(`Target.getTargetInfo` for the tab), and a `browser.sleep-late` warning in -the logs says when the page answered after, or that it never did within 30 -seconds. +wakes it again. The command fails at those 5 seconds; after it, a +`browser.sleep-stalled` warning says whether the browser itself still +answered (`Target.getTargetInfo` for the tab, within 1 second), and a +`browser.sleep-late` warning says when the page answered, or that it never did +within 30 seconds. A tab the desktop app hosts gets the same calls through the relay: `Page` and `Emulation` are among the domains an agent webview takes. The desktop's own @@ -427,7 +428,7 @@ once nobody uses it and meets the next command and viewer awake and focused, one kept awake by `browser.remoteWatch`, and a machine without a browser. `browser-sleep.test.ts` checks, with the page stubbed, that a command arriving during a freeze runs after the wake, and that a held or closed tab never sleeps, that a running turn holds an unused -tab only 5 minutes, and that a wake call that misses its time names who stalled. `AgentBrowserSurface.test.ts` checks that the desktop app +tab only 5 minutes, and that a wake call that misses its time fails at once and then names who stalled. `AgentBrowserSurface.test.ts` checks that the desktop app reports a hosted tab it shows, only while its window is visible. `browser-cli.test.ts` checks the CLI's files with the browser stubbed. `tests/e2e/agent-browser-core.test.ts` runs the whole path on a real core: the owner's desktop at 1280 × 900 and a paired phone at 390 × 844 see the cover, diff --git a/packages/core/src/browser.ts b/packages/core/src/browser.ts index 1166febff..2f3897c0b 100644 --- a/packages/core/src/browser.ts +++ b/packages/core/src/browser.ts @@ -94,7 +94,10 @@ export class AgentBrowser { constructor(core: Core, private findBrowser = findChromium) { this.#core = core; // A freeze or wake step that missed its time: the browser process answers its own targets without the page's renderer. - this.#sleep.browserAnswers = tab => tab.engine.cdp.send('Target.getTargetInfo', { targetId: tab.targetId }); + this.#sleep.browserAnswers = (tab, timeoutMs) => tab.engine.cdp.send('Target.getTargetInfo', { targetId: tab.targetId }, undefined, timeoutMs); + this.#sleep.browserAnswered = (tab, method, ms) => core.logs.record('warn', ms === null + ? `A sleeping tab missed ${method}, and the browser did not answer for itself within 1 s either` + : `A sleeping tab missed ${method}, while the browser answered for itself in ${ms} ms: the page's renderer stalled`, { source: 'browser', event: 'browser.sleep-stalled', threadId: tab.threadId, data: { method } }); this.#sleep.lateAnswer = (tab, method, after) => core.logs.record('warn', typeof after === 'number' ? `A sleeping tab's page answered ${method} ${after} ms after it was sent` : `A sleeping tab's page never answered ${method}: ${after.message}`, { source: 'browser', event: 'browser.sleep-late', threadId: tab.threadId, data: { method } }); diff --git a/packages/core/src/browser/sleep.ts b/packages/core/src/browser/sleep.ts index a44cb7874..b0cdafed2 100644 --- a/packages/core/src/browser/sleep.ts +++ b/packages/core/src/browser/sleep.ts @@ -44,18 +44,20 @@ export function sleepState(): SleepState { const STEP_MS = 5000; /** How long a step that missed its time is still listened to, so the log says whether its answer came late or not at all. */ const LATE_MS = 30_000; -/** What the browser gets to answer for itself once a step missed its time: the command that waits pays for it. */ +/** What the browser gets to answer for itself once a step missed its time. */ const PROBE_MS = 1000; export class TabSleep { /** What each DevTools call of a freeze or a wake may take; tests shorten it. */ stepMs = STEP_MS; /** - * Asked of the browser itself when a step of a tab misses its time: an - * answer puts the stall in that page's renderer, none in the browser or - * its connection. + * Asked of the browser itself, within `timeoutMs`, when a step of a tab + * misses its time: an answer puts the stall in that page's renderer, none + * in the browser or its connection. */ - browserAnswers: (tab: T) => Promise = () => Promise.resolve(); + browserAnswers: (tab: T, timeoutMs: number) => Promise = () => Promise.resolve(); + /** Hears, once the step has failed, how long the browser took to answer for itself, or null for no answer in time. */ + browserAnswered: (tab: T, method: string, ms: number | null) => void = () => {}; /** Hears when a step that missed its time got its answer, in ms after it was sent, or why none came. */ lateAnswer: (tab: T, method: string, after: number | Error) => void = () => {}; @@ -149,19 +151,18 @@ export class TabSleep { /** * One DevTools call of a freeze or a wake, given `stepMs`. A frozen page * answers at once (measured on 2026-10-19), so a call that misses its time - * met a stalled renderer or browser: the error says whether the browser - * itself still answered, and the late answer is still awaited for the log. + * met a stalled renderer or browser. The step fails at its time; whether + * the browser itself still answers, and when the page does, reach the log after. */ async #step(tab: T, method: string, params: Record): Promise { const sent = performance.now(); const answer = tab.page.send(method, params, LATE_MS); if (await within(answer.then(() => true), this.stepMs) !== null) return; void answer.then(() => this.lateAnswer(tab, method, Math.round(performance.now() - sent)), (error: Error) => this.lateAnswer(tab, method, error)); - const probed = performance.now(); - const browser = await within(Promise.resolve(this.browserAnswers(tab)).then(() => true, () => null), Math.min(PROBE_MS, this.stepMs)) === null - ? 'the browser itself did not answer either' - : `the browser itself answered in ${Math.round(performance.now() - probed)} ms`; - throw new Error(`the browser did not answer ${method} within ${this.stepMs / 1000} seconds; ${browser}`); + const probeMs = Math.min(PROBE_MS, this.stepMs), probed = performance.now(); + void within(Promise.resolve(this.browserAnswers(tab, probeMs)).then(() => true, () => null), probeMs) + .then(answered => this.browserAnswered(tab, method, answered === null ? null : Math.round(performance.now() - probed))); + throw new Error(`the browser did not answer ${method} within ${this.stepMs / 1000} seconds`); } #queue(tab: T, run: () => Promise): Promise { diff --git a/packages/core/test/browser-sleep.test.ts b/packages/core/test/browser-sleep.test.ts index 495e9a9a8..98388d947 100644 --- a/packages/core/test/browser-sleep.test.ts +++ b/packages/core/test/browser-sleep.test.ts @@ -117,33 +117,46 @@ test('a wake that fails leaves the tab asleep, and the next use wakes it', async // A wake step that gets no answer in time failed a command on a macOS runner // with only "did not answer Emulation.setFocusEmulationEnabled within 5 -// seconds" (job 118094995614). A frozen page answers at once, so the error -// says whether the browser itself still answered, and the log hears when, or -// whether, the page answered after. -test('a wake step that misses its time says whether the browser answered, and when the page did', async () => { - const { tab, calls, holdNext, release, held } = fakeTab(); +// seconds" (job 118094995614). A frozen page answers at once, so the log says +// after whether the browser itself still answered, and when, or whether, the +// page did. The command fails at the step's time, not after the probe. +test('a wake step that misses its time fails at once, then logs whether the browser answered and when the page did', async () => { + const { tab, calls, holdNext, release } = fakeTab(); const sleep = new TabSleep(() => false, () => false, 20); sleep.stepMs = 50; const late: Array<[string, number | string]> = []; + const stalls: Array<[string, number | null]> = []; sleep.lateAnswer = (_tab, method, after) => late.push([method, typeof after === 'number' ? after : after.message]); + sleep.browserAnswered = (_tab, method, ms) => stalls.push([method, ms]); + let answerProbe!: () => void; + const probes: number[] = []; + sleep.browserAnswers = (_tab, timeoutMs) => { probes.push(timeoutMs); return new Promise(resolve => { answerProbe = resolve; }); }; sleep.schedule(tab); await until(() => tab.sleep.asleep); holdNext('Emulation.setFocusEmulationEnabled'); - await expect(sleep.use(tab, async () => { calls.push('first'); })).rejects.toThrow('the browser did not answer Emulation.setFocusEmulationEnabled within 0.05 seconds; the browser itself answered in'); + await expect(sleep.use(tab, async () => { calls.push('first'); })).rejects.toThrow(/^the browser did not answer Emulation\.setFocusEmulationEnabled within 0\.05 seconds$/); + // The probe is still out: the command did not wait for it. + expect(stalls).toEqual([]); + expect(probes).toEqual([50]); expect(tab.sleep.asleep).toBe(true); + answerProbe(); + await until(() => stalls.length === 1); + expect(stalls[0]![0]).toBe('Emulation.setFocusEmulationEnabled'); + expect(stalls[0]![1]).toBeGreaterThanOrEqual(0); expect(late).toEqual([]); release('Emulation.setFocusEmulationEnabled'); await until(() => late.length === 1); expect(late[0]![0]).toBe('Emulation.setFocusEmulationEnabled'); expect(late[0]![1]).toBeGreaterThanOrEqual(50); - // A browser that does not answer its own targets either is named so. + // A browser that does not answer its own targets either is named so once its time is out. sleep.browserAnswers = () => new Promise(() => {}); holdNext('Page.setWebLifecycleState'); - await expect(sleep.use(tab, async () => {})).rejects.toThrow('within 0.05 seconds; the browser itself did not answer either'); + await expect(sleep.use(tab, async () => {})).rejects.toThrow('within 0.05 seconds'); + await until(() => stalls.length === 2); + expect(stalls[1]).toEqual(['Page.setWebLifecycleState', null]); release('Page.setWebLifecycleState'); await sleep.use(tab, async () => { calls.push('second'); }); expect(calls.at(-1)).toBe('second'); - expect(held('Page.setWebLifecycleState')).toBe(false); sleep.drop(tab); }); diff --git a/packages/core/test/browser/fixture.ts b/packages/core/test/browser/fixture.ts index 1530e288e..4ddcf287d 100644 --- a/packages/core/test/browser/fixture.ts +++ b/packages/core/test/browser/fixture.ts @@ -86,8 +86,8 @@ export function createBrowserFixture() { opened.harness = harness = await startTestCore(); const record = harness.core.logs.record.bind(harness.core.logs); harness.core.logs.record = (level, message, context = {}, at) => { - // A sleeping tab's late answer explains a wake that failed (`browser/sleep.ts`). - if (context.event === 'rpc.failed' || context.event === 'browser.sleep-late') failures.push(message); + // What a sleeping tab's stalled step turned out to be explains a wake that failed (`browser/sleep.ts`). + if (context.event === 'rpc.failed' || context.event === 'browser.sleep-stalled' || context.event === 'browser.sleep-late') failures.push(message); record(level, message, context, at); }; opened.owner = owner = await harness.connect();