fix(cli): cloud render --json reports re-encode progress and times out a stalled cache check

packages/cli/src/cloud/offload.progress.test.ts

@@ -0,0 +1,53 @@
+import { execFileSync } from "node:child_process";
+import { mkdtempSync, readFileSync, rmSync, writeFileSync } from "node:fs";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
+import { afterAll, describe, expect, it } from "vitest";
+import { findFfBinary } from "@hyperframes/parsers/ff-binaries";
+import { buildPublishFileMap } from "../utils/publishProject.js";
+import { OFFLOAD_MIN_BYTES, offloadHeavyMedia, type ReencodeProgress } from "./offload.js";
+
+const ffmpeg = findFfBinary("ffmpeg");
+const ffprobe = findFfBinary("ffprobe");
+const dir = mkdtempSync(join(tmpdir(), "hf-offload-progress-"));
+afterAll(() => rmSync(dir, { recursive: true, force: true }));
+
+/** Two seconds of video with sound, past the offload cutoff, under a name the asset API refuses. */
+function clipNeedingReencode(project: string): void {
+  const made = join(dir, "made.mov");
+  execFileSync(ffmpeg!, [
+    ...["-v", "error", "-y", "-f", "lavfi", "-i", "testsrc2=s=160x90:d=2"],
+    ...["-f", "lavfi", "-i", "sine=f=440:d=2"],
+    ...["-c:v", "libx264", "-pix_fmt", "yuv420p", "-c:a", "aac", "-shortest", made],
+  ]);
+  const free = Buffer.alloc(OFFLOAD_MIN_BYTES);
+  free.writeUInt32BE(free.length);
+  free.write("free", 4);
+  writeFileSync(join(project, "take.mkv"), Buffer.concat([readFileSync(made), free]));
+}
+
+describe.skipIf(!ffmpeg || !ffprobe)("a re-encode before upload", () => {
+  it("reports the output seconds it has made, against the clip's length", async () => {
+    const project = mkdtempSync(join(dir, "project-"));
+    writeFileSync(
+      join(project, "index.html"),
+      `<html><body><video src="take.mkv"></video></body></html>`,
+    );
+    clipNeedingReencode(project);
+    const heard: ReencodeProgress[] = [];
+
+    const [item] = await offloadHeavyMedia(project, buildPublishFileMap(project), {
+      apiBaseUrl: "https://api.example",
+      cachePath: join(project, "cache.json"),
+      upload: async () => ({ asset_id: "a", url: "https://assets.example/a.mp4" }),
+      onReencodeProgress: (event) => heard.push(event),
+    });
+
+    expect(item).toMatchObject({ action: "reencode" });
+    expect(heard.length).toBeGreaterThan(0);
+    const lastHeard = heard.at(-1)!;
+    expect(lastHeard.path).toBe("take.mkv");
+    expect(lastHeard.doneSeconds).toBeGreaterThan(1.5);
+    expect(lastHeard.totalSeconds).toBeCloseTo(2, 0);
+  });
+});

packages/cli/src/cloud/offload.test.ts

@@ -14,6 +14,7 @@ import { tmpdir } from "node:os";
 import { dirname, extname, join } from "node:path";
 import { buildPublishFileMap, stagePublishFiles } from "../utils/publishProject.js";
 import {
+  CACHE_CHECK_TIMEOUT_MS,
   type GifPrep,
   OFFLOAD_MIN_BYTES,
   offloadHeavyMedia,
@@ -305,6 +306,43 @@ describe("offloadHeavyMedia", () => {
     expect(report[0]).toMatchObject({ action: "upload", url: "https://assets.example/2/clip.mp4" });
   });
 
+  it("uploads again when the cached asset URL never answers", async () => {
+    const dir = project({
+      "index.html": html(`<video src="clip.mp4"></video>`),
+      "clip.mp4": HEAVY,
+    });
+    const opts = {
+      apiBaseUrl: "https://api.example",
+      upload: fakeUpload(),
+      cachePath: cachePath(),
+    };
+    await offloadHeavyMedia(dir, buildPublishFileMap(dir), opts);
+    const silentHead = vi.fn(
+      (_url: string, init?: RequestInit) =>
+        new Promise<Response>((_resolve, reject) =>
+          init?.signal?.addEventListener("abort", () => reject(init.signal!.reason)),
+        ),
+    ) as unknown as typeof fetch;
+
+    vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] });
+    try {
+      const pending = offloadHeavyMedia(dir, buildPublishFileMap(dir), {
+        ...opts,
+        fetchImpl: silentHead,
+      });
+      while (vi.mocked(silentHead).mock.calls.length === 0) {
+        await new Promise((resolve) => setImmediate(resolve));
+      }
+      await vi.advanceTimersByTimeAsync(CACHE_CHECK_TIMEOUT_MS);
+      const report = await pending;
+
+      expect(report[0]).toMatchObject({ action: "upload" });
+      expect(opts.upload).toHaveBeenCalledTimes(2);
+    } finally {
+      vi.useRealTimers();
+    }
+  });
+
   it("re-encodes media the asset API refuses and uploads the accepted format", async () => {
     const dir = project({
       "index.html": html(`<video src="take.mkv"></video>`),
@@ -328,7 +366,12 @@ describe("offloadHeavyMedia", () => {
       cachePath: cachePath(),
     });
 
-    expect(reencoder.run).toHaveBeenCalledWith(staged("take.mkv"), "video", undefined);
+    expect(reencoder.run).toHaveBeenCalledWith(
+      staged("take.mkv"),
+      "video",
+      undefined,
+      expect.any(Function),
+    );
     expect(upload.mock.calls[0]![0]).toMatchObject({
       filename: "take.mp4",
       contentType: "video/mp4",
@@ -600,7 +643,12 @@ describe("offloadHeavyMedia", () => {
       cachePath: cachePath(),
     });
 
-    expect(run).toHaveBeenCalledWith(join(dir, "take.mov"), "video", undefined);
+    expect(run).toHaveBeenCalledWith(
+      join(dir, "take.mov"),
+      "video",
+      undefined,
+      expect.any(Function),
+    );
     expect(item).toMatchObject({ path: "take.mov", action: "reencode", size_bytes: 2 ** 32 + 1 });
     expect(fileMap.has("take.mov")).toBe(false);
   }, 60_000);
@@ -694,10 +742,15 @@ describe("offloadHeavyMedia", () => {
       cachePath: cachePath(),
     });
 
-    expect(run).toHaveBeenCalledWith(staged("long.mkv"), "video", [
-      { start: 9.5, end: 12.5 },
-      { start: 100, end: 105 },
-    ]);
+    expect(run).toHaveBeenCalledWith(
+      staged("long.mkv"),
+      "video",
+      [
+        { start: 9.5, end: 12.5 },
+        { start: 100, end: 105 },
+      ],
+      expect.any(Function),
+    );
     expect(report[0]).toMatchObject({ path: "long.mkv", trimmed_to_seconds: 8 });
     const index = fileMap.get("index.html")!.toString();
     expect(index).toMatch(/id="a"[^>]*data-media-start="0.5"/);
@@ -823,7 +876,12 @@ describe("offloadHeavyMedia", () => {
         reencoder: { choose: async () => "video", trimGrid: async () => 30, run },
         cachePath: cachePath(),
       });
-      expect(run).toHaveBeenCalledWith(staged("long.mkv"), "video", undefined);
+      expect(run).toHaveBeenCalledWith(
+        staged("long.mkv"),
+        "video",
+        undefined,
+        expect.any(Function),
+      );
       expect(fileMap.get("index.html")!.toString()).toContain(`data-media-start="10"`);
     }
   });

packages/cli/src/cloud/offload.ts

@@ -3,7 +3,7 @@
  * staged copy's references at the asset URLs. The project on disk is never touched.
  */
 
-import { execFile } from "node:child_process";
+import { execFile, spawn } from "node:child_process";
 import { createHash } from "node:crypto";
 import {
   closeSync,
@@ -38,6 +38,7 @@ import {
   CONVERTIBLE_IMAGE_EXTS,
   VIDEO_EXTS,
 } from "@hyperframes/studio-server/outside-file";
+import { followFfmpegProgress } from "@hyperframes/studio-server/ffmpeg-progress";
 import { type PlayedSegment, planTrim } from "./offloadTrim.js";
 import {
   archiveKey,
@@ -60,6 +61,7 @@ export const OFFLOAD_MIN_BYTES = 5 * 1024 * 1024;
 
 const MiB = 1024 * 1024;
 const AUDIO_MAX_BYTES = 1_500_000_000;
+export const CACHE_CHECK_TIMEOUT_MS = 10_000;
 
 // What POST /v3/assets/direct-uploads takes as-is, and its per-type cap.
 const ACCEPTED: Record<string, { contentType: string; maxBytes: number }> = {
@@ -144,9 +146,17 @@ export interface OffloadOptions {
   /** Overrides the renderer's GIF preparation for tests. */
   gifPrep?: GifPrep;
   onFile?: (item: OffloadedMedia) => void;
+  /** Hears a re-encode's output seconds made so far; `totalSeconds` is null when the length is unknown. */
+  onReencodeProgress?: (event: ReencodeProgress) => void;
   variablesText?: string;
 }
 
+export interface ReencodeProgress {
+  path: string;
+  doneSeconds: number;
+  totalSeconds: number | null;
+}
+
 type MediaKind = "video" | "audio" | "image";
 
 export interface Reencoder {
@@ -160,6 +170,7 @@ export interface Reencoder {
     sourcePath: string,
     preset: PresetName,
     segments?: PlayedSegment[],
+    onProgress?: (doneSeconds: number, totalSeconds: number | null) => void,
   ) => Promise<UploadableFile>;
 }
 
@@ -202,11 +213,15 @@ function writeCache(path: string, cache: Record<string, CacheEntry>): void {
 
 // Asset URLs are public and unsigned, so HEAD needs no auth; a deleted or replaced asset fails it.
 async function stillServed(entry: CacheEntry, fetchImpl: typeof fetch): Promise<boolean> {
+  const controller = new AbortController();
+  const timer = setTimeout(() => controller.abort(), CACHE_CHECK_TIMEOUT_MS);
   try {
-    const res = await fetchImpl(entry.url, { method: "HEAD" });
+    const res = await fetchImpl(entry.url, { method: "HEAD", signal: controller.signal });
     return res.ok && Number(res.headers.get("content-length")) === entry.size_bytes;
   } catch {
     return false;
+  } finally {
+    clearTimeout(timer);
   }
 }
 
@@ -364,14 +379,17 @@ const capOf = (presetName: PresetName) => ACCEPTED[REENCODE_PRESETS[presetName].
 const playedSeconds = (segments: PlayedSegment[]) =>
   segments.reduce((sum, s) => sum + s.end - s.start, 0);
 
+const outputSeconds = (sourcePath: string, segments: PlayedSegment[] | undefined) =>
+  segments?.length ? Promise.resolve(playedSeconds(segments)) : durationSeconds(sourcePath);
+
 export async function limitFor(
   sourcePath: string,
   presetName: PresetName,
   segments: PlayedSegment[] | undefined,
   maxBytes = capOf(presetName),
 ): Promise<string[]> {
   if (mediaOf(presetName) !== "video") return [];
-  const seconds = segments?.length ? playedSeconds(segments) : await durationSeconds(sourcePath);
+  const seconds = await outputSeconds(sourcePath, segments);
   const limit = sizeLimitArgs({
     maxBytes,
     seconds: seconds ?? 0,
@@ -381,21 +399,48 @@ export async function limitFor(
   return presetName === "alphaVideo" && limit.length ? [...limit, "-b:v", limit[1]!] : limit;
 }
 
+/** ffmpeg with `-progress` on stdout, so `onSeconds` hears the output time made; fails with ffmpeg's own stderr. */
+function runFfmpeg(
+  ffmpeg: string,
+  args: string[],
+  onSeconds: (seconds: number) => void,
+): Promise<void> {
+  return new Promise((resolve, reject) => {
+    const proc = spawn(ffmpeg, ["-progress", "pipe:1", "-nostats", ...args], {
+      stdio: ["ignore", "pipe", "pipe"],
+      windowsHide: true,
+    });
+    followFfmpegProgress(proc.stdout, onSeconds);
+    let stderr = "";
+    proc.stderr.on("data", (chunk: Buffer) => {
+      stderr = (stderr + chunk.toString()).slice(-16_384);
+    });
+    proc.on("error", reject);
+    proc.on("close", (code, signal) => {
+      if (code === 0) return resolve();
+      const ended = signal ? `was ended by ${signal}` : `exited with code ${code}`;
+      reject(new Error(`ffmpeg ${ended}: ${stderr.trim()}`));
+    });
+  });
+}
+
 async function ffmpegReencode(
   sourcePath: string,
   presetName: PresetName,
   segments?: PlayedSegment[],
+  onProgress?: (doneSeconds: number, totalSeconds: number | null) => void,
 ): Promise<UploadableFile> {
   const ffmpeg = findFFmpeg();
   if (!ffmpeg) throw new Error(`Re-encoding needs ffmpeg. Install it: ${getFFmpegInstallHint()}`);
   const preset = REENCODE_PRESETS[presetName];
   const probe = preset.contentType.startsWith("video/") ? await probeVideo(sourcePath) : undefined;
   const decoder = probe ? alphaDecoderArgs(probe) : [];
   const color = presetName === "hdrVideo" && probe ? hdrColorArgs(probe) : [];
+  const totalSeconds = onProgress ? await outputSeconds(sourcePath, segments) : null;
   const workDir = mkdtempSync(join(tmpdir(), "hf-offload-"));
   const outPath = join(workDir, `${basename(sourcePath, extname(sourcePath))}${preset.ext}`);
   try {
-    await execFileAsync(
+    await runFfmpeg(
       ffmpeg,
       [
         "-v",
@@ -408,7 +453,7 @@ async function ffmpegReencode(
         ...preset.audio,
         outPath,
       ],
-      { maxBuffer: 16 * MiB },
+      (doneSeconds) => onProgress?.(doneSeconds, totalSeconds),
     );
     // Never read an output the asset API would refuse: it can exceed what one read can hold.
     return {
@@ -701,7 +746,13 @@ async function uploadPlanned(
 ): Promise<{ url: string; asset_id: string }> {
   const filename = basename(path);
   const file: UploadableFile = plan.preset
-    ? await ctx.reencoder.run(plan.sourcePath, plan.preset, plan.segments)
+    ? await ctx.reencoder.run(
+        plan.sourcePath,
+        plan.preset,
+        plan.segments,
+        (doneSeconds, totalSeconds) =>
+          ctx.opts.onReencodeProgress?.({ path, doneSeconds, totalSeconds }),
+      )
     : Buffer.isBuffer(staged)
       ? { bytes: staged, filename, contentType: plan.contentType! }
       : { path: staged.absPath, size: staged.size, filename, contentType: plan.contentType! };

packages/cli/src/commands/cloud/render.test.ts

@@ -10,6 +10,7 @@ import {
   logsTick,
   resolveCloudFpsArg,
   parseAspectRatioFlag,
+  reencodeProgressLines,
   resolveAspectRatioForSubmit,
   validateDryRunSource,
   type ProjectInputSource,
@@ -410,3 +411,53 @@ describe("resolveAspectRatioForSubmit — local dir", () => {
     expect(output).toContain(`project directory ${resolve(dir)}`);
   });
 });
+
+describe("reencodeProgressLines", () => {
+  it("writes one JSON line on stderr per whole percent, and per second when the length is unknown", () => {
+    const lines: string[] = [];
+    vi.spyOn(console, "error").mockImplementation((line: string) => void lines.push(line));
+    let clock = 0;
+    const report = reencodeProgressLines(() => clock);
+
+    report({ path: "take.mkv", doneSeconds: 0.5, totalSeconds: 100 });
+    report({ path: "take.mkv", doneSeconds: 0.9, totalSeconds: 100 });
+    report({ path: "take.mkv", doneSeconds: 1.2, totalSeconds: 100 });
+    report({ path: "raw.mxf", doneSeconds: 3, totalSeconds: null });
+    clock = 400;
+    report({ path: "raw.mxf", doneSeconds: 3.5, totalSeconds: null });
+    clock = 1200;
+    report({ path: "raw.mxf", doneSeconds: 4, totalSeconds: null });
+
+    expect(lines.map((line) => JSON.parse(line))).toEqual([
+      {
+        event: "reencode_progress",
+        file: "take.mkv",
+        percent: 0,
+        done_seconds: 0.5,
+        total_seconds: 100,
+      },
+      {
+        event: "reencode_progress",
+        file: "take.mkv",
+        percent: 1,
+        done_seconds: 1.2,
+        total_seconds: 100,
+      },
+      {
+        event: "reencode_progress",
+        file: "raw.mxf",
+        percent: null,
+        done_seconds: 3,
+        total_seconds: null,
+      },
+      {
+        event: "reencode_progress",
+        file: "raw.mxf",
+        percent: null,
+        done_seconds: 4,
+        total_seconds: null,
+      },
+    ]);
+    vi.restoreAllMocks();
+  });
+});