Window stuttering after these commits

[Monsterovich]

Commits 86d3739...a4fae2b created a stuttering when moving windows, which is very noticeable on the 144hz monitor.

The problem only disappeared when I removed these three commits. Just deleted commits one by one and watched as the lag disappeared.

Here's a video recorded at 120fps that shows this issue.

2023-06-13_16-58-50.mkv.zip

[absolutelynothelix]

try --no-frame-pacing

[Monsterovich]

try --no-frame-pacing

It does fix the problem. What does it do?

[yshui]

can you upload trace logs when the stutter happens?

[yshui]

@Monsterovich sorry, I wasn't clear. I meant the trace log, as in logs generated by picom --log-level trace

[Monsterovich]

picom --log-level trace

Here:

log.txt

[Monsterovich]

By the way, it's also noticeable on 60hz screen, I checked on a laptop with Intel iGPU.

[absolutelynothelix]

It does fix the problem. What does it do?

disables the recently introduced frame pacing feature that's supposed to schedule rendering better and decrease latency. unfortunately, it doesn't always work well, mainly because our rendering has poor performance.

[yshui]

Huh, this is wild:

[ 13.06.2023 19:27:16.808 schedule_render TRACE ] Last render call took: 3727 (gpu) + 34350 (cpu) us, last_msc: 1443218

I didn't expect to see numbers like this. I will add some more timing logs.

[yshui]

@Monsterovich alright, I've added more logs, can you git pull, rebuild, try again, and upload the logs?

[yshui]

@Monsterovich also:

2391:[ 13.06.2023 19:27:07.708 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 19679 16713,043956 896055,688665
5530:[ 13.06.2023 19:27:09.397 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 8798 16670,960784 684218,552902
14576:[ 13.06.2023 19:27:11.488 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 12515 16686,968000 1446907,805419
28265:[ 13.06.2023 19:27:13.600 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 12085 16639,220472 427647,220847
54666:[ 13.06.2023 19:27:16.803 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 24494 16642,882353 3700139,577483
57937:[ 13.06.2023 19:27:17.171 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 10038 17062,826087 3004013,150198
80369:[ 13.06.2023 19:27:19.808 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 9420 16679,703226 1775069,495769
105666:[ 13.06.2023 19:27:22.692 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 21156 16672,438596 1529461,294737
109214:[ 13.06.2023 19:27:23.200 render_statistics_add_vblank_time_sample DEBUG ] vblank time outlier: 3244 16859,034483 10881955,391626

Do you have VRR enabled? your frame rate is really unstable.

[Monsterovich]

@Monsterovich alright, I've added more logs, can you git pull, rebuild, try again, and upload the logs?

log2.txt.gz

Do you have VRR enabled? your frame rate is really unstable.

Did you know that VRR is disabled in picom even if enabled on the monitor, because in the NVidia driver picom is added to the exclusion list of applications in which VRR is forced to be disabled (nvidia-application-profiles-rc file). But it doesn't matter, because I see this problem on my laptop, where there is no FreeSync.

P.S. The log is from my laptop, where there is no VRR.

[yshui]

Did you know that VRR is disabled in picom even if enabled on the monitor

I do, but what I saw in the logs lead me to believe otherwise.

[yshui]

because I see this problem on my laptop, where there is no FreeSync.

Hmm, this is odd. I looked through the log but there is no missed vblanks. do you have a video recording of the stuttering? Also it would be nice if the video is paired with a log file.

[Monsterovich]

because I see this problem on my laptop, where there is no FreeSync.

Hmm, this is odd. I looked through the log but there is no missed vblanks. do you have a video recording of the stuttering?

https://github.com/yshui/picom/files/11736351/2023-06-13_16-58-50.mkv.zip

I've already uploaded it. The video at the end clearly shows that the windows move smoothly (without frame pacing commits).

Here's a log from my PC (NVidia GPU + FreeSync monitor):

log3.txt.gz

[frebib]

Having similar issues. With frame-pacing enabled games claim that they're running at a solid 60 but it feels more like 20-40
https://gist.githubusercontent.com/frebib/ee2118ec065525766952ddc34407ea8b/raw

[yshui]

@frebib what's your graphics card BTW?

[yshui]

@Monsterovich

I've already uploaded it.

No, I need a video that is paired with the log file. i.e. the one from your laptop.

Your log from your PC still has unstable frame rate.

[kwand]

I am experiencing the same problem after the pacing branch was merged in, on an RTX 3090 (so it's not hardware related). VRR is also disabled, and also remains blacklisted - as shown below:

cat /usr/share/nvidia/nvidia-application-profiles-530.41.03-rc | grep picom                                  
        { "pattern" : { "feature" : "procname", "matches" : "picom" },                  "profile" : "No VRR/OSD" }

I suspected that the branch might cause problems for NVIDIA GPUs based on the discussion that was going on in the PR, and been meaning to perform some tests. Unfortunately, my free time is quite limited recently. But since this has been merged in and I'm negatively affected, I'll sink some time into this regardless.

First, here are Nsight profiling results from running picom with and without --no-frame-pacing. The monitor refresh rate is 175hz.

nsys-rep files profiling scrolling in Firefox with and without frame pacing.zip

Clearly, there is a significant difference in behaviour when frame-pacing is applied.

Additionally, here is another 5s profiling run along with accompanying video (recorded in OBS @ 60fps) and picom.log.

Recorded firefox scrolling with frame pacing nsys-rep.zip
picom-log.log
2023-06-15 01-38-35.zip

And my picom.conf: https://gist.github.com/kwand/a824601173b9cc268bdfb4e3c9174989 (log-level set to debug)

Unfortunately, I can't seem to consistently record above 60fps with OBS without (OBS introduced) stuttering showing up in the recording, and it's a bit hard to see the stuttering itself when recorded at only 60. Hopefully, this additional recording (where I switch between picom runs with and w/o frame-pacing) will illustrate the difference more clearly. I think you can definitely notice stuttering in the recording, but the stuttering difference is night and day in real life. (As the Nsight profiling reports evidence, the average frame rate is 50 vs 140fps, with and without frame-pacing respectively)

Uploaded to mega as file size (41MB) was too large to upload here: https://mega.nz/file/UaM3CJ5J#tauIPLtSsT2zV-iXQJj17s5-7TrgVB1L4_FNHxnVFcg

[frebib]

@frebib what's your graphics card BTW?

7900xt. I'm using the amdgpu driver

[yshui]

@frebib yours is different from Monsterovich's. based on the timing information reported by OpenGL, the render had finished in time, but when the next vblank started we found we were still rendering. I have a 6800XT, and this is not happening to me 🤔

[frebib]

@frebib yours is different from Monsterovich's. based on the timing information reported by OpenGL, the render had finished in time, but when the next vblank started we found we were still rendering. I have a 6800XT, and this is not happening to me 🤔

I wouldn't be surprised if it's a driver bug tbh. I've hit many many of those with this card unfortunately. I'll try re-enabling this occasionally to see if it behaves any differently.

[yshui]

https://gitlab.freedesktop.org/drm/amd/-/issues/2631, this is for some weirdness I saw in the log file.

I suspect I probably didn't account for the amount of time scanout takes, let's see if I can get some answers.

[Monsterovich]

@frebib yours is different from Monsterovich's. based on the timing information reported by OpenGL, the render had finished in time, but when the next vblank started we found we were still rendering. I have a 6800XT, and this is not happening to me thinking

I wouldn't be surprised if it's a driver bug tbh. I've hit many many of those with this card unfortunately. I'll try re-enabling this occasionally to see if it behaves any differently.

Unlikely, considering that I have this problem on NVidia GPU and on Intel iGPU.

[tildearrow]

https://gitlab.freedesktop.org/drm/amd/-/issues/2631, this is for some weirdness I saw in the log file.

I suspect I probably didn't account for the amount of time scanout takes, let's see if I can get some answers.

Changing src/picom.c:267 to:

const auto deadline = ps->last_msc_instant + (unsigned long)divisor * frame_time - 4000;

fixes the issue by making the deadline earlier. I don't know whether hard-coding this value is good though...

[yshui]

@frebib hi, can you try the pacing-fixes branch, and see if that helps at all?

[frebib]

Seems more or less the same. Switching to the game yields 60fps feeling for a few seconds, then it drops to feeling more like 30 https://gist.github.com/frebib/49b16ab1081a8175026ad1b92f9ef23b/raw

I see lots of these c769988#diff-c010a812c869b9aeec83b5b76bd93cbcc57535ced07824ead7506809af6c0793R1596

18/06/23 17:45:02.996 handle_present_complete_notify TRACE ] The end of this vblank is 535 us into the future

[yshui]

@frebib

I see lots of these

Those are normal

[Stebalien]

I've tried the pacing-fixes branch to see if it affects #1079 but it doesn't seem to help (while --no-frame-pacing definitely does)

Logs:
picom.log

[yshui]

@Stebalien are you experiencing the same problem? and what's your graphics card?

[Stebalien]

@yshui I'm not experiencing stuttering, just high power usage. I can re-open my issue if you think it's different.

Graphics-card info is in #1079.

[yshui]

@frebib @Monsterovich @kwand I am trying to find a middle ground between pacing and no pacing. Can you guys try the partial-pacing branch see if that helps?

[frebib]

Definitely feels smoother. There are no noticeable frame drops now. I'll stick with it for a while and report back

[Monsterovich]

@frebib @Monsterovich @kwand I am trying to find a middle ground between pacing and no pacing. Can you guys try the partial-pacing branch see if that helps?

2023-06-19_00-22-33.mkv.zip

I don't see any difference, the fps is still about 60 instead of 144.

[yshui]

@Monsterovich what does it look like if you run without pacing?

[Monsterovich]

@Monsterovich what does it look like if you run without pacing?

Smoother window movement/page scrolling, with frame pacing the frame rate is like being limited to 60 fps.

[yshui]

@Monsterovich I mean, you recorded a video with picom running under renderdoc, can you do the same without pacing?

[Monsterovich]

@Monsterovich I mean, you recorded a video with picom running under renderdoc, can you do the same without pacing?

I did this in one video, pay more attention at the fps counter when I added the --no-frame-pacing flag.

[kwand]

@yshui I can confirm with @Monsterovich that I also experience a significant night/day difference between partial pacing and with --no-frame-pacing.

For profiling, I returned to an old, intensive test brought up by an issue long ago: rapidly moving around a video-playing window. In particular, I moved Firefox around in circles with a tab playing this: https://blurbusters.com/hfr-120fps-video-game-recording/. (I think this is self-explanatory, but let me know if you need a recording)

Profiling with Nsight shows clear significant differences, with average FPS of 172 for --no-frame-pacing, 49 FPS with partial pacing, and 44 FPS with 'full' pacing. The full reports can be found here:
Moving 120fps video nsys reports.zip

Screenshots:

[yshui]

@kwand did the partial-pacing branch make any difference?

nvm, I saw you wrote about it already.

[yshui]

@Monsterovich

I did this in one video, pay more attention at the fps counter when I added the --no-frame-pacing flag.

Sorry, which one?

[yshui]

@kwand BTW, can you upload log file with --log-level trace? the one you uploaded is on debug log level.

[yshui]

OK, I am just waiting for @frebib's result of partial-pacing.

[frebib]

I haven't done any scientific tests, but the partial-pacing branch is definitely night&day difference over what is in master right now. https://www.testufo.com/ seems about the same with picom running, and not (both ~60fps) although I am only running on crappy 60hz panels so it's not a great test. I still want to say --no-frame-pacing gives a more consistent experience (no occasional hitches). Power draw seems about the same with/without picom, regardless of no-frame-pacing. If the vote is between partial-pacing and master I'd pick partial-pacing every time, although I might also be tempted to disable pacing entirely because it seems to be mostly no benefit with a few minor downsides.

[yshui]

Thanks, that's the result I was hoping for. Looks like there's definitely some weirdness with VRR capable nvidia setup, even with VRR disabled. With a trace log from @kwand I should be able to find a way to detect that and disable pacing fully in that case.

@frebib Pacing should give you a reduced latency. It's very noticeable (at least for me) when I drag windows around, and when I play games that require short reaction time.

OTOH the difference between full pacing and partial pacing is small

[kwand]

@yshui Here you go, trace log:
picom-log.log

[s0nny7]

I also encountered this problem after updating, here are my log files, hope they help.

picom_logs.tar.gz

[Monsterovich]

I also encountered this problem after updating, here are my log files, hope they help.

picom_logs.tar.gz

@s0nny7 What is your GPU?

[s0nny7]

Mine is NVIDIA GeForce GTX 1060.

[raven2cz]

I have to reopened the issue #1077.

Today I have possibility to simulate it and make full log file according to your description.

The log file is shared here
https://1drv.ms/f/s!Aq_X66v0FnfLltZi2BUUm1yaUUi7jw?e=dAw1kZ

The loss control and large lags start around 12:40.

[yshui]

So a summary of the problems we have so far:

unreliable vblank interval measurement

we use X Present extension to measure how long a vblank interval is. NVIDIA's Present implementation is just unstable, and the vblank interval we measured is a) noisy and b) doesn't match the actual refresh rate. I had made inquiries on NVIDIA's forum but got no reply so far.

there are things other than the Present extension that we can use for this measurement:

• glXWaitVideoSyncSGI
• glXWaitForMscOML
• GLX_INTEL_swap_event

neither GLX_INTEL_swap_event or glXWaitForMscOML is supported by NVIDIA, so they are out. glXWaitVideoSyncSGI maps to either of these two things behind the scenes (in mesa at least):

• DRI2WaitMSC, or
• PresentNotifyMsc, which is exactly what we are using now, and we already know is unreliable on NVIDIA.

so our best bet is to add support for DRI2WaitMsc as an alternative to Present. unless NVIDIA has a different implementation of glXWaitVideoSyncSGI that doesn't use DRI2. we still need some investigation on that front.

unreliable render time measurement

as seen in log files submitted by @frebib. the actual render seems to take long than is reported by OpenGL. i have a branch partial-pacing which does not use render time in pacing, which fixes the problem so i plan to make the default behavior in next release.

high power usage

(#1079) this is because picom is waken up once for every frame, even when there is no change to the screen. this will be fixed once we merge the pacing-fixes branch.

[yshui]

For the investigation I mentioned above, I need some help from NVIDIA users.

If you want to help, you need to build xtrace, then compile this little test program. once you've done that, run the test program under xtrace:

xtrace -olog test_program

press ESC to exit, then upload the log file here.

[absolutelynothelix]

@yshui, xtrace.log

[yshui]

ok, this is kind of what i already expected. NVIDIA is using its own proprietary X extension instead of DRI2. this just means we can't take the DRI2WaitMSC short cut, instead we have to call glXWaitVideoSync

[yshui]

Hi, I've improved the pacing logic, disabled the more "advanced" part of pacing by default, and implemented a alternative to Present for NVIDIA.

Hopefully things will work better now, please give the pacing-fixes branch a go, and report problems here if you encounter any.

[yshui]

Also if you are a NVIDIA user, you can turn on --log-level=info and pay attention to a Using vblank scheduler: xxx in your log. Check and see if it says sgi_video_sync.