QmlProfiler: Record debug messages separately

They are not time-ordered like normal messages, so we need to buffer
them and only insert them when the normal event stream arrives at their
timestamp.

The time ordering is important as the "restrict to range" feature uses
it to determine the start of the range.

Change-Id: If27a3f667c4c39e69efa95fcb9cdfd3dbf01e657
Task-number: QTCREATORBUG-19456
Reviewed-by: Christian Kandeler <christian.kandeler@qt.io>

1 files changed, 26 insertions, 6 deletions

diff --git a/src/plugins/qmlprofiler/qmlprofilertraceclient.cpp b/src/plugins/qmlprofiler/qmlprofilertraceclient.cpp
index 39cdb96ede..6bf359c924 100644
--- a/src/plugins/qmlprofiler/qmlprofilertraceclient.cpp
+++ b/src/plugins/qmlprofiler/qmlprofilertraceclient.cpp
@@ -56,6 +56,7 @@ public:
     bool updateFeatures(ProfileFeature feature);
     int resolveType(const QmlTypedEvent &type);
     int resolveStackTop();
+    void forwardEvents(const QmlEvent &last);
     void processCurrentEvent();
 
     QmlProfilerTraceClient *q;
@@ -74,6 +75,7 @@ public:
     QHash<qint64, int> serverTypeIds;
     QStack<QmlTypedEvent> rangesInProgress;
     QQueue<QmlEvent> pendingMessages;
+    QQueue<QmlEvent> pendingDebugMessages;
 };
 
 int QmlProfilerTraceClientPrivate::resolveType(const QmlTypedEvent &event)
@@ -117,12 +119,21 @@ int QmlProfilerTraceClientPrivate::resolveStackTop()
     typedEvent.event.setTypeIndex(typeIndex);
     while (!pendingMessages.isEmpty()
            && pendingMessages.head().timestamp() < typedEvent.event.timestamp()) {
-        modelManager->addEvent(pendingMessages.dequeue());
+        forwardEvents(pendingMessages.dequeue());
     }
-    modelManager->addEvent(typedEvent.event);
+    forwardEvents(typedEvent.event);
     return typeIndex;
 }
 
+void QmlProfilerTraceClientPrivate::forwardEvents(const QmlEvent &last)
+{
+    while (!pendingDebugMessages.isEmpty()
+           && pendingDebugMessages.front().timestamp() <= last.timestamp()) {
+         modelManager->addEvent(pendingDebugMessages.dequeue());
+    }
+    modelManager->addEvent(last);
+}
+
 void QmlProfilerTraceClientPrivate::processCurrentEvent()
 {
     // RangeData and RangeLocation always apply to the range on the top of the stack. Furthermore,
@@ -142,8 +153,8 @@ void QmlProfilerTraceClientPrivate::processCurrentEvent()
             break;
         currentEvent.event.setTypeIndex(typeIndex);
         while (!pendingMessages.isEmpty())
-            modelManager->addEvent(pendingMessages.dequeue());
-        modelManager->addEvent(currentEvent.event);
+            forwardEvents(pendingMessages.dequeue());
+        forwardEvents(currentEvent.event);
         rangesInProgress.pop();
         break;
     }
@@ -155,11 +166,15 @@ void QmlProfilerTraceClientPrivate::processCurrentEvent()
         if (!rangesInProgress.isEmpty())
             rangesInProgress.top().type.setLocation(currentEvent.type.location());
         break;
+    case DebugMessage:
+        currentEvent.event.setTypeIndex(resolveType(currentEvent));
+        pendingDebugMessages.enqueue(currentEvent.event);
+        break;
     default: {
         int typeIndex = resolveType(currentEvent);
         currentEvent.event.setTypeIndex(typeIndex);
         if (rangesInProgress.isEmpty())
-            modelManager->addEvent(currentEvent.event);
+            forwardEvents(currentEvent.event);
         else
             pendingMessages.enqueue(currentEvent.event);
         break;
@@ -202,6 +217,7 @@ void QmlProfilerTraceClient::clearData()
 {
     d->eventTypeIds.clear();
     d->rangesInProgress.clear();
+    d->pendingDebugMessages.clear();
     if (d->recordedFeatures != 0) {
         d->recordedFeatures = 0;
         emit recordedFeaturesChanged(0);
@@ -246,7 +262,7 @@ void QmlProfilerTraceClient::setRequestedFeatures(quint64 features)
                 [this](QtMsgType type, const QString &text,
                        const QmlDebug::QDebugContextInfo &context)
         {
-            d->updateFeatures(ProfileDebugMessages);
+            QTC_ASSERT(d->updateFeatures(ProfileDebugMessages), return);
             d->currentEvent.event.setTimestamp(context.timestamp > 0 ? context.timestamp : 0);
             d->currentEvent.event.setTypeIndex(-1);
             d->currentEvent.event.setString(text);
@@ -297,6 +313,10 @@ void QmlProfilerTraceClient::messageReceived(const QByteArray &data)
             d->currentEvent.event.setTimestamp(d->maximumTime);
             d->processCurrentEvent();
         }
+        QTC_CHECK(d->pendingMessages.isEmpty());
+        while (!d->pendingDebugMessages.isEmpty())
+            d->modelManager->addEvent(d->pendingDebugMessages.dequeue());
+
         emit complete(d->maximumTime);
     } else if (d->currentEvent.type.message() == Event
                && d->currentEvent.type.detailType() == StartTrace) {