test: Add ASSERT_DEBUG_LOG to unit test framework

MarcoFalke commented at 8:35 pm on August 2, 2019: member

Similar to assert_debug_log in the functional test framework

MarcoFalke force-pushed on Aug 2, 2019

fanquake added the label Tests on Aug 2, 2019

DrahtBot commented at 9:49 pm on August 2, 2019: member

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#16224 (gui: Bilingual GUI error messages by hebasto)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

MarcoFalke force-pushed on Aug 2, 2019

MarcoFalke force-pushed on Aug 3, 2019

in src/test/test_framework/util.h:14 in fae9929f8e outdated

 9+#include <vector>
10+
11+void assert_debug_log_redirect();
12+void assert_debug_log_helper(const std::vector<std::string>& messages);
13+
14+#define ASSERT_DEBUG_LOG(vec_messages, code) [&] { \

promag commented at 10:24 am on August 6, 2019:

Why place in a lambda?

MarcoFalke commented at 12:47 pm on August 6, 2019:

To prevent continue and break without a loop or switch statement in the body.

promag commented at 10:57 pm on August 6, 2019:

Got it, thanks.

in src/noui.h:20 in fae9929f8e outdated

16@@ -17,10 +17,10 @@ void noui_InitMessage(const std::string& message);
17 /** Connect all bitcoind signal handlers */
18 void noui_connect();
19 
20-/** Suppress all bitcoind signal handlers. Used to suppress output during test runs that produce expected errors */
21-void noui_suppress();
22+/** Redirect all bitcoind signal handlers to g_test_debug_log. Used to check or supress output during test runs that produce expected errors */

practicalswift commented at 11:32 am on August 16, 2019:

Should be “suppress”? :-)

MarcoFalke commented at 1:40 pm on August 16, 2019:

Fixed typo

MarcoFalke force-pushed on Aug 16, 2019

MarcoFalke force-pushed on Aug 20, 2019

practicalswift commented at 8:49 pm on August 20, 2019: contributor

Concept ACK

MarcoFalke force-pushed on Sep 23, 2019

MarcoFalke force-pushed on Sep 26, 2019

MarcoFalke force-pushed on Sep 27, 2019

MarcoFalke commented at 7:50 pm on October 3, 2019: member

re-run ci

MarcoFalke closed this on Oct 3, 2019

MarcoFalke reopened this on Oct 3, 2019

ajtowns commented at 7:25 am on October 4, 2019: member

Concept ACK. I think this might be better if implemented with a RAII approach, so you write:

0{
1    ASSERT_DEBUG_LOG("xyzzy");
2    code();
3}

and an error appears if the string wasn’t found by the end of the block. See https://github.com/ajtowns/bitcoin/commits/201910-assertdebuglog for a patch. This way avoids the globals and lets you just do two asserts in the same block rather than having to always create a vector. I also changed it so it only captures the log if you say ASSERT_DEBUG_LOG_CAPTURE("blah");.

MarcoFalke force-pushed on Oct 8, 2019

MarcoFalke commented at 1:47 pm on October 8, 2019: member

Thanks, taken some of the patch and rebased

DrahtBot added the label Needs rebase on Oct 23, 2019

MarcoFalke force-pushed on Oct 23, 2019

DrahtBot removed the label Needs rebase on Oct 23, 2019

ajtowns commented at 2:17 am on October 25, 2019: member

If I change ASSERT_DEBUG_LOG("is not a directory") to "isnt a directory" to trigger an error, it seems to hang after the failure rather than finishing shutdown?

MarcoFalke commented at 4:41 pm on October 30, 2019: member

@ajtowns This is an issue every time an assert is hit. The tests in that case would sleep forever, due to some boost internals, see #16700.

The correct error is still printed and the tests fail. I am not sure how to fix this minor usability issue, given that the logger is global (shared state) and the TestingSetup is not shut down between test cases. (make check shuts down the TestingSetup between test suites, so that is something at least)

DrahtBot added the label Needs rebase on Nov 4, 2019

logging: Add member for arbitrary print callbacks fa1936f57b

test: Add ASSERT_DEBUG_LOG to unit test framework fa2c44c3cc

MarcoFalke force-pushed on Nov 4, 2019

MarcoFalke commented at 3:44 pm on November 4, 2019: member

Rebased

DrahtBot removed the label Needs rebase on Nov 4, 2019

ajtowns commented at 4:12 pm on November 4, 2019: member

ACK fafa1b931ad9a69922bac53fb0a49d568719c2c2

MarcoFalke commented at 4:15 pm on November 4, 2019: member

@laanwj Any objections? Otherwise I will merge tomorrow

MarcoFalke referenced this in commit fea532a5f2 on Nov 5, 2019

MarcoFalke merged this on Nov 5, 2019

MarcoFalke closed this on Nov 5, 2019

MarcoFalke deleted the branch on Nov 5, 2019

in src/test/lib/logging.cpp:30 in fa2c44c3cc

25+void DebugLogHelper::check_found()
26+{
27+    noui_reconnect();
28+    LogInstance().DeleteCallback(m_print_connection);
29+    if (!m_found) {
30+        throw std::runtime_error(strprintf("'%s' not found in debug log\n", m_message));

ryanofsky commented at 9:34 pm on November 5, 2019:

Haven’t looked closely, but I’m kind of surprised you can get away with throwing an exception in a destructor (check_found is called by ~DebugLogHelper).

If this works, it seems fine. But in case there are issues, an alternative could be to use a callback instead of a scope, so instead of:

0{
1    ASSERT_DEBUG_LOG("Please check that your computer's date and time are correct!");
2    MultiAddTimeData(1, DEFAULT_MAX_TIME_ADJUSTMENT + 1); //filter size 5
3}

Something like:

0AssertDebugLog("Please check that your computer's date and time are correct!", [&] {
1    MultiAddTimeData(1, DEFAULT_MAX_TIME_ADJUSTMENT + 1); //filter size 5
2});

ajtowns commented at 4:28 pm on November 6, 2019:

I believe C++11 makes destructors implicitly noexcept, which means that an uncaught exception from results in std::terminate() being called, which is what we want from throwing a runtime exception anyway

MarcoFalke commented at 10:10 pm on November 7, 2019:

I forgot about this, but indeed the test seem to fail either way, which is what we want.

deadalnix referenced this in commit 4bd613e569 on Apr 30, 2020

DrahtBot locked this on Dec 16, 2021

test: Add ASSERT_DEBUG_LOG to unit test framework #16540

Conflicts