Debugger: Improve output of autotests

Change-Id: Ib938d2f39d8a0928c257ef923df5d5fcfa85c4cf
Reviewed-by: Aurindam Jana <aurindam.jana@nokia.com>

9 files changed, 101 insertions, 50 deletions

diff --git a/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp b/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
index 8473774ae6..5df196cb24 100644
--- a/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
+++ b/tests/auto/qml/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp
@@ -183,20 +183,24 @@ void tst_QDebugMessageService::init()
     m_client = new QQmlDebugMsgClient(m_connection);
 
     m_process->start(QStringList() << QLatin1String(NORMALMODE) << QQmlDataTest::instance()->testFile(QMLFILE));
-    if (!m_process->waitForSessionStart()) {
-        QFAIL(QString("Could not launch app. Application output: \n%1").arg(m_process->output()).toAscii());
-    }
+    QVERIFY2(m_process->waitForSessionStart(),
+             "Could not launch application, or did not get 'Waiting for connection'.");
 
     m_connection->connectToHost("127.0.0.1", 3777);
     QVERIFY(m_connection->waitForConnected());
 
-    QVERIFY(QQmlDebugTest::waitForSignal(m_client, SIGNAL(enabled())));
+    if (m_client->state() != QQmlDebugClient::Enabled)
+        QQmlDebugTest::waitForSignal(m_client, SIGNAL(enabled()));
+
+    QVERIFY(m_client->state() == QQmlDebugClient::Enabled);
 }
 
 void tst_QDebugMessageService::cleanup()
 {
-    if (QTest::currentTestFailed())
-        qDebug() << m_process->output();
+    if (QTest::currentTestFailed()) {
+        qDebug() << "Process State:" << m_process->state();
+        qDebug() << "Application Output:" << m_process->output();
+    }
     if (m_process)
         delete m_process;
 
diff --git a/tests/auto/qml/debugger/qqmldebugclient/tst_qqmldebugclient.cpp b/tests/auto/qml/debugger/qqmldebugclient/tst_qqmldebugclient.cpp
index 036641cdfc..1ff45758a9 100644
--- a/tests/auto/qml/debugger/qqmldebugclient/tst_qqmldebugclient.cpp
+++ b/tests/auto/qml/debugger/qqmldebugclient/tst_qqmldebugclient.cpp
@@ -153,7 +153,6 @@ void tst_QQmlDebugClient::parallelConnect()
     QTest::ignoreMessage(QtWarningMsg, "QML Debugger: Another client is already connected.");
     // will connect & immediately disconnect
     connection2.connectToHost("127.0.0.1", PORT);
-    QVERIFY(connection2.waitForConnected());
     QTRY_COMPARE(connection2.state(), QAbstractSocket::UnconnectedState);
     QVERIFY(m_conn->isConnected());
 }
diff --git a/tests/auto/qml/debugger/qqmldebugjs/tst_qqmldebugjs.cpp b/tests/auto/qml/debugger/qqmldebugjs/tst_qqmldebugjs.cpp
index b93be16e0e..8275f18b30 100644
--- a/tests/auto/qml/debugger/qqmldebugjs/tst_qqmldebugjs.cpp
+++ b/tests/auto/qml/debugger/qqmldebugjs/tst_qqmldebugjs.cpp
@@ -1011,18 +1011,29 @@ bool tst_QQmlDebugJS::init(const QString &qmlFile, bool blockMode)
         process->start(QStringList() << QLatin1String(NORMALMODE) << testFile(qmlFile));
 
     if (!process->waitForSessionStart()) {
+        qDebug() << "could not launch application, or did not get 'Waiting for connection'.";
         return false;
     }
 
     connection->connectToHost("127.0.0.1", 3771);
-    if (!connection->waitForConnected())
+    if (!connection->waitForConnected()) {
+        qDebug() << "could not connect to host!";
         return false;
+    }
+
+    if (client->state() == QQmlDebugClient::Enabled)
+        return true;
 
     return QQmlDebugTest::waitForSignal(client, SIGNAL(enabled()));
 }
 
 void tst_QQmlDebugJS::cleanup()
 {
+    if (QTest::currentTestFailed()) {
+        qDebug() << "Process State:" << process->state();
+        qDebug() << "Application Output:" << process->output();
+    }
+
     if (process) {
         process->stop();
         delete process;
diff --git a/tests/auto/qml/debugger/qqmlinspector/tst_qqmlinspector.cpp b/tests/auto/qml/debugger/qqmlinspector/tst_qqmlinspector.cpp
index 39e0f0d3e5..e033700aac 100644
--- a/tests/auto/qml/debugger/qqmlinspector/tst_qqmlinspector.cpp
+++ b/tests/auto/qml/debugger/qqmlinspector/tst_qqmlinspector.cpp
@@ -150,9 +150,8 @@ void tst_QQmlInspector::init()
 
     m_process = new QQmlDebugProcess(executable);
     m_process->start(QStringList() << argument);
-    if (!m_process->waitForSessionStart()) {
-        QFAIL(QString("Could not launch app '%1'.\nApplication output:\n%2").arg(executable, m_process->output()).toAscii());
-    }
+    QVERIFY2(m_process->waitForSessionStart(),
+             "Could not launch application, or did not get 'Waiting for connection'.");
 
     QQmlDebugConnection *m_connection = new QQmlDebugConnection();
     m_client = new QQmlInspectorClient(m_connection);
@@ -162,6 +161,10 @@ void tst_QQmlInspector::init()
 
 void tst_QQmlInspector::cleanup()
 {
+    if (QTest::currentTestFailed()) {
+        qDebug() << "Process State:" << m_process->state();
+        qDebug() << "Application Output:" << m_process->output();
+    }
     delete m_process;
     delete m_connection;
     delete m_client;
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
index 972c3ac6f4..bb17d1d1f4 100644
--- a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
@@ -242,11 +242,7 @@ void tst_QQmlProfilerService::connect(bool block, const QString &testFile)
 
     m_process = new QQmlDebugProcess(executable);
     m_process->start(QStringList() << arguments);
-    if (!m_process->waitForSessionStart()) {
-        QString failMsg = QString("Could not launch app '%1'.\nApplication output:\n%2").arg(
-                    executable, m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(m_process->waitForSessionStart(), "Could not launch application, or did not get 'Waiting for connection'.");
 
     QQmlDebugConnection *m_connection = new QQmlDebugConnection();
     m_client = new QQmlProfilerClient(m_connection);
@@ -256,6 +252,10 @@ void tst_QQmlProfilerService::connect(bool block, const QString &testFile)
 
 void tst_QQmlProfilerService::cleanup()
 {
+    if (QTest::currentTestFailed()) {
+        qDebug() << "Process State:" << m_process->state();
+        qDebug() << "Application Output:" << m_process->output();
+    }
     delete m_process;
     delete m_connection;
     delete m_client;
@@ -268,11 +268,7 @@ void tst_QQmlProfilerService::blockingConnectWithTraceEnabled()
 
     m_client->setTraceState(true);
     m_client->setTraceState(false);
-    if (!QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()))) {
-        QString failMsg
-                = QString("No trace received in time. App output: \n%1\n").arg(m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())), "No trace received in time.");
 
     QVERIFY(m_client->traceMessages.count());
     // must start with "StartTrace"
@@ -292,11 +288,7 @@ void tst_QQmlProfilerService::blockingConnectWithTraceDisabled()
     m_client->setTraceState(false);
     m_client->setTraceState(true);
     m_client->setTraceState(false);
-    if (!QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()))) {
-        QString failMsg
-                = QString("No trace received in time. App output: \n%1\n").arg(m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())), "No trace received in time.");
 
     QVERIFY(m_client->traceMessages.count());
 
@@ -316,11 +308,7 @@ void tst_QQmlProfilerService::nonBlockingConnect()
 
     m_client->setTraceState(true);
     m_client->setTraceState(false);
-    if (!QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()))) {
-        QString failMsg
-                = QString("No trace received in time. App output: \n%1\n").arg(m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())), "No trace received in time.");
 
     // must start with "StartTrace"
     QCOMPARE(m_client->traceMessages.first().messageType, (int)QQmlProfilerClient::Event);
@@ -338,11 +326,7 @@ void tst_QQmlProfilerService::profileOnExit()
 
     m_client->setTraceState(true);
 
-    if (!QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()))) {
-        QString failMsg
-                = QString("No trace received in time. App output: \n%1\n").arg(m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())), "No trace received in time.");
 
     // must start with "StartTrace"
     QCOMPARE(m_client->traceMessages.first().messageType, (int)QQmlProfilerClient::Event);
diff --git a/tests/auto/qml/debugger/qv8profilerservice/tst_qv8profilerservice.cpp b/tests/auto/qml/debugger/qv8profilerservice/tst_qv8profilerservice.cpp
index d482e81009..0c35d1064c 100644
--- a/tests/auto/qml/debugger/qv8profilerservice/tst_qv8profilerservice.cpp
+++ b/tests/auto/qml/debugger/qv8profilerservice/tst_qv8profilerservice.cpp
@@ -220,7 +220,7 @@ bool tst_QV8ProfilerService::connect(bool block, const QString &testFile,
     m_process = new QQmlDebugProcess(executable);
     m_process->start(QStringList() << arguments);
     if (!m_process->waitForSessionStart()) {
-        *error = QLatin1String("Could not launch app ") + executable;
+        *error = QLatin1String("Could not launch application, or did not get 'Waiting for connection'.");
         return false;
     }
 
@@ -234,9 +234,10 @@ bool tst_QV8ProfilerService::connect(bool block, const QString &testFile,
 
 void tst_QV8ProfilerService::cleanup()
 {
-    if (QTest::currentTestFailed())
+    if (QTest::currentTestFailed()) {
+        qDebug() << "Process State:" << m_process->state();
         qDebug() << "Application Output:" << m_process->output();
-
+    }
     delete m_client;
     delete m_process;
     delete m_connection;
@@ -265,11 +266,8 @@ void tst_QV8ProfilerService::blockingConnectWithTraceDisabled()
     QTRY_COMPARE(m_client->state(), QQmlDebugClient::Enabled);
 
     m_client->stopProfiling("");
-    if (QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()), 1000)) {
-        QString failMsg
-                = QString("Unexpected trace received! App output: %1\n\n").arg(m_process->output());
-        QFAIL(qPrintable(failMsg));
-    }
+    QVERIFY2(!QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete()), 1000),
+             "Unexpected trace received.");
     m_client->startProfiling("");
     m_client->stopProfiling("");
     QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())),
diff --git a/tests/auto/qml/debugger/shared/debugutil.cpp b/tests/auto/qml/debugger/shared/debugutil.cpp
index eea777f09d..a6b24ae2b0 100644
--- a/tests/auto/qml/debugger/shared/debugutil.cpp
+++ b/tests/auto/qml/debugger/shared/debugutil.cpp
@@ -99,13 +99,36 @@ QQmlDebugProcess::~QQmlDebugProcess()
     stop();
 }
 
+QString QQmlDebugProcess::state()
+{
+    QString stateStr;
+    switch (m_process.state()) {
+    case QProcess::NotRunning: {
+        stateStr = "not running";
+        if (m_process.exitStatus() == QProcess::CrashExit)
+            stateStr += " (crashed!)";
+        else
+            stateStr += ", return value" + m_process.exitCode();
+        break;
+    }
+    case QProcess::Starting: stateStr = "starting"; break;
+    case QProcess::Running: stateStr = "running"; break;
+    }
+    return stateStr;
+}
+
 void QQmlDebugProcess::start(const QStringList &arguments)
 {
     m_mutex.lock();
     m_process.setEnvironment(m_environment);
     m_process.start(m_executable, arguments);
-    m_process.waitForStarted();
-    m_timer.start();
+    if (!m_process.waitForStarted()) {
+        qWarning() << "QML Debug Client: Could not launch app " << m_executable
+                   << ": " << m_process.errorString();
+        m_eventLoop.quit();
+    } else {
+        m_timer.start();
+    }
     m_mutex.unlock();
 }
 
@@ -120,7 +143,7 @@ void QQmlDebugProcess::stop()
 void QQmlDebugProcess::timeout()
 {
     qWarning() << "Timeout while waiting for QML debugging messages "
-                  "in application output";
+                  "in application output. Process is in state" << m_process.state() << ".";
     m_eventLoop.quit();
 }
 
@@ -162,12 +185,14 @@ void QQmlDebugProcess::processAppOutput()
 
         if (line.startsWith("QML Debugger:")) {
             if (line.contains("Waiting for connection ")) {
+                m_timer.stop();
                 m_started = true;
                 m_eventLoop.quit();
                 continue;
             }
             if (line.contains("Unable to listen")) {
                 qWarning() << "App was unable to bind to port!";
+                m_timer.stop();
                 m_eventLoop.quit();
                 continue;
             }
diff --git a/tests/auto/qml/debugger/shared/debugutil_p.h b/tests/auto/qml/debugger/shared/debugutil_p.h
index 0b3b8ec2a6..fa65230542 100644
--- a/tests/auto/qml/debugger/shared/debugutil_p.h
+++ b/tests/auto/qml/debugger/shared/debugutil_p.h
@@ -87,6 +87,8 @@ public:
     QQmlDebugProcess(const QString &executable);
     ~QQmlDebugProcess();
 
+    QString state();
+
     void setEnvironment(const QStringList &environment);
 
     void start(const QStringList &arguments);
diff --git a/tests/auto/qml/debugger/shared/qqmldebugclient.cpp b/tests/auto/qml/debugger/shared/qqmldebugclient.cpp
index 50feb950fb..f0fa499b9f 100644
--- a/tests/auto/qml/debugger/shared/qqmldebugclient.cpp
+++ b/tests/auto/qml/debugger/shared/qqmldebugclient.cpp
@@ -43,7 +43,9 @@
 #include "../../../../../src/plugins/qmltooling/shared/qpacketprotocol.h"
 
 #include <QtCore/qdebug.h>
+#include <QtCore/qeventloop.h>
 #include <QtCore/qstringlist.h>
+#include <QtCore/qtimer.h>
 #include <QtNetwork/qnetworkproxy.h>
 
 const int protocolVersion = 1;
@@ -67,6 +69,8 @@ public:
     QQmlDebugConnection *q;
     QPacketProtocol *protocol;
     QIODevice *device;
+    QEventLoop handshakeEventLoop;
+    QTimer handshakeTimer;
 
     bool gotHello;
     QHash <QString, float> serverPlugins;
@@ -79,6 +83,7 @@ public Q_SLOTS:
     void connected();
     void readyRead();
     void deviceAboutToClose();
+    void handshakeTimeout();
 };
 
 QQmlDebugConnectionPrivate::QQmlDebugConnectionPrivate(QQmlDebugConnection *c)
@@ -87,6 +92,10 @@ QQmlDebugConnectionPrivate::QQmlDebugConnectionPrivate(QQmlDebugConnection *c)
     protocol = new QPacketProtocol(q, this);
     QObject::connect(c, SIGNAL(connected()), this, SLOT(connected()));
     QObject::connect(protocol, SIGNAL(readyRead()), this, SLOT(readyRead()));
+
+    handshakeTimer.setSingleShot(true);
+    handshakeTimer.setInterval(3000);
+    connect(&handshakeTimer, SIGNAL(timeout()), SLOT(handshakeTimeout()));
 }
 
 void QQmlDebugConnectionPrivate::advertisePlugins()
@@ -158,6 +167,9 @@ void QQmlDebugConnectionPrivate::readyRead()
                 newState = QQmlDebugClient::Enabled;
             iter.value()->stateChanged(newState);
         }
+
+        handshakeTimer.stop();
+        handshakeEventLoop.quit();
     }
 
     while (protocol->packetsAvailable()) {
@@ -226,6 +238,14 @@ void QQmlDebugConnectionPrivate::deviceAboutToClose()
     q->QIODevice::close();
 }
 
+void QQmlDebugConnectionPrivate::handshakeTimeout()
+{
+    if (!gotHello) {
+        qWarning() << "Qml Debug Client: Did not get handshake answer in time";
+        handshakeEventLoop.quit();
+    }
+}
+
 QQmlDebugConnection::QQmlDebugConnection(QObject *parent)
     : QIODevice(parent), d(new QQmlDebugConnectionPrivate(this))
 {
@@ -282,9 +302,14 @@ void QQmlDebugConnection::close()
 bool QQmlDebugConnection::waitForConnected(int msecs)
 {
     QAbstractSocket *socket = qobject_cast<QAbstractSocket*>(d->device);
-    if (socket)
-        return socket->waitForConnected(msecs);
-    return false;
+    if (!socket)
+        return false;
+    if (!socket->waitForConnected(msecs))
+        return false;
+    // wait for handshake
+    d->handshakeTimer.start();
+    d->handshakeEventLoop.exec();
+    return d->gotHello;
 }
 
 QAbstractSocket::SocketState QQmlDebugConnection::state() const