diff --git a/tests/ci-plan.test.ts b/tests/ci-plan.test.ts index 9e80c8a..d6e7def 100644 --- a/tests/ci-plan.test.ts +++ b/tests/ci-plan.test.ts @@ -9,16 +9,23 @@ describe('tools/ci-plan: test shards', () => { expect(shardCount({ STOREBOUND_CI_SHARDS: '3' }, 10)).toBe(3); expect(shardCount({ STOREBOUND_CI_SHARDS: 'x' }, 10)).toBe(8); }); - test('balance: every file once, longest first, heavy suites never share a shard', () => { + test('balance: every file once; the heavy suites first, in one dedicated shard; light files balanced over the rest', () => { const cost: Record = { h1: 10, h2: 9, a: 5, b: 4, c: 3, d: 2, e: 1 }; const shards = balance(Object.keys(cost), 3, f => cost[f]!, ['h1', 'h2']); expect(shards.flat().sort()).toEqual(Object.keys(cost).sort()); - for (const s of shards) expect(s.filter(f => f.startsWith('h')).length).toBeLessThanOrEqual(1); - const loads = shards.map(s => s.reduce((n, f) => n + cost[f]!, 0)); + expect(shards[0]).toEqual(['h1', 'h2']); + const rest = shards.slice(1); + expect(rest).toHaveLength(2); + for (const s of rest) expect(s.some(f => f.startsWith('h'))).toBe(false); + const loads = rest.map(s => s.reduce((n, f) => n + cost[f]!, 0)); expect(Math.max(...loads) - Math.min(...loads)).toBeLessThanOrEqual(cost.a!); }); - test('balance: more heavy suites than shards still places each once; empty shards dropped', () => { - expect(balance(['h1', 'h2', 'h3'], 2, () => 1, ['h1', 'h2', 'h3']).flat().sort()).toEqual(['h1', 'h2', 'h3']); + test('balance: two browser shards split the heavy suites by cost; one shard in all takes everything; empty shards dropped', () => { + const cost: Record = { h1: 10, h2: 9, h3: 2, a: 1 }; + const shards = balance(Object.keys(cost), 4, f => cost[f]!, ['h1', 'h2', 'h3'], 2); + expect(shards.slice(0, 2).map(s => [...s].sort())).toEqual([['h1'], ['h2', 'h3']]); + expect(shards.slice(2)).toEqual([['a']]); + expect(balance(['h1', 'h2', 'a'], 1, () => 1, ['h1', 'h2']).flat().sort()).toEqual(['a', 'h1', 'h2']); expect(balance(['a'], 8, () => 1)).toEqual([['a']]); }); test('JUnit report: per-file seconds from the top-level suites only', () => { diff --git a/tests/console-fill.test.ts b/tests/console-fill.test.ts index 9734ee4..156f7d1 100644 --- a/tests/console-fill.test.ts +++ b/tests/console-fill.test.ts @@ -18,7 +18,7 @@ import { parseArgs } from '../cli/lib/args'; import { type ShipConfig, validateExtras } from '../cli/lib/config'; import { AGE_RATING_API, consoleAnswers, consoleResult, fillValue, FORM_IDS, type FormId, formMeta } from '../cli/lib/console-answers'; import { consoleReached, CREATE_APP_OPENERS, createAppAllowed, formDef, FORM_OPENERS, forbiddenControl, hasToken, isSignInText, isSignInUrl, navAllowed, navPlan, playDeveloperId, switchAllowed } from '../cli/lib/console-forms'; -import { AFTER_ALL_MS, AFTER_EACH_MS, launchTestBrowser, logLines, TEST_TICK_MS, TEST_WAITS, testScope } from './helpers/browser'; +import { AFTER_ALL_MS, AFTER_EACH_MS, launchTestBrowser, logLines, scaled, TEST_TICK_MS, TEST_WAITS, testScope, WaitTimeout } from './helpers/browser'; const config: ShipConfig = { app: { name: 'Example Game', profile: 'game', privacyPolicyUrl: 'https://example.com/privacy', supportUrl: 'https://example.com/support', website: 'https://example.com', contactEmail: 'support@example.com' }, @@ -175,11 +175,11 @@ if (!browser) console.warn(`console-fill browser tests skipped: no Chromium inst /** The contexts and engine runs of the current test, closed / awaited right after it (afterEach below). */ const scope = testScope(() => browser); /** Browser tests: a few seconds each on an idle machine; the timeout leaves room for a loaded one. */ -const BROWSER_TEST_MS = 30_000; +const BROWSER_TEST_MS = scaled(30_000); /** SLOW tests (engine "not here" timeouts, Chromium relaunches): ~5-10 s idle. */ -const SLOW_TEST_MS = 90_000; +const SLOW_TEST_MS = scaled(90_000); /** Engine waits that are expected to SUCCEED: they return as soon as the element is there, so a long cap costs nothing. */ -const FOUND_MS = 15_000; +const FOUND_MS = scaled(15_000); const FIX = join(import.meta.dir, 'fixtures', 'console'); /** Console URLs of the navigation plans -> modeled pages (bases: asc = asc, play = play). */ @@ -542,7 +542,7 @@ const tmpAccounts = () => { const d = mkdtempSync(join(tmpdir(), 'storebound-acc * navTimeoutMs is how long a step that IS there may take to show up (headroom for a loaded machine); a step that is * NOT there ends earlier, once its loaded page stays unchanged for TEST_WAITS.quietMs (tests/helpers/browser.ts). */ -const fast = (log: ReturnType) => ({ say: log.say, tickMs: TEST_TICK_MS, navTimeoutMs: 5000, signInWaitMs: 30_000, accountsFile: tmpAccounts(), env: {} }); +const fast = (log: ReturnType) => ({ say: log.say, tickMs: TEST_TICK_MS, navTimeoutMs: scaled(5000), signInWaitMs: 30_000, accountsFile: tmpAccounts(), env: {} }); const FILLED = (lines: string[]) => lines.some(m => /^New App: filled \d+/.test(m)); describe.skipIf(!browser)('sign-in and watching (headless, modeled pages on the real console hosts, routed locally)', () => { @@ -1004,10 +1004,10 @@ const playOgb = (u: URL): string | null => { return u.pathname === '/console' || u.pathname === '/console/u/0/developers' ? 'play-chooser-ogb.html' : null; }; const frameOn = (page: any, host: string): boolean => page.frames().some((f: any) => { try { return new URL(f.url()).hostname === host; } catch { return false; } }); -/** Test helper: waits until `pred` holds (at most 10 s). */ +/** Test helper: waits until `pred` holds (at most 10 s, scaled by the load). */ async function until(pred: () => boolean): Promise { - const end = Date.now() + 10_000; - while (!pred()) { if (Date.now() > end) throw new Error('until: timed out'); await Bun.sleep(50); } + const end = Date.now() + scaled(10_000); + while (!pred()) { if (Date.now() > end) throw new WaitTimeout('until: timed out'); await Bun.sleep(50); } } describe.skipIf(!browser)('sign-in detection: only the top-level URL, the main frame\'s form or an Apple sign-in frame', () => { diff --git a/tests/console-flow.test.ts b/tests/console-flow.test.ts index d817167..c10bcdb 100644 --- a/tests/console-flow.test.ts +++ b/tests/console-flow.test.ts @@ -13,7 +13,7 @@ import { APPLE_DATA_TYPE_IDS, type AppleDataTypeId, type AppleTypeAnswer } from import type { ShipConfig } from '../cli/lib/config'; import { type FlowWhere, flowAllowed, flowClass, FORM_BUTTONS, labelNames, setUpAllowed, setUpTexts, TYPE_ALIASES } from '../cli/lib/console-forms'; import { APPLE_PRIVACY_TYPES } from '../cli/lib/app-privacy'; -import { AFTER_ALL_MS, AFTER_EACH_MS, launchTestBrowser, logLines, TEST_TICK_MS, TEST_WAITS, testScope } from './helpers/browser'; +import { AFTER_ALL_MS, AFTER_EACH_MS, launchTestBrowser, logLines, scaled, TEST_TICK_MS, TEST_WAITS, testScope } from './helpers/browser'; const FIX = join(import.meta.dir, 'fixtures', 'console'); const base0: ShipConfig = { @@ -38,8 +38,8 @@ const { browser, skipWhy } = shared; if (!browser) console.warn(`console-flow browser tests skipped: no Chromium installed (${skipWhy}). Run \`bunx playwright install chromium\`.`); const scope = testScope(() => browser); // a whole App Privacy walk (6 types x 5 dialog steps) on a loaded CI machine: generous, still bounded -const TEST_MS = 90_000; -const WALK_MS = 75_000; +const TEST_MS = scaled(90_000); +const WALK_MS = scaled(75_000); let server: ReturnType | null = null; let base = ''; @@ -63,7 +63,7 @@ async function local(): Promise { const done = new Promise(r => ctx.on('close', () => { closed = true; r(); })); return { mode: 'profile', context: ctx, page, pages: () => ctx.pages(), closed: done, isClosed: () => closed, close: () => ctx.close(), cleanup: () => {} }; } -const fast = (log: ReturnType) => ({ say: log.say, tickMs: TEST_TICK_MS, navTimeoutMs: 5000, signInWaitMs: 30_000, env: {} }); +const fast = (log: ReturnType) => ({ say: log.say, tickMs: TEST_TICK_MS, navTimeoutMs: scaled(5000), signInWaitMs: 30_000, env: {} }); const clicks = (b: ConsoleBrowser): Promise => b.page.evaluate(() => (window as any).__clicks); const navClicks = (b: ConsoleBrowser): Promise => b.page.evaluate(() => (window as any).__navClicks()); /** Guardrail: a line that tells the owner to click a navigation control themselves. */ @@ -233,30 +233,46 @@ const SETUP = 'apple-app-privacy-setup.html'; const answersOf = (b: ConsoleBrowser) => b.page.evaluate(() => (window as any).__answers); describe.skipIf(!browser)('App Privacy: each data type set up from the real page ("Set Up " as plain text; fixture apple-app-privacy-setup.html)', () => { - scope.concurrent('every collected type is set up through its dialog (purposes > Next > linked > Next > two info steps > Next > Next > tracking > Save; purpose checkboxes without an accessible name); "?", Publish and the Edits never clicked; every step dumped', async () => { + scope.concurrent('every collected type is set up through its dialog (purposes > Next > linked > Next > two info steps > Next > Next > tracking > Save; purpose checkboxes without an accessible name); "?", Publish and the Edits never clicked', async () => { + const b = await local(); + const log = logLines(); + const run = scope.run(fillSession(b, { form: 'apple-app-privacy', config: six(), startUrl: base + SETUP, ...fast(log) })); + await log.wait('the Publish line', l => l.some(m => m.startsWith(PUBLISH)), WALK_MS); + expect(await b.page.evaluate(() => (window as any).__setups)).toEqual(SIX_NAMES.map(n => `Set Up ${n}`)); + expect(await b.page.evaluate(() => (window as any).__saves)).toBe(6); + const got = await answersOf(b); + expect(got['Device ID']).toEqual({ purposes: ['Third-Party Advertising', 'Analytics'], linked: 'no', tracking: 'yes' }); + expect(got['Purchase History']).toEqual({ purposes: ['App Functionality'], linked: 'yes', tracking: 'no' }); + expect(got['Product Interaction']).toEqual({ purposes: ['Analytics', 'Product Personalization'], linked: 'no', tracking: 'no' }); + expect(Object.keys(got).sort()).toEqual([...SIX_NAMES].sort()); + const c = await clicks(b); + for (const never of ['?', 'Publish', 'Edit', 'Cancel', 'Back', 'Definitions and Examples']) expect(c).not.toContain(never); + expect(c.filter(x => x === 'Next')).toHaveLength(24); // purposes, linked and the TWO info steps of each of 6 types + expect(log.lines.filter(m => m === 'an information-only step of the dialog: storebound pressed Next')).toHaveLength(12); + expect(c.filter(x => x === 'Save')).toHaveLength(6); + expect(log.lines).toContain('the Data Types section lists exactly the collected types of the config: storebound sets up each one'); + expect(log.lines).toContain('clicked "Set Up Purchase History" (navigation)'); + expect(log.lines.some(m => m.startsWith('answer needed'))).toBe(false); + expect(navAsked(log.lines)).toEqual([]); + await b.context.close(); + expect((await run).fallback).toBe(false); + }, TEST_MS); + + // --debug-dump writes a page dump (summary, HTML, screenshot) at every step: the first and the last type are walked + // (the four between were set up before with the config's purposes and are left as they are), which covers every + // kind of dump without six types' worth of screenshots on a loaded machine + scope.concurrent('every step dumped with --debug-dump: the start, each Set Up, each dialog step and each filled step', async () => { const dir = mkdtempSync(join(tmpdir(), 'sb-console-debug-')); try { const b = await local(); const log = logLines(); - const run = scope.run(fillSession(b, { form: 'apple-app-privacy', config: six(), startUrl: base + SETUP, ...fast(log), debugDir: dir, debugEveryStep: true })); + const before = ['Emails or Text Messages:App Functionality', 'Device ID:Third-Party Advertising|Analytics', 'Purchase History:App Functionality', 'Product Interaction:Analytics|Product Personalization']; + const url = `${base}${SETUP}?${before.map(p => `preset=${encodeURIComponent(p)}`).join('&')}`; + const run = scope.run(fillSession(b, { form: 'apple-app-privacy', config: six(), startUrl: url, ...fast(log), debugDir: dir, debugEveryStep: true })); await log.wait('the Publish line', l => l.some(m => m.startsWith(PUBLISH)), WALK_MS); - expect(await b.page.evaluate(() => (window as any).__setups)).toEqual(SIX_NAMES.map(n => `Set Up ${n}`)); - expect(await b.page.evaluate(() => (window as any).__saves)).toBe(6); - const got = await answersOf(b); - expect(got['Device ID']).toEqual({ purposes: ['Third-Party Advertising', 'Analytics'], linked: 'no', tracking: 'yes' }); - expect(got['Purchase History']).toEqual({ purposes: ['App Functionality'], linked: 'yes', tracking: 'no' }); - expect(got['Product Interaction']).toEqual({ purposes: ['Analytics', 'Product Personalization'], linked: 'no', tracking: 'no' }); - expect(Object.keys(got).sort()).toEqual([...SIX_NAMES].sort()); - const c = await clicks(b); - for (const never of ['?', 'Publish', 'Edit', 'Cancel', 'Back', 'Definitions and Examples']) expect(c).not.toContain(never); - expect(c.filter(x => x === 'Next')).toHaveLength(24); // purposes, linked and the TWO info steps of each of 6 types - expect(log.lines.filter(m => m === 'an information-only step of the dialog: storebound pressed Next')).toHaveLength(12); - expect(c.filter(x => x === 'Save')).toHaveLength(6); - expect(log.lines).toContain('the Data Types section lists exactly the collected types of the config: storebound sets up each one'); - expect(log.lines).toContain('clicked "Set Up Purchase History" (navigation)'); - expect(log.lines.some(m => m.startsWith('answer needed'))).toBe(false); + expect(await b.page.evaluate(() => (window as any).__setups)).toEqual(['Set Up Coarse Location', 'Set Up Crash Data']); + expect(log.lines).toContain('Device ID was set up before with the purposes of the config: left as it is'); expect(navAsked(log.lines)).toEqual([]); - // --debug-dump: the start, each Set Up, each dialog step and each filled step const names = readdirSync(dir); for (const want of [/-after-set-up-coarse-location$/, /-coarse-location-after-next$/, /-filled-coarse-location-purposes$/, /-filled-coarse-location-linked-to-/, /-filled-crash-data-tracking$/]) expect(names.some(n => want.test(n))).toBe(true); diff --git a/tests/console-persist.test.ts b/tests/console-persist.test.ts index 3bcb698..783ec76 100644 --- a/tests/console-persist.test.ts +++ b/tests/console-persist.test.ts @@ -3,7 +3,7 @@ // product uses for that profile (cli/shots/browser.ts, kind "visible"): real Google Chrome, else Playwright's full // Chromium, headless here so no window appears. Never the headless shell: it does not restore the last session, so the // cookie is always lost there. Skips (with the reason) only when neither is installed. Slow (two real Chrome launches -// and graceful closes per store), so tools/ci-plan.ts lists it as HEAVY: a shard of its own. +// and graceful closes per store), so tools/ci-plan.ts lists it as HEAVY (the dedicated browser shard). import { afterAll, beforeAll, describe, expect, test } from 'bun:test'; import { mkdtempSync, rmSync } from 'node:fs'; import { tmpdir } from 'node:os'; diff --git a/tests/feature-fit.test.ts b/tests/feature-fit.test.ts index 8bb6b5e..e94e9e0 100644 --- a/tests/feature-fit.test.ts +++ b/tests/feature-fit.test.ts @@ -8,6 +8,7 @@ import { join } from 'node:path'; import { boxOutside, DEFAULT_PHONE, FEATURE_CANVAS, featureLayout, rotatedBox } from '../cli/shots/lib'; import { deviceIssues } from '../cli/shots/report'; import { validateConfig } from '../cli/lib/config'; +import { AFTER_ALL_MS, launchTestBrowser, scaled } from './helpers/browser'; const close = (a: number, b: number) => expect(Math.abs(a - b)).toBeLessThan(0.01); @@ -66,14 +67,11 @@ describe('shots.feature config', () => { }); }); -// eslint-disable-next-line @typescript-eslint/no-explicit-any -let browser: any = null; -try { - const { chromium } = await import('playwright-core'); - try { browser = await chromium.launch({ headless: true }); } catch { browser = await chromium.launch({ headless: true, channel: 'chrome' }); } -} catch { /* skipped below */ } -if (!browser) console.warn('feature graphic render test skipped: no Chromium could launch. Run `bunx playwright install chromium`.'); -afterAll(async () => { await browser?.close(); }, 30_000); +// one browser for the file through the shared helper (bounded, load-aware launch and kill); HEAVY in tools/ci-plan.ts +const shared = await launchTestBrowser('playwright-core'); +const { browser } = shared; +if (!browser) console.warn(`feature graphic render test skipped: no Chromium installed (${shared.skipWhy}). Run \`bunx playwright install chromium\`.`); +afterAll(() => shared.close(), AFTER_ALL_MS); // 1x1 PNG const PNG = Buffer.from('iVBORw0KGgoAAAANSUhEUgAAAAEAAAABCAYAAAAfFcSJAAAADUlEQVR42mNk+M9QDwADhgGAWjR9awAAAABJRU5ErkJggg==', 'base64'); @@ -106,5 +104,5 @@ describe.skipIf(!browser)('feature graphic templates at 1024 x 500 (DOM layout b if (fit === 'contain') expect(boxOutside(d, 1024, 500)).toEqual([]); else expect(bleed).toBe(true); } finally { await page.close(); } - }, 30_000); + }, scaled(30_000)); }); diff --git a/tests/glyph-ligatures.test.ts b/tests/glyph-ligatures.test.ts index 74b5735..ebc4660 100644 --- a/tests/glyph-ligatures.test.ts +++ b/tests/glyph-ligatures.test.ts @@ -7,17 +7,15 @@ import { afterAll, describe, expect, test } from 'bun:test'; import { readFileSync } from 'node:fs'; import { join } from 'node:path'; import { measureFonts } from '../cli/shots/glyphs'; +import { AFTER_ALL_MS, launchTestBrowser, scaled } from './helpers/browser'; -// eslint-disable-next-line @typescript-eslint/no-explicit-any -let browser: any = null; -let skipWhy = ''; -try { - const { chromium } = await import('playwright-core'); - try { browser = await chromium.launch({ headless: true }); } catch { browser = await chromium.launch({ headless: true, channel: 'chrome' }); } -} catch (e) { skipWhy = (e as Error).message.split('\n')[0]!; } -if (!browser) console.warn(`glyph ligature test skipped: no Chromium could launch (${skipWhy}). Run \`bunx playwright install chromium\`.`); +// one browser for the file, launched and killed by the shared helper (bounded, load-aware timeouts); tools/ci-plan.ts +// lists this file as HEAVY (the browser shard) +const shared = await launchTestBrowser('playwright-core'); +const { browser, skipWhy } = shared; +if (!browser) console.warn(`glyph ligature test skipped: no Chromium installed (${skipWhy}). Run \`bunx playwright install chromium\`.`); -afterAll(async () => { await browser?.close(); }, 30_000); +afterAll(() => shared.close(), AFTER_ALL_MS); const font = readFileSync(join(import.meta.dir, 'fixtures', 'fonts', 'montserrat-text-subset.woff2')).toString('base64'); const TEXT = 'Outfits, fit, office, affine'; @@ -45,5 +43,5 @@ describe.skipIf(!browser)('shots font usage: ligatures', () => { for (const m of measured) expect(Object.keys(m.faces)).toEqual(['Montserrat']); expect(await page.evaluate("document.getElementById('sb-glyph-probes')")).toBeNull(); } finally { await page.close(); } - }, 30_000); + }, scaled(30_000)); }); diff --git a/tests/helpers/browser.ts b/tests/helpers/browser.ts index fc14023..c3abe8b 100644 --- a/tests/helpers/browser.ts +++ b/tests/helpers/browser.ts @@ -15,11 +15,14 @@ /* eslint-disable @typescript-eslint/no-explicit-any */ import { AsyncLocalStorage } from 'node:async_hooks'; import { test } from 'bun:test'; +import { LOAD, loadFactor, loadNote, RETRY_LOAD, RETRY_MARK, scaled } from './load'; + +export { LOAD, scaled } from './load'; /** Launching Chromium: well above a cold start on a loaded machine (seconds), far below "hung". */ -export const LAUNCH_TIMEOUT_MS = 60_000; +export const LAUNCH_TIMEOUT_MS = scaled(60_000); /** One context close, or an engine run ending after its window closed; longer is abandoned (and the browser killed). */ -export const CLOSE_TIMEOUT_MS = 15_000; +export const CLOSE_TIMEOUT_MS = scaled(15_000); /** * Hook timeouts. afterEach: a test's contexts close in parallel, each capped at CLOSE_TIMEOUT_MS, then the engine runs * it started, each capped at CLOSE_TIMEOUT_MS. afterAll: disconnect (capped) and kill the browser server. @@ -59,6 +62,7 @@ export interface TestBrowser { */ export async function launchTestBrowser(pkg: 'playwright' | 'playwright-core'): Promise { const none = (e: unknown): TestBrowser => ({ browser: null, skipWhy: firstLine(e), close: async () => {} }); + console.log(`browser tests: ${loadNote()}`); let chromium: any; try { chromium = (await import(pkg)).chromium; } catch (e) { return none(e); } const opts = { headless: true, timeout: LAUNCH_TIMEOUT_MS }; @@ -140,30 +144,64 @@ export function testScope(browser: () => any) { track: (ctx: T): T => cur().track(ctx), run: (p: Promise): Promise => cur().run(p), settle: (): Promise => shared.settle(), + /** `ms`: the test's budget, already scaled by the load (scaled(), tests/helpers/load.ts). A run that fails by timing + * out (a wait, a Playwright timeout or the budget itself) while the load factor is above RETRY_LOAD runs once + * more in a fresh scope and prints RETRY_MARK; an assertion failure is never retried. */ concurrent(name: string, fn: () => Promise, ms: number): void { - test.concurrent(name, () => { + const attempt = () => { const s = plainScope(browser); - return own.run(s, async () => { try { await fn(); } finally { await s.settle(); } }); - }, ms + AFTER_EACH_MS); + return own.run(s, () => withBudget(fn, ms, () => s.settle())); + }; + test.concurrent(name, () => retryUnderLoad(name, attempt), 2 * (ms + AFTER_EACH_MS)); }, }; } +/** A wait that ran out of time (logLines().wait, a test's budget): the one kind of failure a loaded machine may cause. */ +export class WaitTimeout extends Error { override name = 'WaitTimeout'; } +/** A failure by timing out (ours or Playwright's), never an assertion. */ +export const isTimeout = (e: unknown): boolean => e instanceof WaitTimeout || (e as Error | null)?.name === 'TimeoutError'; + +/** Runs `fn` within `ms` (else fails with a WaitTimeout), then `after` (the test's settle) either way. */ +export async function withBudget(fn: () => Promise, ms: number, after: () => Promise = async () => {}): Promise { + let t: ReturnType | undefined; + const over = new Promise((_, reject) => { t = setTimeout(() => reject(new WaitTimeout(`test budget of ${ms} ms used up`)), ms); }); + try { await Promise.race([fn(), over]); } finally { clearTimeout(t); await after(); } +} + +/** Runs `attempt`; when it fails by timing out while the load factor is above RETRY_LOAD, says RETRY_MARK (tools/ci.ts + * lists those in its summary) and runs it once more. Any other failure, or a timeout on a quiet machine, is final. */ +export async function retryUnderLoad(name: string, attempt: () => Promise, factor: () => number = loadFactor, say: (m: string) => void = m => console.error(m)): Promise { + try { await attempt(); } catch (e) { + const f = factor(); + if (!isTimeout(e) || f <= RETRY_LOAD) throw e; + // the whole error under the mark line: a wait's timeout lists every log line with its time (where it went) + const rest = (e as Error).message.split('\n').slice(1).map(l => ` ${l}`).join('\n'); + say(`${RETRY_MARK} ${name} (load x${f}): ${firstLine(e)}${rest ? `\n${rest}` : ''}`); + await attempt(); + } +} + /** * The log lines of an engine run (`say`), with event-driven waits: `wait` resolves on the line that makes `pred` * true (checked on every new line, no polling) and fails after `ms` with every line seen so far. */ export function logLines() { const lines: string[] = []; + const at: number[] = []; + const t0 = Date.now(); const waiters = new Set<() => void>(); + /** The lines with the seconds since the log started (a timeout dump shows where the time went). */ + const timed = () => lines.map((l, i) => `+${((at[i]! - t0) / 1000).toFixed(1)}s ${l}`).join('\n'); return { lines, - say: (m: string) => { lines.push(m); for (const w of [...waiters]) w(); }, - wait(what: string, pred: (lines: string[]) => boolean, ms = 30_000): Promise { + say: (m: string) => { lines.push(m); at.push(Date.now()); for (const w of [...waiters]) w(); }, + /** `ms`: already scaled by the caller (scaled()); the default is 30 s scaled by the load. */ + wait(what: string, pred: (lines: string[]) => boolean, ms = scaled(30_000)): Promise { if (pred(lines)) return Promise.resolve(); return new Promise((resolve, reject) => { const check = () => { if (pred(lines)) { done(); resolve(); } }; - const t = setTimeout(() => { done(); reject(new Error(`timed out after ${ms} ms waiting for: ${what}\n${lines.join('\n')}`)); }, ms); + const t = setTimeout(() => { done(); reject(new WaitTimeout(`timed out after ${ms} ms waiting for: ${what}\n${timed()}`)); }, ms); const done = () => { clearTimeout(t); waiters.delete(check); }; waiters.add(check); }); diff --git a/tests/helpers/load.ts b/tests/helpers/load.ts new file mode 100644 index 0000000..250cf95 --- /dev/null +++ b/tests/helpers/load.ts @@ -0,0 +1,26 @@ +// Load-aware timeouts for the browser tests and the CI runner. The machine is shared: other sessions' builds push the +// load average to 100-500 on 10 cores, and a browser walk that takes 5 s idle then takes 30-60 s. Fixed wall-clock +// timeouts turned that into red CI runs that only passed on a quiet machine. Timeouts scale by load ÷ cores (at least +// 1, at most LOAD_CAP), so they still catch a hang; a timeout under heavy load gets ONE retry (testScope().concurrent), +// an assertion failure never does. +import { cpus, loadavg } from 'node:os'; + +export const LOAD_CAP = 5; +/** Above this factor a test that failed by timing out is retried once ("retried under load" in the CI summary). */ +export const RETRY_LOAD = 2; +/** The line a retried test prints; tools/ci.ts collects these for its summary. */ +export const RETRY_MARK = 'RETRIED UNDER LOAD:'; + +/** max(1-min, 5-min load average) ÷ cores, between 1 and cap. STOREBOUND_LOAD_FACTOR=n overrides (tests, debugging). */ +export function loadFactor(env = process.env, load = loadavg(), cores = cpus().length, cap = LOAD_CAP): number { + const forced = Number(env.STOREBOUND_LOAD_FACTOR); + if (Number.isFinite(forced) && forced > 0) return Math.min(cap, Math.max(1, forced)); + const per = Math.max(load[0] ?? 0, load[1] ?? 0) / Math.max(1, cores); + return Math.min(cap, Math.max(1, Math.round(per * 10) / 10)); +} + +/** The factor of this test process, sampled once when the first browser test file loads, so a test's waits and its + * own timeout scale by the same number. */ +export const LOAD = loadFactor(); +export const scaled = (ms: number, f = LOAD): number => Math.round(ms * f); +export const loadNote = (f = LOAD): string => `load ${loadavg().map(n => n.toFixed(0)).join('/')} on ${cpus().length} cores: timeouts x${f}`; diff --git a/tests/load-retry.test.ts b/tests/load-retry.test.ts new file mode 100644 index 0000000..7ead650 --- /dev/null +++ b/tests/load-retry.test.ts @@ -0,0 +1,59 @@ +// Load-aware timeouts and the one retry under load (tests/helpers/load.ts, testScope().concurrent in +// tests/helpers/browser.ts): a timeout on a loaded machine runs once more; an assertion failure never does. +import { describe, expect, test } from 'bun:test'; +import { retryUnderLoad, WaitTimeout, withBudget } from './helpers/browser'; +import { loadFactor, RETRY_MARK, scaled } from './helpers/load'; + +describe('load factor', () => { + test('load ÷ cores from the larger of the 1- and 5-minute averages, between 1 and the cap', () => { + expect(loadFactor({}, [5, 2, 1], 10)).toBe(1); + expect(loadFactor({}, [30, 45, 50], 10)).toBe(4.5); + expect(loadFactor({}, [577, 300, 100], 10)).toBe(5); + expect(loadFactor({ STOREBOUND_LOAD_FACTOR: '3' }, [0, 0, 0], 10)).toBe(3); + expect(loadFactor({ STOREBOUND_LOAD_FACTOR: '50' }, [0, 0, 0], 10)).toBe(5); + expect(scaled(1000, 2.5)).toBe(2500); + }); +}); + +describe('one retry, only for a timeout under load', () => { + const run = async (err: () => unknown, factor: number) => { + const said: string[] = []; + let n = 0; + let failed: unknown = null; + await retryUnderLoad('t', async () => { if (++n === 1) throw err(); }, () => factor, m => said.push(m)).catch(e => { failed = e; }); + return { n, said, failed }; + }; + test('a wait timeout or a Playwright TimeoutError under load: retried once and reported', async () => { + for (const err of [() => new WaitTimeout('timed out after 1 ms'), () => Object.assign(new Error('locator.click: Timeout 50ms exceeded'), { name: 'TimeoutError' })]) { + const r = await run(err, 3); + expect(r.n).toBe(2); + expect(r.failed).toBeNull(); + expect(r.said).toHaveLength(1); + expect(r.said[0]!.startsWith(`${RETRY_MARK} t (load x3)`)).toBe(true); + } + }); + test('an assertion failure is never retried, under any load', async () => { + const r = await run(() => { try { expect(1).toBe(2); } catch (e) { return e; } }, 5); + expect(r.n).toBe(1); + expect(r.failed).not.toBeNull(); + expect(r.said).toEqual([]); + }); + test('a timeout on a quiet machine (factor <= 2) is final', async () => { + const r = await run(() => new WaitTimeout('timed out'), 2); + expect(r.n).toBe(1); + expect(r.failed).toBeInstanceOf(WaitTimeout); + }); + test('a second timeout fails the test (one retry only)', async () => { + let n = 0; + const e = await retryUnderLoad('t', async () => { n++; throw new WaitTimeout('again'); }, () => 4, () => {}).catch(x => x); + expect(n).toBe(2); + expect(e).toBeInstanceOf(WaitTimeout); + }); + test('the test budget: a run past it fails as a timeout, and the settle runs either way', async () => { + let settled = 0; + const e = await withBudget(() => Bun.sleep(200), 20, async () => { settled++; }).catch(x => x); + expect(e).toBeInstanceOf(WaitTimeout); + await withBudget(async () => {}, 1000, async () => { settled++; }); + expect(settled).toBe(2); + }); +}); diff --git a/tests/play-edit-lock.test.ts b/tests/play-edit-lock.test.ts index bd6653b..c2f12d8 100644 --- a/tests/play-edit-lock.test.ts +++ b/tests/play-edit-lock.test.ts @@ -27,7 +27,8 @@ const wait = (ms: number) => new Promise(r => setTimeout(r, ms)); function fakePlay(o: { delay?: number; replaceOnce?: string } = {}) { const open = new Map(); let n = 0; - const peak = { total: 0, now: 0 }; + /** total / now: edits open at once; reads / reading: requests inside an edit in flight at once. */ + const peak = { total: 0, now: 0, reads: 0, reading: 0 }; let replaced = false; globalThis.fetch = (async (input: string | URL | Request, init?: RequestInit) => { const url = String(input); @@ -42,7 +43,8 @@ function fakePlay(o: { delay?: number; replaceOnce?: string } = {}) { return json({ id: e }); } if (method === 'DELETE') { peak.now--; if (open.get(pkg) === id) open.delete(pkg); return json({}); } - await wait(o.delay ?? 15); + peak.reading++; peak.reads = Math.max(peak.reads, peak.reading); + try { await wait(o.delay ?? 15); } finally { peak.reading--; } if (o.replaceOnce === pkg && !replaced) { replaced = true; open.set(pkg, `e${++n}`); } // e.g. a Console save if (open.get(pkg) !== id) return json(DELETED, 400); return json({ ok: rest ?? '' }); @@ -80,11 +82,11 @@ describe('Play edits: one open edit per package', () => { test('different packages still read in parallel', async () => { const peak = fakePlay({ delay: 40 }); const pkgs = ['com.example.a', 'com.example.b', 'com.example.c']; - const started = Date.now(); const out = await Promise.all(pkgs.map(async pkg => { const p = await playClient('/nonexistent', pkg); return p.read(id => p.call<{ ok: string }>('GET', `${p.API}/edits/${id}/details`)); })); expect(out.map(o => o.ok)).toEqual(['/details', '/details', '/details']); expect(peak.total).toBe(3); - expect(Date.now() - started).toBeLessThan(40 * 3); + // all three reads were in flight at the same time (not the wall time: a loaded machine stretches it) + expect(peak.reads).toBe(3); }); test('a read whose edit was deleted is redone once with a new edit', async () => { diff --git a/tools/ci-plan.ts b/tools/ci-plan.ts index 5654f13..d7c7f8c 100644 --- a/tools/ci-plan.ts +++ b/tools/ci-plan.ts @@ -9,17 +9,24 @@ export const ROOT = join(import.meta.dir, '..'); /** Recorded per-file test durations (seconds), written after every run. Gitignored (node_modules/). */ export const TIMINGS = join(ROOT, 'node_modules/.cache/storebound-ci/test-timings.json'); -/** Suites that drive a real Chromium (or a heavy child process): each gets a shard of its own, never another heavy - * suite next to it, so they don't fight for CPU and time out. */ +/** Suites that drive a real Chromium (or a heavy child process). They all run in BROWSER_SHARDS dedicated shards, + * never next to the light tests, and those shards start first: eight browsers at once (one per shard) on a machine + * other sessions already load to 100+ made the walks time out. */ export const HEAVY = [ 'tests/console-fill.test.ts', 'tests/site-overflow.test.ts', 'tests/local-fonts.test.ts', 'tests/glyphs.test.ts', 'tests/capture-web.test.ts', 'tests/console-session.test.ts', 'tests/console-persist.test.ts', 'tests/console-flow.test.ts', + 'tests/glyph-ligatures.test.ts', 'tests/feature-fit.test.ts', ]; -/** Browser tests of one file at the same time (bun test --max-concurrency for the shards with a HEAVY file; the - * tests opt in with testScope().concurrent, tests/helpers/browser.ts): enough to overlap their waits, few enough that - * a loaded machine does not stretch each one towards its timeout. */ -export const BROWSER_CONCURRENCY = 4; +/** Browser tests of one file at the same time (bun test --max-concurrency for the browser shards; the tests opt in + * with testScope().concurrent, tests/helpers/browser.ts): enough to overlap their waits, few enough that a loaded + * machine does not stretch each one towards its timeout. */ +export const BROWSER_CONCURRENCY = 2; +/** Shards for the HEAVY suites (STOREBOUND_CI_BROWSER_SHARDS=n overrides). */ +export function browserShardCount(env = process.env): number { + const n = Number(env.STOREBOUND_CI_BROWSER_SHARDS); + return Number.isInteger(n) && n > 0 ? n : 1; +} /** Changes that can affect every test: run the whole suite. */ export const GLOBAL = /^(package\.json|bun\.lock|bunfig\.toml|tsconfig\.json|tests\/helpers\/preload\.ts)$/; @@ -81,28 +88,29 @@ export function cost(file: string, timings: Record, size: (f: st } /** - * Longest-processing-time-first split into at most n shards. Heavy files each open a shard of their own and never - * share it with another heavy file; light files fill the least loaded shard. Empty shards are dropped. + * Longest-processing-time-first split into at most n shards. The heavy files go to `browser` dedicated shards (first + * in the result, so they start first) and never share one with a light file while n leaves room; light files fill the + * least loaded of the others. Empty shards are dropped. */ -export function balance(files: string[], n: number, costOf: (f: string) => number, heavy: string[] = HEAVY): string[][] { - const shards = Array.from({ length: Math.max(1, n) }, () => ({ files: [] as string[], load: 0, heavy: false })); - const sorted = [...files].sort((a, b) => costOf(b) - costOf(a) || a.localeCompare(b)); +export function balance(files: string[], n: number, costOf: (f: string) => number, heavy: string[] = HEAVY, browser = 1): string[][] { const isHeavy = (f: string) => heavy.includes(f); - for (const f of sorted.filter(isHeavy)) { - const free = shards.filter(s => !s.heavy); - const s = (free.length ? free : shards).reduce((a, b) => (b.load < a.load ? b : a)); - s.files.push(f); s.load += costOf(f); s.heavy = true; - } - for (const f of sorted.filter(f => !isHeavy(f))) { - const s = shards.reduce((a, b) => (b.load < a.load ? b : a)); - s.files.push(f); s.load += costOf(f); - } - return shards.filter(s => s.files.length).map(s => s.files); + const sorted = [...files].sort((a, b) => costOf(b) - costOf(a) || a.localeCompare(b)); + const heavyFiles = sorted.filter(isHeavy), light = sorted.filter(f => !isHeavy(f)); + const total = Math.max(1, n); + const nb = heavyFiles.length ? Math.min(Math.max(1, browser), total) : 0; + const mk = (k: number) => Array.from({ length: k }, () => ({ files: [] as string[], load: 0 })); + const lpt = (fs: string[], shards: ReturnType) => { + for (const f of fs) { const s = shards.reduce((a, b) => (b.load < a.load ? b : a)); s.files.push(f); s.load += costOf(f); } + }; + const heavyShards = mk(nb), lightShards = total > nb ? mk(total - nb) : heavyShards; + lpt(heavyFiles, heavyShards); + lpt(light, lightShards); + return [...heavyShards, ...(lightShards === heavyShards ? [] : lightShards)].filter(s => s.files.length).map(s => s.files); } export function planShards(files: string[], n = shardCount(), root = ROOT): string[][] { const t = readTimings(); - return balance(files, n, f => cost(f, t, p => { try { return statSync(join(root, p)).size; } catch { return 0; } })); + return balance(files, n, f => cost(f, t, p => { try { return statSync(join(root, p)).size; } catch { return 0; } }), HEAVY, browserShardCount()); } // ---- which tests a change touches ---- diff --git a/tools/ci.ts b/tools/ci.ts index 2a351c9..c801bf6 100644 --- a/tools/ci.ts +++ b/tools/ci.ts @@ -6,8 +6,11 @@ // mapped through imports) + scrub // The tests run as shards: N = CPU cores - 1 (max 8; STOREBOUND_CI_SHARDS=n overrides) parallel `bun test ` // processes, balanced by the durations recorded after earlier runs (node_modules/.cache/storebound-ci/, smoothed by -// mergeTimings so one run on a loaded machine does not skew the split; falling back to file size). Browser suites -// (tools/ci-plan.ts HEAVY) each get a shard of their own and run their opted-in tests BROWSER_CONCURRENCY at a time. +// mergeTimings so one run on a loaded machine does not skew the split; falling back to file size). The browser suites +// (tools/ci-plan.ts HEAVY) run in one dedicated shard, started first, their opted-in tests BROWSER_CONCURRENCY at a +// time. The machine is shared: their timeouts scale with load ÷ cores (tests/helpers/load.ts, capped at 5x, the factor +// is logged), and a browser test that fails by timing out under load (factor > 2) runs once more; the summary lists +// those as "retried under load". An assertion failure is never retried. // `bun test` covers the CLI and the desktop webview (apps/desktop/tests), the site overflow check and the // no-hand-written-SVG guard; the desktop boot check (tools/desktop-boot-check.ts: the built window in headless // Chromium, needs playwright's browser or Google Chrome) runs after the desktop build. @@ -18,6 +21,7 @@ import { existsSync, mkdtempSync, readFileSync, rmSync } from 'node:fs'; import { homedir, tmpdir } from 'node:os'; import { join } from 'node:path'; import { hostTarget, OUT_DIR, outName } from './build-sidecars'; +import { loadFactor, loadNote, RETRY_MARK, scaled } from '../tests/helpers/load'; import { BROWSER_CONCURRENCY, changedFiles, HEAVY, junitTimes, listTests, mergeTimings, planShards, readTimings, relatedTests, ROOT, rustNeeded, writeTimings } from './ci-plan'; interface Task { name: string; cmd: string[]; cwd?: string; env?: Record; after?: string[]; junit?: string } @@ -32,6 +36,8 @@ const tasks: Task[] = []; const add = (t: Task) => tasks.push(t); const tsc = (name: string, project: string) => add({ name, cmd: ['bunx', 'tsc', '--noEmit', '--incremental', '-p', project, '--tsBuildInfoFile', join(cache, `${name.replace(/\W+/g, '-')}.tsbuildinfo`)] }); +const retried: string[] = []; +console.log(`ci: ${loadNote(loadFactor())}`); const junitDir = mkdtempSync(join(tmpdir(), 'sb-ci-')); const node = Bun.which('node'); @@ -48,8 +54,10 @@ function addTests(files: string[]) { // the built-bundle check in apps/desktop/tests/webview.test.ts runs as "desktop bundle check" once the build is // done; here it would read dist/ while vite rewrites it // browser suites share the machine with the other steps: a browser start or close can pass bun's 5 s default - // browser tests that opt in (testScope().concurrent) run BROWSER_CONCURRENCY at a time within their file - const timeout = shard.some(f => HEAVY.includes(f)) ? ['--timeout=30000', `--max-concurrency=${BROWSER_CONCURRENCY}`] : []; + // (scaled by the load now); browser tests that opt in (testScope().concurrent) run BROWSER_CONCURRENCY at a time + // every other shard: bun's 5 s default (tests and hooks without their own timeout), scaled the same way + const f = loadFactor(); + const timeout = shard.some(x => HEAVY.includes(x)) ? [`--timeout=${scaled(30_000, f)}`, `--max-concurrency=${BROWSER_CONCURRENCY}`] : [`--timeout=${scaled(5_000, f)}`]; add({ name: `tests ${i + 1}/${all.length}`, cmd: ['bun', 'test', ...timeout, '--reporter=junit', `--reporter-outfile=${junit}`, ...shard.map(f => `./${f}`)], env: { STOREBOUND_SKIP_DIST_CHECK: '1' }, junit }); }); @@ -133,6 +141,7 @@ async function pump(stream: ReadableStream, name: string, out: NodeJ buf += dec.decode(value, { stream: true }); const lines = buf.split('\n'); buf = lines.pop()!; + for (const l of lines) if (l.includes(RETRY_MARK)) retried.push(`${name}: ${l.slice(l.indexOf(RETRY_MARK) + RETRY_MARK.length).trim()}`); if (lines.length) out.write(lines.map(l => `${tag(name)} ${l}\n`).join('')); } if (buf && !(failed && failed !== name)) out.write(`${tag(name)} ${buf}\n`); @@ -186,5 +195,6 @@ for (const r of [...runs.values()].sort((a, b) => a.start - b.start)) { console.log(` ${r.task.name.padEnd(width)} ${secs}s @${((r.start - t0) / 1000).toFixed(1).padStart(5)}s ${s}`); } for (const t of pending) console.log(` ${t.name.padEnd(width)} - not started`); +if (retried.length) console.log(`\nretried under load (${retried.length}; each timed out once while load ÷ cores was above 2, then ran again):\n${retried.map(r => ` ${r}`).join('\n')}`); if (failed) { console.error(`\nci: ${failed} failed`); process.exit(1); } console.log(`\n${quick ? 'ci:quick' : 'ci'}: all green`); diff --git a/tools/desktop-boot-check.ts b/tools/desktop-boot-check.ts index bfed7c9..d65f720 100644 --- a/tools/desktop-boot-check.ts +++ b/tools/desktop-boot-check.ts @@ -25,6 +25,7 @@ import { extname, join, resolve } from 'node:path'; import type { Browser, Page } from 'playwright'; import { APPLE_STATUS_FIRST_REVIEW, APPLE_STATUS_READY, APPLE_STATUS_UNRESOLVED, ownerDry, PLAY_STATUS, PLAY_STATUS_FIRST_200, PLAY_STATUS_FIRST_404 } from '../apps/desktop/src/dev/submit-fixtures'; import { appleReleases, playReleases, releaseTrains } from '../cli/lib/portfolio'; +import { LOAD, loadNote, scaled } from '../tests/helpers/load'; import { EXAMPLE_CLOUD_PROJECT, healthApiDisabled, SCAN_FAILED, SCAN_FAILED_LINE, SCAN_FINDINGS } from '../apps/desktop/src/dev/error-fixtures'; const ROOT = resolve(import.meta.dir, '..'); @@ -241,8 +242,10 @@ async function state(page: Page) { /** A quiet window: no host call in flight and no DOM change for this long means the last action is done. */ const QUIET_MS = 150; -/** Upper bound of one wait for a condition (a loaded machine); a wait that runs out is a failure or a check as-is. */ -const WAIT_MS = 15_000; +/** Upper bound of one wait for a condition, scaled by load ÷ cores (tests/helpers/load.ts: the machine is shared); a + * wait that runs out is a failure or a check as-is. */ +const WAIT_MS = scaled(15_000); +console.log(`desktop boot check: ${loadNote(LOAD)}`); /** * Waits until the window is quiet (initScript's counters: no host call in flight, no DOM change for QUIET_MS): what a @@ -596,7 +599,7 @@ async function runReleaseStateCase(browser: Browser, sidecar: Sidecar, page404: } /** Longest wait for the background reader to read everything of every app (a loaded machine). */ -const READ_ALL_MS = 120_000; +const READ_ALL_MS = scaled(120_000); /** * Auto-read: the dev fixture state (src/dev/fixtures.ts: 2 app folders and the store-only apps of 5 accounts, at least 8