commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying #1369

matte-schwartz · 2024-06-10T05:43:55Z

matt@nobara-pc:~/src/gamescope$ git bisect bad
299bc3410dcfd46da5e3c988354b60ed3a356900 is the first bad commit
commit 299bc3410dcfd46da5e3c988354b60ed3a356900
Author: Joshua Ashton <[email protected]>
Date:   Fri May 17 10:01:49 2024 +0100

    steamcompmgr: Move outdatedInteractiveFocus to window

 src/steamcompmgr.cpp        | 39 +++++++++++++++------------------------
 src/steamcompmgr_shared.hpp |  1 +
 2 files changed, 16 insertions(+), 24 deletions(-)

matt@nobara-pc:~/src/gamescope$ git bisect log
git bisect start
# status: waiting for both good and bad commits
# good: [e998f26a6fe4439461dfeaa6dd57c5be0bb46953] InputEmulation: refcounting/lifetime fixes
git bisect good e998f26a6fe4439461dfeaa6dd57c5be0bb46953
# status: waiting for bad commit, 1 good commit known
# bad: [05fe96c05b54c61ac938204d6b39742318d9ae31] Revert "Update libliftoff"
git bisect bad 05fe96c05b54c61ac938204d6b39742318d9ae31
# good: [d404e0f069d343d8084415832a006585fdef9c99] wlserver: Fix content overrides for reparented windows
git bisect good d404e0f069d343d8084415832a006585fdef9c99
# bad: [aabe499be10a32bf1431e3790dcd216f4258844f] wlserver, steamcompmgr: Don't force repaint on cursor moves if no image
git bisect bad aabe499be10a32bf1431e3790dcd216f4258844f
# good: [312e25b14640f3fa88469b57e898a4b2c069a186] InputEmulation: refcounting/lifetime fixes
git bisect good 312e25b14640f3fa88469b57e898a4b2c069a186
# good: [9350c88007b351c0406702f872e6db3ca9160fc4] steamcompmgr: Add GetGlobalPossibleFocusWindows
git bisect good 9350c88007b351c0406702f872e6db3ca9160fc4
# bad: [751e728d2f2657446ce6a9cdabc3d1f0ca36c01d] steamcompmgr: Add customizable pipewire appid focus
git bisect bad 751e728d2f2657446ce6a9cdabc3d1f0ca36c01d
# bad: [299bc3410dcfd46da5e3c988354b60ed3a356900] steamcompmgr: Move outdatedInteractiveFocus to window
git bisect bad 299bc3410dcfd46da5e3c988354b60ed3a356900
# first bad commit: [299bc3410dcfd46da5e3c988354b60ed3a356900] steamcompmgr: Move outdatedInteractiveFocus to window

299bc34 causes the Steam UI to lag when gamescope is not actively compositing, as determined by the compositor debugging squares (enabled the entire time) with MangoHud overlay. unfortunately, this issue is unrelated to the other gamescope compositing issues I reported because of course life can't be that simple 🐸

Before reverting 299bc34 - stutter and ~40fps (from 6f4bc2e):

IMG_1611-1.mov

After reverting 299bc34 - no stutter and 60fps (from 6f4bc2e):

IMG_1612-1.mov

The text was updated successfully, but these errors were encountered:

matte-schwartz · 2024-06-12T05:52:51Z

well, using mangohud to monitor UI performance ended up throwing a slight wrench in the report... the UI seems to lag the most for me only while presenting mangohud. if mangohud is not on screen the UI performance is much closer to expectations. force compositing still fixes the performance when showing mangohud though

matte-schwartz · 2024-06-22T23:47:42Z

was able to narrow down the effects of this revert further to VRR being enabled on panels that support it. if VRR is on, the revert brings the steam ui performance up from a shakey ~48fps to a stable ~60fps at 3440x1440@60hz on a 7900xtx within gamescope-session

matte-schwartz · 2024-07-18T17:39:50Z

with the new adaptive_sync convar in gamescope, this issue is now much easier to repro on OLED Deck. Set Mangohud overlay to full while the screen hasn't entered a \[drm:amdgpu_dm_crtc_vblank_control_worker \[amdgpu\]\] Allow idle optimizations (MALL): 0 state and you will see the UI fps tank with gamescopectl adaptive_sync 1 and then shoot back up to 90fps with gamescopectl adaptive_sync 0

sharkautarch · 2024-07-20T13:34:41Z

@matte-schwartz
Is this all tested on embedded gamescope (aka "gaming mode" on steam deck)?
Especially w/ embedded mode, you could try profiling w/ gpuvis: https://github.com/ValveSoftware/gamescope/wiki/Tracing

I would advise you to try the above gpuvis profiler first, but there’s also another alternative profiling integration I’ve been working on: Tracy profiler: #1328
One neat thing about Tracy profiler is that the profiling stats are shown live while gamescope is running.
Caveat with my Tracy profiler integration:

Tracy profiler doesn’t collect the DRM-related stats that gpuvis captures. Though it does do gpu/vulkan instrumentation which is useful when gamescope has to do compositing w/ async vulkan compute.
The commit tracking is less detailed compared to gpuvis
the frame-time tracking for gamescope-xwm covers some post-render/post-present work, so can be a bit longer than the actual frame time
Oh also you’ll need to run gamescope as root in order to capture hardware vblank markers

Note that when building gamescope w/ my Tracy integration, you have to add ~~-DTRACY_ENABLE~~ -Dtracy_enable=true to meson setup/configure cmd
Also you have to install the Tracy server to view the profiling data captured from gamescope
How to build Tracy server:
First make sure you have capstone installed

git clone https://github.com/wolfpld/tracy.git
cd tracy/profiler
mkdir build
cd build
cmake -DCMAKE_BUILD_TYPE=Release ..
MAKEFLAGS="-j$(nproc)" make

Now that I think about it, I should probably add some code to use the Tracy custom data plotting functionality w/ the frametime info that’s passed to mangoapp…

matte-schwartz · 2024-07-20T23:03:25Z

this is all tested from SteamOS Main in the shipped gamescope-session, with gamescope compiled from latest git using the SteamOS PKGBUILD paired with the steamos devkit client. I will give Tracy profiling a test in a bit, but the devkit makes gpuvis stupidly easy to use.

from boot (with adaptive sync disabled):
(deck@steamdeck ~)$ gamescopectl adaptive_sync 1
(deck@steamdeck ~)$ gamescopectl adaptive_sync 0
(deck@steamdeck ~)$ gamescopectl adaptive_sync 1

the gpu-trace.zip: https://drive.filen.io/d/69d86e9d-f12e-4b84-9d19-3d7be92f8f8f#flpeGVfwN6bFhRsi9B70uOWI6pFIpLaY
(way too big for GitHub lol)

Hopefully this offers a bit more insight into the issue. Let me know if you need me to recapture anything.

matte-schwartz · 2024-07-21T18:54:41Z

Thanks for the new gamescopectl commits @sharkautarch running tracy with sudo in drm mode has its own set of issues (running steam as root is a big no) but even without sudo hardware vblank logs the tracy profiler has showed some interesting stuff.

Here we have gamescopectl adaptive_sync 0, so adaptive sync disabled.

Here we have gamescopectl adaptive_sync 1

It seems like these repeated longer paint_all() -> Present() calls may be the reason I'm seeing decreased performance with adaptive sync on? The longer initial paint_all() -> Present( &frameInfo,async ) seems normal when changing between adaptive sync options

I also exported my tracy session since I'll be honest, most of the code in gamescope is still a big ??? for me 🐸
adaptive-sync-testing.tracy.tar.gz

Edit:
Well it turns out I get much clearer results if I also force the Steam UI to continuously render video frames with the debugging parameter for it:
adaptive-sync-constant-render-with-mangohud.tracy.tar.gz

It seems like adaptive sync also gives me this lockable which does not seem to show up when gamescope is not using adaptive sync. This could be as designed so maybe it's a nothingburger but that's the other major difference between the two states (aside from the very erratic vblanking of course)

Just as a side note - it seems tracy profiling triggers some instability in gamescope-session if monitoring for too long.

matte-schwartz · 2024-07-24T18:12:40Z

edit: on the left is adaptive_sync 0 and the right is adaptive_sync 1, with continuously rendered frames in the Steam UI on the Home page of Game Mode

took some time to dive deeper into gpuvis today after packaging it for Fedora, and the results are pretty similar to what I was seeing with Tracy (although I've still only been able to run that as non-root so gamescope/steam don't complain) but that's a good indication of its accuracy @sharkautarch

sharkautarch · 2024-07-24T18:31:57Z

@matte-schwartz
a day or so ago, I had made a new commit to my tracy PR to attempt to fix the instability you saw
Are you still having any issues w/ crashing w/ the tracy PR?

It seems like adaptive sync also gives me this lockable which does not seem to show up when gamescope is not using adaptive sync.

Unless you changed the setting yourself, Tracy profiler only displays lock-events wherein at least one thread is blocked waiting to take a lock (meaning a different thread has already acquired the lock).

So it could be an issue in a different scenario, but from looking at your screenshot, there's no lock contention during the long 24ms gamescope-xwm frame so it is extremely unlikely that it is directly causing lag.
I'm pretty sure from the extremely low frequency of lock contention, and the duration looking somehow short, that it is unlikely that this could be indirectly causing lag either.

However, it's possible that the increased lock contention is a symptom of the underlying cause of increased lag when using mangohud + adaptive sync is on.

matte-schwartz · 2024-07-24T18:33:21Z

@matte-schwartz a day or so ago, I had made a new commit to my tracy PR to attempt to fix the instability you saw Are you still having any issues w/ crashing w/ the tracy PR?

No more crashing, was using it merged on top of gamescope master for a bit yesterday

matte-schwartz · 2024-07-24T20:09:37Z

@sharkautarch
On your edit, thanks for the additional context and breakdown. The intricacies of what you're talking about are a bit beyond me, so I think I've taken this as far as I can

I'll wait and see what @Joshua-Ashton makes of this when they get the chance to check out the issue

sharkautarch · 2024-07-30T19:22:56Z

@matte-schwartz
I took a look at the tracy file you sent me
From looking more closely, it seems like vblankmanager's wait times are sometimes longer than they should be. Where it will briefly spike up to ~19-20 ms.

W/ the two screenshots above, the vertical bars at the top show the 'frame-timing' for vblankmanager.
(For those that are unaware, vblankmanager gives gamescope a schedule for when and how long it should wait in-between frames. So w/ the tracy integration, each profiled 'frame' for vblankmanager measures the time duration starting w/ the first time vblankmanager was sent an update (not including updates from the previous vblank) and then ending when gamescope wakes back up from idling )

So the yellow bars are vblank times of ~19-20ms, and the green bars are around ~11ms

The weird thing I'm seeing is that gamescope is sometimes trying to present in the middle of a vblank 'frame'. as can be seen in the second screenshot.
It's possible that this is due to a 'stale' vblank being sent out, which should be picked up by gpuvis (I should probably update my tracy profiling code to pick that up as well...)

That being said, I also noticed that at one point, a vblank 'frame' somehow fully overlapped one present, and then also partially overlapped a tiny bit of the present before that:

When I last tested my tracy profiler integration w/ gamescope, (which was only in nested mode on my x11 desktop), I definitely saw some more innocuous looking overlap between vblank and present, but there was only ever a tiny bit of overlap...

Also, see the frame-timing overview for gamescope-xwm, where w/ the blue vertical bars, it's only ever taking at most 2.68ms (which are the slightly more elevated blue bars) for each recorded gamescope-xwm frame.
Interestingly enough, it seems like the slightly-longer 2.68ms frame-times are always the frames before the long 19-20ms vblankmanager frames:

And now that I look back at screenshot 2 and the vblankmanager frames, I've realized that all or most of the 19-20ms vblankmanager frames overlap a ~10ms present, and that ~10ms present somehow isn't inside of gamescope-xwm frame.
The only reason for why a present wouldn't be inside of a gamescope-xwm frame is if steamcompmgr didn't receive a vblank. This is because I had arbitrarily decided to code my tracy integration that way.
This could mean one of two things:

I made a mistake with my tracy profiler integration code
Somehow, whatever is causing this bug, is causing gamescope to do too many non-vblank-triggered repaints. Which is throwing off gamescope's frame pacing.

Looking at this fifth screenshot, where we have a 2.68ms normal gamescope-xwm frame, followed by one vblankmanager frame w/ a ~10ms repaint, followed by a ~5microsecond gamescope-xwm frame that doesn't do a present for some reason, followed by a ~11ms vblankmanager frame containing a 2.17ms repaint:

I'm now leaning towards the latter of the two things...

matte-schwartz · 2024-08-01T04:54:29Z

Something else I've noticed is that there is a significant amount of "hitching" between direct scan-out and gamescope compositing when VRR is enabled that is not present with VRR disabled. There's a solid 1-2 seconds of laggy response time I'd say. It's pretty noticeable if you're using the drm backend on a high refresh-rate monitor and invoke or move the cursor with VRR disabled, and then do the same with VRR enabled.

sharkautarch · 2024-08-03T15:52:21Z

@matte-schwartz
Oh I just recently noticed that there were some locks used within the drm backend that I somehow entirely missed, and so my tracy profiler hasn't been instrumenting them...
I will update it soon to add instrumentation for those locks

sharkautarch · 2024-08-05T17:36:11Z

@matte-schwartz
I have just added the missing instrumentation for the locks used in the drm backend. I also instrumented the locks used in the wayland backend as well, while I was at it

matte-schwartz · 2024-08-06T16:57:10Z

tracy-adaptive-sync.tracy.zip

Cool, grabbed a new .tracy although I only made it ~30 seconds before gamescope crashed without me really doing anything.

sharkautarch · 2024-08-06T17:19:02Z

@matte-schwartz
I took a look of the callstack of the crash which tracy conveniently automatically records.
Looks like it crashed inside update_wayland_res(), so I pushed out a new commit that comments out the one line I had recently added to that function.
Let me know if it's still crashing for you

revert 299bc34 ValveSoftware#1369

sharkautarch · 2024-08-08T12:23:31Z

@matte-schwartz
Is this issue still acting the same, after issue #1398 was fixed?

matte-schwartz · 2024-08-08T14:23:36Z

@sharkautarch no change, that was a different LE Deck specific issue with only those 3 refresh rates. This issue happens on all my devices, including the LE Deck.

sharkautarch · 2024-08-08T15:07:01Z

@matte-schwartz
Hmm I’m still a bit unsure about why commit 299bc34 is causing this issue…
Could you revert that commit, and then, with that commit reverted, profile it w/ tracy, including toggling adaptive sync on and off during the profiling session?
That way we have a baseline to compare the previous traces against

matte-schwartz · 2024-08-08T16:23:02Z

3.14.28 with a revert: adaptive-sync-with-revert.tracy.zip

3.14.28 without a revert adaptive-sync-no-revert.tracy.zip

the revert I'm using:

diff --git a/src/steamcompmgr.cpp b/src/steamcompmgr.cpp
index d7498e5..d1800a8 100644
--- a/src/steamcompmgr.cpp
+++ b/src/steamcompmgr.cpp
@@ -3271,7 +3271,7 @@ found:;
 		if ( window_has_commits( focus ) ) 
 			out->focusWindow = focus;
 		else
-			focus->outdatedInteractiveFocus = true;
+			out->outdatedInteractiveFocus = true;
 
 		// Always update X's idea of focus, but still dirty
 		// the it being outdated so we can resolve that globally later.
@@ -5995,28 +5995,37 @@ bool handle_done_commit( steamcompmgr_win_t *w, xwayland_ctx_t *ctx, uint64_t co
 			// Window just got a new available commit, determine if that's worth a repaint
 
 			// If this is an overlay that we're presenting, repaint
-			if ( w == global_focus.overlayWindow && w->opacity != TRANSLUCENT )
+			if ( gameFocused )
 			{
-				hasRepaintNonBasePlane = true;
-			}
+				if ( w == global_focus.overlayWindow && w->opacity != TRANSLUCENT )
+				{
+					hasRepaintNonBasePlane = true;
+				}
 
-			if ( w == global_focus.notificationWindow && w->opacity != TRANSLUCENT )
-			{
-				hasRepaintNonBasePlane = true;
+				if ( w == global_focus.notificationWindow && w->opacity != TRANSLUCENT )
+				{
+					hasRepaintNonBasePlane = true;
+				}
 			}
-
-			// If this is an external overlay, repaint
-			if ( w == global_focus.externalOverlayWindow && w->opacity != TRANSLUCENT )
+			if ( ctx )
 			{
-				hasRepaintNonBasePlane = true;
+				if ( ctx->focus.outdatedInteractiveFocus )
+				{
+					MakeFocusDirty();
+					ctx->focus.outdatedInteractiveFocus = false;
+				}
 			}
-
-			if ( w->outdatedInteractiveFocus )
+			if ( global_focus.outdatedInteractiveFocus )
 			{
 				MakeFocusDirty();
-				w->outdatedInteractiveFocus = false;
-			}
+				global_focus.outdatedInteractiveFocus = false;
 
+				// If this is an external overlay, repaint
+				if ( w == global_focus.externalOverlayWindow && w->opacity != TRANSLUCENT )
+				{
+					hasRepaintNonBasePlane = true;
+				}
+			}
 			// If this is the main plane, repaint
 			if ( w == global_focus.focusWindow && !w->isSteamStreamingClient )
 			{

matte-schwartz · 2024-08-08T17:12:35Z

actually @sharkautarch, on closer analysis, I am starting to wonder if this revert is just hiding a different adaptive sync issue... let me explain my though process on this

The Steam Client beta for Steam Deck has a new blur effect on the left side menu when you invoke it from gamescope-session. This blur effect makes gamescope start compositing when it's opened. On 3.14.28 with the revert, I notice that opening this side menu tanks frametiming in a similar way to the bisected bad commit here made it happen with the entire Steam UI - just by toggling adaptive sync.

The fact lag happens under different conditions (i.e. even with gamescope compositing unlike the issue report) just by toggling adaptive sync makes me suspect perhaps we are barking up the wrong tree here... and I wonder if it's actually something to do with adaptive sync itself?

My repro steps with the revert from SteamOS 3.7:

Enable QR debugging squares
Launch Hades 2
Open the left side menu
send the command gamescopectl adaptive_sync 1 to enable adaptive sync

adaptive-sync-side-menu-with-revert.tracy.zip

and then a fun slow-mo video clip since this is kind of tough to explain without showing:

IMG_1923.mov

You can see it slow down considerably when I send the adaptive sync on signal ~0:07 in to that clip. Let me know what you think. Might just be grasping at straws here but the similarity in how adaptive sync makes this other issue happen is suspicious to me.

sharkautarch · 2024-08-08T17:36:27Z

@matte-schwartz
Hmm the trace for the side menu thing definitely looks similar to the other traces...

Try doing one trace running gamescope with the env variable GAMESCOPE_DISABLE_TIMERFD=1
then also try doing another trace where you pass the arguments --backend sdl to gamescope

matte-schwartz · 2024-08-08T18:22:08Z

GAMESCOPE_DISABLE_TIMERFD=1 - no real difference I could tell: adaptive-sync-timer-fd.tracy.zip

--backend sdl doesn't launch, it throws Aug 08 11:19:03 steamdeck gamescope-session[28424]: SDL_Vulkan_CreateSurface failed: Vulkan couldn't find a predefined mode for that window size and couldn't create a suitable mode.terminate called without an active exception and then coredumps when added in /usr/bin/gamescope-session

edit: ~~going to try poking at some older versions of gamescope to see if I can find one where the issue is still reproable while also having a functional SDL backend. can't be earlier than 3.14.2 though.~~ nothing i'm finding since the --backend command was added

matte-schwartz · 2024-08-16T00:12:54Z

adaptive sync on, `mangohudctl set no_display 0` to unhide HUD when first entering session, seemingly no lag yet?

Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4953
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4953 delta: 14401000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 170
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4954
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4954 delta: 8690000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4955
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4955 delta: 8332000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 174
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 182
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4956
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4956 delta: 37039000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 190
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4957
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4957 delta: 8670000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4958
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4958 delta: 8332000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 191
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4959
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4959 delta: 8336000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4960
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 4960 delta: 8329000
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:51:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 4961

Things look okay for now, let's start tinkering.

adaptive sync on, mangohud on, previously good, after using left side menu on the steam deck beta client

Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21936 delta: 8337000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21937
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21937 delta: 8333000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21938
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21938 delta: 14721000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21939
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21939 delta: 8676000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21940
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21940 delta: 8331000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21941
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21941 delta: 8337000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21942
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 21942 delta: 14631000
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:58:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 21943

it starts to go a bit haywire here, with seemingly rhythmic switching between delta flight timing on the page flip handler. this brings my Home page ui from 120fps down to ~90fps on my ROG Ally

adaptive sync on, mangohud on, previously good, steam notification received

Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7392
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7392 delta: 8332000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7393
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7393 delta: 29160000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: make fbid 170
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7394
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7394 delta: 11467000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7395
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7395 delta: 14618000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7396
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7396 delta: 12665000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7397
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7397 delta: 14453000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7398
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7398 delta: 13185000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7399
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7399 delta: 14425000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7400
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7400 delta: 13448000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7401
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7401 delta: 14547000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7402
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 7402 delta: 13541000
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:52:13 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 7403

now this seems to send every delta consistently to around double what it should be, and brings my UI performance on the Home page down even further to ~70fps.

adaptive sync on, UI lagging @70fps, `mangohudctl set no_display 1` to hide mangohud

Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12720 delta: 13789000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12721
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12721 delta: 41626000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12722
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12722 delta: 8683000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12723
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12723 delta: 9914000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12724
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12724 delta: 8690000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12725
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 12725 delta: 8334000
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 2 layers
Aug 15 16:54:18 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 12726

this brings deltas back into the range of exactly where they should be.

and then finally: adaptive sync on -> adaptive sync off with mangohud unhidden

Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16252
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16252 delta: 13801000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16253
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16253 delta: 50317000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16254
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16254 delta: 16671000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16255
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16255 delta: 8331000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16256
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16256 delta: 8332000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16257
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16257 delta: 8333000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16258
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: page_flip_handler 16258 delta: 8334000
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: can drm present 3 layers
Aug 15 16:56:53 rog-ally gamescope-session[4857]: [gamescope] [Debug] drm: flip commit 16259

this also brings deltas back into an acceptable range, even when mangohud is unhidden.

So basically, the best that I can conclude is that something about adaptive sync and the way the Steam UI utilizes window focus is what's actually causing problems here... what I'm lost on is exactly where this could be happening when kernel drm debugging logs don't really show anything noteworthy. perhaps why exactly this does work, albeit briefly, until you interact with the side menus or happen to get a steam notification offers a clue?

edit: oh, and deltas go back to the ~8332000 range under every circumstance if you force compositing

matte-schwartz · 2024-08-20T06:44:35Z

this seems to be fixed with the changes since 3.15.0 today on all devices I've tested on. will report any new issues that pop up separately.

matte-schwartz · 2024-09-14T01:44:41Z

this issue has not gone away after all.

#1513 is a potential duplicate of this, as the same base commit is what causes errors to arise

overplay planes seem to pull away VRR focus between the overlay and the primary plane when in-game now. this issue can be mitigated with gamescopectl adaptive_sync_ignore_overlay 1

matte-schwartz · 2024-09-18T21:42:17Z

my latest findings on this are that now, regardless of compositing status, having any mangoapp overlay displayed in embedded gamescope while VRR is enabled will cause erratic frametimings and delta times to become staggered. This is especially visible on monitors where you can use an on-board OSD to verify the refresh rate the monitor is lighting up at, and in games where performance does not reach the maximum monitor refresh rate. With mangoapp on display, you can see the OSD switch between 120hz and the game's actual refresh rate. The issue is mitigated with adaptive_sync_ignore_overlay or with adaptive_sync_overlay_cycles and greater than 1 cycle.

I'm beginning to wonder if mangoapp itself is now causing VRR issues, although I'm not quite certain how to debug that... in any case, gpu-trace really does not show anything too unusual beyond staggered delta times between when VRR is in use vs not in use.

gpu-trace in Ghost of Tsushima with overlay visible and VRR on: https://drive.filen.io/d/53bb9723-bf4e-45a6-b810-ff026ce96937#vgb4tIwSZRyoR7vVFMPLl9pl5K4FMO29

gpu-trace in Ghost of Tsushima with overlay disabled and VRR on: https://drive.filen.io/d/e8a48d41-022b-4dc1-9c10-fdd87ab90db1#nSCE5bI7ip31uVqAUhbnmbpNeWYCuM3u

matte-schwartz · 2024-10-04T05:22:54Z

after spending many hours debugging this, most of this issue is honestly a pretty inaccurate summary of the real problem. will file a report for the actual bug instead.

matte-schwartz changed the title ~~commit 299bc34 causes Steam UI lag when gamescope is not actively compositing~~ commit 299bc34 causes the Steam UI to lag while showing MangoHud, only while gamescope is not actively compositing Jun 12, 2024

matte-schwartz changed the title ~~commit 299bc34 causes the Steam UI to lag while showing MangoHud, only while gamescope is not actively compositing~~ commit 299bc34 causes the Steam UI to lag while showing MangoHud, only when gamescope is not compositing Jun 12, 2024

matte-schwartz changed the title ~~commit 299bc34 causes the Steam UI to lag while showing MangoHud, only when gamescope is not compositing~~ commit 299bc34 causes the Steam UI to lag while showing MangoHud on VRR displays when using direct scan-out Jun 22, 2024

matte-schwartz mentioned this issue Jun 30, 2024

config.vdf stores external monitor VRR status after disconnection, incorrectly applying VRR to the internal display ValveSoftware/SteamOS#1563

Closed

honjow added a commit to 3003n/gamescope that referenced this issue Aug 7, 2024

Fix VRR stutter

7b85aff

revert 299bc34 ValveSoftware#1369

honjow added a commit to 3003n/gamescope that referenced this issue Aug 7, 2024

Fix VRR stutter

0779b1d

revert 299bc34 ValveSoftware#1369

matte-schwartz mentioned this issue Aug 17, 2024

Latest SteamOS/Update has stuck 40FPS cap when home screen - works fine when playing games. ValveSoftware/SteamOS#1604

Closed

matte-schwartz closed this as completed Aug 20, 2024

matte-schwartz reopened this Sep 14, 2024

matte-schwartz changed the title ~~commit 299bc34 causes the Steam UI to lag while showing MangoHud on VRR displays when using direct scan-out~~ commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying Sep 18, 2024

matte-schwartz closed this as not planned Won't fix, can't repro, duplicate, stale Oct 4, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying #1369

commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying #1369

matte-schwartz commented Jun 10, 2024 •

edited

Loading

matte-schwartz commented Jun 12, 2024

matte-schwartz commented Jun 22, 2024

matte-schwartz commented Jul 18, 2024

sharkautarch commented Jul 20, 2024 •

edited

Loading

matte-schwartz commented Jul 20, 2024 •

edited

Loading

matte-schwartz commented Jul 21, 2024 •

edited

Loading

matte-schwartz commented Jul 24, 2024 •

edited

Loading

sharkautarch commented Jul 24, 2024 •

edited

Loading

matte-schwartz commented Jul 24, 2024

matte-schwartz commented Jul 24, 2024

sharkautarch commented Jul 30, 2024 •

edited

Loading

matte-schwartz commented Aug 1, 2024

sharkautarch commented Aug 3, 2024

sharkautarch commented Aug 5, 2024

matte-schwartz commented Aug 6, 2024

sharkautarch commented Aug 6, 2024 •

edited

Loading

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024 •

edited

Loading

matte-schwartz commented Aug 8, 2024

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024 •

edited

Loading

matte-schwartz commented Aug 16, 2024 •

edited

Loading

matte-schwartz commented Aug 20, 2024

matte-schwartz commented Sep 14, 2024 •

edited

Loading

matte-schwartz commented Sep 18, 2024 •

edited

Loading

matte-schwartz commented Oct 4, 2024

commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying #1369

commit 299bc34 causes erratic frametime graph when VRR is in use and mangoapp is displaying #1369

Comments

matte-schwartz commented Jun 10, 2024 • edited Loading

matte-schwartz commented Jun 12, 2024

matte-schwartz commented Jun 22, 2024

matte-schwartz commented Jul 18, 2024

sharkautarch commented Jul 20, 2024 • edited Loading

matte-schwartz commented Jul 20, 2024 • edited Loading

matte-schwartz commented Jul 21, 2024 • edited Loading

matte-schwartz commented Jul 24, 2024 • edited Loading

sharkautarch commented Jul 24, 2024 • edited Loading

matte-schwartz commented Jul 24, 2024

matte-schwartz commented Jul 24, 2024

sharkautarch commented Jul 30, 2024 • edited Loading

matte-schwartz commented Aug 1, 2024

sharkautarch commented Aug 3, 2024

sharkautarch commented Aug 5, 2024

matte-schwartz commented Aug 6, 2024

sharkautarch commented Aug 6, 2024 • edited Loading

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024 • edited Loading

matte-schwartz commented Aug 8, 2024

sharkautarch commented Aug 8, 2024

matte-schwartz commented Aug 8, 2024 • edited Loading

matte-schwartz commented Aug 16, 2024 • edited Loading

matte-schwartz commented Aug 20, 2024

matte-schwartz commented Sep 14, 2024 • edited Loading

matte-schwartz commented Sep 18, 2024 • edited Loading

matte-schwartz commented Oct 4, 2024

matte-schwartz commented Jun 10, 2024 •

edited

Loading

sharkautarch commented Jul 20, 2024 •

edited

Loading

matte-schwartz commented Jul 20, 2024 •

edited

Loading

matte-schwartz commented Jul 21, 2024 •

edited

Loading

matte-schwartz commented Jul 24, 2024 •

edited

Loading

sharkautarch commented Jul 24, 2024 •

edited

Loading

sharkautarch commented Jul 30, 2024 •

edited

Loading

sharkautarch commented Aug 6, 2024 •

edited

Loading

matte-schwartz commented Aug 8, 2024 •

edited

Loading

matte-schwartz commented Aug 8, 2024 •

edited

Loading

matte-schwartz commented Aug 16, 2024 •

edited

Loading

matte-schwartz commented Sep 14, 2024 •

edited

Loading

matte-schwartz commented Sep 18, 2024 •

edited

Loading