Testlib: Output function / total time along with crash dump.

Previously, only QXmlTestLogger had timers to take elapsed times
and log them. Move those into class QTestLog for access by
the loggers and output the times in the crash dump to make it
easier to spot hangs/recursion crashes.

Produces:

QFATAL : foo() Received signal 11
         Function time: 22ms Total time: 23ms

A crash occurred in ...
Function time: 24ms Total time: 26ms

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

2 files changed, 21 insertions, 5 deletions

diff --git a/tests/auto/testlib/selftests/expected_crashes_3.txt b/tests/auto/testlib/selftests/expected_crashes_3.txt
index 57c3ddc2ba..0e3f60dd1b 100644
--- a/tests/auto/testlib/selftests/expected_crashes_3.txt
+++ b/tests/auto/testlib/selftests/expected_crashes_3.txt
@@ -2,6 +2,7 @@
 Config: Using QtTest library @INSERT_QT_VERSION_HERE@, Qt @INSERT_QT_VERSION_HERE@
 PASS   : tst_Crashes::initTestCase()
 QFATAL : tst_Crashes::crash() Received signal 11
+         Function time: ms Total time: ms
 FAIL!  : tst_Crashes::crash() Received a fatal error.
    Loc: [Unknown file(0)]
 Totals: 1 passed, 1 failed, 0 skipped, 0 blacklisted
diff --git a/tests/auto/testlib/selftests/tst_selftests.cpp b/tests/auto/testlib/selftests/tst_selftests.cpp
index 11de65c3c0..63c48fc809 100644
--- a/tests/auto/testlib/selftests/tst_selftests.cpp
+++ b/tests/auto/testlib/selftests/tst_selftests.cpp
@@ -626,13 +626,28 @@ void tst_Selftests::doRunSubTest(QString const& subdir, QStringList const& logge
 
     for (int n = 0; n < loggers.count(); ++n) {
         QString logger = loggers[n];
-#if defined(Q_OS_WIN)
-        if (n == 0 && subdir == QLatin1String("crashes")) { // Remove stack trace which is output to stdout.
-            const int exceptionLogStart = actualOutputs.first().indexOf("A crash occurred in ");
+        if (n == 0 && subdir == QLatin1String("crashes")) {
+            QByteArray &actual = actualOutputs[0];
+#ifndef Q_OS_WIN
+             // Remove digits of times to match the expected file.
+            const QLatin1String timePattern("Function time:");
+            int timePos = actual.indexOf(timePattern);
+            if (timePos >= 0) {
+                timePos += timePattern.size();
+                const int nextLinePos = actual.indexOf('\n', timePos);
+                for (int c = (nextLinePos != -1 ? nextLinePos : actual.size()) - 1; c >= timePos; --c) {
+                    if (actual.at(c) >= '0' && actual.at(c) <= '9')
+                        actual.remove(c, 1);
+                }
+            }
+#else // !Q_OS_WIN
+            // Remove stack trace which is output to stdout.
+            const int exceptionLogStart = actual.indexOf("A crash occurred in ");
             if (exceptionLogStart >= 0)
-                actualOutputs[0].truncate(exceptionLogStart);
-        }
+                actual.truncate(exceptionLogStart);
 #endif // Q_OS_WIN
+        }
+
         QList<QByteArray> res = splitLines(actualOutputs[n]);
         const QString expectedFileName = expectedFileNameFromTest(subdir, logger);
         QList<QByteArray> exp = expectedResult(expectedFileName);