Inconsistent computation times during Q_INVOKABLE function calls



  • 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 !


  • Lifetime Qt Champion

    Hi,

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



  • 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


  • Lifetime Qt Champion

    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.


  • Moderators

    Same on amd64 Linux :-/



  • @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 :) ).


  • Moderators

    @Oxyde done



  • @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



Looks like your connection to Qt Forum was lost, please wait while we try to reconnect.