chore(engine): add capture navigation timeout diagnostics (#1238)

This commit is contained in:
Kiyeon Jeon
2026-06-06 15:58:11 -04:00
committed by GitHub
parent cf0b6f1b95
commit dc71f411c7
5 changed files with 264 additions and 13 deletions
@@ -1,5 +1,11 @@
import { describe, it, expect } from "vitest";
import { isFontResourceError } from "./frameCapture.js";
import {
formatHttpErrorDiagnostic,
formatNavigationFailureDiagnostic,
formatRequestFailureDiagnostic,
isFontResourceError,
sanitizeDiagnosticUrl,
} from "./frameCapture.js";
describe("isFontResourceError", () => {
it("matches Google Fonts CSS load failures via location.url", () => {
@@ -110,3 +116,62 @@ describe("isFontResourceError", () => {
).toBe(true);
});
});
describe("navigation diagnostics", () => {
it("redacts credentials, query strings, and fragments from diagnostic URLs", () => {
expect(
sanitizeDiagnosticUrl("https://user:pass@example.com/assets/video.mp4?token=secret#frag"),
).toBe("https://example.com/assets/video.mp4");
});
it("redacts data and blob URLs", () => {
expect(sanitizeDiagnosticUrl("data:image/png;base64,abc123")).toBe("data:<redacted>");
expect(sanitizeDiagnosticUrl("blob:https://example.com/abc123")).toBe("blob:<redacted>");
});
it("redacts query strings from relative URLs", () => {
expect(sanitizeDiagnosticUrl("/relative/path.png?token=secret#frag")).toBe(
"/relative/path.png",
);
});
it("formats page.goto failures with mode, timeout, elapsed time, and sanitized URL", () => {
const diagnostic = formatNavigationFailureDiagnostic({
captureMode: "screenshot",
url: "http://127.0.0.1:4173/index.html?claim_token=secret",
timeoutMs: 60_000,
elapsedMs: 60_123,
error: new Error("Navigation timeout of 60000 ms exceeded"),
});
expect(diagnostic).toContain("[FrameCapture:ERROR] page.goto failed");
expect(diagnostic).toContain("mode=screenshot");
expect(diagnostic).toContain("timeoutMs=60000");
expect(diagnostic).toContain("elapsedMs=60123");
expect(diagnostic).toContain("url=http://127.0.0.1:4173/index.html");
expect(diagnostic).not.toContain("claim_token");
});
it("formats request and HTTP failures with sanitized URLs", () => {
expect(
formatRequestFailureDiagnostic({
method: "GET",
resourceType: "media",
url: "https://cdn.example.com/video.mp4?token=secret",
failureText: "net::ERR_FAILED",
}),
).toBe(
"[Browser:REQUESTFAILED] GET https://cdn.example.com/video.mp4 resource=media error=net::ERR_FAILED",
);
expect(
formatHttpErrorDiagnostic({
method: "GET",
resourceType: "image",
url: "https://cdn.example.com/frame.png?token=secret",
status: 403,
statusText: "Forbidden",
}),
).toBe("[Browser:HTTP403] GET https://cdn.example.com/frame.png resource=image Forbidden");
});
});
+123 -10
View File
@@ -79,6 +79,79 @@ export interface CaptureSession {
const BROWSER_CONSOLE_BUFFER_SIZE = 200;
const CAPTURE_SESSION_CLOSE_TIMEOUT_MS = 5_000;
function appendBrowserDiagnostic(session: CaptureSession, text: string): void {
session.browserConsoleBuffer.push(text);
if (session.browserConsoleBuffer.length > BROWSER_CONSOLE_BUFFER_SIZE) {
session.browserConsoleBuffer.shift();
}
}
export function sanitizeDiagnosticUrl(input: string): string {
if (!input) return "(empty)";
if (input.startsWith("data:")) return "data:<redacted>";
if (input.startsWith("blob:")) return "blob:<redacted>";
if (input.startsWith("/")) {
try {
const url = new URL(input, "http://hyperframes.local");
return url.pathname;
} catch {
return input;
}
}
try {
const url = new URL(input);
url.username = "";
url.password = "";
url.search = "";
url.hash = "";
return url.toString();
} catch {
return input;
}
}
export function formatNavigationFailureDiagnostic(input: {
captureMode: CaptureMode;
url: string;
timeoutMs: number;
elapsedMs: number;
error: unknown;
}): string {
const message = input.error instanceof Error ? input.error.message : String(input.error);
return (
`[FrameCapture:ERROR] page.goto failed ` +
`mode=${input.captureMode} timeoutMs=${input.timeoutMs} elapsedMs=${input.elapsedMs} ` +
`url=${sanitizeDiagnosticUrl(input.url)} error=${message}`
);
}
export function formatRequestFailureDiagnostic(input: {
method: string;
resourceType: string;
url: string;
failureText: string;
}): string {
return (
`[Browser:REQUESTFAILED] ${input.method} ${sanitizeDiagnosticUrl(input.url)} ` +
`resource=${input.resourceType} error=${input.failureText}`
);
}
export function formatHttpErrorDiagnostic(input: {
method: string;
resourceType: string;
url: string;
status: number;
statusText: string;
}): string {
const statusText = input.statusText ? ` ${input.statusText}` : "";
return (
`[Browser:HTTP${input.status}] ${input.method} ${sanitizeDiagnosticUrl(input.url)} ` +
`resource=${input.resourceType}${statusText}`
);
}
/**
* Fixed warmup-loop iteration count used when `CaptureOptions.lockWarmupTicks`
* is `true`. Picked to roughly match the median tick count observed by the
@@ -721,10 +794,7 @@ export async function initializeSession(session: CaptureSession): Promise<void>
console.log(`${prefix} ${text}`);
}
session.browserConsoleBuffer.push(`${prefix} ${text}`);
if (session.browserConsoleBuffer.length > BROWSER_CONSOLE_BUFFER_SIZE) {
session.browserConsoleBuffer.shift();
}
appendBrowserDiagnostic(session, `${prefix} ${text}`);
});
page.on("pageerror", (err) => {
@@ -738,10 +808,36 @@ export async function initializeSession(session: CaptureSession): Promise<void>
console.error(text);
}
session.browserConsoleBuffer.push(text);
if (session.browserConsoleBuffer.length > BROWSER_CONSOLE_BUFFER_SIZE) {
session.browserConsoleBuffer.shift();
}
appendBrowserDiagnostic(session, text);
});
page.on("requestfailed", (request) => {
appendBrowserDiagnostic(
session,
formatRequestFailureDiagnostic({
method: request.method(),
resourceType: request.resourceType(),
url: request.url(),
failureText: request.failure()?.errorText ?? "unknown",
}),
);
});
page.on("response", (response) => {
const status = response.status();
if (status < 400) return;
const request = response.request();
appendBrowserDiagnostic(
session,
formatHttpErrorDiagnostic({
method: request.method(),
resourceType: request.resourceType(),
url: response.url(),
status,
statusText: response.statusText(),
}),
);
});
// Navigate to the file server
@@ -752,10 +848,27 @@ export async function initializeSession(session: CaptureSession): Promise<void>
const logInitPhase = (phase: string) => {
console.log(`[initSession:${session.captureMode}] ${phase} (${Date.now() - initStart}ms)`);
};
const gotoEntryPage = async (): Promise<void> => {
try {
await page.goto(url, { waitUntil: "domcontentloaded", timeout: pageNavigationTimeout });
} catch (error) {
appendBrowserDiagnostic(
session,
formatNavigationFailureDiagnostic({
captureMode: session.captureMode,
url,
timeoutMs: pageNavigationTimeout,
elapsedMs: Date.now() - initStart,
error,
}),
);
throw error;
}
};
if (session.captureMode === "screenshot") {
// Screenshot mode: standard navigation, rAF works normally
await page.goto(url, { waitUntil: "domcontentloaded", timeout: pageNavigationTimeout });
await gotoEntryPage();
logInitPhase("page.goto complete");
const pageReadyTimeout =
@@ -894,7 +1007,7 @@ export async function initializeSession(session: CaptureSession): Promise<void>
warmupLoopPromise.catch(() => {});
logInitPhase("warmup loop started");
await page.goto(url, { waitUntil: "domcontentloaded", timeout: pageNavigationTimeout });
await gotoEntryPage();
logInitPhase("page.goto complete");
// Poll for window.__hf readiness using manual evaluate loop (waitForFunction
@@ -2,6 +2,8 @@ import { describe, it, expect } from "vitest";
import {
calculateOptimalWorkers,
distributeFrames,
formatWorkerFailure,
selectWorkerDiagnostics,
shouldVerifyWorkerGpu,
} from "./parallelCoordinator.js";
import type { EngineConfig } from "../config.js";
@@ -74,6 +76,42 @@ describe("calculateOptimalWorkers", () => {
});
});
describe("worker failure diagnostics", () => {
it("keeps only actionable worker diagnostics and caps the tail", () => {
const diagnostics = selectWorkerDiagnostics(
[
"[Browser] harmless log",
"[Browser:WARN] noisy warning",
"[Browser:REQUESTFAILED] GET https://cdn.example.com/a.mp4 resource=media error=net::ERR_FAILED",
"[Browser:HTTP404] GET https://cdn.example.com/missing.png resource=image Not Found",
"[FrameCapture:ERROR] page.goto failed mode=screenshot timeoutMs=60000 elapsedMs=60001 url=http://127.0.0.1:4173/index.html error=timeout",
],
2,
);
expect(diagnostics).toEqual([
"[Browser:HTTP404] GET https://cdn.example.com/missing.png resource=image Not Found",
"[FrameCapture:ERROR] page.goto failed mode=screenshot timeoutMs=60000 elapsedMs=60001 url=http://127.0.0.1:4173/index.html error=timeout",
]);
});
it("adds compact diagnostics to the worker failure message", () => {
expect(
formatWorkerFailure({
workerId: 1,
framesCaptured: 0,
startFrame: 0,
endFrame: 30,
durationMs: 60_100,
error: "Navigation timeout of 60000 ms exceeded",
diagnostics: ["[FrameCapture:ERROR] page.goto failed\n mode=screenshot timeoutMs=60000"],
}),
).toBe(
"Worker 1: Navigation timeout of 60000 ms exceeded; diagnostics: [FrameCapture:ERROR] page.goto failed mode=screenshot timeoutMs=60000",
);
});
});
describe("shouldVerifyWorkerGpu", () => {
const softwareConfig: Partial<EngineConfig> = { browserGpuMode: "software" };
@@ -51,6 +51,7 @@ export interface WorkerResult {
durationMs: number;
perf?: CapturePerfSummary;
error?: string;
diagnostics?: string[];
}
export interface ParallelProgress {
@@ -76,6 +77,7 @@ export interface WorkerSizingConfig extends Partial<
const MEMORY_PER_WORKER_MB = 256;
const MIN_WORKERS = 1;
const MAX_WORKER_DIAGNOSTIC_LINES = 8;
// Hard ceiling on explicit `--workers N` requests. Above this, the cost of
// CDP-protocol dispatch through Node's main event loop and OS scheduling
// noise overwhelms any further parallelism. Bumped from 10 → 24 in hf#732
@@ -95,6 +97,31 @@ function defaultSafeMaxWorkers(): number {
}
const MIN_FRAMES_PER_WORKER = 30;
export function selectWorkerDiagnostics(
lines: readonly string[],
maxLines: number = MAX_WORKER_DIAGNOSTIC_LINES,
): string[] {
return lines
.filter((line) =>
/\[(FrameCapture:ERROR|Browser:ERROR|Browser:PAGEERROR|Browser:REQUESTFAILED|Browser:HTTP\d{3})\]/.test(
line,
),
)
.slice(-maxLines);
}
function compactDiagnosticLine(line: string): string {
return line.replace(/\s+/g, " ").trim();
}
export function formatWorkerFailure(result: WorkerResult): string {
const base = `Worker ${result.workerId}: ${result.error ?? "unknown error"}`;
if (!result.diagnostics || result.diagnostics.length === 0) return base;
const diagnostics = result.diagnostics.map(compactDiagnosticLine).join(" | ");
return `${base}; diagnostics: ${diagnostics}`;
}
export function calculateOptimalWorkers(
totalFrames: number,
requested?: number,
@@ -287,6 +314,7 @@ async function executeWorkerTask(
};
} catch (error) {
const errMsg = error instanceof Error ? error.message : String(error);
const diagnostics = session ? selectWorkerDiagnostics(session.browserConsoleBuffer) : [];
return {
workerId: task.workerId,
framesCaptured,
@@ -295,6 +323,7 @@ async function executeWorkerTask(
durationMs: Date.now() - startTime,
perf,
error: errMsg,
diagnostics: diagnostics.length > 0 ? diagnostics : undefined,
};
} finally {
if (session) await closeCaptureSession(session).catch(() => {});
@@ -351,7 +380,7 @@ export async function executeParallelCapture(
const errors = results.filter((r) => r.error);
if (errors.length > 0) {
const errorMessages = errors.map((e) => `Worker ${e.workerId}: ${e.error}`).join("; ");
const errorMessages = errors.map(formatWorkerFailure).join("; ");
throw new Error(`[Parallel] Capture failed: ${errorMessages}`);
}
@@ -2184,7 +2184,13 @@ export async function executeRenderJob(
workers: job.config.workers ?? "auto",
protocolTimeout: cfg.protocolTimeout,
browserConsoleErrors: lastBrowserConsole
.filter((l) => l.includes("ERROR") || l.includes("PAGEERROR"))
.filter(
(l) =>
l.includes("ERROR") ||
l.includes("PAGEERROR") ||
l.includes("REQUESTFAILED") ||
/\[Browser:HTTP\d{3}\]/.test(l),
)
.slice(-5),
});