Periodically flush profiling data to client.

This reduces memory usage as the data can be deleted once it is sent.
It also reduces the time it takes to transmit the data when profiling
is stopped. It does incur a runtime cost as the sending now takes place
while the application is running. The decision to periodically flush or
not is left to the client, who can specify a flush interval when
starting profiling.

Usage of the flushing feature also relaxes the guarantees regarding the
sorting of events before they are sent. Events with higher timestamps
are now allowed to arrive before events with lower timestamps. Any
clients implementing the flushing need to take this into account. This
will eventually allow us to do away with the server-side ordering
altogether.

Task-number: QTBUG-39756
Change-Id: Idaf4931dc17f224c2bd492078b99e88b1405234e
Reviewed-by: Simon Hausmann <simon.hausmann@theqtcompany.com>

11 files changed, 177 insertions, 50 deletions

diff --git a/src/qml/debugger/qqmlprofiler.cpp b/src/qml/debugger/qqmlprofiler.cpp
index 2fd27617b..30e089ac4 100644
--- a/src/qml/debugger/qqmlprofiler.cpp
+++ b/src/qml/debugger/qqmlprofiler.cpp
@@ -110,7 +110,10 @@ qint64 QQmlProfilerAdapter::sendMessages(qint64 until, QList<QByteArray> &messag
 
 void QQmlProfilerAdapter::receiveData(const QVector<QQmlProfilerData> &new_data)
 {
-    data = new_data;
+    if (data.isEmpty())
+        data = new_data;
+    else
+        data.append(new_data);
     service->dataReady(this);
 }
 
@@ -131,16 +134,12 @@ void QQmlProfiler::stopProfiling()
 {
     featuresEnabled = false;
     reportData();
-    m_data.clear();
 }
 
 void QQmlProfiler::reportData()
 {
-    QVector<QQmlProfilerData> result;
-    result.reserve(m_data.size());
-    for (int i = 0; i < m_data.size(); ++i)
-        result.append(m_data[i]);
-    emit dataReady(result);
+    emit dataReady(m_data);
+    m_data.clear();
 }
 
 QT_END_NAMESPACE
diff --git a/src/qml/debugger/qqmlprofiler_p.h b/src/qml/debugger/qqmlprofiler_p.h
index 93a864bae..67e6c9eda 100644
--- a/src/qml/debugger/qqmlprofiler_p.h
+++ b/src/qml/debugger/qqmlprofiler_p.h
@@ -175,7 +175,7 @@ signals:
 
 protected:
     QElapsedTimer m_timer;
-    QVarLengthArray<QQmlProfilerData> m_data;
+    QVector<QQmlProfilerData> m_data;
 };
 
 class QQmlProfilerAdapter : public QQmlAbstractProfilerAdapter {
diff --git a/src/qml/debugger/qqmlprofilerservice.cpp b/src/qml/debugger/qqmlprofilerservice.cpp
index 6f50b41b1..2b26cdccf 100644
--- a/src/qml/debugger/qqmlprofilerservice.cpp
+++ b/src/qml/debugger/qqmlprofilerservice.cpp
@@ -48,7 +48,8 @@ QT_BEGIN_NAMESPACE
 Q_GLOBAL_STATIC(QQmlProfilerService, profilerInstance)
 
 QQmlProfilerService::QQmlProfilerService()
-    : QQmlConfigurableDebugService<QQmlDebugService>(QStringLiteral("CanvasFrameRate"), 1)
+    : QQmlConfigurableDebugService<QQmlDebugService>(QStringLiteral("CanvasFrameRate"), 1),
+      m_waitingForStop(false)
 {
     m_timer.start();
 }
@@ -242,6 +243,8 @@ void QQmlProfilerService::startProfiling(QQmlEngine *engine, quint64 features)
             if (!profiler->isRunning())
                 profiler->startProfiling(features);
         }
+
+        emit startFlushTimer();
     }
 
     emit messageToClient(name(), message);
@@ -273,6 +276,9 @@ void QQmlProfilerService::stopProfiling(QQmlEngine *engine)
         }
     }
 
+    if (stopping.isEmpty())
+        return;
+
     foreach (QQmlAbstractProfilerAdapter *profiler, m_globalProfilers) {
         if (!profiler->isRunning())
             continue;
@@ -284,6 +290,9 @@ void QQmlProfilerService::stopProfiling(QQmlEngine *engine)
         }
     }
 
+    emit stopFlushTimer();
+    m_waitingForStop = true;
+
     foreach (QQmlAbstractProfilerAdapter *profiler, reporting)
         profiler->reportData();
 
@@ -299,16 +308,19 @@ void QQmlProfilerService::sendMessages()
     QList<QByteArray> messages;
 
     QByteArray data;
-    QQmlDebugStream traceEnd(&data, QIODevice::WriteOnly);
-    traceEnd << m_timer.nsecsElapsed() << (int)Event << (int)EndTrace;
 
-    QSet<QQmlEngine *> seen;
-    foreach (QQmlAbstractProfilerAdapter *profiler, m_startTimes) {
-        for (QMultiHash<QQmlEngine *, QQmlAbstractProfilerAdapter *>::iterator i(m_engineProfilers.begin());
-                i != m_engineProfilers.end(); ++i) {
-            if (i.value() == profiler && !seen.contains(i.key())) {
-                seen << i.key();
-                traceEnd << idForObject(i.key());
+    if (m_waitingForStop) {
+        QQmlDebugStream traceEnd(&data, QIODevice::WriteOnly);
+        traceEnd << m_timer.nsecsElapsed() << (int)Event << (int)EndTrace;
+
+        QSet<QQmlEngine *> seen;
+        foreach (QQmlAbstractProfilerAdapter *profiler, m_startTimes) {
+            for (QMultiHash<QQmlEngine *, QQmlAbstractProfilerAdapter *>::iterator i(m_engineProfilers.begin());
+                    i != m_engineProfilers.end(); ++i) {
+                if (i.value() == profiler && !seen.contains(i.key())) {
+                    seen << i.key();
+                    traceEnd << idForObject(i.key());
+                }
             }
         }
     }
@@ -325,15 +337,26 @@ void QQmlProfilerService::sendMessages()
         }
     }
 
-    //indicate completion
-    messages << data;
-    data.clear();
+    if (m_waitingForStop) {
+        //indicate completion
+        messages << data;
+        data.clear();
 
-    QQmlDebugStream ds(&data, QIODevice::WriteOnly);
-    ds << (qint64)-1 << (int)Complete;
-    messages << data;
+        QQmlDebugStream ds(&data, QIODevice::WriteOnly);
+        ds << (qint64)-1 << (int)Complete;
+        messages << data;
+        m_waitingForStop = false;
+    }
 
     emit messagesToClient(name(), messages);
+
+    // Restart flushing if any profilers are still running
+    foreach (const QQmlAbstractProfilerAdapter *profiler, m_engineProfilers) {
+        if (profiler->isRunning()) {
+            emit startFlushTimer();
+            break;
+        }
+    }
 }
 
 void QQmlProfilerService::stateAboutToBeChanged(QQmlDebugService::State newState)
@@ -360,11 +383,25 @@ void QQmlProfilerService::messageReceived(const QByteArray &message)
     int engineId = -1;
     quint64 features = std::numeric_limits<quint64>::max();
     bool enabled;
+    uint flushInterval = 0;
     stream >> enabled;
     if (!stream.atEnd())
         stream >> engineId;
     if (!stream.atEnd())
         stream >> features;
+    if (!stream.atEnd()) {
+        stream >> flushInterval;
+        m_flushTimer.setInterval(flushInterval);
+        if (flushInterval > 0) {
+            connect(&m_flushTimer, SIGNAL(timeout()), this, SLOT(flush()));
+            connect(this, SIGNAL(startFlushTimer()), &m_flushTimer, SLOT(start()));
+            connect(this, SIGNAL(stopFlushTimer()), &m_flushTimer, SLOT(stop()));
+        } else {
+            disconnect(&m_flushTimer, SIGNAL(timeout()), this, SLOT(flush()));
+            disconnect(this, SIGNAL(startFlushTimer()), &m_flushTimer, SLOT(start()));
+            disconnect(this, SIGNAL(stopFlushTimer()), &m_flushTimer, SLOT(stop()));
+        }
+    }
 
     // If engineId == -1 objectForId() and then the cast will return 0.
     if (enabled)
@@ -375,4 +412,23 @@ void QQmlProfilerService::messageReceived(const QByteArray &message)
     stopWaiting();
 }
 
+void QQmlProfilerService::flush()
+{
+    QMutexLocker lock(&m_configMutex);
+
+    foreach (QQmlAbstractProfilerAdapter *profiler, m_engineProfilers) {
+        if (profiler->isRunning()) {
+            m_startTimes.insert(-1, profiler);
+            profiler->reportData();
+        }
+    }
+
+    foreach (QQmlAbstractProfilerAdapter *profiler, m_globalProfilers) {
+        if (profiler->isRunning()) {
+            m_startTimes.insert(-1, profiler);
+            profiler->reportData();
+        }
+    }
+}
+
 QT_END_NAMESPACE
diff --git a/src/qml/debugger/qqmlprofilerservice_p.h b/src/qml/debugger/qqmlprofilerservice_p.h
index 518f60bb7..d593c43b9 100644
--- a/src/qml/debugger/qqmlprofilerservice_p.h
+++ b/src/qml/debugger/qqmlprofilerservice_p.h
@@ -57,6 +57,7 @@
 #include <QtCore/qvector.h>
 #include <QtCore/qstringbuilder.h>
 #include <QtCore/qwaitcondition.h>
+#include <QtCore/qtimer.h>
 
 #include <limits>
 
@@ -90,6 +91,13 @@ public:
 
     void dataReady(QQmlAbstractProfilerAdapter *profiler);
 
+signals:
+    void startFlushTimer();
+    void stopFlushTimer();
+
+private slots:
+    void flush();
+
 protected:
     virtual void stateAboutToBeChanged(State state);
     virtual void messageReceived(const QByteArray &);
@@ -101,6 +109,8 @@ private:
     void removeProfilerFromStartTimes(const QQmlAbstractProfilerAdapter *profiler);
 
     QElapsedTimer m_timer;
+    QTimer m_flushTimer;
+    bool m_waitingForStop;
 
     QList<QQmlAbstractProfilerAdapter *> m_globalProfilers;
     QMultiHash<QQmlEngine *, QQmlAbstractProfilerAdapter *> m_engineProfilers;
diff --git a/src/qml/debugger/qv4profileradapter.cpp b/src/qml/debugger/qv4profileradapter.cpp
index 667657a06..0da8c4793 100644
--- a/src/qml/debugger/qv4profileradapter.cpp
+++ b/src/qml/debugger/qv4profileradapter.cpp
@@ -70,16 +70,34 @@ qint64 QV4ProfilerAdapter::appendMemoryEvents(qint64 until, QList<QByteArray> &m
     return memory_data.length() == memoryPos ? -1 : memory_data[memoryPos].timestamp;
 }
 
+qint64 QV4ProfilerAdapter::finalizeMessages(qint64 until, QList<QByteArray> &messages,
+                                            qint64 callNext)
+{
+    if (callNext == -1) {
+        data.clear();
+        dataPos = 0;
+    }
+
+    qint64 memoryNext = appendMemoryEvents(until, messages);
+
+    if (memoryNext == -1) {
+        memory_data.clear();
+        memoryPos = 0;
+        return callNext;
+    }
+
+    return callNext == -1 ? memoryNext : qMin(callNext, memoryNext);
+}
+
 qint64 QV4ProfilerAdapter::sendMessages(qint64 until, QList<QByteArray> &messages)
 {
     QByteArray message;
     while (true) {
         while (!stack.isEmpty() && (dataPos == data.length() ||
                                     stack.top() <= data[dataPos].start)) {
-            if (stack.top() > until) {
-                qint64 memoryNext = appendMemoryEvents(until, messages);
-                return memoryNext == -1 ? stack.top() : qMin(stack.top(), memoryNext);
-            }
+            if (stack.top() > until)
+                return finalizeMessages(until, messages, stack.top());
+
             appendMemoryEvents(stack.top(), messages);
             QQmlDebugStream d(&message, QIODevice::WriteOnly);
             d << stack.pop() << RangeEnd << Javascript;
@@ -87,10 +105,9 @@ qint64 QV4ProfilerAdapter::sendMessages(qint64 until, QList<QByteArray> &message
         }
         while (dataPos != data.length() && (stack.empty() || data[dataPos].start < stack.top())) {
             const QV4::Profiling::FunctionCallProperties &props = data[dataPos];
-            if (props.start > until) {
-                qint64 memory_next = appendMemoryEvents(until, messages);
-                return memory_next == -1 ? props.start : qMin(props.start, memory_next);
-            }
+            if (props.start > until)
+                return finalizeMessages(until, messages, props.start);
+
             appendMemoryEvents(props.start, messages);
 
             QQmlDebugStream d_start(&message, QIODevice::WriteOnly);
@@ -110,7 +127,7 @@ qint64 QV4ProfilerAdapter::sendMessages(qint64 until, QList<QByteArray> &message
             ++dataPos;
         }
         if (stack.empty() && dataPos == data.length())
-            return appendMemoryEvents(until, messages);
+            return finalizeMessages(until, messages, -1);
     }
 }
 
@@ -118,10 +135,19 @@ void QV4ProfilerAdapter::receiveData(
         const QVector<QV4::Profiling::FunctionCallProperties> &new_data,
         const QVector<QV4::Profiling::MemoryAllocationProperties> &new_memory_data)
 {
-    data = new_data;
-    memory_data = new_memory_data;
-    dataPos = memoryPos = 0;
-    stack.clear();
+    // In rare cases it could be that another flush or stop event is processed while data from
+    // the previous one is still pending. In that case we just append the data.
+
+    if (data.isEmpty())
+        data = new_data;
+    else
+        data.append(new_data);
+
+    if (memory_data.isEmpty())
+        memory_data = new_memory_data;
+    else
+        memory_data.append(new_memory_data);
+
     service->dataReady(this);
 }
 
diff --git a/src/qml/debugger/qv4profileradapter_p.h b/src/qml/debugger/qv4profileradapter_p.h
index 645b20dd0..34c37baf5 100644
--- a/src/qml/debugger/qv4profileradapter_p.h
+++ b/src/qml/debugger/qv4profileradapter_p.h
@@ -73,6 +73,7 @@ private:
     int memoryPos;
     QStack<qint64> stack;
     qint64 appendMemoryEvents(qint64 until, QList<QByteArray> &messages);
+    qint64 finalizeMessages(qint64 until, QList<QByteArray> &messages, qint64 callNext);
 };
 
 QT_END_NAMESPACE
diff --git a/src/qml/jsruntime/qv4profiling.cpp b/src/qml/jsruntime/qv4profiling.cpp
index a0db2bf5c..9b7759990 100644
--- a/src/qml/jsruntime/qv4profiling.cpp
+++ b/src/qml/jsruntime/qv4profiling.cpp
@@ -84,14 +84,13 @@ void Profiler::reportData()
         resolved.insert(std::upper_bound(resolved.begin(), resolved.end(), props, comp), props);
     }
     emit dataReady(resolved, m_memory_data);
+    m_data.clear();
+    m_memory_data.clear();
 }
 
 void Profiler::startProfiling(quint64 features)
 {
     if (featuresEnabled == 0) {
-        m_data.clear();
-        m_memory_data.clear();
-
         if (features & (1 << FeatureMemoryAllocation)) {
             qint64 timestamp = m_timer.nsecsElapsed();
             MemoryAllocationProperties heap = {timestamp,
diff --git a/src/quick/util/qquickprofiler.cpp b/src/quick/util/qquickprofiler.cpp
index d9132a9cb..7bd32f07e 100644
--- a/src/quick/util/qquickprofiler.cpp
+++ b/src/quick/util/qquickprofiler.cpp
@@ -113,10 +113,15 @@ void QQuickProfilerData::toByteArrays(QList<QByteArray> &messages) const
 qint64 QQuickProfiler::sendMessages(qint64 until, QList<QByteArray> &messages)
 {
     QMutexLocker lock(&m_dataMutex);
-    while (next < m_data.size() && m_data[next].time <= until) {
-        m_data[next++].toByteArrays(messages);
+    while (next < m_data.size()) {
+        if (m_data[next].time <= until)
+            m_data[next++].toByteArrays(messages);
+        else
+            return m_data[next].time;
     }
-    return next < m_data.size() ? m_data[next].time : -1;
+    m_data.clear();
+    next = 0;
+    return -1;
 }
 
 void QQuickProfiler::initialize()
@@ -196,17 +201,12 @@ void QQuickProfiler::stopProfilingImpl()
     {
         QMutexLocker lock(&m_dataMutex);
         featuresEnabled = 0;
-        next = 0;
     }
     service->dataReady(this);
 }
 
 void QQuickProfiler::reportDataImpl()
 {
-    {
-        QMutexLocker lock(&m_dataMutex);
-        next = 0;
-    }
     service->dataReady(this);
 }
 
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/data/timer.qml b/tests/auto/qml/debugger/qqmlprofilerservice/data/timer.qml
new file mode 100644
index 000000000..18b894717
--- /dev/null
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/data/timer.qml
@@ -0,0 +1,14 @@
+import QtQuick 2.0
+
+Rectangle {
+    width: 100
+    height: 62
+
+    Timer {
+        running: true
+        repeat: true
+        interval: 50
+        onTriggered: height = (2 * height) % 99;
+    }
+}
+
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/qqmlprofilerservice.pro b/tests/auto/qml/debugger/qqmlprofilerservice/qqmlprofilerservice.pro
index ec8413979..e422d3ef9 100644
--- a/tests/auto/qml/debugger/qqmlprofilerservice/qqmlprofilerservice.pro
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/qqmlprofilerservice.pro
@@ -21,4 +21,5 @@ OTHER_FILES += \
     data/scenegraphTest.qml \
     data/TestImage_2x2.png \
     data/signalSourceLocation.qml \
-    data/javascript.qml
+    data/javascript.qml \
+    data/timer.qml
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
index f9f05964a..744830b55 100644
--- a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
@@ -145,10 +145,12 @@ public:
     QVector<QQmlProfilerData> asynchronousMessages;
     QVector<QQmlProfilerData> pixmapMessages;
 
-    void setTraceState(bool enabled) {
+    void setTraceState(bool enabled, quint32 flushInterval = 0) {
         QByteArray message;
         QDataStream stream(&message, QIODevice::WriteOnly);
         stream << enabled;
+        if (enabled && flushInterval)
+            stream << -1 << std::numeric_limits<quint64>::max() << flushInterval;
         sendMessage(message);
     }
 
@@ -213,6 +215,7 @@ private slots:
     void controlFromJS();
     void signalSourceLocation();
     void javascript();
+    void flushInterval();
 };
 
 #define VERIFY(type, position, expected, checks) QVERIFY(verify(type, position, expected, checks))
@@ -766,6 +769,24 @@ void tst_QQmlProfilerService::javascript()
     VERIFY(MessageListJavaScript, 21, expected, CheckMessageType | CheckDetailType);
 }
 
+void tst_QQmlProfilerService::flushInterval()
+{
+    connect(true, "timer.qml");
+    QVERIFY(m_client);
+    QTRY_COMPARE(m_client->state(), QQmlDebugClient::Enabled);
+
+    m_client->setTraceState(true, 1);
+
+    // Make sure we get multiple messages
+    QTRY_VERIFY(m_client->qmlMessages.length() > 0);
+    QVERIFY(m_client->qmlMessages.length() < 100);
+    QTRY_VERIFY(m_client->qmlMessages.length() > 100);
+
+    m_client->setTraceState(false);
+    checkTraceReceived();
+    checkJsHeap();
+}
+
 QTEST_MAIN(tst_QQmlProfilerService)
 
 #include "tst_qqmlprofilerservice.moc"