test: trace frame-file removals in concurrent video renders (repro only, do not merge)

This commit is contained in:
Miguel Ángel
2026-10-29 06:54:11 -04:00
parent 71f716a91b
commit cc982826ea
5 changed files with 176 additions and 1 deletions
@@ -0,0 +1,29 @@
<!doctype html>
<html lang="en">
<head>
<meta charset="UTF-8" />
<script src="https://cdn.jsdelivr.net/npm/gsap@3.14.2/dist/gsap.min.js"></script>
<style>
html, body { margin: 0; width: 1920px; height: 1080px; overflow: hidden; background: #101418; }
.tile { position: absolute; width: 160px; height: 160px; border-radius: 24px; }
</style>
</head>
<body>
<div id="root" data-composition-id="main" data-start="0" data-duration="240" data-width="1920" data-height="1080"></div>
<script>
const root = document.getElementById("root");
const tl = gsap.timeline({ paused: true });
for (let i = 0; i < 40; i++) {
const tile = document.createElement("div");
tile.className = "tile";
tile.style.background = `hsl(${i * 9}, 70%, 55%)`;
tile.style.left = `${(i % 10) * 190 + 20}px`;
tile.style.top = `${Math.floor(i / 10) * 260 + 40}px`;
root.appendChild(tile);
tl.to(tile, { rotation: 360 * 40, x: 60, duration: 240, ease: "none" }, 0);
tl.to(tile, { opacity: 0.3, yoyo: true, repeat: 119, duration: 1, ease: "sine.inOut" }, 0);
}
window.__timelines = { main: tl };
</script>
</body>
</html>
@@ -0,0 +1,16 @@
<!doctype html>
<html lang="en">
<head><meta charset="UTF-8" /><script src="https://cdn.jsdelivr.net/npm/gsap@3.14.2/dist/gsap.min.js"></script>
<style>html, body { margin: 0; width: 1920px; height: 1080px; overflow: hidden; background: #000; }</style></head>
<body>
<div id="root" data-composition-id="main" data-start="0" data-duration="DUR" data-width="1920" data-height="1080">
<video id="clip" src="clip.mp4" data-start="0" data-duration="DUR" muted playsinline style="position:absolute;inset:0;width:100%;height:100%"></video>
<div id="t" style="position:absolute;left:80px;top:80px;width:200px;height:200px;background:#fc0"></div>
</div>
<script>
const tl = gsap.timeline({ paused: true });
tl.to("#t", { x: 1500, rotation: 3600, duration: DUR, ease: "none" }, 0);
window.__timelines = { main: tl };
</script>
</body>
</html>
@@ -0,0 +1,41 @@
// Repro-only preload (NODE_OPTIONS=--require): log every delete/rename of a frame or capture dir with its caller.
const fs = require("node:fs");
const fsp = require("node:fs/promises");
const WATCHED =
/frame_\d|captured-frames|capture-attempt-\d|worker-\d|work-[0-9a-f]{8}|hf-render|extract|frame-cache|hyperframes[\\/]cache/;
function trace(op, args) {
const paths = args.filter((a) => typeof a === "string" || a instanceof URL).map(String);
if (process.env.HF_TRACE_ALL !== "1" && !paths.some((p) => WATCHED.test(p))) return;
const stack = (new Error().stack || "")
.split("\n")
.slice(3, 9)
.map((l) => l.trim())
.join(" < ");
process.stderr.write(
`[frame-fs] ${new Date().toISOString()} pid ${process.pid} ${op} ${paths.join(" -> ")} | ${stack}\n`,
);
}
for (const op of [
"rename",
"renameSync",
"unlink",
"unlinkSync",
"rm",
"rmSync",
"rmdir",
"rmdirSync",
]) {
const original = fs[op];
fs[op] = function (...args) {
trace(op, args);
return original.apply(this, args);
};
}
for (const op of ["rename", "unlink", "rm", "rmdir"]) {
const original = fsp[op];
fsp[op] = function (...args) {
trace(`promises.${op}`, args);
return original.apply(this, args);
};
}
process.stderr.write(`[frame-fs] tracing on, pid ${process.pid}\n`);
+72
View File
@@ -0,0 +1,72 @@
# Repro-only: long streaming renders with frame-file tracing, to find what removes frame_#.jpg mid-capture.
name: ENOENT frame repro
on:
pull_request:
paths:
[
".github/workflows/lp-enoent-repro.yml",
".github/workflows/fixtures/frame-fs-trace.cjs",
".github/workflows/fixtures/enoent-video.html",
]
permissions:
contents: read
jobs:
render:
strategy:
fail-fast: false
matrix:
os: [windows-latest, ubuntu-latest]
run: [1, 2, 3]
runs-on: ${{ matrix.os }}
timeout-minutes: 60
env:
HF_TRACE_FRAME_FS: "1"
HYPERFRAMES_NO_TELEMETRY: "1"
DO_NOT_TRACK: "1"
steps:
- uses: actions/checkout@11d5960a326750d5838078e36cf38b85af677262 # v4
- if: runner.os == 'Windows'
uses: ./.github/actions/install-ffmpeg-windows
- if: runner.os == 'Linux'
run: sudo apt-get -qq update && sudo apt-get -qq install -y ffmpeg
- uses: oven-sh/setup-bun@0c5077e51419868618aeaa5fe8019c62421857d6 # v2
- uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4
with:
node-version: 22
- shell: bash
run: bun install --frozen-lockfile --linker=hoisted
- shell: bash
run: |
bun run --filter '@hyperframes/{parsers,lint,studio-server}' build
bun run --cwd packages/core build
bun run --filter @hyperframes/player build
bun run --filter @hyperframes/studio build
bun run --filter @hyperframes/inspector build
bun run --filter @hyperframes/cli build
- name: Two concurrent video renders and a snapshot, traced
shell: bash
env:
HYPERFRAMES_EXTRACT_CACHE_MAX_MB: "50"
run: |
TRACE="--require $GITHUB_WORKSPACE/.github/workflows/fixtures/frame-fs-trace.cjs"
CLI="$GITHUB_WORKSPACE/packages/cli/dist/cli.js"
mk() { mkdir -p "$RUNNER_TEMP/$1"; sed "s/DUR/$2/g" .github/workflows/fixtures/enoent-video.html > "$RUNNER_TEMP/$1/index.html"
ffmpeg -loglevel error -f lavfi -i "testsrc2=size=1280x720:rate=30:duration=$2" -vf "hue=h=$3" -pix_fmt yuv420p -c:v libx264 -preset ultrafast "$RUNNER_TEMP/$1/clip.mp4"; }
mk long 240 0; mk short 60 120; mk snap 90 240
set +e
(cd "$RUNNER_TEMP/long" && NODE_OPTIONS="$TRACE" node "$CLI" render --fps 30 --quality standard --workers 3 --output out.mp4 > render.log 2>&1; echo "long rc=$?" >> render.log) &
LONG=$!
sleep 90
(cd "$RUNNER_TEMP/short" && NODE_OPTIONS="$TRACE" node "$CLI" render --fps 30 --quality standard --workers 2 --output out.mp4 > render.log 2>&1; echo "short rc=$?" >> render.log)
(cd "$RUNNER_TEMP/snap" && NODE_OPTIONS="$TRACE" node "$CLI" snapshot . --at 5,30,60,85 --no-end > render.log 2>&1; echo "snap rc=$?" >> render.log)
wait $LONG
for r in long short snap; do echo "== $r"; tail -1 "$RUNNER_TEMP/$r/render.log"; grep -E "READ FAILED|ENOENT" "$RUNNER_TEMP/$r/render.log" | head -3; done
echo "== removals of anything the long render owns, by other processes"
LPID=$(grep -m1 -oE "tracing on, pid [0-9]+" "$RUNNER_TEMP/long/render.log" | awk '{print $4}')
cat "$RUNNER_TEMP"/{short,snap}/render.log | grep "\[frame-fs\]" | grep -E "rmSync|rm |rmdir|unlink" | cut -c1-400 | head -40
mkdir -p "$RUNNER_TEMP/logs" && for r in long short snap; do cp "$RUNNER_TEMP/$r/render.log" "$RUNNER_TEMP/logs/$r.log"; done
- if: always()
uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4
with:
name: enoent-${{ matrix.os }}-${{ matrix.run }}
path: ${{ runner.temp }}/logs/
@@ -333,7 +333,24 @@ async function readLandedFrame(workerPath: string | undefined, mergedPath: strin
if ((error as NodeJS.ErrnoException).code !== "ENOENT") throw error;
}
}
return readFile(mergedPath);
try {
return await readFile(mergedPath);
} catch (error) {
if (process.env.HF_TRACE_FRAME_FS === "1") {
const { existsSync, readdirSync } = await import("node:fs");
const { dirname, basename } = await import("node:path");
const near = (dir: string, name: string) =>
existsSync(dir)
? readdirSync(dir).filter(
(f) => Math.abs(parseInt(f.slice(6)) - parseInt(name.slice(6))) < 4,
)
: "NO DIR";
process.stderr.write(
`[frame-fs] READ FAILED worker=${workerPath} merged=${mergedPath} workerNear=${JSON.stringify(workerPath ? near(dirname(workerPath), basename(workerPath)) : null)} mergedNear=${JSON.stringify(near(dirname(mergedPath), basename(mergedPath)))}\n`,
);
}
throw error;
}
}
/**