[MetaIX]

Stacked on #1377: this branch includes its commit. Only the last commit (AV1 pictures by the movie's clock…) is this PR's; I'll rebase once #1377 is in.

What and why

Symptom: Ocarina of Time's player (0400486024DEC000 v131072, profile in #1299) shows one picture per game frame and sends packets until the decoder refuses them. All 26 of its movies are 60 fps. On a Mac that renders the title below 60 fps, the movie plays slowly and out of step with its sound: at 28 frames a second (an M1 Max, under the title's NDVE filter) it ran at 0.44×.

Change: the decoder hands out pictures by the movie's clock, as a video player does.

• It compares the pictures' timestamps (ns, from the first picture) with the guest clock (guest_ns, which does not run while the Mac sleeps, an iPhone app is in the background or DM_DETCLOCK steps it).
• When the game gives a buffer back, it gets the newest waiting picture that is due; the late ones before it are dropped.
• A picture counts as late only once the next one is 50 ms overdue. Without that slack, a game running at the movie's rate but a frame behind its clock after a hitch went on skipping every other picture.
• A timestamp going back (a loop, a new stream) restarts the clock; Reset restarts it too. So does a picture over a second late when the game held the movie: it presented 6 or more frames without taking a picture (a pause menu, a load screen), or its window lost the focus.
• After a stall in the host with no frames presented (a pipeline built on first use, a long GPU wait), the late pictures are skipped instead, so the picture catches up with the sound, which went on. The log says when the clock restarts and why, and when a stall is caught up.
• A picture that ends the stream is never dropped.
• A game that keeps up drops nothing.
• AV1 only (the only codec whose timestamps I checked); DM_CV_LATE=0 turns it off.

Checked

• Tests: make -C dm/host/tests GAME=0100000000010000 run passes. t_codec_video checks the rules on a clock it sets:
  • the first picture starts the clock;
  • late pictures are dropped and the 50 ms slack is kept;
  • a picture that ends the stream stays;
  • the clock restarts after a pause (frames presented, no picture taken), a focus change and a timestamp going back;
  • after a stall with nothing presented, the late pictures are skipped and the clock stays.
• Games run: Ocarina of Time v131072 on our stack (main 95f9a6a + [WIP] The Legend of Zelda: Ocarina of Time (Switch 2, 0400486024DEC000, v0, SDK 22.2.8) runs on the Mac through the title movie into Kokiri Forest #1299 + Ampere F2IP and a task shader's own payload read: Ocarina of Time's untranslated shaders translate, all but one that is data #1300 + Zelda: Ocarina of Time — Restore missing mesh and texture effects on Mac #1312 with AV1 on dav1d decodes frames in parallel, each picture with its packet's timestamp, outside the decoder lock #1377 and this change).
  • Movie time against host time: 0.44× before; 1.00× after (66.03 s of movie in 66.05 s; three movies in a row, 87.47 s in 87.53 s, with their ends and restarts).
  • At 60 fps, 59.7 of 60 pictures a second shown.
  • A 1.6 s stall (dmhost stopped with SIGSTOP during the title movie, NDVE on, 28 fps): afterwards the picture is 0.06 s off the movie's clock, as before the stall. The first version of this PR restarted the clock there and stayed 1.72 s behind for the rest of the movie: the slip reported on an M2 Pro below.
  • Sound not measured: the timestamps track the guest clock, and the sound was out of step before.
• Not run: Fortune's Weave (see AV1 on dav1d decodes frames in parallel, each picture with its packet's timestamp, outside the decoder lock #1377).
• Devices and OS: MacBook Pro, Apple M1 Max, 64 GB, macOS 26.6.2, Xcode 27.2.

Docs

• The finding is in its docs/reference/movies.md entry, and python3 dm/tools/docs_symptoms.py was run (the symptom index)
• DM_CV_LATE is in docs/env_switches.tsv (test_env_switches passes on this branch)
• No game files, keys or data extracted from a game in the change or the attachments

🤖 Generated with Claude Code

[reefbluesky]

Tested on a MacBook Pro 14" (M2 Pro, no hardware AV1, 32 GB), macOS 27.2: main 865cc35 plus #1299, #1312, #1300, #1331 and this PR with #1377.

Before: the title movie ran at 22 fps (GPU 36 ms a frame), a scene's sound played before its picture, and when the picture reached the scene its sound had already ended (silence).

With this PR the log shows AV1 decoder 1: late pictures skipped to keep the movie on its clock and the sound now follows the picture. The movie shows fewer pictures a second, as expected. There was one slip in the middle of the sequence, where the narration and the picture went briefly out of step; afterwards the picture caught up with the scenes. The audio device is fine (0 underruns over 50,000 callbacks).

[MetaIX]

Thanks for testing on the M2 Pro. The slip matches a rule in the first version: a picture over a second late restarted the clock. That was meant for a pause, but on a stall in the host (a pipeline built on first use, a long GPU wait) the narration goes on, so the picture stayed behind until the next stream started.

The PR now restarts the clock only when the game held the movie (it presented frames without taking a picture, or the window lost the focus), and otherwise skips the late pictures to catch up. Reproduced here by stopping dmhost for 1.6 s during the title movie: before, the picture stayed 1.72 s behind for the rest of the movie; now it is back within 0.06 s of the movie's clock. If you rerun it, the log says the movie clock starts again … : <why> or … behind after the game stood still where a slip would have been.

Also, your build has #1331: with DM_NVN_NDVE_MOVIE_DIRECT=1 the title movie runs at 60 fps with nothing to skip (about 1 ms of GPU a frame on our M1 Max, against 35–42 ms with the network).

Drafted with Claude; reviewed by me.

[Amost-]

Tested #1377 and #1379 on an M2 Pro (MacBook Pro, 19-core GPU, 32 GB, macOS 27.2, no hardware AV1) with #1331's direct mode on (DM_NVN_NDVE_MOVIE_DIRECT=1), since your note says the title movie has nothing to skip there.

Build: main 863bc6b7 plus my local picks (#1331, #1176, #1585 and a few host-side changes), app chain 3f146103c47b. Three hosts built the same way: as is, + #1377 (d234d4f6), and + #1377 + #1379 (3b588ca6, 7ee81e91). All cherry-picked cleanly and t_codec_video passes. Runs are headless at the title with no input. DM_NVN_REGLUM records a patch of moving grass in the title movie on every present; a present whose patch is identical to the previous one counts as a repeat (near-black frames in the loop's fade are left out). Window: 60 s from 55 s after the first present.

host	presents	repeats	the movie
main + picks	60/s	19.0%	about 48.5 pictures/s, 0.8×
+ #1377	60/s	0.1%	every picture: end of stream at 97.8 s for 5,947 pictures
+ #1377 + #1379	60/s	0.1%	the same; 11 late pictures skipped over the loop (one log line)

Control: the baseline reaches the same loop end, the game's fade to black, at 120.4 s, against 97.8 s with #1377 and 97.6 s with #1379, so the same 5,947 pictures take 1.23× as long (0.81×). The fade, about 5.6 s, is there in all three. A second #1377 run gave 0.1% again.

So with the direct mode the game does present at 60, but without #1377 its player takes a new picture on only about 4 frames in 5. The decoder itself keeps up: dav1d with the host's settings (2 threads, frame delay 1) decodes this movie at 133 fps on this Mac, and the queue is full (a packet refused with 12 pictures waiting). An earlier trace of the output buffers on this build showed the player's release intervals at one frame 58% of the time with a tail of 20–50 ms (movie clock 0.78–0.82×), and the on-screen repeats lined up with the frames where it took no picture. In cutscenes that is the sound running ahead of the picture. #1377 removes it here; I have not separated its two parts (frames in flight, decode outside the lock).

The 5.5 s with an unchanged patch at 97.8 s in the #1377 runs is the game's fade to black between two loops (luminance 1.2 → 0.15 → 0 → back up), not a stall.