fix(engine): keep capture diagnostics on stderr

.oxlintrc.json

@@ -24,7 +24,10 @@
         "packages/cli/src/capture/**/*.ts",
         "packages/cli/src/registry/**/*.ts",
         "packages/cli/src/templates/**/*.ts",
-        "packages/cli/src/telemetry/**/*.ts"
+        "packages/cli/src/telemetry/**/*.ts",
+        "packages/engine/src/services/browserManager.ts",
+        "packages/engine/src/services/frameCapture.ts",
+        "packages/engine/src/services/parallelCoordinator.ts"
       ],
       "excludeFiles": ["**/*.test.ts", "**/*.test.tsx", "packages/cli/src/telemetry/feedback.ts"],
       "rules": {

docs/packages/engine.mdx

@@ -82,6 +82,10 @@ These are rendering internals. Their result and error conventions differ by
 operation: browser and capture orchestration throws, FFmpeg wrappers generally
 return result objects, and teardown helpers avoid masking the original failure.
 
+Browser and frame-capture diagnostics, including motion-blur reports, go to
+stderr. This keeps stdout available for machine-readable results such as
+`hyperframes benchmark --json`.
+
 ## Related topics
 
 <CardGroup cols={2}>

packages/engine/src/services/browserManager.test.ts

@@ -1337,6 +1337,23 @@ describe("browser pool", () => {
     _setPuppeteerForTests(undefined);
   });
 
+  it("keeps the launch diagnostic on stderr when a command emits JSON", async () => {
+    const stdout = vi.spyOn(console, "log").mockImplementation(() => {});
+    const stderr = vi.spyOn(console, "error").mockImplementation(() => {});
+    try {
+      const result = await acquireBrowser(["--no-sandbox"], poolCfg);
+      await result.release();
+
+      expect(stderr).toHaveBeenCalledWith(
+        expect.stringMatching(/^\[BrowserManager\] Browser launched/),
+      );
+      expect(stdout).not.toHaveBeenCalled();
+    } finally {
+      stdout.mockRestore();
+      stderr.mockRestore();
+    }
+  });
+
   it("sequential acquires with pool enabled return the same browser", async () => {
     const first = await acquireBrowser(["--no-sandbox"], poolCfg);
     const second = await acquireBrowser(["--no-sandbox"], poolCfg);

packages/engine/src/services/browserManager.ts

@@ -866,7 +866,7 @@ async function launchBrowser(
     const gpuFlags = fingerprint.args.filter(
       (a) => a.startsWith("--use-gl=") || a.startsWith("--use-angle="),
     );
-    console.log(
+    console.error(
       `[BrowserManager] Browser launched (${browserVersion}, ${captureMode}, gl=${gpuFlags.join(" ") || "default"}, headlessShell=${!!fingerprint.executablePath}, platform=${process.platform})`,
     );
 

packages/engine/src/services/frameCapture-motionBlur.test.ts

@@ -637,7 +637,7 @@ describe("a stall on a motion-blurred frame names the step in progress", () => {
 });
 
 describe("the per-session blur line", () => {
-  const log = () => vi.spyOn(console, "log").mockImplementation(() => {});
+  const log = () => vi.spyOn(console, "error").mockImplementation(() => {});
   const askForBlur = (report: object) => {
     const page = (globalThis as Record<string, unknown>).window as Record<string, unknown>;
     page.__hfMotionBlur = { report: () => report };
@@ -647,6 +647,7 @@ describe("the per-session blur line", () => {
 
   it("is logged once, after the session's first captured frame, from the page's report", async () => {
     const spy = log();
+    const stdout = vi.spyOn(console, "log").mockImplementation(() => {});
     askForBlur({ state: "on", reasonCode: null, movers: 4, failedFrames: 0 });
     const session = makeSession({ motionBlur: undefined });
     await captureFrameToBuffer(session, 0, 0);
@@ -656,6 +657,7 @@ describe("the per-session blur line", () => {
       .map(([line]) => line)
       .filter((l) => `${l}`.includes("[motion-blur]"));
     expect(lines).toEqual(["[motion-blur] on reasonCode=null movers=4 failedFrames=0"]);
+    expect(stdout).not.toHaveBeenCalled();
   });
 
   it("says why blur is off for the session", async () => {

packages/engine/src/services/frameCapture.test.ts

@@ -1,4 +1,4 @@
-import { describe, it, expect } from "vitest";
+import { describe, it, expect, vi } from "vitest";
 import type { Protocol } from "puppeteer-core";
 import { COMPOSITION_SOURCE_URL } from "@hyperframes/core";
 import type { CaptureSession } from "./frameCapture.js";
@@ -184,6 +184,41 @@ describe("classifyPageError", () => {
     return { session, pageListeners, runtimeListeners };
   }
 
+  it("keeps browser diagnostics on stderr and in the session buffer", async () => {
+    const stdout = vi.spyOn(console, "log").mockImplementation(() => {});
+    const stderr = vi.spyOn(console, "error").mockImplementation(() => {});
+    try {
+      const { session, pageListeners } = await listenedSession();
+      const emit = (type: string, text: string, url = "") =>
+        pageListeners.get("console")?.({
+          type: () => type,
+          text: () => text,
+          location: () => ({ url }),
+        });
+      emit("info", "[hyperframes] render runtime fps");
+      emit("warn", "GPU readback warning");
+      emit("error", "[HyperFrames] composition script error: scene TypeError: x");
+      emit("error", "Failed to load resource", "https://fonts.gstatic.com/font.woff2");
+
+      expect(stderr.mock.calls).toEqual([
+        ["[HyperFrames] render runtime fps"],
+        ["[Browser:WARN] GPU readback warning"],
+        ["[Browser:ERROR] [HyperFrames] composition script error: scene TypeError: x"],
+      ]);
+      expect(stdout).not.toHaveBeenCalled();
+      expect(session.browserConsoleBuffer).toEqual([
+        "[HyperFrames] render runtime fps",
+        "[Browser:WARN] GPU readback warning",
+        "[Browser:ERROR] [HyperFrames] composition script error: scene TypeError: x",
+        "[Browser] Failed to load resource",
+      ]);
+      expect(session.pageErrors).toEqual(["runtime-error:scene TypeError: x"]);
+    } finally {
+      stdout.mockRestore();
+      stderr.mockRestore();
+    }
+  });
+
   it("records the page's uncaught errors from scripts it loaded from the server", async () => {
     const { session, pageListeners, runtimeListeners } = await listenedSession();
     const loaded = (url: string, resourceType: string) => ({

packages/engine/src/services/frameCapture.ts

@@ -960,15 +960,15 @@ async function initDrawElementOrTransparentBackground(
   if ((session.config?.useDrawElement ?? false) && supersampling) {
     session.deGateReason = "supersampling";
     session.deFallbackTrigger = "supersampling";
-    console.log(
+    console.error(
       "[engine] --experimental-fast-capture disabled for this render: drawElementImage " +
         "ignores deviceScaleFactor, so scaled (DPR other than 1) output uses screenshot capture.",
     );
   }
   if ((session.config?.useDrawElement ?? false) && !supersampling && forceScreenshot) {
     session.deGateReason = "render_mode_hint";
     session.deFallbackTrigger = "render_mode_hint";
-    console.log(
+    console.error(
       "[engine] fast capture falls back to screenshot: render-mode compatibility " +
         "hint forced screenshot capture (e.g. raw requestAnimationFrame composition).",
     );
@@ -1020,7 +1020,7 @@ async function initDrawElementOrTransparentBackground(
     if (!supportsDrawElement) {
       session.deGateReason = "unsupported_chrome";
       session.deFallbackTrigger = "unsupported_chrome";
-      console.log(
+      console.error(
         `[engine] fast capture falls back to ${session.launchCaptureMode} capture: ` +
           "this Chrome build does not implement canvas.drawElementImage (Dev/Canary-only " +
           "feature); run `hyperframes browser ensure --force` to fetch a supported " +
@@ -1072,7 +1072,7 @@ async function initDrawElementOrTransparentBackground(
       // "screenshot": on a BeginFrame-launched browser (Linux fast capture)
       // Page.captureScreenshot hangs for the full protocol timeout, while
       // beginFrameCapture is the platform's normal baseline path.
-      console.log(
+      console.error(
         `[engine] fast capture falls back to ${session.launchCaptureMode} capture: ` +
           "SwiftShader (software rasterizer, no GPU egress to skip, drawElement is " +
           "parity-or-slower; see fast-capture-limitations.md)",
@@ -1092,7 +1092,7 @@ async function initDrawElementOrTransparentBackground(
           // "mix-blend-mode", "webgl-context") — `deGateReason` keeps its
           // low-cardinality prefix, `deFallbackTrigger` the full value.
           session.deFallbackTrigger = cssFx;
-          console.log(
+          console.error(
             `[engine] fast capture falls back to ${session.launchCaptureMode} capture: ` +
               `${cssFx} detected (drawElementImage cannot reproduce it; see fast-capture-limitations.md)`,
           );
@@ -1127,7 +1127,7 @@ async function initDrawElementOrTransparentBackground(
         if (atRisk.size > 0 && atRiskFraction > fractionFloor) {
           session.deGateReason = "at_risk_timeline";
           session.deFallbackTrigger = "at_risk_timeline";
-          console.log(
+          console.error(
             `[engine] fast capture falls back to ${session.launchCaptureMode} capture: ` +
               `${atRisk.size}/${totalFrames} frames animate a compositor-incompatible prop ` +
               `(blend/3D/clip/mask); drawElementImage drops these mid-animation ` +
@@ -1145,7 +1145,7 @@ async function initDrawElementOrTransparentBackground(
       if (!forceDE && !threeD.ok) {
         session.deGateReason = "3d_init_failed";
         session.deFallbackTrigger = "3d_init_failed";
-        console.log(
+        console.error(
           `[engine] fast capture falls back to ${session.launchCaptureMode} capture: ` +
             `3D projection init failed (${threeD.reason ?? "unknown"})`,
         );
@@ -1246,7 +1246,7 @@ export async function completeDeferredDrawElementInit(session: CaptureSession):
   if (!session.deInitDeferred || !session.onBeforeCapture) return;
   const page = session.page;
   const logInitPhase = (phase: string) =>
-    console.log(`[initSession:${session.captureMode}] ${phase} (deferred drawElement init)`);
+    console.error(`[initSession:${session.captureMode}] ${phase} (deferred drawElement init)`);
   await finalizeDrawElementInit(session, page, logInitPhase, {
     transparent: session.options.format === "png",
     forceDE: process.env.HF_FORCE_DRAWELEMENT === "1",
@@ -2499,13 +2499,13 @@ export async function initializeSession(session: CaptureSession): Promise<void>
   const { page, serverUrl } = session;
 
   // Forward browser console to host. HyperFrames runtime logs get a dedicated
-  // prefix so page-context observability is visible in producer stdout.
+  // prefix so page-context observability is visible in producer stderr.
   page.on("console", (msg: ConsoleMessage) => {
     const type = msg.type();
     const text = msg.text();
     const locationUrl = msg.location()?.url ?? "";
     const diagnostic = formatConsoleDiagnostic(type, text, locationUrl);
-    if (!diagnostic.suppressHostLog) console.log(diagnostic.text);
+    if (!diagnostic.suppressHostLog) console.error(diagnostic.text);
     appendBrowserDiagnostic(session, diagnostic.text);
 
     // A blocked script can never register its timeline (#3352); a thrown one may still, so it only counts on timeout.
@@ -2581,7 +2581,7 @@ export async function initializeSession(session: CaptureSession): Promise<void>
     session.config?.pageNavigationTimeout ?? DEFAULT_CONFIG.pageNavigationTimeout;
   const initStart = Date.now();
   const logInitPhase = (phase: string) => {
-    console.log(`[initSession:${session.captureMode}] ${phase} (${Date.now() - initStart}ms)`);
+    console.error(`[initSession:${session.captureMode}] ${phase} (${Date.now() - initStart}ms)`);
   };
   const gotoEntryPage = async (): Promise<void> => {
     appendBrowserDiagnostic(
@@ -4512,7 +4512,7 @@ async function captureFrameCore(
     session.capturePerf.frameMs.push(captureTimeMs);
     if (session.capturePerf.frames === 1) {
       const blur = await describePageMotionBlur(session.page).catch(() => null);
-      if (blur) console.log(blur);
+      if (blur) console.error(blur);
     }
 
     // Retain this freshly-captured buffer so the following static frames can reuse it.
@@ -4602,7 +4602,7 @@ export async function captureFrameToBuffer(
             // works. Counted here rather than in captureFrameCore's catch: the
             // deadline rejects from outside it, so that catch never runs.
             session.deFrameTimeouts = (session.deFrameTimeouts ?? 0) + 1;
-            console.log(
+            console.error(
               `[engine] fast capture frame ${frameIndex}: capture exceeded ` +
                 `${DE_FRAME_TIMEOUT_MS}ms; renderer stalled after drawElementImage ` +
                 `(PRINFRA-488). Failing the drawElement attempt so the whole render ` +
@@ -4863,7 +4863,7 @@ export async function captureFramesBatchPipelined(
       session.deNcprFallbacks = (session.deNcprFallbacks ?? 0) + 1;
       throw new DrawElementCaptureError(frameIndices[failedAt] ?? failedAt, reason, error);
     } else {
-      console.log(
+      console.error(
         `[engine] fast capture: batch produce failed at frame ` +
           `${frameIndices[failedAt] ?? "?"} (${error ?? "?"}); ` +
           `re-capturing ${frameIndices.length - failedAt} frame(s) per-frame`,
@@ -4962,7 +4962,7 @@ export async function closeCaptureSession(session: CaptureSession): Promise<void
   }
   if (session.page && !session.pageReleased) {
     const blur = await describePageMotionBlurAtEnd(session.page);
-    if (blur) console.log(blur);
+    if (blur) console.error(blur);
   }
   // Realized static-dedup telemetry: how much the cache actually helped this
   // render (vs the prediction logged at arm time). Both capture paths
@@ -4975,7 +4975,7 @@ export async function closeCaptureSession(session: CaptureSession): Promise<void
     const total = captured + reused;
     const pct = total > 0 ? Math.round((reused / total) * 100) : 0;
     const avgTotalMs = captured > 0 ? Math.round(session.capturePerf.totalMs / captured) : 0;
-    console.log(
+    console.error(
       `[static-dedup] reused ${reused}/${total} frame(s) (${pct}%), ` +
         `est. ~${reused * avgTotalMs}ms saved (avg ${avgTotalMs}ms/frame)`,
     );

packages/engine/src/services/pageMotionBlur.test.ts

@@ -163,7 +163,8 @@ describe("closeCaptureSession", () => {
   afterEach(() => vi.restoreAllMocks());
 
   it("logs the blur's closing line once, before the page closes", async () => {
-    const log = vi.spyOn(console, "log").mockImplementation(() => {});
+    const log = vi.spyOn(console, "error").mockImplementation(() => {});
+    const stdout = vi.spyOn(console, "log").mockImplementation(() => {});
     const order: string[] = [];
     vi.stubGlobal("window", {
       __hfMotionBlur: {
@@ -188,6 +189,7 @@ describe("closeCaptureSession", () => {
       "[motion-blur] on reasonCode=null movers=1 failedFrames=2 (session end)",
     ]);
     expect(order).toEqual(["read", "close"]);
+    expect(stdout).not.toHaveBeenCalled();
     vi.unstubAllGlobals();
   });
 });

packages/engine/src/services/parallelCoordinator.ts

@@ -608,7 +608,7 @@ async function captureFrameRange(
       if (signal?.aborted) throw new Error("Parallel worker cancelled");
       const time = (i * captureOptions.fps.den) / captureOptions.fps.num;
       if (dbg && i < task.startFrame + dbgWin) {
-        console.log(`[par:w${task.workerId}] +${Date.now() - dbgT0}ms produce ${i} start`);
+        console.error(`[par:w${task.workerId}] +${Date.now() - dbgT0}ms produce ${i} start`);
       }
       const { encodeResult } = await runCaptureOperation("frame_capture", i, () =>
         captureFrameToBufferPipelined(session, i - outputOffset, time),
@@ -620,23 +620,25 @@ async function captureFrameRange(
       // and would otherwise surface as an unhandled rejection during teardown.
       encodeResult.catch(() => {});
       if (dbg && i < task.startFrame + dbgWin) {
-        console.log(`[par:w${task.workerId}] +${Date.now() - dbgT0}ms produce ${i} kicked`);
+        console.error(`[par:w${task.workerId}] +${Date.now() - dbgT0}ms produce ${i} kicked`);
       }
       if (prev) {
         if (dbg && prev.idx < task.startFrame + dbgWin) {
-          console.log(
+          console.error(
             `[par:w${task.workerId}] +${Date.now() - dbgT0}ms drain ${prev.idx} await-encode`,
           );
         }
         const buf = await awaitEncode(prev.idx, prev.encodeResult);
         if (dbg && prev.idx < task.startFrame + dbgWin) {
-          console.log(
+          console.error(
             `[par:w${task.workerId}] +${Date.now() - dbgT0}ms drain ${prev.idx} encoded ${buf.length}B`,
           );
         }
         await onFrameBuffer(prev.idx, buf, session);
         if (dbg && prev.idx < task.startFrame + dbgWin) {
-          console.log(`[par:w${task.workerId}] +${Date.now() - dbgT0}ms drain ${prev.idx} written`);
+          console.error(
+            `[par:w${task.workerId}] +${Date.now() - dbgT0}ms drain ${prev.idx} written`,
+          );
         }
         framesCaptured++;
         if (onFrameCaptured) onFrameCaptured(task.workerId, prev.idx);
@@ -711,7 +713,7 @@ export function selectVerifySampleIndicesForTask(
  */
 /** HF_DE_PAR_DEBUG=1 gated per-worker trace line (message built lazily). */
 function logParDebug(message: () => string): void {
-  if (process.env.HF_DE_PAR_DEBUG === "1") console.log(message());
+  if (process.env.HF_DE_PAR_DEBUG === "1") console.error(message());
 }
 
 /**
@@ -733,7 +735,7 @@ function assertDiskSampleAboveFloor(
       { kind: "psnr", frameIndex: idx, failedDb: db, verifyThresholdDb: verifyMinDb },
     );
   }
-  console.log(
+  console.error(
     `[Parallel] drawElement disk self-verify passed (worker ${workerId}, frame ${idx}, ` +
       `${db === Infinity ? "inf" : db.toFixed(1)}dB)`,
   );