Merge #16540: test: Add ASSERT_DEBUG_LOG to unit test framework

fa2c44c3cc test: Add ASSERT_DEBUG_LOG to unit test framework (MarcoFalke)
fa1936f57b logging: Add member for arbitrary print callbacks (MarcoFalke)

Pull request description:

  Similar to `assert_debug_log` in the functional test framework

Top commit has no ACKs.

Tree-SHA512: aa9eaeca386b61d806867c04a33275f6eb4624fa5bf50f2928d16c83f5634bac96bcac46f9e8eda3b00b4251c5f12d7b01d6ffd84ba8e05c09eeec810cc31251

src/Makefile.test.include

@@ -59,6 +59,8 @@ GENERATED_TEST_FILES = $(JSON_TEST_FILES:.json=.json.h) $(RAW_TEST_FILES:.raw=.r
 BITCOIN_TEST_SUITE = \
   test/lib/blockfilter.cpp \
   test/lib/blockfilter.h \
+  test/lib/logging.cpp \
+  test/lib/logging.h \
   test/lib/transaction_utils.cpp \
   test/lib/transaction_utils.h \
   test/main.cpp \

src/logging.cpp

@@ -67,6 +67,9 @@ bool BCLog::Logger::StartLogging()
 
         if (m_print_to_file) FileWriteStr(s, m_fileout);
         if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout);
+        for (const auto& cb : m_print_callbacks) {
+            cb(s);
+        }
 
         m_msgs_before_open.pop_front();
     }
@@ -81,6 +84,7 @@ void BCLog::Logger::DisconnectTestLogger()
     m_buffering = true;
     if (m_fileout != nullptr) fclose(m_fileout);
     m_fileout = nullptr;
+    m_print_callbacks.clear();
 }
 
 void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
@@ -270,6 +274,9 @@ void BCLog::Logger::LogPrintStr(const std::string& str)
         fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
         fflush(stdout);
     }
+    for (const auto& cb : m_print_callbacks) {
+        cb(str_prefixed);
+    }
     if (m_print_to_file) {
         assert(m_fileout != nullptr);
 

src/logging.h

@@ -77,6 +77,9 @@ namespace BCLog {
 
         std::string LogTimestampStr(const std::string& str);
 
+        /** Slots that connect to the print signal */
+        std::list<std::function<void(const std::string&)>> m_print_callbacks /* GUARDED_BY(m_cs) */ {};
+
     public:
         bool m_print_to_console = false;
         bool m_print_to_file = false;
@@ -95,7 +98,22 @@ namespace BCLog {
         bool Enabled() const
         {
             std::lock_guard<std::mutex> scoped_lock(m_cs);
-            return m_buffering || m_print_to_console || m_print_to_file;
+            return m_buffering || m_print_to_console || m_print_to_file || !m_print_callbacks.empty();
+        }
+
+        /** Connect a slot to the print signal and return the connection */
+        std::list<std::function<void(const std::string&)>>::iterator PushBackCallback(std::function<void(const std::string&)> fun)
+        {
+            std::lock_guard<std::mutex> scoped_lock(m_cs);
+            m_print_callbacks.push_back(std::move(fun));
+            return --m_print_callbacks.end();
+        }
+
+        /** Delete a connection */
+        void DeleteCallback(std::list<std::function<void(const std::string&)>>::iterator it)
+        {
+            std::lock_guard<std::mutex> scoped_lock(m_cs);
+            m_print_callbacks.erase(it);
         }
 
         /** Start logging (and flush all buffered messages) */

src/noui.cpp

@@ -66,28 +66,31 @@ void noui_connect()
     noui_InitMessageConn = uiInterface.InitMessage_connect(noui_InitMessage);
 }
 
-bool noui_ThreadSafeMessageBoxSuppressed(const std::string& message, const std::string& caption, unsigned int style)
+bool noui_ThreadSafeMessageBoxRedirect(const std::string& message, const std::string& caption, unsigned int style)
 {
+    LogPrintf("%s: %s\n", caption, message);
     return false;
 }
 
-bool noui_ThreadSafeQuestionSuppressed(const std::string& /* ignored interactive message */, const std::string& message, const std::string& caption, unsigned int style)
+bool noui_ThreadSafeQuestionRedirect(const std::string& /* ignored interactive message */, const std::string& message, const std::string& caption, unsigned int style)
 {
+    LogPrintf("%s: %s\n", caption, message);
     return false;
 }
 
-void noui_InitMessageSuppressed(const std::string& message)
+void noui_InitMessageRedirect(const std::string& message)
 {
+    LogPrintf("init message: %s\n", message);
 }
 
-void noui_suppress()
+void noui_test_redirect()
 {
     noui_ThreadSafeMessageBoxConn.disconnect();
     noui_ThreadSafeQuestionConn.disconnect();
     noui_InitMessageConn.disconnect();
-    noui_ThreadSafeMessageBoxConn = uiInterface.ThreadSafeMessageBox_connect(noui_ThreadSafeMessageBoxSuppressed);
-    noui_ThreadSafeQuestionConn = uiInterface.ThreadSafeQuestion_connect(noui_ThreadSafeQuestionSuppressed);
-    noui_InitMessageConn = uiInterface.InitMessage_connect(noui_InitMessageSuppressed);
+    noui_ThreadSafeMessageBoxConn = uiInterface.ThreadSafeMessageBox_connect(noui_ThreadSafeMessageBoxRedirect);
+    noui_ThreadSafeQuestionConn = uiInterface.ThreadSafeQuestion_connect(noui_ThreadSafeQuestionRedirect);
+    noui_InitMessageConn = uiInterface.InitMessage_connect(noui_InitMessageRedirect);
 }
 
 void noui_reconnect()

src/noui.h

@@ -17,10 +17,10 @@ void noui_InitMessage(const std::string& message);
 /** Connect all bitcoind signal handlers */
 void noui_connect();
 
-/** Suppress all bitcoind signal handlers. Used to suppress output during test runs that produce expected errors */
-void noui_suppress();
+/** Redirect all bitcoind signal handlers to LogPrintf. Used to check or suppress output during test runs that produce expected errors */
+void noui_test_redirect();
 
-/** Reconnects the regular Non-GUI handlers after having used noui_suppress */
+/** Reconnects the regular Non-GUI handlers after having used noui_test_redirect */
 void noui_reconnect();
 
 #endif // BITCOIN_NOUI_H

src/test/lib/logging.cpp

@@ -0,0 +1,32 @@
+// Copyright (c) 2019 The Bitcoin Core developers
+// Distributed under the MIT software license, see the accompanying
+// file COPYING or http://www.opensource.org/licenses/mit-license.php.
+
+#include <test/lib/logging.h>
+
+#include <logging.h>
+#include <noui.h>
+#include <tinyformat.h>
+#include <util/memory.h>
+
+#include <stdexcept>
+
+DebugLogHelper::DebugLogHelper(std::string message)
+    : m_message{std::move(message)}
+{
+    m_print_connection = LogInstance().PushBackCallback(
+        [this](const std::string& s) {
+            if (m_found) return;
+            m_found = s.find(m_message) != std::string::npos;
+        });
+    noui_test_redirect();
+}
+
+void DebugLogHelper::check_found()
+{
+    noui_reconnect();
+    LogInstance().DeleteCallback(m_print_connection);
+    if (!m_found) {
+        throw std::runtime_error(strprintf("'%s' not found in debug log\n", m_message));
+    }
+}

src/test/lib/logging.h

@@ -0,0 +1,29 @@
+// Copyright (c) 2019 The Bitcoin Core developers
+// Distributed under the MIT software license, see the accompanying
+// file COPYING or http://www.opensource.org/licenses/mit-license.php.
+
+#ifndef BITCOIN_TEST_LIB_LOGGING_H
+#define BITCOIN_TEST_LIB_LOGGING_H
+
+#include <util/macros.h>
+
+#include <functional>
+#include <list>
+#include <string>
+
+class DebugLogHelper
+{
+    const std::string m_message;
+    bool m_found{false};
+    std::list<std::function<void(const std::string&)>>::iterator m_print_connection;
+
+    void check_found();
+
+public:
+    DebugLogHelper(std::string message);
+    ~DebugLogHelper() { check_found(); }
+};
+
+#define ASSERT_DEBUG_LOG(message) DebugLogHelper PASTE2(debugloghelper, __COUNTER__)(message)
+
+#endif // BITCOIN_TEST_LIB_LOGGING_H

src/test/timedata_tests.cpp

@@ -5,6 +5,7 @@
 
 #include <netaddress.h>
 #include <noui.h>
+#include <test/lib/logging.h>
 #include <test/setup_common.h>
 #include <timedata.h>
 #include <warnings.h>
@@ -59,9 +60,10 @@ BOOST_AUTO_TEST_CASE(addtimedata)
     MultiAddTimeData(3, DEFAULT_MAX_TIME_ADJUSTMENT + 1);
     // Filter size is 1 + 3 = 4: It is always initialized with a single element (offset 0)
 
-    noui_suppress();
-    MultiAddTimeData(1, DEFAULT_MAX_TIME_ADJUSTMENT + 1); //filter size 5
-    noui_reconnect();
+    {
+        ASSERT_DEBUG_LOG("Please check that your computer's date and time are correct!");
+        MultiAddTimeData(1, DEFAULT_MAX_TIME_ADJUSTMENT + 1); //filter size 5
+    }
 
     BOOST_CHECK(GetWarnings("gui").find("clock is wrong") != std::string::npos);
 

src/wallet/test/init_tests.cpp

@@ -5,6 +5,7 @@
 #include <boost/test/unit_test.hpp>
 
 #include <noui.h>
+#include <test/lib/logging.h>
 #include <test/setup_common.h>
 #include <util/system.h>
 #include <wallet/test/init_test_fixture.h>
@@ -34,28 +35,31 @@ BOOST_AUTO_TEST_CASE(walletinit_verify_walletdir_custom)
 BOOST_AUTO_TEST_CASE(walletinit_verify_walletdir_does_not_exist)
 {
     SetWalletDir(m_walletdir_path_cases["nonexistent"]);
-    noui_suppress();
-    bool result = m_chain_client->verify();
-    noui_reconnect();
-    BOOST_CHECK(result == false);
+    {
+        ASSERT_DEBUG_LOG("does not exist");
+        bool result = m_chain_client->verify();
+        BOOST_CHECK(result == false);
+    }
 }
 
 BOOST_AUTO_TEST_CASE(walletinit_verify_walletdir_is_not_directory)
 {
     SetWalletDir(m_walletdir_path_cases["file"]);
-    noui_suppress();
-    bool result = m_chain_client->verify();
-    noui_reconnect();
-    BOOST_CHECK(result == false);
+    {
+        ASSERT_DEBUG_LOG("is not a directory");
+        bool result = m_chain_client->verify();
+        BOOST_CHECK(result == false);
+    }
 }
 
 BOOST_AUTO_TEST_CASE(walletinit_verify_walletdir_is_not_relative)
 {
     SetWalletDir(m_walletdir_path_cases["relative"]);
-    noui_suppress();
-    bool result = m_chain_client->verify();
-    noui_reconnect();
-    BOOST_CHECK(result == false);
+    {
+        ASSERT_DEBUG_LOG("is a relative path");
+        bool result = m_chain_client->verify();
+        BOOST_CHECK(result == false);
+    }
 }
 
 BOOST_AUTO_TEST_CASE(walletinit_verify_walletdir_no_trailing)