diff --git a/packages/cli/src/browser/launch.startupFailure.test.ts b/packages/cli/src/browser/launch.startupFailure.test.ts new file mode 100644 index 0000000000..24e7260d61 --- /dev/null +++ b/packages/cli/src/browser/launch.startupFailure.test.ts @@ -0,0 +1,86 @@ +import { chmodSync, mkdtempSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { describe, expect, it } from "vitest"; +import { launchManagedBrowser } from "./launch.js"; + +function fakeBrowser(body: string): string { + const path = join(mkdtempSync(join(tmpdir(), "hf-fake-chrome-")), "chrome"); + writeFileSync(path, `#!/usr/bin/env node\n${body}\n`); + chmodSync(path, 0o755); + return path; +} + +describe.runIf(process.platform !== "win32")("a browser that dies at startup", () => { + it("fails the launch with its exit code and last stderr lines, not just 'Target closed'", async () => { + const executablePath = fakeBrowser( + 'process.stderr.write("[1:1:FATAL:headless_shell] out of memory\\n"); process.exit(7);', + ); + const puppeteer = (await import("puppeteer-core")).default; + const failure = await launchManagedBrowser(puppeteer, { + executablePath, + headless: true, + args: [], + }).then( + () => undefined, + (error: unknown) => error as Error, + ); + expect(failure).toBeInstanceOf(Error); + expect(failure?.message).toContain("exited with code 7"); + expect(failure?.message).toContain("out of memory"); + expect(failure?.cause).toBeInstanceOf(Error); + }, 60_000); + + it("starts the probe headless, as puppeteer starts it, so a full Chrome is not run headful", async () => { + const executablePath = fakeBrowser( + "console.error(process.argv.slice(2).join(' ')); process.exit(3);", + ); + const puppeteer = (await import("puppeteer-core")).default; + const failure = await launchManagedBrowser(puppeteer, { + executablePath, + headless: true, + args: [], + }).then( + () => undefined, + (error: unknown) => error as Error, + ); + expect(failure?.message).toMatch(/--headless/); + }, 60_000); + + it("skips the diagnosis for a launch whose failure the caller handles, such as the GPU probe", async () => { + const executablePath = fakeBrowser("process.exit(3);"); + const puppeteer = (await import("puppeteer-core")).default; + const failure = await launchManagedBrowser( + puppeteer, + { executablePath, headless: true, args: [] }, + { diagnose: false }, + ).then( + () => undefined, + (error: unknown) => error as Error, + ); + expect(failure?.message).not.toContain("exited with code"); + }, 60_000); +}); + +describe("a launch failure whose diagnosis cannot run", () => { + it("still reports the launch error when puppeteer cannot give the default arguments", async () => { + const launchError = new Error("Failed to launch the browser process"); + const puppeteer = { + launch: async () => { + throw launchError; + }, + defaultArgs: () => { + throw new TypeError("no defaults"); + }, + }; + const failure = await launchManagedBrowser(puppeteer as never, { + executablePath: "/bin/true", + headless: true, + args: [], + }).then( + () => undefined, + (error: unknown) => error as Error, + ); + expect(failure).toBe(launchError); + }); +}); diff --git a/packages/cli/src/browser/launch.ts b/packages/cli/src/browser/launch.ts index 453d5a4bd0..2c9ef8144f 100644 --- a/packages/cli/src/browser/launch.ts +++ b/packages/cli/src/browser/launch.ts @@ -1,3 +1,4 @@ +import { explainChromeLaunchFailure } from "@hyperframes/engine/chrome-startup"; import type { Browser, LaunchOptions, PuppeteerNode } from "puppeteer-core"; import { withHyperframesBrowserMarker } from "@hyperframes/core/browser-marker"; import { @@ -24,9 +25,11 @@ const browsers = new Set(); const closing = new WeakMap>(); const watchdogs = new WeakMap(); const pending = new Map, AbortController>(); +const diagnosing = new Set(); const sessionCleanups = new Set<() => Promise>(); const CLOSE_GRACE_MS = 1_000; const LAUNCH_TIMEOUT_MS = 30_000; +const SLOW_START_NOTICE_MS = 5_000; const EXIT_POLL_MS = 50; let listening = false; let shutdown: Promise | undefined; @@ -75,11 +78,15 @@ export async function resolveManagedGpuMode( return resolveCaptureBrowserGpuMode(requestedMode, chromePath, { launch: async (puppeteer, options) => { context.signal?.throwIfAborted(); - const browser = await launchManagedBrowser(puppeteer, { - ...options, - ...(context.noListen ? oneProcessOverPipe(options) : {}), - signal: context.signal, - }); + const browser = await launchManagedBrowser( + puppeteer, + { + ...options, + ...(context.noListen ? oneProcessOverPipe(options) : {}), + signal: context.signal, + }, + { diagnose: false }, + ); try { context.onBrowser?.(browser); } catch (error) { @@ -95,6 +102,7 @@ export async function resolveManagedGpuMode( export async function launchManagedBrowser( puppeteer: PuppeteerNode, options: LaunchOptions, + { diagnose = true }: { diagnose?: boolean } = {}, ): Promise { const sandboxed = isOneProcessOverPipe(options) || inAgentSandbox(); try { @@ -103,15 +111,40 @@ export async function launchManagedBrowser( const unnamedSeatbelt = !sandboxed && (machServiceDenied(normalizeErrorMessage(error)) || pipeLaunchClosedOnMac(error)); - if (!unnamedSeatbelt) throw withRemediation(error); + if (!unnamedSeatbelt) + throw await withStartupDiagnosis(withRemediation(error), puppeteer, options, diagnose); return launchOwnedBrowser(puppeteer, oneProcessOverPipe(options)).catch( - (retryError: unknown) => { - throw withRemediation(retryError); + async (retryError: unknown) => { + throw await withStartupDiagnosis(withRemediation(retryError), puppeteer, options, diagnose); }, ); } } +async function withStartupDiagnosis( + error: unknown, + puppeteer: PuppeteerNode, + options: LaunchOptions, + diagnose: boolean, +): Promise { + if (!diagnose || !options.executablePath || options.signal?.aborted || shutdown) return error; + if (!(error instanceof Error)) return error; + if (sandboxDeniedRemediation(normalizeErrorMessage(error))) return error; + const args = await (async () => + puppeteer.defaultArgs({ + headless: options.headless ?? true, + args: withHyperframesBrowserMarker(options.args), + }))().catch(() => undefined); + if (!args) return error; + const abort = new AbortController(); + diagnosing.add(abort); + try { + return await explainChromeLaunchFailure(error, options.executablePath, args, abort.signal); + } finally { + diagnosing.delete(abort); + } +} + function withRemediation(error: unknown): unknown { const remediation = sandboxDeniedRemediation(normalizeErrorMessage(error)); return remediation ? new Error(remediation, { cause: error }) : error; @@ -145,6 +178,7 @@ async function launchOwnedBrowser( limit, ) : undefined; + const slow = setTimeout(() => console.error("Chrome is still starting..."), SLOW_START_NOTICE_MS); pending.set(launch, abort); try { const browser = await launch; @@ -157,6 +191,7 @@ async function launchOwnedBrowser( return browser; } finally { clearTimeout(timer); + clearTimeout(slow); pending.delete(launch); } } @@ -174,7 +209,7 @@ function untilLaunchOrAbort(launch: Promise, signal: AbortSignal): Prom /** Resolved launches keep their signal live; only pending launches are aborted during shutdown. */ async function closeManagedBrowsers(): Promise { - for (const abort of pending.values()) abort.abort(); + for (const abort of [...pending.values(), ...diagnosing]) abort.abort(); await Promise.allSettled(pending.keys()); const results = await Promise.allSettled([...browsers].map(closeManagedBrowser)); results.push(...(await Promise.allSettled([...sessionCleanups].map((cleanup) => cleanup())))); diff --git a/packages/cli/src/commands/snapshot.timeoutHint.test.ts b/packages/cli/src/commands/snapshot.timeoutHint.test.ts new file mode 100644 index 0000000000..507f93cdf5 --- /dev/null +++ b/packages/cli/src/commands/snapshot.timeoutHint.test.ts @@ -0,0 +1,13 @@ +import { describe, expect, it } from "vitest"; +import { timeoutUnitHint } from "./snapshot.js"; + +describe("timeoutUnitHint", () => { + it("says --timeout is in milliseconds when the value looks like seconds", () => { + expect(timeoutUnitHint(45)).toContain("milliseconds"); + expect(timeoutUnitHint(45)).toContain("45000"); + }); + + it("stays quiet for a real millisecond value", () => { + expect(timeoutUnitHint(45_000)).toBe(""); + }); +}); diff --git a/packages/cli/src/commands/snapshot.ts b/packages/cli/src/commands/snapshot.ts index 0024d66cb0..6debd37aee 100644 --- a/packages/cli/src/commands/snapshot.ts +++ b/packages/cli/src/commands/snapshot.ts @@ -135,10 +135,16 @@ const FFMPEG_EXTRACT_TIMEOUT_MS = 30_000; const FALLBACK_SEEK_LEAD_SECONDS = 5; const RENDER_READY_TIMEOUT_MS = DEFAULT_CONFIG.playerReadyTimeout; +export function timeoutUnitHint(timeoutMs: number): string { + return timeoutMs < 1_000 + ? ` --timeout is in milliseconds, so ${timeoutMs} is ${timeoutMs} ms; 45000 is 45 s.` + : ""; +} + export async function renderNotReadyError(page: Page, timeoutMs: number): Promise { const diagnostic = await evaluateHfDiagnostic(page).then(buildZeroDurationDiagnostic, () => ""); return new Error( - `The composition was not render-ready after ${timeoutMs}ms, so no frame was saved (raise --timeout if it loads slowly).\n${diagnostic}`, + `The composition was not render-ready after ${timeoutMs}ms, so no frame was saved (raise --timeout if it loads slowly).${timeoutUnitHint(timeoutMs)}\n${diagnostic}`, ); } /** Each 4K decode is already multi-threaded, so a few at once fill the cores without exhausting memory. */ diff --git a/packages/cli/tsup.config.ts b/packages/cli/tsup.config.ts index 177394a0fd..16981ef6e9 100644 --- a/packages/cli/tsup.config.ts +++ b/packages/cli/tsup.config.ts @@ -103,6 +103,7 @@ var __dirname = __hf_dirname(__filename);`, ...sourceAliases(resolve(__dirname, "../engine"), [ ".", "./chrome-host-ceiling", + "./chrome-startup", "./shader-transitions", "./system-memory", "./wsl-host", diff --git a/packages/engine/package-subpaths.json b/packages/engine/package-subpaths.json index a0366430b4..53fef421b3 100644 --- a/packages/engine/package-subpaths.json +++ b/packages/engine/package-subpaths.json @@ -19,6 +19,12 @@ "types": "./dist/services/chromeHostCeiling.d.ts", "environments": ["bun", "node"] }, + "./chrome-startup": { + "source": "./src/services/chromeStartup.ts", + "runtime": "./dist/services/chromeStartup.js", + "types": "./dist/services/chromeStartup.d.ts", + "environments": ["bun", "node"] + }, "./system-memory": { "source": "./src/services/systemMemory.ts", "runtime": "./dist/services/systemMemory.js", diff --git a/packages/engine/package.json b/packages/engine/package.json index 46df2e5bf5..65f50415af 100644 --- a/packages/engine/package.json +++ b/packages/engine/package.json @@ -30,6 +30,11 @@ "import": "./src/services/chromeHostCeiling.ts", "types": "./src/services/chromeHostCeiling.ts" }, + "./chrome-startup": { + "bun": "./src/services/chromeStartup.ts", + "import": "./src/services/chromeStartup.ts", + "types": "./src/services/chromeStartup.ts" + }, "./system-memory": { "bun": "./src/services/systemMemory.ts", "import": "./src/services/systemMemory.ts", @@ -62,6 +67,10 @@ "import": "./dist/services/chromeHostCeiling.js", "types": "./dist/services/chromeHostCeiling.d.ts" }, + "./chrome-startup": { + "import": "./dist/services/chromeStartup.js", + "types": "./dist/services/chromeStartup.d.ts" + }, "./system-memory": { "import": "./dist/services/systemMemory.js", "types": "./dist/services/systemMemory.d.ts" diff --git a/packages/engine/src/services/browserManager.ts b/packages/engine/src/services/browserManager.ts index f1c8f18fe5..f1da7d9a3c 100644 --- a/packages/engine/src/services/browserManager.ts +++ b/packages/engine/src/services/browserManager.ts @@ -6,6 +6,7 @@ * launch args, pooled browser acquisition/release. */ +import { explainChromeLaunchFailure } from "./chromeStartup.js"; import { withHyperframesBrowserMarker } from "@hyperframes/core/browser-marker"; import { scanHtmlOpeningTags } from "@hyperframes/parsers/html-attribute-spans"; import type { Browser, LaunchOptions, Page, PuppeteerNode } from "puppeteer-core"; @@ -885,16 +886,24 @@ async function launchBrowser( let captureMode = fingerprint.requestedCaptureMode; let browser: Browser | undefined; const launch = (args: readonly string[]) => - ppt.launch({ - ...ownedLaunchOptions(), - headless: true, - args: withHyperframesBrowserMarker(args), - defaultViewport: null, - executablePath: fingerprint.executablePath, - env, - timeout: fingerprint.browserTimeoutMs, - protocolTimeout: fingerprint.protocolTimeoutMs, - }); + ppt + .launch({ + ...ownedLaunchOptions(), + headless: true, + args: withHyperframesBrowserMarker(args), + defaultViewport: null, + executablePath: fingerprint.executablePath, + env, + timeout: fingerprint.browserTimeoutMs, + protocolTimeout: fingerprint.protocolTimeoutMs, + }) + .catch(async (error: unknown) => { + const defaults = await ppt.defaultArgs({ + headless: true, + args: withHyperframesBrowserMarker(args), + }); + throw await explainChromeLaunchFailure(error, fingerprint.executablePath, defaults); + }); const probe = (target: Browser, timeoutMs?: number) => probeBeginFrameSupport(target, timeoutMs).catch((error) => ({ supported: true, diff --git a/packages/engine/src/services/chromeStartup.test.ts b/packages/engine/src/services/chromeStartup.test.ts new file mode 100644 index 0000000000..92a5dbc84e --- /dev/null +++ b/packages/engine/src/services/chromeStartup.test.ts @@ -0,0 +1,84 @@ +import { chmodSync, mkdtempSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { describe, expect, it } from "vitest"; +import { diagnoseChromeStartup, nameChromeExit } from "./chromeStartup.js"; + +function fakeBrowser(body: string): string { + const path = join(mkdtempSync(join(tmpdir(), "hf-fake-chrome-")), "chrome"); + writeFileSync(path, `#!/usr/bin/env node\n${body}\n`); + chmodSync(path, 0o755); + return path; +} + +describe("nameChromeExit", () => { + it("names the Windows codes a browser dies with, signed or unsigned", () => { + expect(nameChromeExit(0xc0000135, "win32")).toContain("missing"); + expect(nameChromeExit(-1073741515, "win32")).toContain("0xC0000135"); + expect(nameChromeExit(3221225495, "win32")).toContain("out of memory"); + }); + + it("names nothing off Windows or for an unknown code", () => { + expect(nameChromeExit(0xc0000135, "linux")).toBeUndefined(); + expect(nameChromeExit(1, "win32")).toBeUndefined(); + expect(nameChromeExit(null, "win32")).toBeUndefined(); + }); +}); + +describe.runIf(process.platform !== "win32")("diagnoseChromeStartup", () => { + it("reports the exit code and last stderr lines of a browser that dies at start", async () => { + const chrome = fakeBrowser( + 'process.stderr.write("[1:1:FATAL:zygote_host] No usable sandbox\\n"); process.exit(7);', + ); + const diagnosis = await diagnoseChromeStartup(chrome, ["--headless"]); + expect(diagnosis).toContain("exited with code 7"); + expect(diagnosis).toContain("No usable sandbox"); + }); + + it("starts the probe on its own debugging port and profile, not the failed launch's pipe", async () => { + const chrome = fakeBrowser("console.error(process.argv.slice(2).join(' ')); process.exit(3);"); + const diagnosis = await diagnoseChromeStartup(chrome, [ + "--remote-debugging-pipe", + "--user-data-dir=/gone", + "--no-sandbox", + ]); + expect(diagnosis).toContain("--no-sandbox"); + expect(diagnosis).toContain("--remote-debugging-port=0"); + expect(diagnosis).not.toContain("--remote-debugging-pipe"); + expect(diagnosis).not.toContain("/gone"); + }); + + it("says so when the browser stays up, instead of inventing a crash", async () => { + const chrome = fakeBrowser("setInterval(() => {}, 1000);"); + const diagnosis = await diagnoseChromeStartup(chrome, [], { timeoutMs: 300 }); + expect(diagnosis).toContain("kept running"); + }); + + it("reports a binary that cannot be started", async () => { + expect(await diagnoseChromeStartup("/no/such/chrome", [])).toContain("could not be started"); + }); +}); + +describe.runIf(process.platform !== "win32")("diagnoseChromeStartup cancel and arguments", () => { + it("stops the probe at once when the caller cancels it", async () => { + const chrome = fakeBrowser("setInterval(() => {}, 1000);"); + const abort = new AbortController(); + const started = Date.now(); + const pending = diagnoseChromeStartup(chrome, [], { signal: abort.signal, timeoutMs: 30_000 }); + setTimeout(() => abort.abort(), 100); + expect(await pending).toContain("cancelled"); + expect(Date.now() - started).toBeLessThan(5_000); + }); + + it("passes the flags it is given, such as --headless, and drops stray positional arguments", async () => { + const chrome = fakeBrowser("console.error(process.argv.slice(2).join(' ')); process.exit(3);"); + const diagnosis = await diagnoseChromeStartup(chrome, [ + "--headless=new", + "about:blank", + "--no-first-run", + ]); + expect(diagnosis).toContain("--headless=new"); + expect(diagnosis).toContain("--no-first-run"); + expect(diagnosis.match(/about:blank/g)).toHaveLength(1); + }); +}); diff --git a/packages/engine/src/services/chromeStartup.ts b/packages/engine/src/services/chromeStartup.ts new file mode 100644 index 0000000000..48f6e96a24 --- /dev/null +++ b/packages/engine/src/services/chromeStartup.ts @@ -0,0 +1,110 @@ +import { spawn } from "node:child_process"; +import { mkdtempSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { removeTreeBestEffort } from "@hyperframes/core/remove-tree"; + +const STDERR_TAIL_LINES = 8; +const PROBE_TIMEOUT_MS = 8_000; + +// NTSTATUS codes a Windows process dies with before it can print anything. +const WINDOWS_EXITS: ReadonlyArray = [ + [0xc0000135, "0xC0000135: a required runtime or DLL is missing (Visual C++ runtime)."], + [0xc0000017, "0xC0000017: Windows had no memory to start it (out of memory)."], + [0xc0000142, "0xC0000142: a DLL failed to initialise, often security software blocking it."], + [0xc0000022, "0xC0000022: access denied, often antivirus or a policy blocking the executable."], + [0xc000007b, "0xC000007B: the executable and a DLL do not match (32-bit and 64-bit)."], +]; + +/** Names an exit code the way a person can act on it; undefined when it has no name. */ +export function nameChromeExit( + code: number | null, + platform: NodeJS.Platform = process.platform, +): string | undefined { + if (platform !== "win32" || code === null) return undefined; + const unsigned = code >>> 0; + return WINDOWS_EXITS.find(([known]) => known === unsigned)?.[1]; +} + +function startupArgs(args: readonly string[], profile: string): string[] { + const kept = args.filter( + (arg) => + arg.startsWith("--") && + !arg.startsWith("--remote-debugging") && + !arg.startsWith("--user-data-dir"), + ); + return [...kept, `--user-data-dir=${profile}`, "--remote-debugging-port=0", "about:blank"]; +} + +function tail(stderr: string): string { + return stderr + .split(/\r?\n/) + .map((line) => line.trim()) + .filter(Boolean) + .slice(-STDERR_TAIL_LINES) + .join("\n"); +} + +/** Starts the browser once more with the failed launch's flags and says how it ended. */ +export async function diagnoseChromeStartup( + executablePath: string, + args: readonly string[], + options: { timeoutMs?: number; platform?: NodeJS.Platform; signal?: AbortSignal } = {}, +): Promise { + const profile = mkdtempSync(join(tmpdir(), "hf-chrome-probe-")); + const timeoutMs = options.timeoutMs ?? PROBE_TIMEOUT_MS; + try { + return await new Promise((resolve) => { + let stderr = ""; + const child = spawn(executablePath, startupArgs(args, profile), { + stdio: ["ignore", "ignore", "pipe"], + windowsHide: true, + }); + const timer = setTimeout(() => { + child.kill(); + resolve(`Chrome started and kept running for ${timeoutMs} ms when launched on its own.`); + }, timeoutMs); + options.signal?.addEventListener( + "abort", + () => { + clearTimeout(timer); + child.kill(); + resolve("The startup check was cancelled."); + }, + { once: true }, + ); + child.stderr.on("data", (chunk: Buffer) => { + stderr = (stderr + chunk.toString()).slice(-4000); + }); + child.once("error", (error) => { + clearTimeout(timer); + resolve(`Chrome could not be started: ${error.message}`); + }); + child.once("exit", (code, signal) => { + clearTimeout(timer); + const how = signal ? `was stopped by ${signal}` : `exited with code ${code}`; + const named = nameChromeExit(code, options.platform); + const lines = tail(stderr); + resolve( + [`Chrome ${how} when launched on its own.`, named, lines && `stderr:\n${lines}`] + .filter(Boolean) + .join("\n"), + ); + }); + }); + } finally { + removeTreeBestEffort(profile); + } +} + +/** The launch error, with the startup diagnosis appended; the original stays as `cause`. */ +export async function explainChromeLaunchFailure( + error: unknown, + executablePath: string | undefined, + args: readonly string[] | undefined, + signal?: AbortSignal, +): Promise { + if (!executablePath || !(error instanceof Error)) return error; + const diagnosis = await diagnoseChromeStartup(executablePath, args ?? [], { signal }); + return new Error(`${error.message}\n${diagnosis}`, { cause: error }); +}