vsyncthread mode for qopenglwindow frameswapped driven phase locked loop

[m0dB]

This PR adds a VSyncMode ST_PLL to the VSyncThread.

With this mode, a phase locked loop is used to determine the vsync time and -interval based on the frameSwapped signal, that is coming from an invisible QOpenGLWindow (that of the WInitialGLWidget, which is used to query OpenGL).

This solves the problem that the phase offset between the vsync and the VSyncThread timer could effect the animation very badly and that timer could drift from the actual vsync.

In the Qt documentation we can read that using the frameSwapped signal is the preferred mechanism for animation:

Applications that wish to continuously repaint synchronized to the vertical refresh, should issue an update() upon this signal. This allows for a much smoother experience compared to the traditional usage of timers.

Unfortunately, this doesn't play nice with our multiple QOpenGLWindow-based widgets, for which we still need to use the manual and coordinated call to swapBuffers().

Notes:

• I have tested this on macOS only.
• This mode is enabled by adding

VSync 5

to [Waveform] in mixxx.cfg

Question:

• If we decide to take this, how do we proceed

[JoergAtGithub]

On Windows, it seems that the PLL never locks:

[m0dB]

Where does that 99.90 come from? And how does it look? If you uncomment the logging of the delta in the phase locked loop, don't you see it settle on a value. BTW, on Windows there was no problem with the animation to start with, was there?

IIRC we use setSwapInterval(0) on windows. Can you try with setSwapInterval(1) ?

(The dropped frames was not correct btw, fixing now)

[ywwg]

works on linux -- hard to tell if it's better because waveforms are generally smooth already.

[JoergAtGithub]

Where does that 99.90 come from? And how does it look? If you uncomment the logging of the delta in the phase locked loop, don't you see it settle on a value

BTW, on Windows there was no problem with the animation to start with, was there?

On Windows there were always stucking Waveforms, but for some seconds they can run smooth with 60fps in VSync. My guess is that the Qt event queue is blocked and the signal/slot connection for the VSync isn't delivered in time. I can measure this for scrolling the library (using #12094) and I found #12445 as root cause for some other stucking using the profiler - but there are also cases where I couldn't identify the cause yet - this might be a slowly increasing phase shift.

But with this PR it's a different behavior. Here the vsyncthread seems to be free wheeling - I guess the 100fps are real, but out of VSync.

If I set setSwapInterval to 1 the PLL seems to lock somehow, but not to 60fps:

With setSwapInterval(0) I get:

debug [Main] PLL delta 6238.56
debug [Main] PLL delta 6239.76
debug [Main] PLL delta 6240.03
debug [Main] PLL delta 6238.82
debug [Main] PLL delta 6236.05
debug [Main] PLL delta 6235.12
debug [Main] PLL delta 6233.9
debug [Main] PLL delta 6235.87
debug [Main] PLL delta 6236.8
debug [Main] PLL delta 6236.4
debug [Main] PLL delta 6235.32
debug [Main] PLL delta 6232.39
debug [Main] PLL delta 6232.2
debug [Main] PLL delta 6230.39
debug [Main] PLL delta 6228.91
debug [Main] PLL delta 6228.96
debug [Main] PLL delta 6228.95
debug [Main] PLL delta 6228.91
debug [Main] PLL delta 6227.52
debug [Main] PLL delta 6226.54
debug [Main] PLL delta 6224.53
debug [Main] PLL delta 6225.4
debug [Main] PLL delta 6223.87
debug [Main] PLL delta 6223.19
debug [Main] PLL delta 6226.06

With setSwapInterval(1) I get:

debug [Main] PLL delta 16691.8
debug [Main] PLL delta 16692.9
debug [Main] PLL delta 16692.5
debug [Main] PLL delta 16693.2
debug [Main] PLL delta 16693.9
debug [Main] PLL delta 16693.1
debug [Main] PLL delta 16693.8
debug [Main] PLL delta 16693.4
debug [Main] PLL delta 16694.2
debug [Main] PLL delta 16694.7
debug [Main] PLL delta 16694.4
debug [Main] PLL delta 16695.3
debug [Main] PLL delta 16695.7
debug [Main] PLL delta 16696.3
debug [Main] PLL delta 16695.7
debug [Main] PLL delta 16696.5
debug [Main] PLL delta 16695.7
debug [Main] PLL delta 16696.8
debug [Main] PLL delta 16696.1
debug [Main] PLL delta 16695.8
debug [Main] PLL delta 16696.6
debug [Main] PLL delta 16696.8
debug [Main] PLL delta 16695.7
debug [Main] PLL delta 16694.8
debug [Main] PLL delta 16693.7
debug [Main] PLL delta 16694.2
debug [Main] PLL delta 16693.6
debug [Main] PLL delta 16693.8
debug [Main] PLL delta 16692.9
debug [Main] PLL delta 16692
debug [Main] PLL delta 16691.9
debug [Main] PLL delta 16692.3
debug [Main] PLL delta 16691.4
debug [Main] PLL delta 16690.7
debug [Main] PLL delta 16689.6
debug [Main] PLL delta 16689
debug [Main] PLL delta 16688.4
debug [Main] PLL delta 16687.6
debug [Main] PLL delta 16687
debug [Main] PLL delta 16686.3
debug [Main] PLL delta 16685.9
debug [Main] PLL delta 16685.6
debug [Main] PLL delta 16686
debug [Main] PLL delta 16686
debug [Main] PLL delta 16685.8
debug [Main] PLL delta 16685.6
debug [Main] PLL delta 16684.9
debug [Main] PLL delta 16684.6
debug [Main] PLL delta 16684.2
debug [Main] PLL delta 16684.7
debug [Main] PLL delta 16684.5

[JoergAtGithub]

I set this to 12000 and it looks much better on Windows (with setSwapInterval=1). I would say better than before, but not perfect.

[m0dB]

Interesting, so with setSwapInterval(0) you get 160 fps from the phase locked loop.

When you say better than before, do you mean better than with this PR with setSwapInterval(0), or better than without this PR ?

[JoergAtGithub]

I meant, this PR + setSwapInterval(1) + offset=12000 was slightly better than 2.4. All other combinations were worse.
I haven't tried your last commit.

[m0dB]

I tested on my 2015 MacBook. It runs smooth there too, though not as smooth as on my M1: Disruptions (like scrolling the library, resizing, hide/show) have a more noticable effect. (That is not surprising as the M1 is much faster). Now, compared to ST_TIMER, after a disruption it seems to take a bit longer to stabilize, but eventually it does. Not sure if that's because the PLL gets out of sync or because the event queue is chocking. When I have time, I'll do a bit of logging and tweaking.

[daschuer]

For me the VSync 5 mode is a regression.

Without it and ALSA @ 23 ms and 60 Hz, I have a smooth waveform with blocks of ~5 jitters every 60-90 s. The jitter effects sometimes both decks in the same way or shifts the waveform against each other.
My guess is that this is an interference effect when the Audio clock and the VSync clock expiring at the same time.

With VSync 5 I see these jitters all the time.

[JoergAtGithub]

Try to set setSwapInterval to 1 as on macOS. Without I see exactly the same on Windows, as you describe.
With, it can be better but I had to tune the offset const in vsyncthread manually.

[ronso0]

With VSync 5 I see these jitters all the time.

Same for me on Linux.
Usually I have smooth waveforms, unless I do stuff in the preferences or other other dialogs.

[JoergAtGithub]

The latest version works out of the box on my Windows11 system, except that I need to set

mixxx/src/waveform/waveformwidgetfactory.cpp

Line 1218 in 71dceb2

format.setSwapInterval(0);

to 1.

But I noticed that the CPU load increased significiantly (from ~33% to 50% on my laptop which 8 physical cores).

Than I played further with the value of setSwapInterval, and noticed that higher values than 1 reduce the CPU load, but the lagging comes back - looks similar as with ST_TIMER mode.
I found out that there are other events than calling swapBuffers(); that trigger swapping buffers. With setSwapBuffers(1) this happens immediatly, with e.g. setSwapBuffers(100) we will need 100 of these events.
You can test this by commenting out

mixxx/src/waveform/waveformwidgetfactory.cpp

Line 802 in 71dceb2

glw->swapBuffers();

Than you will first see no waveform drawn. But if you do things like moving or resizing the window, the waveform appears.
I could imagine that one reason for the lag we see in Mixxx is that swapBuffers() does not always work.

Maybe this is related to the behavior described here: https://stackoverflow.com/questions/74613205/qopenglwidget-swapbuffers-happening-without-redrawing-the-scene

[m0dB]

No idea why using setSwapInterval(1) increases your CPU. Definitely not the case on macOS.

Now about Qt triggering additional update + swap, yes, I am aware of this behaviour, and it is also the reason why I do this:

void OpenGLWindow::paintGL() {
    if (m_pWidget && isExposed()) {
        if (m_dirty) {
            // Extra render and swap to avoid flickering when resizing
            m_pWidget->paintGL();
            m_pWidget->swapBuffers();
            m_dirty = false;
        }
        m_pWidget->paintGL();
    }
}

I am not sure if we can avoid Qt triggering the update on resize (so the paint and swapBuffers is exclusively done through the vsyncthread). Since it only happens when resizing, I don't think it's a big problem, but I agree it's not ideal. I remember looking into this and getting stuck, but I can give it another go.

[JoergAtGithub]

I am not sure if we can avoid Qt triggering the update

AFAIK, this is done by sending the event QEvent::UpdateRequest to QOpenGLWindow. I guess if we handle it there, it shouldn't swap automatically.

[JoergAtGithub]

But maybe the opposite is the right thing to do - sending QEvent::UpdateRequest instead of calling swapBuffers() ?

[m0dB]

No, we need swapBuffers because relying on Qt event delivery results in bad frame rate and jitter. Intercepting the QEvent::UpdateRequest event doesn't avoid the additional update/swap on resize.

[m0dB]

In any case, this now works smooth both on my M1 and on my 2015 MBP, so I think this is ready for merge, at least for macOS.

IIUC, @JoergAtGithub , for window and linux we should also setSwapInterval(1) if ST_PLL is the selected VSync mode right?

[JoergAtGithub]

Yes, ST_PLL works on Windows only with reasonable framerate, if setSwapInterval is set to 1.

Which somehow matchs to the Qt docu: "Setting an interval value of 0 will turn the vertical refresh syncing off, any value higher than 0 will turn the vertical syncing on."
https://doc.qt.io/qt-5/qsurfaceformat.html#setSwapInterval

[m0dB]

Do you think it's worth it to make ST_PLL usable on windows and linux? It requires setting setSwapInterval(1) only if ST_PLL is selected, and that is not trivial due to the order of initialization.

[JoergAtGithub]

On my fast Windows 11 laptop, it shows the smoothest waveform animation I've seen yet. Therefore I think it makes sense.
But the variance of differenent hardware and drivers on Windows and Linux is big, and therefore need a lot of testing.

[m0dB]

@JoergAtGithub setSwapInterval is now set to 1 if the mode is ST_PLL (VSync 5 in the config)

[JoergAtGithub]

Works as expected! Thank you!
@ronso0 @daschuer Could you test the latest version of this PR again (with and without VSync 5)

[m0dB]

On my fast Windows 11 laptop, it shows the smoothest waveform animation I've seen yet.

Nice!

Therefore I think it makes sense. But the variance of differenent hardware and drivers on Windows and Linux is big, and therefore need a lot of testing.

Yes, I feel comfortable making ST_PLL the default on macOS. For 2.4.1 we can decide it to make it the default on Windows as well, and/or to expose it to the user.

[ronso0]

Works as expected! Thank you! @ronso0 @daschuer Could you test the latest version of this PR again (with and without VSync 5)

Without VSync it's like before, mostly smooth waveforms.
With VSync 5 it's jittery, much more dropped frames, about 1 per second per deck.

With this (without VSync 5) and with 2.4 I see jitter and about 20 dropped frames during the first 30 seconds of a session, after that it stabilizes and there are a lot less dropped frames.
Interestingly, with 2.4 I see jitter after that, but the number of dropped frames does not increase.

Tested with 60 Hz and 4.6 (Compatibility Profile) Mesa 21.2.6 (Mesa Intel(R) UHD Graphics 620 (KBL GT2)), no sound output configured.

[JoergAtGithub]

Interestingly, with 2.4 I see jitter after that, but the number of dropped frames does not increase.

This might be #12470

[ronso0]

Hmm no, #12470 doesn't fix that unfortunately.

[m0dB]

Without VSync 5 it's like before, mostly smooth waveforms.

That is not surprising, because that code didn't change at all (but still good to confirm that I didn't accidentally touch anything)

With VSync 5 it's jittery, much more dropped frames, about 1 per second per deck.

Ok, that's too bad. I'd like to investigate this a bit more at some point but now.

Anyway, this doesn't change anything, we stick with ST_TIMER on Linux and Windows, ST_PLL on macOS, and people can test ST_PLL on Linux and Windows if they like.

[ronso0]

Interestingly, with 2.4 I see jitter after that, but the number of dropped frames does not increase.

Off topic: FWIW I have super smooth waveforms with my personal branch based on main with @poelzi's #3534 which I'm using for ages, maybe that's why I didn't notice it in 2.4/main.

[JoergAtGithub]

I tested this on my old Windows 7 Laptop, with ST_TIMER it runs with 60fps but framedrops - as before. With ST_PLL it runs with ~5.5fps, but at least it works somehow. To be metioned is, that the Mixxx process consumes only 2% of the CPU time - therefore it's not an CPU issue:

�[34mdebug�[0m [�[97mMain�[0m] Displaying main window
�[34mdebug�[0m [�[97mMain�[0m] Running Mixxx
�[34mdebug�[0m [�[97mMain�[0m] OpenGL driver version string "3.1.0 - Build 9.17.10.4229", vendor "Intel", renderer "Intel(R) HD Graphics 3000"
�[34mdebug�[0m [�[97mMain�[0m] Supported OpenGL version: 3.1

�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 2.70901e+07 16684.4
�[34mdebug�[0m [�[97mMain�[0m] BaseTrackCache(0x153e6f10) updateIndexWithQuery took 0 ms
�[34mdebug�[0m [�[97mMain�[0m] Committing transaction successfully on "MIXXX-1"
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 3.71291e+07 16707.4
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 4.70305e+07 16729.5
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 5.71796e+07 16752.7
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 6.71587e+07 16775.7
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 7.71854e+07 16798.1
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[93mwarning�[0m [�[97mEngine�[0m] underflowHappened code: 25
�[34mdebug�[0m [�[97mMain�[0m] phase-locked-loop: 8.71421e+07 16821.8

[JoergAtGithub]

The code is LGTM and I can confirm that ST_PLL works smoother on my Windows11 laptop (the earlier mentionend high CPU usage, is not reproduceable anymore).
On my old Windows7 dual-core laptop with Intel GPU the ST_PLL mode showed very low framerate, while ST_Timer still achieves 60fps.
Since this PR doesn't change the default behavior, we can merge this new mode without risk. Thank you!