[MU4 Issue] When selecting first note there is an appreciable time lag before it sounds and is highlighted

[rgreen5]

Describe the bug

If you have nothing selected, then click on a notehead with the mouse, there is a short, but appreciable, delay before the note sounds and is highlighted. However, now that a note is selected and you click on another note, the delay disappears and the new note sounds and is highlighted virtually instantaneously. If you clear the selection and try the same thing again, exactly the same thing happens.

By contrast, if you select any other, non-sounding, element there is no delay in highlighting.

There was never any delay between clicking on a note and it sounding or highlighting in MS3.

To Reproduce

1. Open the attached score example. delayed_note.zip
2. With nothing selected, click on a notehead.
3. Now, with the notehead selected, click on another notehead (releasing the previous notehead). RESULT: In step 2, there is a short, but appreciable delay. But virtually no delay in step 3.
4. Now export a musicXML file and do the same experiemnt in MS3. RESULT: There is no delay at any stage.

Expected behavior

When you click on a notehead, it should sound and be highlighted instantaneously – just as it did in MS3. There should not be the difference in time lag between the cases shown above in MS4.

Platform information

OS: Linux Mint 20.1, Arch.: x86_64, MuseScore version (64-bit): 4.0.0-223110421, revision: github-musescore-musescore-ff5a8c7

Intel Pentium CPU 2020M @ 2.40GHz × 2 / 3.7 Gb. RAM

[Tantacrul]

We have a new build with a lot of performance improvements which will be merged soon. That may conclusively solve this.

In the meantime, it would be good to find out whether this problem is still occurring, since the issue is two weeks old and there have been a lot of changes in the meantime to performance. Thanks!

[rgreen5]

OS: Linux Mint 20.1, Arch.: x86_64, MuseScore version (64-bit): 4.0.0-223270405, revision: github-musescore-musescore-46ce488

Issue still present here.

[rgreen5]

OS: Linux Mint 20.1, Arch.: x86_64, MuseScore version (64-bit): 4.0.2-230460504, revision: github-musescore-musescore-a36e598

Some more observations:

1. Click on a note in the demonstration score RESULT: Appreciable sound lag from key press to audio.
2. Click on another note. RESULT: The sound lag is now negligible
3. Clear the selection by clicking on a blank space on the score paper. Then click on a note again. RESULT: The sound lag appears again.
4. Shift + click on another note to create a range selection. RESULT: There is a lag between the key press and the selection being highlighted.

[bluebear94]

I just discovered that MuseScore 4 has a profiler and tried running it after selecting notes a few times. Unfortunately, I can’t find a way to copy the text from the profiler, so a screenshot will have to do.

It might be that most of the delay is coming from updating the Properties panel.

[bluebear94]

As of MS 4.2.1, the lag at least occurs only if the Properties panel is visible (as opposed to being opened but not on the current tab).

[DmitryArefiev]

Intel Pentium CPU 2020M @ 2.40GHz × 2 / 3.7 Gb. RAM

We don't support that configuration, that's a rather old CPU for MS4

And I can't reproduce it on my laptop with Pentium Gold 6805

[DmitryArefiev]

@rgreen5 But please check the latest performance improvements in #22791, it might work better on slow machines too

[bluebear94]

Sorry, I’m still experiencing this issue on the latest nightly (to be precise, this build) when the Properties panel is open, and I have a newer CPU than rgreen5.

[bluebear94]

I’ve taken some time to drill down with TRACEFUNCs, and strangely, the bottleneck seems to be the call to QAbstractModel::endInsertRows from InspectorListModel::createModelsBySectionType. In particular, the bottleneck is with adding the NotationSettingsProxyModel to the model list.

It might be possible to change the code so that the note can be highlighted and played without waiting for the properties panel to update, but I’m not familiar enough with Qt to be sure.

[bluebear94]

Note: Skipping the note inspector model by adding if (model->modelType() == InspectorModelType::TYPE_NOTE) continue; after the for (AbstractInspectorModel* model : models) { line in AbstractInspectorProxyModel::setModels removes the delay, so something must be going on with that.

Edit: Commenting out the setModelType call in NoteSettingsProxyModel’s constructor also removes the delay.

[bluebear94]

The StackLayout in NoteSettings.qml seems to be responsible for most of the delay when selecting a note, but the three children have roughly equal contributions to the delay.

[bluebear94]

Thank you for reopening!

[bluebear94]

I suspect that the delay arises from creating QML components synchronously; see this Samply profile. There are two causes:

1. First, we’re not setting the incubation controller on our QQmlEngine.
2. Even then, something down the line calls QQuickRepeater::modelUpdated, which incubates objects using the QQmlIncubator::AsynchronousIfNested mode. It appears that this is called outside any “nested asynchronous creation”, causing the objects to be created synchronously.

[MarcSabatella]

I'm curious, on my systems (which are on the slow side), if there is a delay, it's not more than a few milliseconds. Are there systems where the delay is actually large enough to be problematic? If so, I wonder if it has to do with the graphics drivers on those systems, something having to to do with OpenGL support (or lack thereof), perhaps? Knowing what makes the delay larger for some than others might prove useful in determining how to circumvent it.

[bluebear94]

Are there systems where the delay is actually large enough to be problematic?

Yes, with the following patch:

diff --git a/src/inspector/models/inspectorlistmodel.cpp b/src/inspector/models/inspectorlistmodel.cpp
index 212951ddb1..eb2bd60acd 100644
--- a/src/inspector/models/inspectorlistmodel.cpp
+++ b/src/inspector/models/inspectorlistmodel.cpp
@@ -32,6 +32,7 @@

 #include "internal/services/elementrepositoryservice.h"

+#include <QMetaEnum>
 #include "log.h"

 using namespace mu::inspector;
@@ -156,6 +157,7 @@ void InspectorListModel::setInspectorVisible(bool visible)
 void InspectorListModel::createModelsBySectionType(const InspectorSectionTypeSet& sectionTypes,
                                                    const ElementKeySet& selectedElementKeySet)
 {
+    TRACEFUNC;
     for (InspectorSectionType sectionType : sectionTypes) {
         if (sectionType == InspectorSectionType::SECTION_UNDEFINED) {
             continue;
@@ -207,7 +209,12 @@ void InspectorListModel::createModelsBySectionType(const InspectorSectionTypeSet
             m_modelList << newModel;
         }

+        TIMER_START("a");
         endInsertRows();
+
+        qInfo("Time taken to add row for %s:", QMetaEnum::fromType<InspectorSectionType>().valueToKey((int) sectionType));
+        TIMER_PRINT("a");
+        TIMER_STOP("a");
     }
 }

I get the following console output when selecting a note:

19:45:06.815 | INFO  | main_thread     | Qt              | Time taken to add row for SECTION_GENERAL:
19:45:06.815 | DEBUG | main_thread     | Profiler        | a : 5.240 ms
19:45:06.899 | INFO  | main_thread     | Qt              | Time taken to add row for SECTION_NOTATION:
19:45:06.900 | DEBUG | main_thread     | Profiler        | a : 84.445 ms

If so, I wonder if it has to do with the graphics drivers on those systems, something having to to do with OpenGL support (or lack thereof), perhaps? Knowing what makes the delay larger for some than others might prove useful in determining how to circumvent it.

I also get the “Detecting problems with graphics api” message earlier in the log. MuseScore doesn’t detect any problems with the graphics API:

20:02:15.062 | INFO  | main_thread     | GuiApp::perform | No problems detected with graphics api

In my case, lspci -nnk gives:

...
05:00.0 VGA compatible controller [0300]: Advanced Micro Devices, Inc. [AMD/ATI] Lucienne [1002:164c] (rev c1)
    Subsystem: CLEVO/KAPOK Computer Device [1558:a600]
    Kernel driver in use: amdgpu
    Kernel modules: amdgpu
...

[MarcSabatella]

So to be clear, we're talking about a delay of around 90 milliseconds? And it's only on the first note you click after selection is cleared?

[bluebear94]

So to be clear, we're talking about a delay of around 90 milliseconds? And it's only on the first note you click after selection is cleared?

Yep. It actually varies from about 60 ms to 120.

(To be exact, it happens as long as the selection isn’t a note. Going from a rest to a note, for example, still has the delay.)

[cbjeukendrup]

The Repeater in question is probably the one from InspectorForm.qml. You could try replacing it (and it's containing StyledFlickable) with a StyledListView. Or perhaps wrapping the delegate of the Repeater in a Loader { asynchronous: true; sourceComponent: … }.

[bluebear94]

Applying the latter change (along with the change that sets the incubation controller) indeed removes the delay. Unfortunately, this messes up the inspector: