From 84042523f272c1d30247e9329eea21036ff793f4 Mon Sep 17 00:00:00 2001 From: Friedemann Kleint Date: Thu, 29 Oct 2015 10:20:52 +0100 Subject: [PATCH] Testlib: Output total test time in plain text logger. This makes it easier to spot slow tests. Produces: Totals: 314 passed, 0 failed, 0 skipped, 0 blacklisted, 137ms ********* Finished testing of tst_QStringRef ********* Task-number: QTBUG-38890 Change-Id: Iaee4dd677fd8f18b82f7c9c4934eb5b1119ade43 Reviewed-by: Frederik Gladhorn --- src/testlib/qplaintestlogger.cpp | 9 +++++---- tests/auto/testlib/selftests/tst_selftests.cpp | 4 ++++ 2 files changed, 9 insertions(+), 4 deletions(-) diff --git a/src/testlib/qplaintestlogger.cpp b/src/testlib/qplaintestlogger.cpp index d820e87ccb9..80b93886bbe 100644 --- a/src/testlib/qplaintestlogger.cpp +++ b/src/testlib/qplaintestlogger.cpp @@ -348,16 +348,17 @@ void QPlainTestLogger::startLogging() void QPlainTestLogger::stopLogging() { char buf[1024]; + const int timeMs = qRound(QTestLog::msecsTotalTime()); if (QTestLog::verboseLevel() < 0) { - qsnprintf(buf, sizeof(buf), "Totals: %d passed, %d failed, %d skipped, %d blacklisted\n", + qsnprintf(buf, sizeof(buf), "Totals: %d passed, %d failed, %d skipped, %d blacklisted, %dms\n", QTestLog::passCount(), QTestLog::failCount(), - QTestLog::skipCount(), QTestLog::blacklistCount()); + QTestLog::skipCount(), QTestLog::blacklistCount(), timeMs); } else { qsnprintf(buf, sizeof(buf), - "Totals: %d passed, %d failed, %d skipped, %d blacklisted\n" + "Totals: %d passed, %d failed, %d skipped, %d blacklisted, %dms\n" "********* Finished testing of %s *********\n", QTestLog::passCount(), QTestLog::failCount(), - QTestLog::skipCount(), QTestLog::blacklistCount(), + QTestLog::skipCount(), QTestLog::blacklistCount(), timeMs, QTestResult::currentTestObjectName()); } outputMessage(buf); diff --git a/tests/auto/testlib/selftests/tst_selftests.cpp b/tests/auto/testlib/selftests/tst_selftests.cpp index 63c48fc8094..389cb65c0b3 100644 --- a/tests/auto/testlib/selftests/tst_selftests.cpp +++ b/tests/auto/testlib/selftests/tst_selftests.cpp @@ -775,6 +775,10 @@ void tst_Selftests::doRunSubTest(QString const& subdir, QStringList const& logge QRegularExpressionMatch match = durationRegExp.match(line); QVERIFY2(match.hasMatch(), qPrintable(QString::fromLatin1("Invalid Duration tag at line %1 (%2): '%3'") .arg(i).arg(loggers.at(n), output))); + } else if (line.startsWith("Totals:")) { + const int lastCommaPos = line.lastIndexOf(','); + if (lastCommaPos > 0) + line.truncate(lastCommaPos); // Plain text logger: strip time (", 2323dms"). } else { QVERIFY2(output == expected, qPrintable(QString::fromLatin1("Mismatch at line %1 (%2, %3):\n'%4'\n !=\n'%5'")