The opening movies stutter: a quarter to a third of their pictures are skipped (RTX 3090, Linux) #73

New issue

Open

opened 2026-11-13 01:43:19 +00:00 by HumanBean · 2 comments

HumanBean commented

2026-11-13 01:43:19 +00:00

Owner

What happens

The opening movies of a new game play with visible stutter: the picture jumps, because many of the movie's pictures are skipped to keep up with the sound. A second tester has reproduced it.

One session, measured

RTX 3090, NVIDIA 620.70.06, Linux, 2048x1152 window, default options, frame rate cap 60. A build of main at 4dd972a8 (before the rename) with #40 on top; nothing in #40 touches video, and no shader work happened in the session (0 pipelines compiled, 0 draws left out, 0 pipeline waits). A new game from the title, the intro left to play.

What the log says about the two movies (both AV1, 1920x1080, decoded by libdav1d):

movie	pictures	skipped to keep up	decode each	worst decode
first	700	249 (36 %)	0.7 ms	23.6 ms
second	9,254	2,511 (27 %)	2.0 ms	190.0 ms

So decoding is not the cost: a picture takes 0.7 to 2.0 ms and one is due every 16.7 ms. The pictures are skipped because the frames that show them are late.

The frames, from the frame trace (22,288 frames in the session):

Over 33 ms: 1,657. Over 50 ms: 1,300. Over 100 ms: 515. Over 300 ms: 8.
By stretches of 1,500 frames, the slow ones come in blocks: mean 37.4 ms (27 fps) with 145 frames over 100 ms in the first 1,500; then two clean stretches at 60 fps; then every second stretch has 60 to 80 frames over 100 ms (p95 89 to 112 ms) while the stretches between them have none.
Of the 548 frames over 60 ms that the slow-frame log lists, 524 spend under half their time in the renderer's submit and 357 under a quarter. A typical one: 140.4 ms in all, 22.7 ms of it in the submit (draw 9.8, descriptors 3.1, commands 2.8). So for most of them the time is outside the replay: the frame is waiting on something else.
The log also has, for each movie: video: the first buffer went out before the first picture was decoded (shown black).
One frame at the first movie's end took 2,296 ms (13,388 draws in it, 955 ms in descriptors, 750 ms in commands), followed by frames of 403, 148 and 203 ms: the scene behind the movie loading.

Not known

What the late frames wait for. The slow-frame log only splits the submit; the rest of the frame is not broken down. A run with HOS_CHAIN (the frame's critical path across threads) during a movie would name it.
Whether it is the same on AMD or on Windows, and whether it depends on the frame rate cap or V-Sync.
Whether the blocks of slow frames in the later stretches are the second movie or play between movies: the frame trace has no movie marker.

## What happens The opening movies of a new game play with visible stutter: the picture jumps, because many of the movie's pictures are skipped to keep up with the sound. A second tester has reproduced it. ## One session, measured RTX 3090, NVIDIA 620.70.06, Linux, 2048x1152 window, default options, frame rate cap 60. A build of main at 4dd972a8 (before the rename) with #40 on top; nothing in #40 touches video, and no shader work happened in the session (0 pipelines compiled, 0 draws left out, 0 pipeline waits). A new game from the title, the intro left to play. What the log says about the two movies (both AV1, 1920x1080, decoded by libdav1d): | movie | pictures | skipped to keep up | decode each | worst decode | |---|---|---|---|---| | first | 700 | 249 (36 %) | 0.7 ms | 23.6 ms | | second | 9,254 | 2,511 (27 %) | 2.0 ms | 190.0 ms | So decoding is not the cost: a picture takes 0.7 to 2.0 ms and one is due every 16.7 ms. The pictures are skipped because the frames that show them are late. The frames, from the frame trace (22,288 frames in the session): - Over 33 ms: 1,657. Over 50 ms: 1,300. Over 100 ms: 515. Over 300 ms: 8. - By stretches of 1,500 frames, the slow ones come in blocks: mean 37.4 ms (27 fps) with 145 frames over 100 ms in the first 1,500; then two clean stretches at 60 fps; then every second stretch has 60 to 80 frames over 100 ms (p95 89 to 112 ms) while the stretches between them have none. - Of the 548 frames over 60 ms that the slow-frame log lists, 524 spend under half their time in the renderer's submit and 357 under a quarter. A typical one: 140.4 ms in all, 22.7 ms of it in the submit (draw 9.8, descriptors 3.1, commands 2.8). So for most of them the time is outside the replay: the frame is waiting on something else. - The log also has, for each movie: `video: the first buffer went out before the first picture was decoded (shown black)`. - One frame at the first movie's end took 2,296 ms (13,388 draws in it, 955 ms in descriptors, 750 ms in commands), followed by frames of 403, 148 and 203 ms: the scene behind the movie loading. ## Not known - What the late frames wait for. The slow-frame log only splits the submit; the rest of the frame is not broken down. A run with `HOS_CHAIN` (the frame's critical path across threads) during a movie would name it. - Whether it is the same on AMD or on Windows, and whether it depends on the frame rate cap or V-Sync. - Whether the blocks of slow frames in the later stretches are the second movie or play between movies: the frame trace has no movie marker.

HumanBean commented

2026-11-13 02:39:08 +00:00

Author

Owner

Claimed. First step: name what the late frames wait for during the movies (a critical-path recording with HOS_CHAIN while a movie plays, and a read of the video path: how pictures are handed to the presenter and why they are skipped to keep up with the sound). Findings will be posted here before any fix.

Claimed. First step: name what the late frames wait for during the movies (a critical-path recording with `HOS_CHAIN` while a movie plays, and a read of the video path: how pictures are handed to the presenter and why they are skipped to keep up with the sound). Findings will be posted here before any fix.

HumanBean commented

2026-11-13 02:43:33 +00:00

Author

Owner

First read of the same session, with corrections to the issue text. Nothing new was run; this is from the log, the frame trace and the code.

Corrections

The slow-frame log has no line before play starts, so "548 frames over 60 ms, 524 with under half their time in the submit" and "every second stretch of 1,500 frames" describe play after the movies, not the movies. Read those two bullets as play.
By the decoder's create and free lines, the first movie is frames 137 to 815 and the second 853 to 7692.

The two movies behave differently

First movie: 679 frames in 11.6 s, only 2 over 33 ms, a steady 60 fps. Still 249 of 700 pictures were skipped: one handed out every 25.9 ms. So there the pictures are not skipped because frames are late.
Second movie: 6,840 frames in 154.3 s, 622 over 33 ms, in two blocks (about seconds 2 to 40 at 9 to 16 fps, and seconds 112 to 129 at 20 to 47 fps); the rest is a flat 60 fps. 9,254 pictures minus 6,840 frames is 2,414, against 2,511 skipped: there the skips are the missing frames.
In the slow movie frames the renderer does next to nothing: 2 to 5 draws, 14 dispatches, no texture uploads, memory sync 1.0 ms. Decoding is 0.7 to 2.0 ms. Uploads and decoding are ruled out.

Likely causes, not confirmed

Second movie's slow blocks: the game's threads queue for virtual cores. The log's 5-second vcores: lines show 0.3 to 0.4 s of waiting for a core per 5 s in every smooth stretch and 6 to 40 s per 5 s in every slow block, with single waits of 100 to 800 ms against 3 to 5 ms. The first block is when the scene behind the movie loads (3,438 shader programs created in the movie's first 20 s). Against: it is a correlation so far; the log does not say who held the cores, and it could be a lock the loaders hold.
First movie: the catch-up clock in host/nn_video.c (pictures more than 25 ms behind the wall clock since the first hand-out are dropped) against the movie library's own pacing. Mechanism not known yet.
One-offs: a 2.3 s frame at the second movie's end and a 280 ms one in the first are loads and one texture upload; one jump each.

Next: a run with HOS_VIDEO_LOG=1 for the skips, and a critical-path recording in the second movie's first block for the core waits.

First read of the same session, with corrections to the issue text. Nothing new was run; this is from the log, the frame trace and the code. **Corrections** - The slow-frame log has no line before play starts, so "548 frames over 60 ms, 524 with under half their time in the submit" and "every second stretch of 1,500 frames" describe play after the movies, not the movies. Read those two bullets as play. - By the decoder's create and free lines, the first movie is frames 137 to 815 and the second 853 to 7692. **The two movies behave differently** - First movie: 679 frames in 11.6 s, only 2 over 33 ms, a steady 60 fps. Still 249 of 700 pictures were skipped: one handed out every 25.9 ms. So there the pictures are not skipped because frames are late. - Second movie: 6,840 frames in 154.3 s, 622 over 33 ms, in two blocks (about seconds 2 to 40 at 9 to 16 fps, and seconds 112 to 129 at 20 to 47 fps); the rest is a flat 60 fps. 9,254 pictures minus 6,840 frames is 2,414, against 2,511 skipped: there the skips are the missing frames. - In the slow movie frames the renderer does next to nothing: 2 to 5 draws, 14 dispatches, no texture uploads, memory sync 1.0 ms. Decoding is 0.7 to 2.0 ms. Uploads and decoding are ruled out. **Likely causes, not confirmed** 1. Second movie's slow blocks: the game's threads queue for virtual cores. The log's 5-second `vcores:` lines show 0.3 to 0.4 s of waiting for a core per 5 s in every smooth stretch and 6 to 40 s per 5 s in every slow block, with single waits of 100 to 800 ms against 3 to 5 ms. The first block is when the scene behind the movie loads (3,438 shader programs created in the movie's first 20 s). Against: it is a correlation so far; the log does not say who held the cores, and it could be a lock the loaders hold. 2. First movie: the catch-up clock in `host/nn_video.c` (pictures more than 25 ms behind the wall clock since the first hand-out are dropped) against the movie library's own pacing. Mechanism not known yet. 3. One-offs: a 2.3 s frame at the second movie's end and a 280 ms one in the first are loads and one texture upload; one jump each. Next: a run with `HOS_VIDEO_LOG=1` for the skips, and a critical-path recording in the second movie's first block for the core waits.