Stale Wayland frames after hide/show

Original report by email, that describe the problem along with logs from both Wayland, Qt and our code. These are intermixed client/server logs

Hi Pat & Kyle,

Apologies if I’m going about this the wrong way – but we require a bit of urgent technical support.

Mostly our Wayland implementation is working well – but we have one issue that is causing us some grief. At first glance it seems like a cosmetic issue, but in our application it is quite an ugly one, so it needs to be fixed.

The problem is this: When we show a Wayland window after it has been hidden, we see a couple of frames from the client from before it was hidden. Since our framerate is not particularly fast, this is quite noticeable to the user. It seems that when the window is hidden, Wayland prevents the client from rendering frames (this is good) but somewhere a couple of frames are queued up and these are rendered after the window is shown again.

Is there any way of avoiding this? We are using Qt5.12.2 on the compositor side, and Qt5.12.4 on the client side (the difference in versions is because the client is supplied by a third party).

The log below shows what we see when we Hide the wayland window, then wait a few seconds, then show the window. We want the user to see an “Engines” page before the window is hidden, then while it is hidden the client should switch to an “idle” page, then when it is shown the user will see the idle page until the client can load a new page (in the case below, the “Naviop Home” page. Note the problem only happens if we use an OpenGL surface for rendering on the client. If we use raster / shared memory on the client, then the client appears to continue rendering even when hidden, and the problem doesn’t occur. Unfortunately, it is not practical for us to use raster rendering on the client for performance reasons.

Some things we think may fix the issue for us:

· In our case we’d actually be OK if the client continued rendering even when hidden (since we have other ways to control the client to make sure it doesn’t use up too much CPU). Therefore, if we could make the client continue rendering, even when hidden, we think it would work OK (this is what happens when we use a raster surface on the client, and it works OK).

· It seems the client detects that it is hidden if it doesn’t receive a frame callback within 100uS. In our case, this is not enough time for the client to switch to the “idle” frame, which is what we need it to do. If we could extend this timeout to, say, 1s, it would probably work, as well

· The behaviour doesn’t seem right in a general sense. If the Wayland system could avoid rendering “stale” frames when a window is shown (in our case we see frames that are many seconds old) then this would also fix our problem.

Client commits engine frame, then server receives the commit, then Navico FB renders the frame (Swap, then blit)

Aug  8 14:24:27 jmlauncher: [3501022.440]  -> wl_surface@28.commit() 
Aug  8 14:24:27 rc.app: [3501023.622] wl_surface@28.commit()         
Aug  8 14:24:27 rc.app: 15:24:27.383 app:0 Dbg: : QNavicoGlContext(0x5224500) swapBuffers at: 3142370 lock wait: 0 duration: 17
Aug  8 14:24:27 rc.app: 15:24:27.389 app:0 Dbg: MFDApp: QNavicoGlContext(0x5224500) blit at: 3142388 lock wait: 0 duration: 5 

Now the window gets hidden. MFDApp sends out-of-band “Application-switch” message to client

Aug  8 14:24:27 rc.app: 15:24:27.421 app:0 Inf: MFDApp: tWaylandPanel::hideEvent "com.naviop.wayland.jmobile.Engines"
Aug  8 14:24:30 rc.app: 15:24:30.998 app:0 Inf: MFDApp: tWaylandPanel::showEvent "com.naviop.wayland.jmobile.Naviop"

Client hasn’t received the application-switch message yet, so renders and commits another engine frame

Aug  8 14:24:27 jmlauncher: qt.qpa.backingstore: Composing and flushing QRegion(null) of QWidgetWindow(0x8220f668, name="CHMIViewerFrameClassWindow") at offset QPoint(0,0) with 1 texture(s) in QPlatformTextureList(0x826f6648) 
Aug  8 14:24:27 jmlauncher: [3501221.778]  -> wl_surface@28.commit() 
Aug  8 14:24:27 rc.app: [3501331.104] wl_surface@28.commit()         

Client still hasn’t received the application-switch message, so starts rendering another engine frame. Note that this time the Wayland plugin detects that the window has been hidden. It still commits the frame, though.

Aug  8 14:24:27 jmlauncher: qt.qpa.backingstore: Composing and flushing QRegion(null) of QWidgetWindow(0x8220f668, name="CHMIViewerFrameClassWindow") at offset QPoint(0,0) with 1 texture(s) in QPlatformTextureList(0x826f6648)
Aug  8 14:24:27 jmlauncher: qt.qpa.wayland.backingstore: Didn't receive frame callback in time, window should now be inexposed
Aug  8 14:24:27 jmlauncher: [3501507.059]  -> wl_surface@28.commit()

NDesign now receives the application-switch message, and changes to the “idle” page

Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.772 : Update Received
Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.774 : 24 > Empty
Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.775 : currentpage=nav_engines1_full.jmxb
Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.775 : Stored in lastEnginePage: nav_engines1_full.jmxb
Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.776 : loading: idle.jmxb disalbed for empty messages Workaround

Wayland Server sees the previous commit – note this is an engine frame – not the idle page yet. Potentially the server now has 2 engine frames queued up that it hasn’t rendered.

Aug  8 14:24:27 rc.app: [3501520.360] wl_surface@28.commit()

NDesign continues process of loading Idle Page. Wayland plugin knows that the window is hidden, so doesn’t commit anything.

Aug  8 14:24:27 jmlauncher: Console.log 14:24:27.813 : Loaded IDLE 
Aug  8 14:24:27 jmlauncher: qt.qpa.wayland.backingstore: Didn't receive frame callback in time, window should now be inexposed

After a few seconds, the user presses “Naviop” icon, and MFDApp shows the Wayland panel, and sends another out-of-band application-switch message.

Aug  8 14:24:30 rc.app: 15:24:30.995 app:0 Inf: MFDApp: tWaylandPanel::hideEvent "com.naviop.wayland.jmobile.Naviop"
Aug  8 14:24:30 rc.app: 15:24:30.998 app:0 Inf: MFDApp: tWaylandPanel::showEvent "com.naviop.wayland.jmobile.Naviop"

Wayland compositor flushes out any frames it has in its queue. Note that there are potentially two frames – both engine frames. It seems that there is some kind of bug here, because it does swap-swap-blit-blit rather than swap-blit-swap-blit. In any case, it is an engine page frame that ends up on the screen. Not the idle page – despite the fact that we told the client process to change to the idle page over 3 seconds ago.

Aug  8 14:24:31 rc.app: 15:24:31.014 app:0 Dbg: : QNavicoGlContext(0x5224500) swapBuffers at: 3146011 lock wait: 0 duration: 7
Aug  8 14:24:31 rc.app: 15:24:31.047 app:0 Dbg: : QNavicoGlContext(0x5224500) swapBuffers at: 3146043 lock wait: 0 duration: 7
Aug  8 14:24:31 rc.app: 15:24:31.050 app:0 Dbg: MFDApp: QNavicoGlContext(0x5224500) blit at: 3146054 lock wait: 0 duration: 0
Aug  8 14:24:31 rc.app: 15:24:31.211 app:0 Dbg: MFDApp: QNavicoGlContext(0x5224500) blit at: 3146209 lock wait: 0 duration: 5

Note sure what this log message means

Aug  8 14:24:31 jmlauncher: "14:24:31.263"  =>  "idle"

Client renders the idle page…

Aug  8 14:24:31 jmlauncher: qt.qpa.backingstore: Composing and flushing QRegion(0,0 1280x780) of QWidgetWindow(0x8220f668, name="CHMIViewerFrameClassWindow") at offset QPoint(0,0) with 1 texture(s) in QPlatformTextureList(0x826f6648)

NDesign receives application-switch message to render Naviop home page.

Aug  8 14:24:31 jmlauncher: Console.log 14:24:31.328 : Update Received
Aug  8 14:24:31 jmlauncher: Console.log 14:24:31.328 : 25 > jmobile.Naviop
Aug  8 14:24:31 jmlauncher: Console.log 14:24:31.329 : loading: home_full.jmxb

Client commits the idle page…

Aug  8 14:24:31 jmlauncher: [3505086.008]  -> wl_surface@28.commit()

NDesign finishes loading Naviop home page

Aug  8 14:24:31 jmlauncher: Console.log 14:24:31.348 : Loaded HOME
Aug  8 14:24:31 jmlauncher: "14:24:31.413"  =>  "home_full"

Client renders Naviop home page

Aug  8 14:24:31 jmlauncher: qt.qpa.backingstore: Composing and flushing QRegion(0,0 1280x780) of QWidgetWindow(0x8220f668, name="CHMIViewerFrameClassWindow") at offset QPoint(0,0) with 1 texture(s) in QPlatformTextureList(0x826f6648)

Server receives idle page commit.

Aug  8 14:24:31 rc.app: [3505229.848] wl_surface@28.commit()

NavicoFB renders idle page – 0.5s after the show event – eg. The screen has been showing engines page for 0.5s.

Aug  8 14:24:31 rc.app: 15:24:31.506 app:0 Dbg: : QNavicoGlContext(0x5224500) swapBuffers at: 3146500 lock wait: 0 duration: 10

Client commits Naviop home page

Aug  8 14:24:31 jmlauncher: [3505257.878]  -> wl_surface@28.commit()

NavicoFB continues rendering the idle page.

Aug  8 14:24:31 rc.app: 15:24:31.515 app:0 Dbg: MFDApp: QNavicoGlContext(0x5224500) blit at: 3146510 lock wait: 0 duration: 8

NavicoFB receives commit for the Naviop home page

Aug  8 14:24:31 rc.app: [3505266.279] wl_surface@28.commit()

NavicoFB renders the Naviop home page – finally. Life is now good, but 0.5s of engines page has made our UI look very unprofessional.

Aug  8 14:24:31 rc.app: 15:24:31.551 app:0 Dbg: : QNavicoGlContext(0x5224500) swapBuffers at: 3146536 lock wait: 0 duration: 18
Aug  8 14:24:31 jmlauncher: qt.qpa.backingstore: Composing and flushing QRegion(null) of QWidgetWindow(0x8220f668, name="CHMIViewerFrameClassWindow") at offset QPoint(0,0) with 1 texture(s) in QPlatformTextureList(0x826f6648)
Aug  8 14:24:31 rc.app: 15:24:31.557 app:0 Dbg: MFDApp: QNavicoGlContext(0x5224500) blit at: 3146554 lock wait: 0 duration: 7