allow to set threshold for MixxxApp::notify() event warning

[ronso0]

The settings key is [Config],NotifyMaxDbgTime.

At least on my machine there's so many events that take longer than 10 millis, and I want to reduce log spam.
There are probably more elegant ways to accomplish this, ie. keep MixxxApplication clean, like avoid adding a method and no new includes in its header. If you agree this is worth being implemented, please suggest better ways.

[JoergAtGithub]

10ms are already a relative high threshold, as this thread must render every 16.6ms a new waveform, which consumes several milliseconds on it's own. This means, that every occurence nearly certainly indicates an event, that result in a frame drop.

[ronso0]

Just an example of a quick test session: start Mixxx, select a track, load it, open preferences, adjust latency, apply.
Threshold set to 15 ms

Processing QEvent::ActionAdded for object WMainMenuBar(0x557d290b5440, name = "MainMenu") running in thread: "Main" took 55 ms
Processing QEvent::Polish for object WCueMenuPopup(0x557d4eafd5f0, name = "WCueMenuPopup") running in thread: "Main" took 21 ms
Processing QEvent::PolishRequest for object WWidgetGroup(0x557d4e383020, name = "Mixxx") running in thread: "Main" took 68 ms
Processing QEvent::Resize for object OpenGLWindow(0x557d348cbc30) running in thread: "Main" took 3442 ms
Processing QEvent::Show for object WSingletonContainer(0x557d4f0316f0, name = "Deck1_Full") running in thread: "Main" took 107 ms
Processing QEvent::Paint for object WEffectParameterKnobComposed(0x557d35500310) running in thread: "Main" took 26 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 45 ms
Processing QEvent::Show for object WWidgetStack(0x557d4e40f100, name = "WidgetStack") running in thread: "Main" took 46 ms
Processing QEvent::Show for object WSingletonContainer(0x557d51140b70, name = "Deck1_Src") running in thread: "Main" took 290 ms
Processing QEvent::Show for object WSingletonContainer(0x557d4f8efbd0, name = "Deck2_Full") running in thread: "Main" took 107 ms
Processing QEvent::Show for object WSingletonContainer(0x557d5116f3e0, name = "Deck2_Src") running in thread: "Main" took 227 ms
Processing QEvent::Show for object WSingletonContainer(0x557d534ddb80, name = "LibrarySingleton") running in thread: "Main" took 139 ms
Processing QEvent::MetaCall for object WWidgetGroup(0x557d4e383020, name = "Mixxx") running in thread: "Main" took 681 ms
Processing QEvent::Resize for object OpenGLWindow(0x557d504c3750) running in thread: "Main" took 27 ms
Processing QEvent::Resize for object OpenGLWindow(0x557d5068cc60) running in thread: "Main" took 17 ms
Processing QEvent::Paint for object QWidget(0x557d507d2860, name = "qt_scrollarea_viewport") running in thread: "Main" took 26 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 62 ms
Processing QEvent::MetaCall for object ControlProxy(0x557d50f65d10) running in thread: "Main" took 63 ms
Processing QEvent::Expose for object QWidgetWindow(0x557d290b4d00, name = "MixxxMainWindowClassWindow") running in thread: "Main" took 19 ms
Processing QEvent::Paint for object QWidget(0x557d507d2860, name = "qt_scrollarea_viewport") running in thread: "Main" took 17 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 22 ms
Processing QEvent::MetaCall for object WaveformWidgetFactory(0x557d354bc760) running in thread: "Main" took 28 ms
Processing QEvent::MetaCall for object WaveformWidgetFactory(0x557d354bc760) running in thread: "Main" took 47 ms
Processing QEvent::Paint for object QWidget(0x557d507d2860, name = "qt_scrollarea_viewport") running in thread: "Main" took 15 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 19 ms
Processing QEvent::MouseButtonPress for object WPushButton(0x557d4ef7f810, name = "PlayDeck") running in thread: "Main" took 33 ms
Processing QEvent::MouseButtonPress for object QWidgetWindow(0x557d290b4d00, name = "MixxxMainWindowClassWindow") running in thread: "Main" took 34 ms
Processing QEvent::Timer for object PlayerInfo(0x557d3201a390) running in thread: "Main" took 25 ms
Processing QEvent::Paint for object QWidget(0x557d507d2860, name = "qt_scrollarea_viewport") running in thread: "Main" took 17 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 20 ms
Processing QEvent::Show for object DlgPreferences(0x557d490e7680, name = "DlgPreferencesDlg") running in thread: "Main" took 189 ms
Processing QEvent::Shortcut for object QAction(0x557d291904f0) running in thread: "Main" took 232 ms
Processing QEvent::DeferredDelete for object 0x557d562cd110 took 15 ms
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 15 ms
Processing QEvent::Expose for object QWidgetWindow(0x557d55ce9490, name = "DlgPreferencesDlgWindow") running in thread: "Main" took 18 ms
Processing QEvent::UpdateRequest for object DlgPreferences(0x557d490e7680, name = "DlgPreferencesDlg") running in thread: "Main" took 17 ms
Processing QEvent::MouseButtonRelease for object QPushButton(0x557d4914aa50) running in thread: "Main" took 5056 ms
Processing QEvent::MouseButtonRelease for object QWidgetWindow(0x557d55ce9490, name = "DlgPreferencesDlgWindow") running in thread: "Main" took 5056 ms
Processing QEvent::Timer for object QPushButton(0x557d491439d0) running in thread: "Main" took 45 ms
Processing QEvent::Close for object MixxxMainWindow(0x7ffc8a486c10) running in thread: "Main" took 1127 ms
Processing QEvent::Close for object QWidgetWindow(0x557d290b4d00, name = "MixxxMainWindowClassWindow") running in thread: "Main" took 1136 ms
Processing QEvent::DeferredDelete for object 0x557d4e383020 took 298 ms

This is used in developer sessions only, so performance is not as high as in user sessions, and I don't care about framedrops in these sessions. Almost all logged events are irrelevant for what I'm usually testing, hence a custom threshold makes sense to have a clean log.
The setting is hidden anyway, ie. set on purpose by devs.

[ronso0]

FYI when running the S4 Mk3 script I get repeatedly
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffda02fa850) running in thread: "Main" took 27 ms
and no frame drops.

[JoergAtGithub]

FYI when running the S4 Mk3 script I get repeatedly
Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffda02fa850) running in thread: "Main" took 27 ms
and no frame drops.

Do you mean that the waveforms are glitch free, or that the frame drop counter does not count drops. The later is also not working if the event queue is blocked.
But one is for sure, while the main thread processes an event, it can not render the next waveform.

[ronso0]

FYI when running the S4 Mk3 script I get repeatedly Processing QEvent::UpdateRequest for object MixxxMainWindow(0x7ffda02fa850) running in thread: "Main" took 27 ms and no frame drops.

Sorry, I meant
Processing QEvent::MetaCall for object HidController(0x7f9134118910) running in thread: "Controller" took 29 ms

[ronso0]

Do you mean that the waveforms are glitch free, or that the frame drop counter does not count drops. The later is also not working if the event queue is blocked.
But one is for sure, while the main thread processes an event, it can not render the next waveform.

Thanks for the explanation.
I never got 100% glitch free waveforms.
I meant the farme drop counter.

I guess logging each and every event > 10ms doesn't improve the situation ? ; )

[ronso0]

To reiterate:

• this PR is just to reduce the log spam (and apparently increase performance in dev mode)
• the threshold has to be set explictly in mixxx.cfg

If you fear a custom value migh be forgotten, we may remember devs of that by printing the threshold info at startup (log).

Anyhow, I'll (have to) incorporate this into my dev branches, because for example when contiously logging controller values the event logs disrupt my workflow and I sometimes scroll back in the log stream to check whether I missed another logging of interest. in other cases I'll simply use the 'warning' log level.