Inconsistent computation times during Q_INVOKABLE function calls

Oxyde

Hi there,

I am making a little application targeting Android 5 with Qt 5 (using the latest dev branch but tried with 5.5.* and 5.6 beta) and i am experiencing periodic and very annoying lag while my application is running.

Some times, without warnings or doing anything special, an ordinary function will spend a lot more time than usual to complete. I made a basic example with a rotating box, here it is:

Item {
    id: level

    Rectangle {
        id: box
        width: 100
        height: width
        color: "red"

        RotationAnimator {
            target: box
            from: 0
            to: 360
            duration: 10000
            running: true
            loops: Animator.Infinite
        }

        property var test

        Timer {
            running: true
            interval: 1
            repeat: true

            onTriggered: {
                test = box.mapToItem(level, 0.0, 7.0);
            }
        }
    }
}

And when i QML profile this on OS X Clang, letting the application runs for 30 seconds and starting the profiler 10 seconds after the application starts to avoid the initialisation part, here the stats i found for the call of 'onTriggered':

Mean Time: 28µs
Median Time: 31µs
Longest Time: 1.19ms (half this value with Qt 5.5.1 but still ...)
Shortest Time: 10.947µs

Take a look at the units.
We have a shortest time around 11 microseconds, a mean time around 28 microseconds, we would expect a longest time around 50 microseconds but no, we got 1.19 milliseconds thus 1190 microseconds, more than 20 times what we expected !!!

If i replace the source for onTriggered by pure Javascript code like the following one, the computation times seems to be consistent staying in the same order of magnitude (mean : 21.5µs, median : 24.5µs, longest : 79µs, shortest: 11.2µs) :

onTriggered: {
    var a = 5;
    for(var i = 0; i < 5000; ++i)
        a += a;
}

On my android mobile phone i got exactly the same issue - ordinary functions sometimes taking a lot of time to do nearly nothing - but multiplied because the cpu is a lot slower hence the lag spikes becoming very annoying for the user and ruining the experience.

Does anyone know where does this issue come from ?
Any ideas how to solve it or how to workaround it ?

Thanks !

SGaist

Hi,

Since you're using Xcode's profiler, can you spot the hot path when you are "losing" time ?

Oxyde

Hi,
I am not, i use the QML profiler in Qt Creator and sadly i am not use to the XCode environment. Is there a way to do this from Qt Creator ?

This issue does not seem specific to my configuration, i tried with three different version of Qt (5.5.1, 5.6 beta and Qt 5 dev) on two Mac OS and one Android and it reproduce the same problem. I first noticed it on a more complex application where i need extreme fluidity. At first, i though my code just needed some optimisations (and yes of course it needed a bit) but then the lags were still there after removing everything, just calling basic qt functions (instantiating qml types like Qt.vector3d for instance or as in my example calling mapToItem or custom functions) without even assigning the result (no call to bindings), i noticed that even with a basic example i still have these awful lag spikes.

I simplified my test to the following :

import QtQuick 2.4

Timer {
    running: true
    interval: 1
    repeat: true

    onTriggered: Qt.vector3d(0, 0, 0);
}

And here is the result of the profiling :

Location Type Time in Percent Total Time Calls Mean Time Median Time Longest Time Shortest Time Details
<program> 100.00 % 344.098 ms 1 344.098 ms 344.098 ms 344.098 ms 344.098 ms Main Program
main.qml:8 Signal 100.00 % 344.098 ms 18928 18.179 µs 14.082 µs 2.287 ms 3.218 µs onTriggered: Qt.vector3d(0, 0, 0);
main.qml:8 JavaScript 80.28 % 276.240 ms 18928 14.594 µs 11.139 µs 2.281 ms 2.628 µs onTriggered

Awful isn't it ? ^^

I am going to submit a Qt Bug hoping it'll have a high priority.

Edit: Qt Bug submitted - https://bugreports.qt.io/browse/QTBUG-50443

SGaist

You could take a look at your application using GammaRay That might give you some more clues.

As for the checking your application, you can use Instruments without having to run Xcode.

? Offline

Same on amd64 Linux :-/

Oxyde

@Wieland : Hi Wieland,
Thank you for your concern. Can you add a comment about your test on the Qt Bug please ?
https://bugreports.qt.io/browse/QTBUG-50443

@SGaist : i am going to try GammaRay, that's seems to be a great tool. But my concern is more about this particular bug more related to Qt itself than about my application (but yes it will surely be helpful thanks for the tip :) ).

? Offline

@Oxyde done

Oxyde

@Wieland Thank you very much :)

I hope this will be quickly fixed, this is kinda critical since we cannot have a totally fluid application on embedded devices because of this but that's seems to be a nasty bug to fix :s