tests: Reduce noise level in test_bitcoin output #15352

pull practicalswift wants to merge 3 commits into bitcoin:master from practicalswift:test_bitcoin-output-spam changing 6 files +9 −7
  1. practicalswift commented at 10:05 am on February 6, 2019: contributor

    Reduce noise level in test_bitcoin output.

    Context: When working on the non-determinism issues in the unit tests (see #15296) I got a bit tired of the amount of noise in the test_bitcoin output :-)

    Before:

     0$ src/test/test_bitcoin --log_level=test_suite 2>&1 | grep -vE '(Entering|Leaving)' | uniq -c
 1      1 Running 341 test cases...
 2      1 Test case blockencodings_tests/TransactionsRequestDeserializationOverflowTest did not check any assertions
 3      1 CheckSplitTorReplyLine(PROTOCOLINFO PIVERSION)
 4      1 CheckSplitTorReplyLine(AUTH METHODS=COOKIE,SAFECOOKIE COOKIEFILE="/home/x/.tor/control_auth_cookie")
 5      1 CheckSplitTorReplyLine(AUTH METHODS=NULL)
 6      1 CheckSplitTorReplyLine(AUTH METHODS=HASHEDPASSWORD)
 7      1 CheckSplitTorReplyLine(VERSION Tor="0.2.9.8 (git-a0df013ea241b026)")
 8      1 CheckSplitTorReplyLine(AUTHCHALLENGE SERVERHASH=aaaa SERVERNONCE=bbbb)
 9      1 CheckSplitTorReplyLine(COMMAND)
10      1 CheckSplitTorReplyLine(COMMAND SOME  ARGS)
11      1 CheckSplitTorReplyLine(COMMAND  ARGS)
12      1 CheckSplitTorReplyLine(COMMAND   EVEN+more  ARGS)
13      1 CheckParseTorReplyMapping(METHODS=COOKIE,SAFECOOKIE COOKIEFILE="/home/x/.tor/control_auth_cookie")
14      1 CheckParseTorReplyMapping(METHODS=NULL)
15      1 CheckParseTorReplyMapping(METHODS=HASHEDPASSWORD)
16      1 CheckParseTorReplyMapping(Tor="0.2.9.8 (git-a0df013ea241b026)")
17      1 CheckParseTorReplyMapping(SERVERHASH=aaaa SERVERNONCE=bbbb)
18      1 CheckParseTorReplyMapping(ServiceID=exampleonion1234)
19      1 CheckParseTorReplyMapping(PrivateKey=RSA1024:BLOB)
20      1 CheckParseTorReplyMapping(ClientAuth=bob:BLOB)
21      1 CheckParseTorReplyMapping(Foo=Bar=Baz Spam=Eggs)
22      1 CheckParseTorReplyMapping(Foo="Bar=Baz")
23      1 CheckParseTorReplyMapping(Foo="Bar Baz")
24      1 CheckParseTorReplyMapping(Foo="Bar\ Baz")
25      1 CheckParseTorReplyMapping(Foo="Bar\Baz")
26      1 CheckParseTorReplyMapping(Foo="Bar\@Baz")
27      1 CheckParseTorReplyMapping(Foo="Bar\"Baz" Spam="\"Eggs\"")
28      1 CheckParseTorReplyMapping(Foo="Bar\\Baz")
29      1 CheckParseTorReplyMapping(Foo="Bar\nBaz\t" Spam="\rEggs" Octals="\1a\11\17\18\81\377\378\400\2222" Final=Check)
30      1 CheckParseTorReplyMapping(Valid=Mapping Escaped="Escape\\")
31      1 CheckParseTorReplyMapping(Valid=Mapping Bare="Escape\")
32      1 CheckParseTorReplyMapping(OneOctal="OneEnd\1" TwoOctal="TwoEnd\11")
33      1 CheckParseTorReplyMapping(Null="\0")
34      1 CheckParseTorReplyMapping(SOME=args,here MORE optional=arguments  here)
35      1 CheckParseTorReplyMapping(ARGS)
36      1 CheckParseTorReplyMapping(MORE ARGS)
37      1 CheckParseTorReplyMapping(MORE  ARGS)
38      1 CheckParseTorReplyMapping(EVEN more=ARGS)
39      1 CheckParseTorReplyMapping(EVEN+more ARGS)
40      1 Test case util_tests/util_criticalsection did not check any assertions
41      1 Testing known outcomes
42    326 Error: Specified -walletdir "/tmp/test_bitcoin/1553850209_943311758/tempdir/path_does_not_exist" does not exist
43    327 Error: Specified -walletdir "/tmp/test_bitcoin/1553850209_643733972/tempdir/not_a_directory.dat" is not a directory
44    328 Error: Specified -walletdir "wallets" is a relative path
45      1
46      1 *** No errors detected

    After:

    0$ src/test/test_bitcoin --log_level=test_suite 2>&1 | grep -vE '(Entering|Leaving)' | uniq -c
1      1 Running 341 test cases...
2      1 Error: Specified -walletdir "/tmp/test_bitcoin/1553850026_943311758/tempdir/path_does_not_exist" does not exist
3      1 Error: Specified -walletdir "/tmp/test_bitcoin/1553850026_643733972/tempdir/not_a_directory.dat" is not a directory
4      1 Error: Specified -walletdir "wallets" is a relative path
5      1
6      1 *** No errors detected
  2. fanquake added the label Tests on Feb 6, 2019
  3. practicalswift force-pushed on Feb 6, 2019
  4. promag commented at 1:30 pm on February 6, 2019: member
    Concept ACK.
  5. in src/noui.cpp:17 in b84d2bedf1 outdated 
    13@@ -14,6 +14,8 @@
14 
15 #include <boost/signals2/connection.hpp>
16 
17+bool g_suppress_noui_stderr_output = false;
    laanwj commented at 1:15 pm on February 12, 2019:
    wouldn’t it be better to not connect this signal at all?
    practicalswift commented at 9:25 am on February 15, 2019:
    I’m likely missing something but if skipping the uiInterface.ThreadSafeMessageBox_connect call then boost::signals2::no_slots_error will get thrown? What am I doing wrong? :-)
    MarcoFalke commented at 12:39 pm on March 27, 2019:
    Couldn’t you connect a [](){return true;}?
  6. practicalswift force-pushed on Mar 27, 2019
  7. practicalswift commented at 3:01 pm on March 27, 2019: contributor

    Updated in light of @laanwj and @MarcoFalke’s feedback. Thanks!

    Please re-review :-)

  8. in src/noui.h:20 in 2cc0e9f9e4 outdated 
    15@@ -16,5 +16,7 @@ void noui_InitMessage(const std::string& message);
16 
17 /** Connect all bitcoind signal handlers */
18 void noui_connect();
19+/** Connect all bitcoind signal handlers to silent no-op functions */
20+void noui_connect_noop_handlers();
    MarcoFalke commented at 3:50 pm on March 27, 2019:
    This should probably only be somewhere in src/test
    practicalswift commented at 4:39 pm on March 27, 2019:
    Good point! Fixed. Please re-review!
  9. practicalswift force-pushed on Mar 27, 2019
  10. in src/test/test_bitcoin.cpp:34 in 3a22955fb7 outdated 
    30@@ -31,6 +31,8 @@ std::ostream& operator<<(std::ostream& os, const uint256& num)
31     return os;
32 }
33 
34+extern void noui_connect_noop_handlers();
    MarcoFalke commented at 5:30 pm on March 27, 2019:
    No need for extern and I meant to move the whole function body. There shouldn’t be need to modify the binary for fixing up tests.
    practicalswift commented at 7:57 pm on March 27, 2019:
    Good point. Now touching only src/test/ and src/wallet/test/. Please re-re-review :-)
  11. practicalswift force-pushed on Mar 27, 2019
  12. practicalswift force-pushed on Mar 27, 2019
  13. in src/test/blockencodings_tests.cpp:392 in e558977cc5 outdated 
    386@@ -386,7 +387,9 @@ BOOST_AUTO_TEST_CASE(TransactionsRequestDeserializationOverflowTest) {
387         BOOST_CHECK(0);
388     } catch(std::ios_base::failure &) {
389         // deserialize should fail
390+        exception_thrown = true;
391     }
392+    BOOST_CHECK(exception_thrown);
    MarcoFalke commented at 9:21 pm on March 27, 2019:
    Could you please explain the control flow where this check fails, but the BOOST_CHECK(0); above passes?
    practicalswift commented at 10:46 pm on March 27, 2019:

    There shouldn’t exist such a case: they are meant to be equivalent.

    IIRC the re-formulation was needed to avoid having the test runner warn that the test case succeeded without executing any succeeding checks (or something along those lines).

    The re-formulated version made sure that a succeeding check (BOOST_CHECK(exception_thrown); ) was executed as part of the test case.

    However, when re-running without this I don’t get this warning so it must have been under some exotic command-line option. I’m unable to reproduce the condition this was meant to solve.

    I’ve now removed this since it isn’t needed to silence src/test/test_bitcoin which is the goal of this PR :-)

    practicalswift commented at 8:39 am on March 29, 2019:

    After some additional testing I was able to reproduce the warnings that these formulations were meant to silence:

    0$ src/test/test_bitcoin --log_level=test_suite 2>&1 | grep "did not check any assertions"
1Test case blockencodings_tests/TransactionsRequestDeserializationOverflowTest did not check any assertions
2Test case util_tests/util_criticalsection did not check any assertions

    Re-adding those re-formulations to get rid of these warnings.

    MarcoFalke commented at 2:05 pm on March 29, 2019:

    Why would you need to keep a variable for this?

    Wouldn’t BOOST_CHECK(true); // Explain why this is needed be sufficient?

    practicalswift commented at 2:29 pm on March 29, 2019:
    Yes, absolutely. Reformulated to an equivalent version not introducing any new variables. Please re-review :-)
  14. in src/test/util_tests.cpp:46 in e558977cc5 outdated 
    43             break;
44-
45+        }
46         BOOST_ERROR("break was swallowed!");
47     } while(0);
48+    BOOST_CHECK(success);
    MarcoFalke commented at 9:23 pm on March 27, 2019:
    Same here
  15. MarcoFalke commented at 9:24 pm on March 27, 2019: member
    utACK
  16. practicalswift force-pushed on Mar 27, 2019
  17. in src/test/test_bitcoin.cpp:61 in 9ca97d8063 outdated 
    57@@ -45,7 +58,7 @@ BasicTestingSetup::BasicTestingSetup(const std::string& chainName)
58     // TODO: fix the code to support SegWit blocks.
59     gArgs.ForceSetArg("-vbparams", strprintf("segwit:0:%d", (int64_t)Consensus::BIP9Deployment::NO_TIMEOUT));
60     SelectParams(chainName);
61-    noui_connect();
62+    noui_connect_noop_handlers();
    MarcoFalke commented at 12:41 pm on March 28, 2019:
    Thinking more about this, could this only be disabled for specific test cases? Otherwise writing tests will get a lot harder when errors and warnings are no longer printed.
    practicalswift commented at 9:07 am on March 29, 2019:
    Good point. Pushed updated version. No longer trying to suppress any output. The spamming problem was solved by running noui_connect() only once :-)
    laanwj commented at 9:24 am on March 29, 2019:

    Otherwise writing tests will get a lot harder when errors and warnings are no longer printed.

    Yes, thanks, good point—in my experience errors being mysteriously swallowed is awful for being able to diagnose problems when they happen.

  18. practicalswift force-pushed on Mar 29, 2019
  19. practicalswift commented at 9:10 am on March 29, 2019: contributor

    Please review updated version.

    I found the root cause to the nine hundred (!) lines of debug outputted when running test_bitcoin compiled from current master.

    Turns out we are running noui_connect() once per test (more specifically: we call noui_connect() in the ctor of BasicTestingSetup) which means that we end up with quite a few logging functions connected to the signals :-)

    Now connecting only once.

    Please re-review :-)

    Before this PR (note how the wallet messages are repeated >300 times each! :-)):

     0$ src/test/test_bitcoin --log_level=test_suite 2>&1 | grep -vE '(Entering|Leaving)' | uniq -c
 1      1 Running 341 test cases...
 2      1 Test case blockencodings_tests/TransactionsRequestDeserializationOverflowTest did not check any assertions
 3      1 CheckSplitTorReplyLine(PROTOCOLINFO PIVERSION)
 4      1 CheckSplitTorReplyLine(AUTH METHODS=COOKIE,SAFECOOKIE COOKIEFILE="/home/x/.tor/control_auth_cookie")
 5      1 CheckSplitTorReplyLine(AUTH METHODS=NULL)
 6      1 CheckSplitTorReplyLine(AUTH METHODS=HASHEDPASSWORD)
 7      1 CheckSplitTorReplyLine(VERSION Tor="0.2.9.8 (git-a0df013ea241b026)")
 8      1 CheckSplitTorReplyLine(AUTHCHALLENGE SERVERHASH=aaaa SERVERNONCE=bbbb)
 9      1 CheckSplitTorReplyLine(COMMAND)
10      1 CheckSplitTorReplyLine(COMMAND SOME  ARGS)
11      1 CheckSplitTorReplyLine(COMMAND  ARGS)
12      1 CheckSplitTorReplyLine(COMMAND   EVEN+more  ARGS)
13      1 CheckParseTorReplyMapping(METHODS=COOKIE,SAFECOOKIE COOKIEFILE="/home/x/.tor/control_auth_cookie")
14      1 CheckParseTorReplyMapping(METHODS=NULL)
15      1 CheckParseTorReplyMapping(METHODS=HASHEDPASSWORD)
16      1 CheckParseTorReplyMapping(Tor="0.2.9.8 (git-a0df013ea241b026)")
17      1 CheckParseTorReplyMapping(SERVERHASH=aaaa SERVERNONCE=bbbb)
18      1 CheckParseTorReplyMapping(ServiceID=exampleonion1234)
19      1 CheckParseTorReplyMapping(PrivateKey=RSA1024:BLOB)
20      1 CheckParseTorReplyMapping(ClientAuth=bob:BLOB)
21      1 CheckParseTorReplyMapping(Foo=Bar=Baz Spam=Eggs)
22      1 CheckParseTorReplyMapping(Foo="Bar=Baz")
23      1 CheckParseTorReplyMapping(Foo="Bar Baz")
24      1 CheckParseTorReplyMapping(Foo="Bar\ Baz")
25      1 CheckParseTorReplyMapping(Foo="Bar\Baz")
26      1 CheckParseTorReplyMapping(Foo="Bar\@Baz")
27      1 CheckParseTorReplyMapping(Foo="Bar\"Baz" Spam="\"Eggs\"")
28      1 CheckParseTorReplyMapping(Foo="Bar\\Baz")
29      1 CheckParseTorReplyMapping(Foo="Bar\nBaz\t" Spam="\rEggs" Octals="\1a\11\17\18\81\377\378\400\2222" Final=Check)
30      1 CheckParseTorReplyMapping(Valid=Mapping Escaped="Escape\\")
31      1 CheckParseTorReplyMapping(Valid=Mapping Bare="Escape\")
32      1 CheckParseTorReplyMapping(OneOctal="OneEnd\1" TwoOctal="TwoEnd\11")
33      1 CheckParseTorReplyMapping(Null="\0")
34      1 CheckParseTorReplyMapping(SOME=args,here MORE optional=arguments  here)
35      1 CheckParseTorReplyMapping(ARGS)
36      1 CheckParseTorReplyMapping(MORE ARGS)
37      1 CheckParseTorReplyMapping(MORE  ARGS)
38      1 CheckParseTorReplyMapping(EVEN more=ARGS)
39      1 CheckParseTorReplyMapping(EVEN+more ARGS)
40      1 Test case util_tests/util_criticalsection did not check any assertions
41      1 Testing known outcomes
42    326 Error: Specified -walletdir "/tmp/test_bitcoin/1553850209_943311758/tempdir/path_does_not_exist" does not exist
43    327 Error: Specified -walletdir "/tmp/test_bitcoin/1553850209_643733972/tempdir/not_a_directory.dat" is not a directory
44    328 Error: Specified -walletdir "wallets" is a relative path
45      1
46      1 *** No errors detected

    After this PR:

    0$ src/test/test_bitcoin --log_level=test_suite 2>&1 | grep -vE '(Entering|Leaving)' | uniq -c
1      1 Running 341 test cases...
2      1 Error: Specified -walletdir "/tmp/test_bitcoin/1553850026_943311758/tempdir/path_does_not_exist" does not exist
3      1 Error: Specified -walletdir "/tmp/test_bitcoin/1553850026_643733972/tempdir/not_a_directory.dat" is not a directory
4      1 Error: Specified -walletdir "wallets" is a relative path
5      1
6      1 *** No errors detected
  20. tests: Reduce noise level in test_bitcoin output e502c3c515
  21. Avoid repeated log messages in tests by connecting to signal handlers (ThreadSafeMessageBox, etc.) only once 5fd73c8694
  22. practicalswift force-pushed on Mar 29, 2019
  23. practicalswift force-pushed on Mar 29, 2019
  24. Silence "Test case [...] did not check any assertions" warnings when running "test_bitcoin --log_level=test_suite" 0aef39d067
  25. practicalswift force-pushed on Mar 29, 2019
  26. MarcoFalke commented at 3:43 pm on March 29, 2019: member
    utACK 0aef39d0678ec2f26633028d44eea0ba0087e7c0
  27. DrahtBot added the label Needs rebase on Apr 16, 2019
  28. DrahtBot commented at 5:14 pm on April 16, 2019: member
  29. MarcoFalke commented at 6:19 pm on April 16, 2019: member
    Merged via git’s auto-merge
  30. MarcoFalke merged this on Apr 16, 2019
  31. MarcoFalke closed this on Apr 16, 2019
  32. MarcoFalke referenced this in commit 0c9de67f34 on Apr 16, 2019
  33. laanwj removed the label Needs rebase on Oct 24, 2019
  34. practicalswift deleted the branch on Apr 10, 2021
  35. Munkybooty referenced this in commit 832b2ab570 on Sep 30, 2021
  36. Munkybooty referenced this in commit 904eece82c on Oct 7, 2021
  37. kittywhiskers referenced this in commit 9172499a2f on Oct 8, 2021
  38. Munkybooty referenced this in commit 4306ca966f on Oct 12, 2021
  39. kittywhiskers referenced this in commit c3fbcccb10 on Oct 12, 2021
  40. PastaPastaPasta referenced this in commit a68f06226b on Oct 12, 2021
  41. Munkybooty referenced this in commit 0d9074977f on Oct 16, 2021
  42. Munkybooty referenced this in commit b128c108b9 on Oct 20, 2021
  43. Munkybooty referenced this in commit 57453a23b6 on Oct 21, 2021
  44. Munkybooty referenced this in commit 97f31af382 on Oct 23, 2021
  45. PastaPastaPasta referenced this in commit c916ca2a6b on Oct 24, 2021
  46. PastaPastaPasta referenced this in commit e0e2a2e3fe on Oct 25, 2021
  47. pravblockc referenced this in commit 2fb06fd96f on Nov 18, 2021
  48. pravblockc referenced this in commit cd90eefb06 on Nov 18, 2021
  49. DrahtBot locked this on Aug 16, 2022


practicalswift promag laanwj MarcoFalke DrahtBot

Labels
Tests

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-12-19 00:12 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me