From 5a66f48ad2773fe6599cd315453f4c5d05ad8ea9 Mon Sep 17 00:00:00 2001 From: sganggs Date: Tue, 6 Oct 2026 17:31:01 +0800 Subject: [PATCH] =?UTF-8?q?feedback4:=20the=20real-server=20suites'=20long?= =?UTF-8?q?=20"own=20battle=20over"=20waits=20poll=20in=20slices=20under?= =?UTF-8?q?=20the=20browser's=20CDP=20protocol=20timeout=20(test/e2e/clien?= =?UTF-8?q?t.mjs=20waitForFunctionLong,=20PROTOCOL=5FTIMEOUT=5FMS=20=3D=20?= =?UTF-8?q?the=20Client's=2090=20s)=20=E2=80=94=20puppeteer=20runs=20a=20p?= =?UTF-8?q?age.waitForFunction's=20whole=20poll=20inside=20one=20Runtime.c?= =?UTF-8?q?allFunctionOn,=20so=20watch-bonds.e2e=20subtest=203's=20240=20s?= =?UTF-8?q?=20wait=20(line=20489)=20died=20with=20a=20bare=20"Waiting=20fa?= =?UTF-8?q?iled"=20(cause:=20Runtime.callFunctionOn=20timed=20out)=20whene?= =?UTF-8?q?ver=20the=20own=20battle=20at=201=C3=97=20outlasted=2090=20s=20?= =?UTF-8?q?(the=200.1.4=20candidate=20rerun:=20152=20s=20=E2=89=88=2062=20?= =?UTF-8?q?s=20to=20COMBAT=20+=2090=20s;=2065=E2=80=9367=20s=20in=20isolat?= =?UTF-8?q?ed=20runs);=20reproduced=20at=20the=20same=20line=20with=20a=20?= =?UTF-8?q?30=20s=20protocol=20timeout,=20which=20passes=20with=20the=20sl?= =?UTF-8?q?ices;=20playtest2.real's=20120=20s=20wait=20had=20the=20same=20?= =?UTF-8?q?gap=20(a=20silent=20'timeout'=20round);=20test/e2e/client-wait.?= =?UTF-8?q?test.js=20(slices=20until=20the=20deadline,=20other=20errors=20?= =?UTF-8?q?not=20retried,=20no=20Client=20suite=20with=20a=20plain=20wait?= =?UTF-8?q?=20as=20long=20as=20the=20protocol=20timeout);=20a=20test-harne?= =?UTF-8?q?ss=20timing=20flake,=20no=20product=20change;=20golden=20unchan?= =?UTF-8?q?ged?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- test/e2e/client-wait.test.js | 86 ++++++++++++++++++++++++++++++ test/e2e/client.mjs | 32 ++++++++++- test/ui/playtest2.real.e2e.test.js | 6 +-- test/ui/watch-bonds.e2e.test.js | 7 +-- 4 files changed, 124 insertions(+), 7 deletions(-) create mode 100644 test/e2e/client-wait.test.js diff --git a/test/e2e/client-wait.test.js b/test/e2e/client-wait.test.js new file mode 100644 index 00000000..09fec6ec --- /dev/null +++ b/test/e2e/client-wait.test.js @@ -0,0 +1,86 @@ +// test/e2e/client.mjs waitForFunctionLong (Node, no browser): a long wait of the real-server browser suites polls in +// slices shorter than the CDP protocol timeout. A plain page.waitForFunction runs its whole poll inside one +// Runtime.callFunctionOn, which the 90 s protocol timeout cut off: watch-bonds.e2e's "own battle over" wait (240 s) failed +// with a bare "Waiting failed" whenever the own battle at 1× lasted longer than 90 s (0.1.4 release candidate). +import { test } from 'node:test'; +import assert from 'node:assert/strict'; +import { readFileSync, readdirSync } from 'node:fs'; +import path from 'node:path'; +import { ROOT, PROTOCOL_TIMEOUT_MS, waitForFunctionLong } from './client.mjs'; + +const timeoutError = (ms) => Object.assign(new Error(`Waiting failed: ${ms}ms exceeded`), { name: 'TimeoutError' }); + +/** A page whose predicate turns true after `trueAfter` ms; each waitForFunction slice behaves like puppeteer's. */ +function fakePage(trueAfter) { + const t0 = Date.now(); + const calls = []; + return { + calls, + waitForFunction(fn, opts, ...args) { + calls.push({ fn, opts, args }); + const left = t0 + trueAfter - Date.now(); + return new Promise((resolve, reject) => { + if (left <= opts.timeout) setTimeout(() => resolve({ handle: 'ok', args }), Math.max(0, left)); + else setTimeout(() => reject(timeoutError(opts.timeout)), opts.timeout); + }); + }, + }; +} + +test('a wait longer than one slice keeps polling the same predicate until it holds', async () => { + const page = fakePage(95); + const fn = () => true; + const got = await waitForFunctionLong(page, fn, { timeout: 1000, polling: 200, slice: 30 }, 'a', 2); + assert.deepEqual(got, { handle: 'ok', args: ['a', 2] }); + assert.ok(page.calls.length >= 4, `sliced (${page.calls.length} calls)`); + for (const c of page.calls) { + assert.equal(c.fn, fn); + assert.deepEqual(c.args, ['a', 2]); + assert.equal(c.opts.polling, 200); + assert.ok(c.opts.timeout > 0 && c.opts.timeout <= 30, `slice ${c.opts.timeout}`); + } +}); + +test('the overall timeout still ends the wait with a TimeoutError naming it; the last slice is the remainder', async () => { + const page = fakePage(10_000); + const t0 = Date.now(); + await assert.rejects(waitForFunctionLong(page, () => false, { timeout: 70, slice: 30 }), (e) => e.name === 'TimeoutError' && /70ms exceeded/.test(e.message)); + assert.ok(Date.now() - t0 >= 65, 'not before the deadline'); + assert.ok(page.calls.at(-1).opts.timeout <= 30); + assert.ok(page.calls.reduce((n, c) => n + c.opts.timeout, 0) <= 75, 'the slices add up to the timeout'); +}); + +test('any other failure is not retried (a page error, a detached frame, the protocol timeout itself)', async () => { + for (const err of [new Error('Waiting failed'), Object.assign(new Error('boom'), { name: 'ProtocolError' })]) { + let n = 0; + const page = { waitForFunction: () => { n++; return Promise.reject(err); } }; + await assert.rejects(waitForFunctionLong(page, () => true, { timeout: 1000, slice: 30 }), (e) => e === err); + assert.equal(n, 1); + } +}); + +test('the default slice stays well under the protocol timeout every Client launches with', async () => { + const page = fakePage(0); + await waitForFunctionLong(page, () => true, { timeout: 240000 }); + assert.ok(page.calls[0].opts.timeout < PROTOCOL_TIMEOUT_MS / 2, `slice ${page.calls[0].opts.timeout}`); + const client = readFileSync(path.join(ROOT, 'test/e2e/client.mjs'), 'utf8'); + assert.match(client, /protocolTimeout: PROTOCOL_TIMEOUT_MS \}/, 'Client.open launches with the exported constant'); +}); + +test('no Client suite has a plain page.waitForFunction as long as the protocol timeout (use waitForFunctionLong)', () => { + const files = []; + for (const dir of ['test/ui', 'test/e2e']) { + for (const f of readdirSync(path.join(ROOT, dir))) if (/\.(m?js)$/.test(f)) files.push(path.join(dir, f)); + } + const long = []; + for (const f of files) { + const src = readFileSync(path.join(ROOT, f), 'utf8'); + if (!/from '\.\.\/e2e\/client\.mjs'|from '\.\/client\.mjs'/.test(src)) continue; + for (let i = src.indexOf('.waitForFunction('); i >= 0; i = src.indexOf('.waitForFunction(', i + 1)) { + const next = src.indexOf('.waitForFunction(', i + 1); + const m = src.slice(i, next < 0 ? undefined : next).match(/\{ timeout: ([0-9_]+)/); + if (m && Number(m[1].replace(/_/g, '')) >= PROTOCOL_TIMEOUT_MS) long.push(`${f}:${src.slice(0, i).split('\n').length} (${m[1]} ms)`); + } + } + assert.deepEqual(long, []); +}); diff --git a/test/e2e/client.mjs b/test/e2e/client.mjs index d425176f..a3ef4c1d 100644 --- a/test/e2e/client.mjs +++ b/test/e2e/client.mjs @@ -16,6 +16,36 @@ export const hasChrome = () => existsSync(CHROME); const CHROME_ARGS = ['--no-sandbox', '--no-first-run', '--autoplay-policy=no-user-gesture-required', '--disable-background-timer-throttling', '--disable-renderer-backgrounding', '--disable-backgrounding-occluded-windows', '--mute-audio', '--force-device-scale-factor=1']; +/** The CDP protocol timeout of every Client's browser: one DevTools call that takes longer fails (a hung page fails fast). */ +export const PROTOCOL_TIMEOUT_MS = 90000; + +/** + * `page.waitForFunction` for a wait that may outlast PROTOCOL_TIMEOUT_MS. Puppeteer awaits the whole poll inside ONE + * `Runtime.callFunctionOn`, so a predicate that is still false when the protocol timeout strikes rejects the wait with the + * bare "Waiting failed" (cause: "Runtime.callFunctionOn timed out") long before the wait's own `timeout` — e.g. an own + * battle at 1× that lasts longer than 90 s. This polls the same predicate in slices shorter than the protocol timeout until + * `timeout`: the condition and the deadline stay the same. Resolves to the predicate's JSHandle, rejects with a + * TimeoutError once `timeout` is over and at once with any other error. + * @param {{ waitForFunction: Function }} page + * @param {Function|string} fn + * @param {{ timeout?: number, polling?: number|string, slice?: number }} [opts] + * @param {...any} args passed to `fn` as with page.waitForFunction + */ +export async function waitForFunctionLong(page, fn, { timeout = 30000, polling = 250, slice = PROTOCOL_TIMEOUT_MS / 3 } = {}, ...args) { + const deadline = Date.now() + timeout; + for (;;) { + try { + return await page.waitForFunction(fn, { timeout: Math.max(1, Math.min(slice, deadline - Date.now())), polling }, ...args); + } catch (e) { + if (e?.name !== 'TimeoutError') throw e; + if (Date.now() >= deadline) { + const err = new Error(`Waiting failed: ${timeout}ms exceeded`, { cause: e }); + err.name = 'TimeoutError'; + throw err; + } + } + } +} /** A free TCP port on 127.0.0.1. */ export function freePort() { @@ -96,7 +126,7 @@ export class Client { async open(query = '') { mkdirSync(OUT, { recursive: true }); - this.browser = await this.puppeteer.launch({ executablePath: CHROME, headless: true, args: CHROME_ARGS, protocolTimeout: 90000 }); + this.browser = await this.puppeteer.launch({ executablePath: CHROME, headless: true, args: CHROME_ARGS, protocolTimeout: PROTOCOL_TIMEOUT_MS }); const [first] = await this.browser.pages(); const page = first || await this.browser.newPage(); this.page = page; diff --git a/test/ui/playtest2.real.e2e.test.js b/test/ui/playtest2.real.e2e.test.js index a5c79bf2..377ee9b0 100644 --- a/test/ui/playtest2.real.e2e.test.js +++ b/test/ui/playtest2.real.e2e.test.js @@ -20,7 +20,7 @@ import { test, describe } from 'node:test'; import assert from 'node:assert/strict'; import { existsSync } from 'node:fs'; import path from 'node:path'; -import { Client, ROOT, sleep, hasChrome, startRealServer, problemsOf } from '../e2e/client.mjs'; +import { Client, ROOT, sleep, hasChrome, startRealServer, problemsOf, waitForFunctionLong } from '../e2e/client.mjs'; const ENABLED = process.env.SP_E2E === '1' && hasChrome() && existsSync(path.join(ROOT, 'public/assets')); const ONLY = process.env.SP_P2_REAL || ''; @@ -252,8 +252,8 @@ describe('user playtest #2 item 6 — 前往查看 → 返回战场 in combat (r await c.waitFor((s) => s.phase === 'COMBAT', 'combat', 60000); await sleep(1500); assertNoPen(await battleViewState(c), `R${s0.round} own battle`); - // own battle over while the AI's field still runs - const target = await c.page.waitForFunction(() => { + // own battle over while the AI's field still runs (sliced: longer than the browser's 90 s protocol timeout) + const target = await waitForFunctionLong(c.page, () => { const s = globalThis.__SP__.store.get(); const r = globalThis.__SP_RUNNER__?.state?.(); const pub = s.match.public; diff --git a/test/ui/watch-bonds.e2e.test.js b/test/ui/watch-bonds.e2e.test.js index 3fb40ca9..40ee4225 100644 --- a/test/ui/watch-bonds.e2e.test.js +++ b/test/ui/watch-bonds.e2e.test.js @@ -30,7 +30,7 @@ import { test, describe } from 'node:test'; import assert from 'node:assert/strict'; import { existsSync } from 'node:fs'; import path from 'node:path'; -import { Client, ROOT, sleep, hasChrome, startRealServer, problemsOf } from '../e2e/client.mjs'; +import { Client, ROOT, sleep, hasChrome, startRealServer, problemsOf, waitForFunctionLong } from '../e2e/client.mjs'; const ENABLED = process.env.SP_E2E === '1' && hasChrome() && existsSync(path.join(ROOT, 'public/assets')); const HOST_KIT = ['chess_char_1_10_a', 'chess_char_1_12_a']; // 古米 (坚守), 艾丝黛尔 (萨尔贡) @@ -485,8 +485,9 @@ describe('DESIGN §20.15 — the bond strip shows the watched teammate\'s bonds await sleep(1500); for (const c of [host, guest]) if (!(await c.st()).ready) await c.click('.readybtn'); await host.waitFor((s) => s.phase === 'COMBAT', 'combat', 60000); - // the own battle over while a teammate's still runs - const target = await host.page.waitForFunction(() => { + // the own battle over while a teammate's still runs (at 1× it may last longer than the browser's 90 s protocol + // timeout, which cut a plain page.waitForFunction off with a bare "Waiting failed") + const target = await waitForFunctionLong(host.page, () => { const s = globalThis.__SP__.store.get(); const pub = s.match.public; if (pub?.phase !== 'COMBAT') return { gone: true };