From 837967c839f6cb33ba7cd355d9fc5835715ba93c Mon Sep 17 00:00:00 2001 From: Tim Blechmann Date: Thu, 31 Oct 2024 09:29:12 +0800 Subject: [PATCH] Testlib: extend lifetime of loggers during message handler QTest injects a message handler to redirect messages to the loggers and resets the message handler on shutdown. This currently causes a race condition if the application thread resets the message handler while at the same time it is called by a worker thread: Application Thread Worker Thread qWarn() -> calls messageHandler stopLogging() -> restores message handler stopLogging() -> clears loggers messageHandler accesses loggers This use-after-free scenario can be prevented by extending the lifetime of the message loggers during the invocation of the message handler. Fixes: QTBUG-129722 Fixes: QTBUG-130630 Change-Id: I404145f5e13a0f0e9e7500e7c24900dd31ddc18a Reviewed-by: Thiago Macieira (cherry picked from commit a0303cc7c590ff17fb5b0a5975bff98669e42942) Reviewed-by: Qt Cherry-pick Bot --- src/testlib/qtestlog.cpp | 157 +++++++++++++++++++++++++++------------ src/testlib/qtestlog_p.h | 2 +- 2 files changed, 111 insertions(+), 48 deletions(-) diff --git a/src/testlib/qtestlog.cpp b/src/testlib/qtestlog.cpp index e5781fbeaae..bdaeb21ac71 100644 --- a/src/testlib/qtestlog.cpp +++ b/src/testlib/qtestlog.cpp @@ -30,14 +30,15 @@ #include #endif -#include - #include #include #include -#include +#include +#include +#include #include +#include QT_BEGIN_NAMESPACE @@ -71,7 +72,71 @@ static void saveCoverageTool(const char * appname, bool testfailed, bool install Q_CONSTINIT static QElapsedTimer elapsedFunctionTime; Q_CONSTINIT static QElapsedTimer elapsedTotalTime; -#define FOREACH_TEST_LOGGER for (const auto &logger : std::as_const(*QTest::loggers())) +namespace { +class LoggerRegistry +{ + using LoggersContainer = std::vector>; + using SharedLoggersContainer = std::shared_ptr; + +public: + void addLogger(std::unique_ptr logger) + { + // read/update/clone + const SharedLoggersContainer currentLoggers = load(); + SharedLoggersContainer newLoggers = currentLoggers + ? std::make_shared(*currentLoggers) + : std::make_shared(); + newLoggers->emplace_back(std::move(logger)); + store(std::move(newLoggers)); + } + + void clear() { store(SharedLoggersContainer{}); } + + auto allLoggers() const + { + struct LoggersRange + { + const SharedLoggersContainer loggers; + + auto begin() const + { + return loggers ? loggers->cbegin() : LoggersContainer::const_iterator{}; + } + auto end() const + { + return loggers ? loggers->cend() : LoggersContainer::const_iterator{}; + } + bool isEmpty() const { return loggers ? loggers->empty() : true; } + }; + + const SharedLoggersContainer currentLoggers = load(); + return LoggersRange{ + std::move(currentLoggers), + }; + } + +private: +#if __cpp_lib_atomic_shared_ptr + SharedLoggersContainer load() const { return loggers.load(std::memory_order_relaxed); } + void store(SharedLoggersContainer newLoggers) + { + loggers.store(std::move(newLoggers), std::memory_order_relaxed); + } + std::atomic loggers; +#else + SharedLoggersContainer load() const + { + return std::atomic_load_explicit(&loggers, std::memory_order_relaxed); + } + void store(SharedLoggersContainer newLoggers) + { + std::atomic_store_explicit(&loggers, std::move(newLoggers), std::memory_order_relaxed); + } + SharedLoggersContainer loggers; +#endif +}; + +} // namespace namespace QTest { @@ -144,7 +209,7 @@ namespace QTest { static std::vector failOnWarningList; - Q_GLOBAL_STATIC(std::vector>, loggers) + Q_GLOBAL_STATIC(LoggerRegistry, loggers) static int verbosity = 0; static int maxWarnings = 2002; @@ -208,9 +273,11 @@ namespace QTest { { static QBasicAtomicInt counter = Q_BASIC_ATOMIC_INITIALIZER(QTest::maxWarnings); - if (!QTestLog::hasLoggers()) { - // the message handler may be called from a worker thread, after the main thread stopped logging. - // Forwarding to original message handler to avoid swallowing the message + auto loggerCapture = loggers->allLoggers(); + + if (loggerCapture.isEmpty()) { + // the message handler may be called from a worker thread, after the main thread stopped + // logging. Forwarding to original message handler to avoid swallowing the message Q_ASSERT(oldMessageHandler); oldMessageHandler(type, context, message); return; @@ -229,19 +296,20 @@ namespace QTest { return; if (!counter.deref()) { - FOREACH_TEST_LOGGER { + for (auto &logger : loggerCapture) logger->addMessage(QAbstractTestLogger::Warn, - QStringLiteral("Maximum amount of warnings exceeded. Use -maxwarnings to override.")); - } + QStringLiteral("Maximum amount of warnings exceeded. Use " + "-maxwarnings to override.")); + return; } } - FOREACH_TEST_LOGGER + for (auto &logger : loggerCapture) logger->addMessage(type, context, message); if (type == QtFatalMsg) { - /* Right now, we're inside the custom message handler and we're + /* Right now, we're inside the custom message handler and we're * being qt_message_output in qglobal.cpp. After we return from * this function, it will proceed with calling exit() and abort() * and hence crash. Therefore, we call these logging functions such @@ -261,7 +329,7 @@ void QTestLog::enterTestFunction(const char* function) QTEST_ASSERT(function); - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->enterTestFunction(function); } @@ -269,7 +337,7 @@ void QTestLog::enterTestData(QTestData *data) { QTEST_ASSERT(data); - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->enterTestData(data); } @@ -290,7 +358,7 @@ void QTestLog::leaveTestFunction() if (printAvailableTags) return; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->leaveTestFunction(); } @@ -308,7 +376,7 @@ void QTestLog::printUnhandledIgnoreMessages() list->pattern.toRegularExpression().pattern()); #endif } - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addMessage(QAbstractTestLogger::Info, message); list = list->next; @@ -344,7 +412,7 @@ void QTestLog::addPass(const char *msg) ++QTest::passes; QTest::currentTestState = QTest::Passed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::Pass, msg); } @@ -364,7 +432,7 @@ void QTestLog::addFail(const char *msg, const char *file, int line) // subsequent failures; they may carry useful information. QTest::currentTestState = QTest::Failed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::Fail, msg, file, line); } @@ -374,7 +442,7 @@ void QTestLog::addXFail(const char *msg, const char *file, int line) // Will be counted in addPass() if we get there. - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::XFail, msg, file, line); } @@ -392,7 +460,7 @@ void QTestLog::addXPass(const char *msg, const char *file, int line) } QTest::currentTestState = QTest::Failed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::XPass, msg, file, line); } @@ -404,7 +472,7 @@ void QTestLog::addBPass(const char *msg) ++QTest::blacklists; // Not passes ? QTest::currentTestState = QTest::Suppressed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::BlacklistedPass, msg); } @@ -422,7 +490,7 @@ void QTestLog::addBFail(const char *msg, const char *file, int line) } QTest::currentTestState = QTest::Suppressed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::BlacklistedFail, msg, file, line); } @@ -440,7 +508,7 @@ void QTestLog::addBXPass(const char *msg, const char *file, int line) } QTest::currentTestState = QTest::Suppressed; - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::BlacklistedXPass, msg, file, line); } @@ -450,7 +518,7 @@ void QTestLog::addBXFail(const char *msg, const char *file, int line) // Will be counted in addBPass() if we get there. - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::BlacklistedXFail, msg, file, line); } @@ -471,13 +539,13 @@ void QTestLog::addSkip(const char *msg, const char *file, int line) // It is up to particular loggers to decide whether to report such // subsequent skips; they may carry useful information. - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addIncident(QAbstractTestLogger::Skip, msg, file, line); } void QTestLog::addBenchmarkResults(const QList &results) { - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addBenchmarkResults(results); } @@ -485,7 +553,7 @@ void QTestLog::startLogging() { elapsedTotalTime.start(); elapsedFunctionTime.start(); - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->startLogging(); QTest::oldMessageHandler = qInstallMessageHandler(QTest::messageHandler); } @@ -493,10 +561,10 @@ void QTestLog::startLogging() void QTestLog::stopLogging() { qInstallMessageHandler(QTest::oldMessageHandler); - FOREACH_TEST_LOGGER { + for (auto &logger : QTest::loggers->allLoggers()) logger->stopLogging(); - } - QTest::loggers()->clear(); + + QTest::loggers->clear(); saveCoverageTool(QTestResult::currentAppName(), failCount() != 0, QTestLog::installedTestCoverage()); } @@ -541,7 +609,7 @@ void QTestLog::addLogger(LogMode mode, const char *filename) } QTEST_ASSERT(logger); - addLogger(logger); + addLogger(std::unique_ptr{ logger }); } /*! @@ -549,18 +617,16 @@ void QTestLog::addLogger(LogMode mode, const char *filename) Adds a new logger to the set of loggers that will be used to report incidents and messages during testing. - - The function takes ownership of the logger. */ -void QTestLog::addLogger(QAbstractTestLogger *logger) +void QTestLog::addLogger(std::unique_ptr logger) { QTEST_ASSERT(logger); - QTest::loggers()->emplace_back(logger); + QTest::loggers()->addLogger(std::move(logger)); } bool QTestLog::hasLoggers() { - return !QTest::loggers()->empty(); + return !QTest::loggers()->allLoggers().isEmpty(); } /*! @@ -570,29 +636,26 @@ bool QTestLog::hasLoggers() */ bool QTestLog::isRepeatSupported() { - FOREACH_TEST_LOGGER { + for (auto &logger : QTest::loggers->allLoggers()) if (!logger->isRepeatSupported()) return false; - } return true; } bool QTestLog::loggerUsingStdout() { - FOREACH_TEST_LOGGER { - if (logger->isLoggingToStdout()) - return true; - } - - return false; + auto loggersCapture = QTest::loggers->allLoggers(); + return q20::ranges::any_of(loggersCapture.begin(), loggersCapture.end(), [](auto &logger) { + return logger->isLoggingToStdout(); + }); } void QTestLog::warn(const char *msg, const char *file, int line) { QTEST_ASSERT(msg); - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addMessage(QAbstractTestLogger::Warn, QString::fromUtf8(msg), file, line); } @@ -600,7 +663,7 @@ void QTestLog::info(const char *msg, const char *file, int line) { QTEST_ASSERT(msg); - FOREACH_TEST_LOGGER + for (auto &logger : QTest::loggers->allLoggers()) logger->addMessage(QAbstractTestLogger::Info, QString::fromUtf8(msg), file, line); } diff --git a/src/testlib/qtestlog_p.h b/src/testlib/qtestlog_p.h index ab5fb593d49..8998a436e5c 100644 --- a/src/testlib/qtestlog_p.h +++ b/src/testlib/qtestlog_p.h @@ -89,7 +89,7 @@ public: static void stopLogging(); static void addLogger(LogMode mode, const char *filename); - static void addLogger(QAbstractTestLogger *logger); + static void addLogger(std::unique_ptr logger); static bool hasLoggers(); static bool isRepeatSupported();