diff --git a/src/test/util/logging.cpp b/src/test/util/logging.cpp index 7debe2b0be479b..2999d90a593533 100644 --- a/src/test/util/logging.cpp +++ b/src/test/util/logging.cpp @@ -12,13 +12,18 @@ #include #include -DebugLogHelper::DebugLogHelper(std::string message, MatchFn match) - : m_message{std::move(message)}, m_match(std::move(match)) +DebugLogHelper::DebugLogHelper(std::string message, MatchFn match, std::optional timeout) + : m_message{std::move(message)}, m_timeout{timeout}, m_match(std::move(match)) { m_print_connection = LogInstance().PushBackCallback( [this](const std::string& s) { - if (m_found) return; - m_found = s.find(m_message) != std::string::npos && m_match(&s); + StdLockGuard lock{m_mutex}; + if (!m_found) { + if (s.find(m_message) != std::string::npos && m_match(&s)) { + m_found = true; + m_cv.notify_all(); + } + } }); noui_test_redirect(); m_receiving_log = true; @@ -26,6 +31,12 @@ DebugLogHelper::DebugLogHelper(std::string message, MatchFn match) DebugLogHelper::~DebugLogHelper() { + { + StdUniqueLock lock{m_mutex}; + if (m_timeout.has_value()) { + m_cv.wait_for(lock, m_timeout.value(), [this]() EXCLUSIVE_LOCKS_REQUIRED(m_mutex) { return m_found; }); + } + } StopReceivingLog(); if (!m_found && m_match(nullptr)) { std::cerr << "Fatal error: expected message not found in the debug log: " << m_message << "\n"; diff --git a/src/test/util/logging.h b/src/test/util/logging.h index 122acb2509b125..316b32f9a040bf 100644 --- a/src/test/util/logging.h +++ b/src/test/util/logging.h @@ -5,10 +5,14 @@ #ifndef BITCOIN_TEST_UTIL_LOGGING_H #define BITCOIN_TEST_UTIL_LOGGING_H +#include #include +#include +#include #include #include +#include #include class DebugLogHelper @@ -16,13 +20,27 @@ class DebugLogHelper public: using MatchFn = std::function; - explicit DebugLogHelper(std::string message, MatchFn match = [](const std::string*){ return true; }); + static bool MatchFnDefault(const std::string*) + { + return true; + } + + explicit DebugLogHelper( + std::string message, + MatchFn match = MatchFnDefault, + std::optional timeout = std::nullopt); ~DebugLogHelper(); private: const std::string m_message; - bool m_found{false}; + const std::optional m_timeout; + // Mutex + LOCK() is not usable here because LOCK() may print to the log + // itself (see DEBUG_LOCKCONTENTION) causing a deadlock between this mutex + // and BCLog::Logger::m_cs which is acquired when logging a message. + StdMutex m_mutex; + std::condition_variable_any m_cv; + bool m_found GUARDED_BY(m_mutex){false}; std::list>::iterator m_print_connection; //! Custom match checking function. @@ -42,4 +60,7 @@ class DebugLogHelper #define ASSERT_DEBUG_LOG(message) DebugLogHelper UNIQUE_NAME(debugloghelper)(message) +#define ASSERT_DEBUG_LOG_WAIT(message, timeout) \ + DebugLogHelper UNIQUE_NAME(debugloghelper)(message, DebugLogHelper::MatchFnDefault, timeout) + #endif // BITCOIN_TEST_UTIL_LOGGING_H diff --git a/src/threadsafety.h b/src/threadsafety.h index 2e9a39bfc95e36..2f65b413b47fec 100644 --- a/src/threadsafety.h +++ b/src/threadsafety.h @@ -74,4 +74,13 @@ class SCOPED_LOCKABLE StdLockGuard : public std::lock_guard ~StdLockGuard() UNLOCK_FUNCTION() = default; }; +// StdUniqueLock provides an annotated version of std::unique_lock for us, +// and should only be used when sync.h Mutex/LOCK/etc are not usable. +class SCOPED_LOCKABLE StdUniqueLock : public std::unique_lock +{ +public: + explicit StdUniqueLock(StdMutex& cs) EXCLUSIVE_LOCK_FUNCTION(cs) : std::unique_lock(cs) {} + ~StdUniqueLock() UNLOCK_FUNCTION() {} +}; + #endif // BITCOIN_THREADSAFETY_H