Repository navigation
fix(producer): page timers during a render run on film time - #7362
Conversation
…, heygen-com#7360, heygen-com#7347); review to PR heygen-com#7362 Adopt heygen-com#7357 and heygen-com#7361 (upload completion waits and retries), heygen-com#7360 (Chrome start failure names its cause in check) and heygen-com#7347 (Safari perf tooling); release v0.9.20 not applicable. Pin open heygen-com#7362 (needs its golden LFS pointer when adopted); record issue heygen-com#7363. Monitored 126 -> 127. Co-authored-by: Miguel Ángel <miguel.sierra@heygen.com> Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com> Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
There was a problem hiding this comment.
Requesting changes at 331ce783. CI is green, and the "fails without the fix" line is acceptable: it names fileServer-virtualTimers.test.ts and the timers-on-film-time fixture. The blocker is a side effect on the renderer's own safety timeouts.
Blocker: page-side timeouts the engine waits on can no longer fire
After the first ready seek, every setTimeout on the page goes to the film-time queue. That includes the runtime's and the engine's own timeouts. Several of these are deadlines on waits that the engine awaits after seeking frame N and before seeking frame N+1. Under this shim, a queued timer fires only on a later seekToTime. If the awaited thing never settles, the deadline never arrives, and the frame stalls until Puppeteer's CDP protocolTimeout (~180 s). Today it fails or falls back after a short, bounded wait.
core/src/runtime/vfx.ts,awaitCanvasPaint: the 2 sCAPTURE_PAINT_TIMEOUT_MS. Its own doc says this deadline is the only way out on a BeginFrame host. The engine drains this barrier inprepareFrameForCapture(waitForPendingSeekCompletioninframeCapture.ts) before the per-framebeginFrame. The rAF fallback is already on film time under the shim, so after this PR nothing can settle the barrier before the next seek, and the next seek never comes.core/src/runtime/adapters/seek-dispatch.ts,settledBy: thewaitForSeekCompletion({ timeoutMs })deadline is asetTimeout.Date.now()is already frozen, so this timer was the only thing enforcing the timeout.engine/src/services/frameCapture.ts,decodeDynamicCssBackgroundImages: the in-pagesetTimeout(() => resolve("late"), limitMs)race againstimage.decode().engine/src/services/drawElementService.ts,waitPaint: thesetTimeout(settle, 250)paint fallback. The vfx docs describe it as firing every frame under BeginFrame control.- Also affected:
mediaProxy.tsshownScale(DISPLAY_SCALE_WAIT_MS) and any otherPromise.race([..., setTimeout])shape that runs after the ready seek.
I reproduced the mechanism with the shim from this branch and from main in a VM. Both got real timers, __renderReady = true and one seekToTime(0), then ran Promise.race([never, new Promise(r => setTimeout(() => r("late"), 50))]):
- This branch: still
pendingafter 1000 ms of real time. main:late.
The regression fixtures pass because in them every hold settles through its normal path. The timeouts exist for the cases where that doesn't happen: a canvas that never paints, an image whose decode hangs, BeginFrame drawelement capture.
Suggested direction
- Keep engine and runtime deadlines on the wall clock. The codebase already has a convention for this:
hf-early-stub.tsuseswindow.__HF_VIRTUAL_TIME__.originalSetTimeout. Route at leastsettledBy,awaitCanvasPaint,waitPaint, the CSS-background decode race andshownScalethrough it. The cleanest way is a small helper in core that prefers__HF_VIRTUAL_TIME__?.originalSetTimeout/originalClearTimeoutwhen present. - The other option is to virtualize only composition timers, but the shim can't tell callers apart. Going through the original timers is the practical fix.
- Add a test that fails on this head: after a ready seek, a wait raced against a
setTimeoutdeadline still settles within real time. For example,waitForSeekCompletion({ timeoutMs: 50 })with a never-settling hold throwsSeekNotSettledError, orawaitCanvasPainton a canvas that never paints returns"timeout".
Non-blocking
clearTimeouton a virtual id that already fired falls through to the browser'sclearTimeout(1e9+n). That's harmless.fireDueTimersdoes a linear scan per fire, which is fine at page scale.- The film-time semantics in the description are right for composition code, and the new fixture is a good regression guard.
|
Thanks, this is right. A deadline the engine awaits between two seeks could only fire at the next seek, so a hold that never settled waited until the protocol timeout. Fixed; the branch head is now
On the non-blocking points: agreed. The fall-through |
There was a problem hiding this comment.
Approving at b6c2bfad. This head resolves my earlier blocker.
- The renderer's waits are back on the wall clock.
wallClock.tsresolves__HF_VIRTUAL_TIME__.original*at call time and falls back to the plain timers, the same conventionhf-early-stub.tsfollows.- Covered in the runtime:
settledBy,awaitCanvasPaint,shownScale, the media seek-barrier cap and the other runtime timers. - Covered in the engine's page-side code: the CSS-background decode race, the drawElement paint and encode fallbacks, the registry-settle macrotask and the WebGPU probe. These use the shim's original timers inline.
- Covered in the runtime:
- The fails-without-the-fix claim holds. I put
settledByback on baresetTimeout. Two tests then fail:a seek's deadline still fires while the render shim holds page timers for the next seek(pending after about 1 s) andare the only timers the runtime calls(17 tests, 2 failed). With the fix restored,wallClock.test.tsandseek-dispatch.test.tspass 17 of 17, andpageTimers.test.tspasses 2 of 2. - The guards are well shaped. The runtime source scan plus the engine AST scan, which covers page-call arguments, functions passed by name and page-script strings, should stop this class of bug from coming back.
- CI on this head: all green, including regression, preview-regression, Windows render verification, and Player Safari perf and audio.
Non-blocking, for a follow-up if you want:
- Neither scan covers page code outside
core/src/runtimeandengine/src. What I checked is fine today:core/src/compositionReadiness.tsruns before__renderReady, so its timers stay native.shader-transitions/engineModePageComposite.ts's bridge poll is created before the ready seek.hyper-shader.ts's 240 ms overlay hide would now run on film time ifhide()were called mid-render. That's arguably the right behavior.
Extending the runtime scan to those packages would make the guard complete.
- In
settledBy,deadline - Date.now()still reads the frozen virtualDate, so the deadline works only because the virtual clock doesn't move inside a wait. Aperformance.timeOrigin-free wall reading would be sturdier. This was already true before this PR.
What
Page timers set during a render now run on film time.
setTimeoutandsetIntervalcallbacks set once rendering has started fire at the seek that reaches their due time, in due order. Inside the callback,Date.now()andperformance.now()read the timer's due time. Until the renderer seeks a page that reports ready (window.__renderReady), timers still run on the wall clock, so page setup behaves as before. The renderer's own waits and deadlines, in the runtime and in the engine's page-side code, stay on the wall clock throughout.Why
The render's virtual-time shim already freezes
Date,performance.nowandrequestAnimationFrameto film time, but it left timers on the wall clock. Motion driven by a timer therefore advanced at whatever speed frames happened to be captured, not by frame number. A 100 mssetTimeoutchain fired every 2 frames at 30 fps instead of every 3, about 1.5x film speed, on every version tested. Because capture speed changes between releases and machines, the same film could render differently from one version to the next.Related work
#6599 also edits
buildVirtualTimeShim, to drain pending animation frames before a PNG-sequence capture. The two changes touch different parts of the shim.How
buildVirtualTimeShiminpackages/producer/src/services/fileServer.tsreplacessetTimeout,setInterval,clearTimeoutandclearInterval.seekToTimearrives whilewindow.__renderReadyis true, they pass straight to the browser's timers. That keeps every timer set during page setup on the wall clock, even if a seek arrives before setup ends.seekToTime(t)fires every queued timer due byt, earliest first, before the frame's animation callbacks run.waitForSeekCompletion's timeout, the CSS-background decode race, the drawElement paint fallback. On film time, such a deadline would fire only at the next seek, which waits for it, so a canvas that never paints would hang the frame until the protocol timeout.packages/core/src/runtime/wallClock.tsexportswallSetTimeout,wallClearTimeout,wallSetIntervalandwallClearInterval. They call the shim'soriginalSetTimeoutand the other originals whenwindow.__HF_VIRTUAL_TIME__is present, the conventionhf-early-stub.tsalready follows, and the plain timers otherwise.packages/core/src/runtimegoes through them: 51 call sites in 15 files. A test fails if a runtime source file callssetTimeout,clearTimeout,setIntervalorclearIntervaldirectly.page.evaluateserializes each function. Its seven page-side timers call the shim'soriginalSetTimeoutinline, falling back tosetTimeout. They are the CSS-background decode race and the registry-settle macrotask inframeCapture.ts, the encode hand-off and the paint fallbacks of the single, pipelined and batch captures indrawElementService.ts, and the WebGPU device probe's deadline inbrowserManager.ts.pageTimers.test.tsparses every engine source and fails on a baresetTimeoutorsetIntervalcall in code the engine runs in the page. That covers every function passed toevaluate,evaluateOnNewDocument,evaluateHandle,$eval,$$evalorwaitForFunction(inline or by name), and every page-script string.Test plan
fileServer-virtualTimers.test.ts. They run the shim in a VM and seek it frame by frame at 30 fps:seek-dispatch.test.ts: with page timers held for the next seek, as after a ready seek,waitForSeekCompletion({ timeoutMs: 50 })on a hold that never settles throwsseek did not settle within 50 ms. Fails without the fix: at331ce783it is still pending after 1 s.wallClock.test.ts: the helper uses the shim's original timers while page timers are held, and no runtime source calls a timer directly. Fails without the fix: routingsettledByback tosetTimeoutfails the deadline test and the source scan; dropping the shim lookup from the helper fails the helper test and the deadline test.pageTimers.test.ts: on this head it finds no bare page-side timer, and its own case finds the three shapes (inline function, function passed by name, script string). Fails without the fix: with331ce783's page code it lists all seven sites. The WebGPU probe was one my hand grep had filed as Node-side.fileServer-virtualTimers.test.ts(8 tests) passes 3 runs in a row;fileServer.test.tsandfileServer-seededRandom.test.tspass (68 tests); producertsc --noEmit, oxlint, oxfmt and test classification are clean.requestAnimationFrame,element.animate, CSS transitions and GSAP bars are unchanged.timers-on-film-time: a 100 mssetTimeoutchain and a 250 mssetIntervalstarted from the first animation frame, against aperformance.nowreference bar, all at 200 px per second of film time. Its baseline was generated in Docker from this branch; all three bars match their film-time widths on all 90 frames, and the harness passes it against that baseline.timers-on-film-timefixture above.fast-capture-gsap,heygen-promo-preview-assets,page-side-shader-compositor-render-compatandwebgl-video-texture-render-compatfail the same number of frames on both images (100, 18, 41 and 99).d3-adapterandmaplibre-adapterload their libraries from public CDNs and time out in setup on both images on that machine; CI renders them.Timers checked
Every timer call in the runtime and the engine, found with:
packages/core/src/runtime: all 26 timer starts and their clears now go throughwallClock.ts. They areafterFonts.ts(font wait),webAudioTransport.ts(2),mediaProxy.ts(shownScalewait, hold cap, copies-ahead check),proxyWait.ts,colorGrading.ts(context-restore grace),bridge.ts(flash),media.ts(seek-barrier cap),init.ts(8: debounce, task yields, caps, transport timers),captureMotionBlur/index.ts,vfx.ts(awaitCanvasPaint),previewCopies.ts,filmBridge.ts(2),adapters/seek-dispatch.ts(settledBy),adapters/typegpu.ts(present heartbeat) andcompositionLoader.ts(external script timeout).positionEdits.tscallstarget.setIntervalon a Studio editing window, not in a render, and is left as is.packages/engine/src: seven calls run in the page and now use the shim's original:frameCapture.ts2,drawElementService.ts4 andbrowserManager.ts1 (the WebGPU probe).pageTimers.test.tskeeps it that way. The other 29 run in Node, where the shim does not reach: the rest ofbrowserManager.ts,parallelCoordinator.ts,chromeStartup.ts,browserLeasePool.ts,screenshotService.ts,pageMotionBlur.ts,riskFrames.ts,urlDownloader.ts,managedChildProcess.ts,processTracker.ts, the Node-side polls and races inframeCapture.tsand the encode watchdogs indrawElementService.ts.packages/producer/src: the page scripts already use the shim's originals (hf-early-stub.tsand the shim itself); every other timer runs in Node.Size
One shim function and its tests, plus a four-function timer helper that the runtime and the engine's page code route through.