Extend QDebugMessageService

Add category and timestamp, and allow synchronizing the timestamps with
QQmlProfilerService.

Change-Id: I8dc67e43e1087e231167fc4cfdfb5f659e00c5b2
Reviewed-by: Simon Hausmann <simon.hausmann@theqtcompany.com>

7 files changed, 40 insertions, 8 deletions

diff --git a/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.cpp b/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.cpp
index 6300b2b9c6..6880417f1d 100644
--- a/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.cpp
+++ b/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.cpp
@@ -49,6 +49,7 @@ QDebugMessageServiceImpl::QDebugMessageServiceImpl(QObject *parent) :
 {
     // don't execute stateChanged() in parallel
     QMutexLocker lock(&initMutex);
+    timer.start();
     if (state() == Enabled) {
         oldMsgHandler = qInstallMessageHandler(DebugMessageHandler);
         prevState = Enabled;
@@ -64,8 +65,8 @@ void QDebugMessageServiceImpl::sendDebugMessage(QtMsgType type,
     //only if a client is connected to it.
     QQmlDebugPacket ws;
     ws << QByteArray("MESSAGE") << type << buf.toUtf8();
-    ws << QString::fromLatin1(ctxt.file).toUtf8();
-    ws << ctxt.line << QString::fromLatin1(ctxt.function).toUtf8();
+    ws << QByteArray(ctxt.file) << ctxt.line << QByteArray(ctxt.function);
+    ws << QByteArray(ctxt.category) << timer.nsecsElapsed();
 
     emit messageToClient(name(), ws.data());
     if (oldMsgHandler)
@@ -89,4 +90,10 @@ void QDebugMessageServiceImpl::stateChanged(State state)
     prevState = state;
 }
 
+void QDebugMessageServiceImpl::synchronizeTime(const QElapsedTimer &otherTimer)
+{
+    QMutexLocker lock(&initMutex);
+    timer = otherTimer;
+}
+
 QT_END_NAMESPACE
diff --git a/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.h b/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.h
index 04f5966dd7..a5ff1fc3d7 100644
--- a/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.h
+++ b/src/plugins/qmltooling/qmldbg_debugger/qdebugmessageservice.h
@@ -49,6 +49,7 @@
 
 #include <QtCore/qlogging.h>
 #include <QtCore/qmutex.h>
+#include <QtCore/qelapsedtimer.h>
 
 QT_BEGIN_NAMESPACE
 
@@ -60,8 +61,8 @@ class QDebugMessageServiceImpl : public QDebugMessageService
 public:
     QDebugMessageServiceImpl(QObject *parent = 0);
 
-    void sendDebugMessage(QtMsgType type, const QMessageLogContext &ctxt,
-                          const QString &buf);
+    void sendDebugMessage(QtMsgType type, const QMessageLogContext &ctxt, const QString &buf);
+    void synchronizeTime(const QElapsedTimer &otherTimer);
 
 protected:
     void stateChanged(State);
@@ -72,6 +73,7 @@ private:
     QtMessageHandler oldMsgHandler;
     QQmlDebugService::State prevState;
     QMutex initMutex;
+    QElapsedTimer timer;
 };
 
 QT_END_NAMESPACE
diff --git a/src/plugins/qmltooling/qmldbg_profiler/qqmlprofilerservice.cpp b/src/plugins/qmltooling/qmldbg_profiler/qqmlprofilerservice.cpp
index e05717f8eb..462bd5e394 100644
--- a/src/plugins/qmltooling/qmldbg_profiler/qqmlprofilerservice.cpp
+++ b/src/plugins/qmltooling/qmldbg_profiler/qqmlprofilerservice.cpp
@@ -215,6 +215,12 @@ void QQmlProfilerServiceImpl::startProfiling(QJSEngine *engine, quint64 features
 {
     QMutexLocker lock(&m_configMutex);
 
+    if (features & static_cast<quint64>(1) << ProfileDebugMessages) {
+        if (QDebugMessageService *messageService =
+                QQmlDebugConnector::instance()->service<QDebugMessageService>())
+            messageService->synchronizeTime(m_timer);
+    }
+
     QQmlDebugPacket d;
 
     d << m_timer.nsecsElapsed() << (int)Event << (int)StartTrace;
diff --git a/src/qml/debugger/qqmldebugserviceinterfaces_p.h b/src/qml/debugger/qqmldebugserviceinterfaces_p.h
index 59712ee8ea..1b45392680 100644
--- a/src/qml/debugger/qqmldebugserviceinterfaces_p.h
+++ b/src/qml/debugger/qqmldebugserviceinterfaces_p.h
@@ -133,6 +133,8 @@ class Q_QML_PRIVATE_EXPORT QDebugMessageService : protected QQmlDebugService
 public:
     static const QString s_key;
 
+    virtual void synchronizeTime(const QElapsedTimer &otherTimer) = 0;
+
 protected:
     friend class QQmlDebugConnector;
 
diff --git a/src/qml/debugger/qqmlprofilerdefinitions_p.h b/src/qml/debugger/qqmlprofilerdefinitions_p.h
index f87df8cfe5..ce708132f8 100644
--- a/src/qml/debugger/qqmlprofilerdefinitions_p.h
+++ b/src/qml/debugger/qqmlprofilerdefinitions_p.h
@@ -134,6 +134,7 @@ struct QQmlProfilerDefinitions {
         ProfileBinding,
         ProfileHandlingSignal,
         ProfileInputEvents,
+        ProfileDebugMessages,
 
         MaximumProfileFeature
     };
diff --git a/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp b/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
index 0289a6d725..75c301f958 100644
--- a/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
+++ b/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
@@ -79,15 +79,19 @@ struct LogEntry {
     int line;
     QString file;
     QString function;
+    QString category;
 
-    QString toString() const { return QString::number(type) + ": " + message; }
+    QString toString() const
+    {
+        return QString::number(type) + ": " + message + " (" + category + ")";
+    }
 };
 
 bool operator==(const LogEntry &t1, const LogEntry &t2)
 {
     return t1.type == t2.type && t1.message == t2.message
             && t1.line == t2.line && t1.file == t2.file
-            && t1.function == t2.function;
+            && t1.function == t2.function && t1.category == t2.category;
 }
 
 class QQmlDebugMsgClient : public QQmlDebugClient
@@ -129,17 +133,21 @@ void QQmlDebugMsgClient::messageReceived(const QByteArray &data)
         QByteArray message;
         QByteArray file;
         QByteArray function;
+        QByteArray category;
+        qint64 timestamp;
         int line;
-        ds >> type >> message >> file >> line >> function;
+        ds >> type >> message >> file >> line >> function >> category >> timestamp;
         QVERIFY(ds.atEnd());
 
         QVERIFY(type >= QtDebugMsg);
         QVERIFY(type <= QtFatalMsg);
+        QVERIFY(timestamp > 0);
 
         LogEntry entry((QtMsgType)type, QString::fromUtf8(message));
         entry.line = line;
         entry.file = QString::fromUtf8(file);
         entry.function = QString::fromUtf8(function);
+        entry.category = QString::fromUtf8(category);
         logBuffer << entry;
         emit debugOutput();
     } else {
@@ -223,10 +231,12 @@ void tst_QDebugMessageService::retrieveDebugOutput()
     entry1.line = 40;
     entry1.file = path;
     entry1.function = QLatin1String("onCompleted");
+    entry1.category = QLatin1String("qml");
     LogEntry entry2(QtDebugMsg, QLatin1String("console.count: 1"));
     entry2.line = 41;
     entry2.file = path;
     entry2.function = QLatin1String("onCompleted");
+    entry2.category = QLatin1String("default");
 
     QVERIFY(m_client->logBuffer.contains(entry1));
     QVERIFY(m_client->logBuffer.contains(entry2));
diff --git a/tools/qmlprofiler/qmlprofilerapplication.cpp b/tools/qmlprofiler/qmlprofilerapplication.cpp
index cd34cd603f..455faeb1c0 100644
--- a/tools/qmlprofiler/qmlprofilerapplication.cpp
+++ b/tools/qmlprofiler/qmlprofilerapplication.cpp
@@ -71,9 +71,13 @@ static const char *features[] = {
     "creating",
     "binding",
     "handlingsignal",
-    "inputevents"
+    "inputevents",
+    "debugmessages"
 };
 
+Q_STATIC_ASSERT(sizeof(features) ==
+                QQmlProfilerDefinitions::MaximumProfileFeature * sizeof(char *));
+
 QmlProfilerApplication::QmlProfilerApplication(int &argc, char **argv) :
     QCoreApplication(argc, argv),
     m_runMode(LaunchMode),