test: Show debug log on unit test failure #16975

pull MarcoFalke wants to merge 1 commits into bitcoin:master from MarcoFalke:1909-testPrintLogOnFail changing 7 files +34 −0
  1. MarcoFalke commented at 2:52 PM on September 27, 2019: member

    Often, it is hard to debug unit test failures without the debug log. Especially when the failure happens remotely (e.g. on a ci system).

    Fix that by printing the log on failure.

  2. fanquake added the label Tests on Sep 27, 2019
  3. MarcoFalke force-pushed on Sep 27, 2019
  4. MarcoFalke force-pushed on Sep 27, 2019
  5. MarcoFalke force-pushed on Sep 27, 2019
  6. MarcoFalke force-pushed on Sep 27, 2019
  7. MarcoFalke force-pushed on Sep 27, 2019
  8. MarcoFalke commented at 5:57 PM on September 27, 2019: member

    Can be tested by injecting a failure in any test case and then running make check

  9. jamesob commented at 6:07 PM on September 27, 2019: member

    Concept ACK.

    Ran make -j7 check with following patch and got confusing output - looks like a lot of duplicated lines. Maybe unavoidable?

    diff --git a/src/test/net_tests.cpp b/src/test/net_tests.cpp
index fed65afdbf..d0948dcbca 100644
--- a/src/test/net_tests.cpp
+++ b/src/test/net_tests.cpp
@@ -88,6 +88,7 @@ BOOST_AUTO_TEST_CASE(cnode_listen_port)
     BOOST_CHECK(gArgs.SoftSetArg("-port", std::to_string(altPort)));
     port = GetListenPort();
     BOOST_CHECK(port == altPort);
+    BOOST_CHECK(false);
 }
 
 BOOST_AUTO_TEST_CASE(caddrdb_read)

    Making check in src
make[1]: Entering directory '/home/james/src/bitcoin/src'
make[2]: Entering directory '/home/james/src/bitcoin/src'
make[3]: Entering directory '/home/james/src/bitcoin'
make[3]: Leaving directory '/home/james/src/bitcoin'
make  check-TESTS check-local
make[3]: Entering directory '/home/james/src/bitcoin/src'
Running tests: arith_uint256_tests from test/arith_uint256_tests.cpp
Running tests: addrman_tests from test/addrman_tests.cpp
Running tests: amount_tests from test/amount_tests.cpp
Running tests: allocator_tests from test/allocator_tests.cpp
Running tests: base32_tests from test/base32_tests.cpp
Running tests: base58_tests from test/base58_tests.cpp
Running tests: base64_tests from test/base64_tests.cpp
Running tests: bech32_tests from test/bech32_tests.cpp
Running tests: bip32_tests from test/bip32_tests.cpp
Running tests: blockchain_tests from test/blockchain_tests.cpp
Running tests: blockencodings_tests from test/blockencodings_tests.cpp
Running tests: blockfilter_tests from test/blockfilter_tests.cpp
Running tests: blockfilter_index_tests from test/blockfilter_index_tests.cpp
Running tests: bloom_tests from test/bloom_tests.cpp
Running tests: bswap_tests from test/bswap_tests.cpp
Running tests: checkqueue_tests from test/checkqueue_tests.cpp
Running tests: coins_tests from test/coins_tests.cpp
Running tests: compilerbug_tests from test/compilerbug_tests.cpp
Running tests: compress_tests from test/compress_tests.cpp
Running tests: crypto_tests from test/crypto_tests.cpp
Running tests: cuckoocache_tests from test/cuckoocache_tests.cpp
Running tests: denialofservice_tests from test/denialofservice_tests.cpp
make[4]: Entering directory '/home/james/src/bitcoin/src'
make[5]: Entering directory '/home/james/src/bitcoin'
make[5]: Leaving directory '/home/james/src/bitcoin'
Running tests: descriptor_tests from test/descriptor_tests.cpp
Running tests: flatfile_tests from test/flatfile_tests.cpp
Running tests: fs_tests from test/fs_tests.cpp
Running tests: getarg_tests from test/getarg_tests.cpp
Running tests: hash_tests from test/hash_tests.cpp
Running tests: key_io_tests from test/key_io_tests.cpp
Running tests: key_tests from test/key_tests.cpp
Running tests: limitedmap_tests from test/limitedmap_tests.cpp
Running tests: dbwrapper_tests from test/dbwrapper_tests.cpp
Running tests: validation_tests from test/validation_tests.cpp
Running tests: mempool_tests from test/mempool_tests.cpp
Running tests: merkle_tests from test/merkle_tests.cpp
Running tests: merkleblock_tests from test/merkleblock_tests.cpp
Running tests: miner_tests from test/miner_tests.cpp
PASS: qt/test/test_bitcoin-qt
============================================================================
Testsuite summary for Bitcoin Core 0.18.99
============================================================================
# TOTAL: 1
# PASS:  1
# SKIP:  0
# XFAIL: 0
# FAIL:  0
# XPASS: 0
# ERROR: 0
============================================================================
make[4]: Leaving directory '/home/james/src/bitcoin/src'
Running tests: multisig_tests from test/multisig_tests.cpp
Running tests: net_tests from test/net_tests.cpp
Running 9 test cases...
Entering test module "Bitcoin Core Test Suite"
test/net_tests.cpp(79): Entering test suite "net_tests"
test/net_tests.cpp(81): Entering test case "cnode_listen_port"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(91): error: in "net_tests/cnode_listen_port": check false has failed
test/net_tests.cpp(81): Leaving test case "cnode_listen_port"; testing time: 36113us
test/net_tests.cpp(94): Entering test case "caddrdb_read"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(94): Leaving test case "caddrdb_read"; testing time: 12342us
test/net_tests.cpp(139): Entering test case "caddrdb_read_corrupted"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z ERROR: DeserializeDB: Deserialize or I/O error - CDataStream::read(): end of data: iostream error
2019-09-27T18:03:51Z ERROR: DeserializeDB: Deserialize or I/O error - CDataStream::read(): end of data: iostream error
2019-09-27T18:03:51Z ERROR: DeserializeDB: Deserialize or I/O error - CDataStream::read(): end of data: iostream error
test/net_tests.cpp(139): Leaving test case "caddrdb_read_corrupted"; testing time: 7922us
test/net_tests.cpp(170): Entering test case "cnode_simple_test"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(170): Leaving test case "cnode_simple_test"; testing time: 7579us
test/net_tests.cpp(195): Entering test case "ipv4_peer_with_ipv6_addrMe_test"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(195): Leaving test case "ipv4_peer_with_ipv6_addrMe_test"; testing time: 6446us
test/net_tests.cpp(233): Entering test case "LimitedAndReachable_Network"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(233): Leaving test case "LimitedAndReachable_Network"; testing time: 5801us
test/net_tests.cpp(256): Entering test case "LimitedAndReachable_NetworkCaseUnroutableAndInternal"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(256): Leaving test case "LimitedAndReachable_NetworkCaseUnroutableAndInternal"; testing time: 5789us
test/net_tests.cpp(279): Entering test case "LimitedAndReachable_CNetAddr"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/net_tests.cpp(279): Leaving test case "LimitedAndReachable_CNetAddr"; testing time: 5767us
test/net_tests.cpp(293): Entering test case "LocalAddress_BasicLifecycle"
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Bitcoin Core version v0.18.99.0-fa8e20aaca-dirty (debug build)
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z AddLocal(2.1.1.1:1000,1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
2019-09-27T18:03:51Z RemoveLocal(2.1.1.1:1000)
test/net_tests.cpp(293): Leaving test case "LocalAddress_BasicLifecycle"; testing time: 5885us
test/net_tests.cpp(79): Leaving test suite "net_tests"; testing time: 93768us
Leaving test module "Bitcoin Core Test Suite"; testing time: 93846us

*** 1 failure is detected in the test module "Bitcoin Core Test Suite"
Makefile:13822: recipe for target 'test/net_tests.cpp.test' failed
make[3]: *** [test/net_tests.cpp.test] Error 1
make[3]: *** Waiting for unfinished jobs....
make[3]: Leaving directory '/home/james/src/bitcoin/src'
Makefile:13560: recipe for target 'check-am' failed
make[2]: *** [check-am] Error 2
make[2]: Leaving directory '/home/james/src/bitcoin/src'
Makefile:13248: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/home/james/src/bitcoin/src'
Makefile:775: recipe for target 'check-recursive' failed
make: *** [check-recursive] Error 1
  10. MarcoFalke commented at 6:31 PM on September 27, 2019: member

    Whoops. Fixing ...

  11. MarcoFalke force-pushed on Sep 27, 2019
  12. MarcoFalke force-pushed on Sep 27, 2019
  13. MarcoFalke commented at 7:16 PM on September 27, 2019: member

    Fixed

  14. in src/logging.h:81 in fa006d833d outdated 
      76 | @@ -77,6 +77,9 @@ namespace BCLog {
  77 |  
  78 |          std::string LogTimestampStr(const std::string& str);
  79 |  
  80 | +        /** Slots that connect to the print signal */
  81 | +        std::list<std::function<void(const std::string&)>> m_print_callbacks /* GUARDED_BY(m_cs) */ {};
    jamesob commented at 7:39 PM on September 27, 2019:

    Why comment the lock annotation?

    MarcoFalke commented at 7:47 PM on September 27, 2019:

    It can't compile otherwise. If you include sync.h, the tests won't run after compilation.

  15. in src/logging.h:113 in fa006d833d outdated 
     109 | +            m_print_callbacks.push_back(std::move(fun));
 110 | +            return --m_print_callbacks.end();
 111 | +        }
 112 | +
 113 | +        /** Delete a connection */
 114 | +        void DeleteCallback(std::list<std::function<void(const std::string&)>>::iterator it)
    jamesob commented at 7:42 PM on September 27, 2019:

    Unused?

    MarcoFalke commented at 7:47 PM on September 27, 2019:

    Used in #16540

  16. MarcoFalke force-pushed on Sep 27, 2019
  17. MarcoFalke force-pushed on Sep 27, 2019
  18. practicalswift commented at 8:10 AM on September 28, 2019: contributor

    Concept ACK

  19. promag commented at 8:48 AM on September 28, 2019: member

    Concept ACK.

  20. mzumsande commented at 11:49 PM on September 29, 2019: member

    Concept ACK. There is a data race warning in the Travis TSan build for txindex_tests, which I could reproduce.

  21. DrahtBot commented at 8:48 PM on October 3, 2019: member

    <!--e57a25ab6845829454e8d69fc972939a-->

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

    <!--174a7506f384e20aa4161008e828411d-->

    Conflicts

    No conflicts as of last run.

  22. MarcoFalke force-pushed on Oct 7, 2019
  23. MarcoFalke force-pushed on Oct 7, 2019
  24. MarcoFalke commented at 8:37 PM on October 7, 2019: member

    Ah, forgot to push one more tsan suppression. Fixed.

    Though, longer term I'd like to do #8670 (comment)

  25. adamjonas commented at 7:48 PM on October 22, 2019: member

    utACK faa5a01d523b8eb0436128eb6c87ef22694cf13f. Tried a few different scenarios and noted that logging is provided for multiple failed test cases in a file before exiting.

    For example:

    test/arith_uint256_tests.cpp:345: Entering test case "divide"
2019-10-22T19:44:29Z Bitcoin Core version v0.18.99.0-faa5a01d5-dirty (release build)
2019-10-22T19:44:29Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-10-22T19:44:29Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/arith_uint256_tests.cpp:353: error: in "arith_uint256_tests/divide": check MaxL / R1L == 3 has failed
test/arith_uint256_tests.cpp:345: Leaving test case "divide"; testing time: 2732us
...
test/arith_uint256_tests.cpp:404: Entering test case "bignum_SetCompact"
2019-10-22T19:44:29Z Bitcoin Core version v0.18.99.0-faa5a01d5-dirty (release build)
2019-10-22T19:44:29Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-10-22T19:44:29Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
test/arith_uint256_tests.cpp:430: error: in "arith_uint256_tests/bignum_SetCompact": check fNegative == true has failed [false != true]
test/arith_uint256_tests.cpp:404: Leaving test case "bignum_SetCompact"; testing time: 2225us
  26. DrahtBot added the label Needs rebase on Oct 24, 2019
  27. MarcoFalke force-pushed on Oct 24, 2019
  28. MarcoFalke commented at 2:32 PM on October 24, 2019: member

    Rebased for minor merge conflict

  29. DrahtBot removed the label Needs rebase on Oct 24, 2019
  30. laanwj added this to the "Blockers" column in a project
  31. fjahr commented at 11:55 PM on October 28, 2019: member

    Concept ACK

    If there are multiple test cases in a single test file and one of them fails currently the logs of all the test cases are printed, also the succeeding ones. Could that be improved? It could be especially annoying if there are a lot of logs for every test case and the developer would have to search for the failing one (I discovered this on merkle_tests.cpp where logs were short, not sure which unit test has the most logs).

  32. MarcoFalke commented at 5:17 PM on October 30, 2019: member

    @fjahr I don't think I can solve that without having a way to detect (inside the TestingSetup, e.g. the destructor) whether a test case failed

    Also, I think having too much logs is better than having no logs to debug at all.

  33. MarcoFalke force-pushed on Nov 5, 2019
  34. laanwj commented at 11:44 AM on November 6, 2019: member

    Concept ACK.

    Also, I think having too much logs is better than having no logs to debug at all.

    Usually true, though having too much (unrelated) logging can also distract. And CI web interfaces make the experience of browsing large files quite horrible. Also, too much logging can slow down the tests.

    But I don't think that's the case with this change.

  35. DrahtBot added the label Needs rebase on Nov 7, 2019
  36. MarcoFalke force-pushed on Nov 7, 2019
  37. MarcoFalke force-pushed on Nov 7, 2019
  38. MarcoFalke commented at 3:49 PM on November 7, 2019: member

    Usually true, though having too much (unrelated) logging can also distract. And CI web interfaces make the experience of browsing large files quite horrible. Also, too much logging can slow down the tests. But I don't think that's the case with this change.

    Agree on the distraction part, but if you set the log level to "debug" or "test_suite" I think a verbose log should be expected.

    Note that this is not printed to the ci log unless the test fails.

    Also note that the tests already log to the debug.log, so logging to the test log shouldn't slow them down.

    See the comparison:

    $ /usr/bin/time ./src/test/test_bitcoin-fab72a301a86373d7d7a8d05a300391687048ec8
Running 381 test cases...

*** No errors detected
42.97user 9.04system 0:41.84elapsed 124%CPU (0avgtext+0avgdata 250648maxresident)k

$ /usr/bin/time ./src/test/test_bitcoin-master
Running 381 test cases...

*** No errors detected
44.08user 8.72system 0:42.28elapsed 124%CPU (0avgtext+0avgdata 250176maxresident)k

    So it might or might not be slower, but I don't think there is any significant difference

  39. DrahtBot removed the label Needs rebase on Nov 7, 2019
  40. MarcoFalke force-pushed on Nov 7, 2019
  41. promag commented at 9:47 PM on November 24, 2019: member

    ACK fad5fe2dbaef662a8d00385a3a9060aa7f4e74d7.

  42. MarcoFalke commented at 5:58 PM on December 20, 2019: member

    Anything left to do here?

  43. practicalswift commented at 6:59 PM on December 20, 2019: contributor

    ACK fad5fe2dbaef662a8d00385a3a9060aa7f4e74d7 -- diff looks correct

  44. test: Show debug log on unit test failure fa37e0a68b
  45. MarcoFalke force-pushed on Jan 2, 2020
  46. MarcoFalke commented at 11:20 PM on January 2, 2020: member

    Rebased to fix trivial merge conflict

  47. jamesob commented at 4:46 PM on January 3, 2020: member

    Would-be ACK https://github.com/bitcoin/bitcoin/pull/16975/commits/fa37e0a68bea65979f9f8f2e5258fe608acf2bdf but it looks like I've hit a deadlock.

    Modified the coins test for failure:

    diff --git a/src/test/coins_tests.cpp b/src/test/coins_tests.cpp
index 436c1bffa0..2c20efc12b 100644
--- a/src/test/coins_tests.cpp
+++ b/src/test/coins_tests.cpp
@@ -213,6 +213,7 @@ BOOST_AUTO_TEST_CASE(coins_cache_simulation_test)
                 unsigned int flushIndex = InsecureRandRange(stack.size() - 1);
                 BOOST_CHECK(stack[flushIndex]->Flush());
             }
+            assert(false);
         }
         if (InsecureRandRange(100) == 0) {
             // Every 100 iterations, change the cache stack.

    and ran with make -j 4 check.

    Noticed the test seemed to be hanging, so straced:

    $ ps aux | grep test
...
james    20079  0.0  0.0  19992  3180 pts/15   S+   11:38   0:00 /bin/bash -c test/test_bitcoin -l test_suite -t "`cat test/coins_tests.cpp | grep -E "(BOOST_FIXTURE_TEST_SUITE\\(|BOOST_AUTO_TEST_SUITE\\()" | cut -d '(' -f 2 | cut -d ',' -f 1 | cut -d ')' -f 1`" > test/coins_tests.cpp.log 2>&1 || (cat test/coins_tests.cpp.log && false)
...

$ sudo strace -p 20079

strace: Process 20079 attached
wait4(-1,
  48. MarcoFalke commented at 5:30 PM on January 3, 2020: member

    @jamesob I think you can't use assert in the boost test framework, see #16700. I'd guess this issue also happens on master

  49. jamesob commented at 3:35 PM on January 4, 2020: member

    ACK fa37e0a68bea65979f9f8f2e5258fe608acf2bdf (jamesob/ackr/16975.1.MarcoFalke.test_show_debug_log_on_u)

    Confirmed that assert(false); behavior deadlocks on master too.

    <details><summary>Show signature data</summary> <p>

    -----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA512

ACK fa37e0a68bea65979f9f8f2e5258fe608acf2bdf ([`jamesob/ackr/16975.1.MarcoFalke.test_show_debug_log_on_u`](https://github.com/jamesob/bitcoin/tree/ackr/16975.1.MarcoFalke.test_show_debug_log_on_u))

Confirmed that `assert(false);` behavior deadlocks on master too.
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCgAdFiEEpm2+LMqPsWj2rAwWyrywS1A+5mgFAl4QsLcACgkQyrywS1A+
5mhfUQ//f7fDaV29XKZ6Ww7Cb1NWzLedvSbkpYmE/6EgGhT2/HHQyCLWg6z+xbmI
273lVXdjIUKShuoSk97SjfAJAkyAk9bcehrVTvbSSixh5uVrdSKe6OENIoIoOWRO
wUWDIu7uR3zBcrdHkVIF+RxbTybtKhzZ6pPPpB6lMUZD/YFzrCZjG7NrwNWMxJ5i
ikDQfL5Jx80lc6BkvfEjtYVWJIazDvEty7UWqzlex3wtKS5QfA0a02KZ2H+v0D9V
9bfnl7WDDXqmVJdgkD0x9jsc2twcsPbw8CmQLV+/josYpgD9r9LM0uGE9l9rz2W2
2Ik6zQ2aSJZiOjJa1pmR9472LuS48folnyVYvvoVkhBiokgK2N5mLxFNAvIm8snf
Bx2p9xj4ts88loBwbKu1k00x/9wRgUk+Thd1va/32FJ1DcWN+JPbkxJwJp85D2Hc
3zD5CgxZYYIhddXu7qvwIi3xPMXeQZrYImtASeOOsHklVvkjhkAt136Gt1ZGjnzB
CeR9Kb1/mcfIooGuUIeO0PDNWQsWjG4JU+0UBVSOB/bSqx4ioKLLz3NvjT0NwIde
yONvxlJRGUjbaUZ5elEMGI0RRX/Ncw9b/jQglZWuqj6iJN+3bja+BnZoCwbwoh5/
dwajH3AZOTos5QR+kjY58WstyjNT98jx9Hm83BcqYXkqBgOnUEk=
=jrpf
-----END PGP SIGNATURE-----

    </p></details>

  50. laanwj referenced this in commit 40a495a38a on Jan 8, 2020
  51. laanwj merged this on Jan 8, 2020
  52. laanwj closed this on Jan 8, 2020
  53. laanwj removed this from the "Blockers" column in a project
  54. sidhujag referenced this in commit 14372aca31 on Jan 8, 2020
  55. MarcoFalke deleted the branch on Mar 30, 2020
  56. MarcoFalke referenced this in commit eb773f1063 on Apr 1, 2020
  57. sidhujag referenced this in commit 118b867af6 on Nov 10, 2020
  58. Fabcien referenced this in commit ee4e128c03 on Aug 31, 2021
  59. DrahtBot locked this on Feb 15, 2022
Contributors
MarcoFalkejamesobpracticalswiftpromagmzumsandeDrahtBotadamjonasfjahrlaanwj
Labels
Tests
Linked (view graph)
#18486 doc: Explain new test logging
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: 2026-04-17 06:14 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me