test: queue runs on slow windows runners stop failing four timing tests (#5949)

* test: queue runs on slow windows runners stop failing four timing tests

* test(cli): the keepalive process test budgets for a cold start on a slow runner
This commit is contained in:
Miguel Ángel
2026-10-20 09:12:43 +00:00
committed by GitHub
parent d898ad89ee
commit f98ef09be4
6 changed files with 74 additions and 24 deletions
@@ -3,8 +3,8 @@ import type { AddressInfo } from "node:net";
import { afterAll, beforeAll, expect, it } from "vitest";
import { openSettledCompositionPage } from "./captureCompositionFrame.js";
// An image, then a fetched asset after the load event, both well inside the 1.5 s settle cap: with the
// asset at 1.1 s a busy Windows runner settled at up to 1.48 s, 18 ms from the cap.
// An image, then a fetched asset after the load event. The settle cap is lifted: a starved runner
// has not even loaded the page by the default 1.5 s, and the test is about waiting, not the cap.
const IMAGE_MS = 300;
const FETCH_MS = 500;
const PNG = Buffer.from(
@@ -45,6 +45,7 @@ it("returns only once images and fetched assets that land after DOMContentLoaded
const { browser, page } = await openSettledCompositionPage(HTML, url, {
renderReadyTimeoutMs: 5_000,
renderReadyWarningSuffix: "test",
lateSubresourceTimeoutMs: 60_000,
browserGpuMode: "software",
});
try {
@@ -106,6 +106,7 @@ export interface OpenSettledCompositionPageOptions {
navigationTimeoutMs?: number;
renderReadyTimeoutMs: number;
renderReadyWarningSuffix: string;
lateSubresourceTimeoutMs?: number;
browserGpuMode?: BrowserGpuMode;
signal?: AbortSignal;
onBrowser?: (browser: Browser) => void;
@@ -249,16 +250,16 @@ async function waitForCompositionSettle(
console.warn(` ${c.warn("⚠")} Shader transitions did not finish pre-rendering`);
});
await waitForLateSubresources(page);
await waitForLateSubresources(page, options.lateSubresourceTimeoutMs ?? CAPTURE_SETTLE_MS);
return runtimeReady;
}
async function waitForLateSubresources(page: Page): Promise<void> {
async function waitForLateSubresources(page: Page, timeoutMs: number): Promise<void> {
let cap: ReturnType<typeof setTimeout> | undefined;
const deadline = Date.now() + CAPTURE_SETTLE_MS;
const deadline = Date.now() + timeoutMs;
const ready = (async () => {
await page.waitForFunction(() => document.readyState === "complete", {
timeout: CAPTURE_SETTLE_MS,
timeout: timeoutMs,
});
await page.waitForNetworkIdle({
idleTime: NETWORK_IDLE_MS,
@@ -273,7 +274,7 @@ async function waitForLateSubresources(page: Page): Promise<void> {
await Promise.race([
ready,
new Promise((resolveCap) => {
cap = setTimeout(resolveCap, CAPTURE_SETTLE_MS);
cap = setTimeout(resolveCap, timeoutMs);
}),
]);
} catch {
@@ -148,5 +148,6 @@ describe("render cancellation process keepalive", () => {
} finally {
rmSync(testDir, { recursive: true, force: true });
}
}, 5_000);
// Sized for a cold tsx start on a slow Windows runner (1.4-2.7 s healthy); the work is 250 ms.
}, 30_000);
});
@@ -55,7 +55,7 @@ import {
extractVideoMetadata,
type VideoMetadata,
} from "../utils/ffprobe.js";
import { runFfmpeg } from "../utils/runFfmpeg.js";
import { ffmpegStatsReader, runFfmpeg, type RunFfmpegOptions } from "../utils/runFfmpeg.js";
// Pass-through, so a test can tell whether extraction ran ffmpeg.
vi.mock("../utils/runFfmpeg.js", async (importOriginal) => {
@@ -2082,30 +2082,44 @@ describe.skipIf(!HAS_FFMPEG)("frame sampling at the output frame rate", () => {
60_000,
);
it("keeps a run that outlasts the timeout while it still writes frames", async () => {
const source = join(FIXTURE_DIR, "paced-5s.mp4");
it("stops extraction only on a stall, and its ffmpeg reports each frame it writes", async () => {
const source = join(FIXTURE_DIR, "paced-2s.mp4");
const synth = await runFfmpeg([
...["-y", "-hide_banner", "-loglevel", "error", "-f", "lavfi"],
...["-i", `testsrc=s=${WIDTH}x${HEIGHT}:r=30:d=5`, "-pix_fmt", "yuv420p", source],
...["-i", `testsrc=s=${WIDTH}x${HEIGHT}:r=30:d=2`, "-pix_fmt", "yuv420p", source],
]);
if (!synth.success) throw new Error(`paced fixture synthesis failed: ${synth.stderr}`);
const { runFfmpeg: real } =
await vi.importActual<typeof import("../utils/runFfmpeg.js")>("../utils/runFfmpeg.js");
// Real-time pacing makes 5 s of source take 5 s against a 2 s timeout.
vi.mocked(runFfmpeg).mockImplementation((args, opts) =>
real(["-stats_period", "0.1", "-re", ...args], opts),
);
let requested: RunFfmpegOptions | undefined;
const reported: number[] = [];
const readStats = ffmpegStatsReader(({ frames }) => {
if (frames) reported.push(frames);
});
// Real-time pacing spreads the stats over the run. The stall clock itself is runFfmpeg's to
// test; here it is lifted so a starved runner cannot race it.
vi.mocked(runFfmpeg).mockImplementation((args, opts) => {
requested = opts;
return real(["-stats_period", "0.1", "-re", ...args], {
...opts,
stallTimeout: 60_000,
onStderr: readStats,
});
});
try {
const extracted = await extractVideoFramesRange(
source,
"paced-past-timeout",
"paced-stall-only",
0,
5,
2,
{ fps: 10, outputDir: FIXTURE_DIR, format: "png" },
undefined,
{ ffmpegProcessTimeout: 2000 },
);
expect(extracted.totalFrames).toBe(50);
expect(extracted.totalFrames).toBe(20);
expect(requested).toMatchObject({ stallTimeout: 2000 });
expect(requested).not.toHaveProperty("timeout");
expect(new Set(reported).size).toBeGreaterThan(1);
} finally {
vi.mocked(runFfmpeg).mockImplementation(real);
}
@@ -245,6 +245,39 @@ describe("ffmpegStatsReader", () => {
});
});
describe("a run with a stall timeout", () => {
afterEach(() => {
vi.useRealTimers();
vi.doUnmock("child_process");
vi.resetModules();
});
it("outlives the timeout while frames advance, and stops once they do not", async () => {
vi.useFakeTimers();
const proc = Object.assign(new EventEmitter(), {
stderr: new EventEmitter(),
kill: vi.fn(() => queueMicrotask(() => proc.emit("close", null, "SIGTERM"))),
});
vi.resetModules();
vi.doMock("child_process", () => ({ spawn: () => proc }));
const { runFfmpeg } = await import("./runFfmpeg.js");
const run = runFfmpeg(["-i", "in.mp4", "out-%05d.png"], { stallTimeout: 2_000 });
for (let frame = 1; frame <= 4; frame += 1) {
await vi.advanceTimersByTimeAsync(1_500);
proc.stderr.emit("data", Buffer.from(`frame=${frame} fps=1 time=00:00:0${frame}.00\r`));
}
// Six seconds in: three stall timeouts, never one without a new frame.
expect(proc.kill).not.toHaveBeenCalled();
await vi.advanceTimersByTimeAsync(1_000);
proc.stderr.emit("data", Buffer.from("frame=4 fps=1 time=00:00:04.00\r"));
await vi.advanceTimersByTimeAsync(1_000);
expect(proc.kill).toHaveBeenCalledWith("SIGTERM");
await expect(run).resolves.toMatchObject({ terminationReason: "inactivity" });
});
});
describe("a run whose signal already aborted", () => {
afterEach(() => {
vi.doUnmock("child_process");
@@ -112,10 +112,10 @@ function isoBmffMediaBytes(marker: string): Buffer {
return Buffer.concat([ftyp, Buffer.from(marker)]);
}
// Fake Date, and hold the 1_000 ms attempt deadline every test passes: on a slow runner one
// Freeze Date, and hold the 1_000 ms attempt deadline every test passes: on a slow runner one
// attempt (hash, fsync, refetch) can outlast it and throw "Download timeout". A test that
// needs the deadline calls fireAttemptDeadline(). Other timers (cache-lock poll, test
// delays) stay real.
// delays) stay real. Not fake timers: vi.waitFor advances those, shortening the deadline.
const ATTEMPT_DEADLINE_MS = 1_000;
const heldDeadlines = new Map<ReturnType<typeof setTimeout>, () => void>();
let realSetTimeout: typeof setTimeout;
@@ -129,7 +129,7 @@ function fireAttemptDeadline(): void {
}
beforeEach(() => {
vi.useFakeTimers({ toFake: ["Date"] });
vi.setSystemTime(Date.now());
realSetTimeout = globalThis.setTimeout;
vi.spyOn(globalThis, "setTimeout").mockImplementation(((
handler: () => void,
@@ -1616,9 +1616,9 @@ describe("downloadToTemp atomic publication and bounded retry", () => {
kind: "cancelled",
retryable: false,
} satisfies Partial<UrlDownloadError>);
// Cancel the first caller's request in flight; the second caller's may already be sent too.
await vi.waitFor(() => expect(fetchMock).toHaveBeenCalled());
firstController.abort();
await vi.waitFor(() => expect(fetchMock).toHaveBeenCalledTimes(1));
fireAttemptDeadline();
await firstRejected;
const path = await second;