Unit test validation_flush_tests fails on with recent libstdc++? #18111

issue laanwj openend this issue on February 10, 2020
  1. laanwj commented at 8:50 pm on February 10, 2020: member

    validation_flush_tests/getcoinscachesizestate fails on RISCV-64 on master:

    0Running 394 test cases...
1test/validation_flush_tests.cpp(99): error: in "validation_flush_tests/getcoinscachesizestate": check chainstate.GetCoinsCacheSizeState(tx_pool, MAX_COINS_CACHE_BYTES, 0) == CoinsCacheSizeState::OK has failed [1 != 0]
2
3*** 1 failure is detected in the test module "Bitcoin Core Test Suite"

    Haven’t investigated why, yet. Apart from the architecture it could also be some dependency version causing the problem (this is a fedora rawhide install with very new versions of everything including gcc and boost).

    Edit: see below, this is likely due to a newer libstdc++

  2. laanwj added the label Tests on Feb 10, 2020
  3. MarcoFalke commented at 0:17 am on February 11, 2020: member

    Same on debian:sid (ports)

      0make[4]: Entering directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
  1============================================================================
  2Testsuite summary for Bitcoin Core 0.19.99
  3============================================================================
  4# TOTAL: 0
  5# PASS:  0
  6# SKIP:  0
  7# XFAIL: 0
  8# FAIL:  0
  9# XPASS: 0
 10# ERROR: 0
 11============================================================================
 12make[4]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
 13Running tests: addrman_tests from test/addrman_tests.cpp
 14Running tests: amount_tests from test/amount_tests.cpp
 15Running tests: allocator_tests from test/allocator_tests.cpp
 16Running tests: base32_tests from test/base32_tests.cpp
 17Running tests: base58_tests from test/base58_tests.cpp
 18Running tests: base64_tests from test/base64_tests.cpp
 19Running tests: bech32_tests from test/bech32_tests.cpp
 20Running tests: bip32_tests from test/bip32_tests.cpp
 21Running tests: blockchain_tests from test/blockchain_tests.cpp
 22Running tests: blockencodings_tests from test/blockencodings_tests.cpp
 23Running tests: blockfilter_tests from test/blockfilter_tests.cpp
 24Running tests: blockfilter_index_tests from test/blockfilter_index_tests.cpp
 25Running tests: bloom_tests from test/bloom_tests.cpp
 26Running tests: bswap_tests from test/bswap_tests.cpp
 27Running tests: checkqueue_tests from test/checkqueue_tests.cpp
 28Running tests: coins_tests from test/coins_tests.cpp
 29Running tests: compilerbug_tests from test/compilerbug_tests.cpp
 30Running tests: compress_tests from test/compress_tests.cpp
 31Running tests: crypto_tests from test/crypto_tests.cpp
 32Running tests: cuckoocache_tests from test/cuckoocache_tests.cpp
 33Running tests: denialofservice_tests from test/denialofservice_tests.cpp
 34Running tests: descriptor_tests from test/descriptor_tests.cpp
 35Running tests: flatfile_tests from test/flatfile_tests.cpp
 36Running tests: fs_tests from test/fs_tests.cpp
 37Running tests: getarg_tests from test/getarg_tests.cpp
 38Running tests: hash_tests from test/hash_tests.cpp
 39Running tests: key_io_tests from test/key_io_tests.cpp
 40Running tests: key_tests from test/key_tests.cpp
 41Running tests: limitedmap_tests from test/limitedmap_tests.cpp
 42Running tests: logging_tests from test/logging_tests.cpp
 43Running tests: dbwrapper_tests from test/dbwrapper_tests.cpp
 44Running tests: validation_tests from test/validation_tests.cpp
 45Running tests: mempool_tests from test/mempool_tests.cpp
 46Running tests: merkle_tests from test/merkle_tests.cpp
 47Running tests: merkleblock_tests from test/merkleblock_tests.cpp
 48Running tests: miner_tests from test/miner_tests.cpp
 49Running tests: multisig_tests from test/multisig_tests.cpp
 50Running tests: net_tests from test/net_tests.cpp
 51Running tests: netbase_tests from test/netbase_tests.cpp
 52Running tests: pmt_tests from test/pmt_tests.cpp
 53Running tests: policyestimator_tests from test/policyestimator_tests.cpp
 54Running tests: pow_tests from test/pow_tests.cpp
 55Running tests: prevector_tests from test/prevector_tests.cpp
 56Running tests: raii_event_tests from test/raii_event_tests.cpp
 57Running tests: random_tests from test/random_tests.cpp
 58Running tests: reverselock_tests from test/reverselock_tests.cpp
 59Running tests: rpc_tests from test/rpc_tests.cpp
 60Running tests: sanity_tests from test/sanity_tests.cpp
 61Running tests: scheduler_tests from test/scheduler_tests.cpp
 62Running tests: script_p2sh_tests from test/script_p2sh_tests.cpp
 63Running tests: script_tests from test/script_tests.cpp
 64Running tests: script_standard_tests from test/script_standard_tests.cpp
 65Running tests: scriptnum_tests from test/scriptnum_tests.cpp
 66Running tests: serialize_tests from test/serialize_tests.cpp
 67Running tests: settings_tests from test/settings_tests.cpp
 68Running tests: sighash_tests from test/sighash_tests.cpp
 69Running tests: sigopcount_tests from test/sigopcount_tests.cpp
 70Running tests: skiplist_tests from test/skiplist_tests.cpp
 71Running tests: streams_tests from test/streams_tests.cpp
 72Running tests: sync_tests from test/sync_tests.cpp
 73Running tests: util_threadnames_tests from test/util_threadnames_tests.cpp
 74Running tests: timedata_tests from test/timedata_tests.cpp
 75Running tests: torcontrol_tests from test/torcontrol_tests.cpp
 76Running tests: transaction_tests from test/transaction_tests.cpp
 77Running tests: txindex_tests from test/txindex_tests.cpp
 78Running tests: txvalidation_tests from test/txvalidation_tests.cpp
 79Running tests: txvalidationcache_tests from test/txvalidationcache_tests.cpp
 80Running tests: uint256_tests from test/uint256_tests.cpp
 81Running tests: util_tests from test/util_tests.cpp
 82Running tests: validation_block_tests from test/validation_block_tests.cpp
 83Running tests: validation_flush_tests from test/validation_flush_tests.cpp
 84Running 1 test case...
 85Test cases order is shuffled using seed: 902477190
 86Entering test module "Bitcoin Core Test Suite"
 87test/validation_flush_tests.cpp(12): Entering test suite "validation_flush_tests"
 88test/validation_flush_tests.cpp(19): Entering test case "getcoinscachesizestate"
 892020-02-11T00:10:09Z Seed: Setting random seed for current tests to RANDOM_CTX_SEED=96807d9fd7f28bc0da6041aeaf760a509ee36b39cfa80ed6d37f4abb89713310
 902020-02-11T00:10:09Z Bitcoin Core version v0.19.99.0-55ece5fe2-dirty (release build)
 912020-02-11T00:10:09Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
 922020-02-11T00:10:09Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
 932020-02-11T00:10:09Z Opened LevelDB successfully
 942020-02-11T00:10:09Z Wrote new obfuscate key for /tmp/test_common_Bitcoin Core/3944085796/chainstate: 2f91067c72122910
 952020-02-11T00:10:09Z Using obfuscation key for /tmp/test_common_Bitcoin Core/3944085796/chainstate: 2f91067c72122910
 96CCoinsViewCache memory usage: 32
 97CCoinsViewCache memory usage: 336
 98CCoinsViewCache memory usage: 544
 99CCoinsViewCache memory usage: 752
100CCoinsViewCache memory usage: 960
101test/validation_flush_tests.cpp(99): error: in "validation_flush_tests/getcoinscachesizestate": check chainstate.GetCoinsCacheSizeState(tx_pool, MAX_COINS_CACHE_BYTES, 0) == CoinsCacheSizeState::OK has failed [1 != 0]
102CCoinsViewCache memory usage: 1168
1032020-02-11T00:10:09Z Cache size (1168) exceeds total space (1024)
1042020-02-11T00:10:09Z Cache size (1168) exceeds total space (1024)
105CCoinsViewCache memory usage: 1376
106CCoinsViewCache memory usage: 1584
107CCoinsViewCache memory usage: 1792
108CCoinsViewCache memory usage: 2000
109CoinsTip usage percentage: 0.976562
1102020-02-11T00:10:09Z Cache size (218768) exceeds total space (1024)
111CCoinsViewCache memory usage: 8896
1122020-02-11T00:10:09Z Cache size (8896) exceeds total space (1024)
113test/validation_flush_tests.cpp(19): Leaving test case "getcoinscachesizestate"; testing time: 204280us
114test/validation_flush_tests.cpp(12): Leaving test suite "validation_flush_tests"; testing time: 205321us
115Leaving test module "Bitcoin Core Test Suite"; testing time: 206834us
116
117*** 1 failure is detected in the test module "Bitcoin Core Test Suite"
118make[3]: *** [Makefile:17898: test/validation_flush_tests.cpp.test] Error 1
119make[3]: *** Waiting for unfinished jobs....
120make[3]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
121make[2]: *** [Makefile:16441: check-am] Error 2
122make[2]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
123make[1]: *** [Makefile:16126: check-recursive] Error 1
124make[1]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
125make: *** [Makefile:790: check-recursive] Error 1
  4. laanwj commented at 1:07 pm on February 11, 2020: member

    Thanks for reporting.

    It seems like quite a fragile test, depending specifically the dynamic memory use of structures. This can definitely differ per platform, or compiler/library versions especially when using C++ stdlib or boost data structures.

  5. laanwj commented at 1:38 pm on February 11, 2020: member

    The failing test part is

    0    constexpr int COINS_UNTIL_CRITICAL = is_64_bit ? 4 : 5;
1
2    for (int i{0}; i < COINS_UNTIL_CRITICAL; ++i) {
3        COutPoint res = add_coin(view);
4        print_view_mem_usage(view);
5        BOOST_CHECK_EQUAL(view.AccessCoin(res).DynamicMemoryUsage(), COIN_SIZE);
6        BOOST_CHECK_EQUAL(
7            chainstate.GetCoinsCacheSizeState(tx_pool, MAX_COINS_CACHE_BYTES, /*max_mempool_size_bytes*/ 0),
8            CoinsCacheSizeState::OK);
9    }

    This is the progression (of the 5 loop passes) in the passing circumstances (e.g.g amd64 Ubuntu 18.04):

    0CCoinsViewCache memory usage: 32
1CCoinsViewCache memory usage: 256
2CCoinsViewCache memory usage: 464
3CCoinsViewCache memory usage: 704
4CCoinsViewCache memory usage: 912

    This is the progression in the failing circumstances (RV64 fedora rawhide):

    0CCoinsViewCache memory usage: 32
1CCoinsViewCache memory usage: 336
2CCoinsViewCache memory usage: 544
3CCoinsViewCache memory usage: 752
4CCoinsViewCache memory usage: 960

    960 is larger than the large_threshold so hainstate.GetCoinsCacheSizeState returns CoinsCacheSizeState::LARGE instead of CoinsCacheSizeState::OK

    One level deeper;

    02020-02-11T14:32:06Z DynamicMemoryUsage 32 0 -> 32
12020-02-11T14:32:06Z DynamicMemoryUsage 176 80 -> 256
22020-02-11T14:32:06Z DynamicMemoryUsage 304 160 -> 464
32020-02-11T14:32:06Z DynamicMemoryUsage 464 240 -> 704
42020-02-11T14:32:06Z DynamicMemoryUsage 592 320 -> 912

    02020-02-11T14:31:19Z DynamicMemoryUsage 32 0 -> 32            
12020-02-11T14:31:19Z DynamicMemoryUsage 256 80 -> 336                                                   
22020-02-11T14:31:19Z DynamicMemoryUsage 384 160 -> 544            
32020-02-11T14:31:19Z DynamicMemoryUsage 512 240 -> 752        
42020-02-11T14:31:19Z DynamicMemoryUsage 640 320 -> 960

    memusage::DynamicUsage(cacheCoins) is responsible for the divergence. So the difference is in DynamicUsage(const std::unordered_map.

  6. laanwj commented at 4:10 pm on February 11, 2020: member

    This is interesting, I added instrumentation to static inline size_t DynamicUsage(const std::unordered_map<X, Y, Z>& m):

    • sizeof(unordered_node<std::pair<const X, Y> >) stays the same
    • m.size() stays the same
    • sizeof(void*) stays the same (obvs)
    • m.bucket_count() is the factor that changes

    Here’s bucket_count() per iteration, before and after:

    0before after delta
11      1     0      +0 bytes
23      13    10     +80 bytes
33      13    10     +80 bytes
47      13    6      +48 bytes
57      13    6      +48 bytes

    This explains the difference in memory usage notes in previous post.

    So it looks like the bucket allocation is done in coarser chunks “optimistically”. A difference in stdc++ behavior.

  7. laanwj renamed this:
    Unit test validation_flush_tests fails on RV64
    Unit test validation_flush_tests fails on with recent libstdc++?
    on Feb 11, 2020
  8. MarcoFalke commented at 5:09 pm on February 11, 2020: member
    What is the test testing exactly? @jamesob
  9. MarcoFalke commented at 1:56 am on February 18, 2020: member

    I also saw a failure on x86_64:

     0Running 1 test case...
 1
 2Entering test module "Bitcoin Core Test Suite"
 3
 4../../src/test/validation_flush_tests.cpp(12): Entering test suite "validation_flush_tests"
 5
 6../../src/test/validation_flush_tests.cpp(19): Entering test case "getcoinscachesizestate"
 7
 82020-02-18T01:15:33Z Seed: Setting random seed for current tests to RANDOM_CTX_SEED=3dc88853ef5f7e3ba8b13ea59166ea781e275e7b00f4b9dd3156fc3e66834f11
 9
102020-02-18T01:15:33Z Bitcoin Core version v0.19.99.0-unk (release build)
11
122020-02-18T01:15:33Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
13
142020-02-18T01:15:33Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
15
162020-02-18T01:15:33Z Opened LevelDB successfully
17
182020-02-18T01:15:33Z Wrote new obfuscate key for /tmp/test_common_Bitcoin Core/3560114667/chainstate: 5c21e65492dd3c16
19
202020-02-18T01:15:33Z Using obfuscation key for /tmp/test_common_Bitcoin Core/3560114667/chainstate: 5c21e65492dd3c16
21
22CCoinsViewCache memory usage: 32
23
24CCoinsViewCache memory usage: 336
25
26CCoinsViewCache memory usage: 544
27
28CCoinsViewCache memory usage: 752
29
30CCoinsViewCache memory usage: 960
31
32../../src/test/validation_flush_tests.cpp(99): error: in "validation_flush_tests/getcoinscachesizestate": check chainstate.GetCoinsCacheSizeState(tx_pool, MAX_COINS_CACHE_BYTES, 0) == CoinsCacheSizeState::OK has failed [1 != 0]
33
34CCoinsViewCache memory usage: 1168
35
362020-02-18T01:15:33Z Cache size (1168) exceeds total space (1024)
37
382020-02-18T01:15:33Z Cache size (1168) exceeds total space (1024)
39
40CCoinsViewCache memory usage: 1376
41
42CCoinsViewCache memory usage: 1584
43
44CCoinsViewCache memory usage: 1792
45
46CCoinsViewCache memory usage: 2000
47
48CoinsTip usage percentage: 0.976562
49
502020-02-18T01:15:33Z Cache size (218768) exceeds total space (1024)
51
52CCoinsViewCache memory usage: 8896
53
542020-02-18T01:15:33Z Cache size (8896) exceeds total space (1024)
55
56../../src/test/validation_flush_tests.cpp(19): Leaving test case "getcoinscachesizestate"; testing time: 32889us
57
58../../src/test/validation_flush_tests.cpp(12): Leaving test suite "validation_flush_tests"; testing time: 32903us
59
60Leaving test module "Bitcoin Core Test Suite"; testing time: 32948us
61
62*** 1 failure is detected in the test module "Bitcoin Core Test Suite"
  10. jamesob commented at 7:35 pm on February 18, 2020: member

    Oops, just seeing this. This is supposed to give us a comprehensive understanding of when coins cache flushes happen, but (as you can probably already see) the test is particularly narrow and brittle. I had to special-case out certain architectures, and now I guess the newer version of libstdc++ has created an additional case that allocates buckets differently.

    For posterity, this test was introduced in #16945. @ryanofsky was rightly concerned that the test was too finicky, but my rationale for including it is here: #16945 (comment)

    A few options here:

    • we can special-case test behavior based upon the bucket_count() @laanwj mentioned above,
    • we can remove the test altogether,
    • we can make the test less specific (i.e. just fill the cache with a bunch of entries and make sure we hit the highest severity cache state).

    I’m probably for the third option.

  11. MarcoFalke commented at 7:41 pm on February 18, 2020: member
    Agree that the third option to loosen up the test a bit and not depend on compiler or library internals makes sense.
  12. MarcoFalke closed this on Feb 22, 2020
  13. sidhujag referenced this in commit bb1a7056d9 on Feb 22, 2020
  14. sidhujag referenced this in commit 957ea7a98a on Nov 10, 2020
  15. PastaPastaPasta referenced this in commit f3d97f2f7f on Oct 23, 2021
  16. UdjinM6 referenced this in commit e66f5e4e70 on Oct 24, 2021
  17. PastaPastaPasta referenced this in commit f0cc5955b6 on Nov 1, 2021
  18. pravblockc referenced this in commit a9a9e00cce on Nov 18, 2021
  19. DrahtBot locked this on Feb 15, 2022


laanwj MarcoFalke jamesob

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-07-03 10:13 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me