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

validation_flush_tests/getcoinscachesizestate fails on RISCV-64 on master:

Running 394 test cases...
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]

*** 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++

Same on debian:sid (ports)

make[4]: Entering directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
============================================================================
Testsuite summary for Bitcoin Core 0.19.99
============================================================================
# TOTAL: 0
# PASS:  0
# SKIP:  0
# XFAIL: 0
# FAIL:  0
# XPASS: 0
# ERROR: 0
============================================================================
make[4]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
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
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: logging_tests from test/logging_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
Running tests: multisig_tests from test/multisig_tests.cpp
Running tests: net_tests from test/net_tests.cpp
Running tests: netbase_tests from test/netbase_tests.cpp
Running tests: pmt_tests from test/pmt_tests.cpp
Running tests: policyestimator_tests from test/policyestimator_tests.cpp
Running tests: pow_tests from test/pow_tests.cpp
Running tests: prevector_tests from test/prevector_tests.cpp
Running tests: raii_event_tests from test/raii_event_tests.cpp
Running tests: random_tests from test/random_tests.cpp
Running tests: reverselock_tests from test/reverselock_tests.cpp
Running tests: rpc_tests from test/rpc_tests.cpp
Running tests: sanity_tests from test/sanity_tests.cpp
Running tests: scheduler_tests from test/scheduler_tests.cpp
Running tests: script_p2sh_tests from test/script_p2sh_tests.cpp
Running tests: script_tests from test/script_tests.cpp
Running tests: script_standard_tests from test/script_standard_tests.cpp
Running tests: scriptnum_tests from test/scriptnum_tests.cpp
Running tests: serialize_tests from test/serialize_tests.cpp
Running tests: settings_tests from test/settings_tests.cpp
Running tests: sighash_tests from test/sighash_tests.cpp
Running tests: sigopcount_tests from test/sigopcount_tests.cpp
Running tests: skiplist_tests from test/skiplist_tests.cpp
Running tests: streams_tests from test/streams_tests.cpp
Running tests: sync_tests from test/sync_tests.cpp
Running tests: util_threadnames_tests from test/util_threadnames_tests.cpp
Running tests: timedata_tests from test/timedata_tests.cpp
Running tests: torcontrol_tests from test/torcontrol_tests.cpp
Running tests: transaction_tests from test/transaction_tests.cpp
Running tests: txindex_tests from test/txindex_tests.cpp
Running tests: txvalidation_tests from test/txvalidation_tests.cpp
Running tests: txvalidationcache_tests from test/txvalidationcache_tests.cpp
Running tests: uint256_tests from test/uint256_tests.cpp
Running tests: util_tests from test/util_tests.cpp
Running tests: validation_block_tests from test/validation_block_tests.cpp
Running tests: validation_flush_tests from test/validation_flush_tests.cpp
Running 1 test case...
Test cases order is shuffled using seed: 902477190
Entering test module "Bitcoin Core Test Suite"
test/validation_flush_tests.cpp(12): Entering test suite "validation_flush_tests"
test/validation_flush_tests.cpp(19): Entering test case "getcoinscachesizestate"
2020-02-11T00:10:09Z Seed: Setting random seed for current tests to RANDOM_CTX_SEED=96807d9fd7f28bc0da6041aeaf760a509ee36b39cfa80ed6d37f4abb89713310
2020-02-11T00:10:09Z Bitcoin Core version v0.19.99.0-55ece5fe2-dirty (release build)
2020-02-11T00:10:09Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2020-02-11T00:10:09Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2020-02-11T00:10:09Z Opened LevelDB successfully
2020-02-11T00:10:09Z Wrote new obfuscate key for /tmp/test_common_Bitcoin Core/3944085796/chainstate: 2f91067c72122910
2020-02-11T00:10:09Z Using obfuscation key for /tmp/test_common_Bitcoin Core/3944085796/chainstate: 2f91067c72122910
CCoinsViewCache memory usage: 32
CCoinsViewCache memory usage: 336
CCoinsViewCache memory usage: 544
CCoinsViewCache memory usage: 752
CCoinsViewCache memory usage: 960
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]
CCoinsViewCache memory usage: 1168
2020-02-11T00:10:09Z Cache size (1168) exceeds total space (1024)
2020-02-11T00:10:09Z Cache size (1168) exceeds total space (1024)
CCoinsViewCache memory usage: 1376
CCoinsViewCache memory usage: 1584
CCoinsViewCache memory usage: 1792
CCoinsViewCache memory usage: 2000
CoinsTip usage percentage: 0.976562
2020-02-11T00:10:09Z Cache size (218768) exceeds total space (1024)
CCoinsViewCache memory usage: 8896
2020-02-11T00:10:09Z Cache size (8896) exceeds total space (1024)
test/validation_flush_tests.cpp(19): Leaving test case "getcoinscachesizestate"; testing time: 204280us
test/validation_flush_tests.cpp(12): Leaving test suite "validation_flush_tests"; testing time: 205321us
Leaving test module "Bitcoin Core Test Suite"; testing time: 206834us

*** 1 failure is detected in the test module "Bitcoin Core Test Suite"
make[3]: *** [Makefile:17898: test/validation_flush_tests.cpp.test] Error 1
make[3]: *** Waiting for unfinished jobs....
make[3]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
make[2]: *** [Makefile:16441: check-am] Error 2
make[2]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
make[1]: *** [Makefile:16126: check-recursive] Error 1
make[1]: Leaving directory '/home/test/bitcoin/build/bitcoin-riscv64-linux-gnu/src'
make: *** [Makefile:790: check-recursive] Error 1

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.

The failing test part is

    constexpr int COINS_UNTIL_CRITICAL = is_64_bit ? 4 : 5;

    for (int i{0}; i < COINS_UNTIL_CRITICAL; ++i) {
        COutPoint res = add_coin(view);
        print_view_mem_usage(view);
        BOOST_CHECK_EQUAL(view.AccessCoin(res).DynamicMemoryUsage(), COIN_SIZE);
        BOOST_CHECK_EQUAL(
            chainstate.GetCoinsCacheSizeState(tx_pool, MAX_COINS_CACHE_BYTES, /*max_mempool_size_bytes*/ 0),
            CoinsCacheSizeState::OK);
    }

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

CCoinsViewCache memory usage: 32
CCoinsViewCache memory usage: 256
CCoinsViewCache memory usage: 464
CCoinsViewCache memory usage: 704
CCoinsViewCache memory usage: 912

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

CCoinsViewCache memory usage: 32
CCoinsViewCache memory usage: 336
CCoinsViewCache memory usage: 544
CCoinsViewCache memory usage: 752
CCoinsViewCache memory usage: 960

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

One level deeper;

2020-02-11T14:32:06Z DynamicMemoryUsage 32 0 -> 32
2020-02-11T14:32:06Z DynamicMemoryUsage 176 80 -> 256
2020-02-11T14:32:06Z DynamicMemoryUsage 304 160 -> 464
2020-02-11T14:32:06Z DynamicMemoryUsage 464 240 -> 704
2020-02-11T14:32:06Z DynamicMemoryUsage 592 320 -> 912

2020-02-11T14:31:19Z DynamicMemoryUsage 32 0 -> 32            
2020-02-11T14:31:19Z DynamicMemoryUsage 256 80 -> 336                                                   
2020-02-11T14:31:19Z DynamicMemoryUsage 384 160 -> 544            
2020-02-11T14:31:19Z DynamicMemoryUsage 512 240 -> 752        
2020-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.

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:

before after delta
1      1     0      +0 bytes
3      13    10     +80 bytes
3      13    10     +80 bytes
7      13    6      +48 bytes
7      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.

What is the test testing exactly? @jamesob

I also saw a failure on x86_64:

Running 1 test case...

Entering test module "Bitcoin Core Test Suite"

../../src/test/validation_flush_tests.cpp(12): Entering test suite "validation_flush_tests"

../../src/test/validation_flush_tests.cpp(19): Entering test case "getcoinscachesizestate"

2020-02-18T01:15:33Z Seed: Setting random seed for current tests to RANDOM_CTX_SEED=3dc88853ef5f7e3ba8b13ea59166ea781e275e7b00f4b9dd3156fc3e66834f11

2020-02-18T01:15:33Z Bitcoin Core version v0.19.99.0-unk (release build)

2020-02-18T01:15:33Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements

2020-02-18T01:15:33Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements

2020-02-18T01:15:33Z Opened LevelDB successfully

2020-02-18T01:15:33Z Wrote new obfuscate key for /tmp/test_common_Bitcoin Core/3560114667/chainstate: 5c21e65492dd3c16

2020-02-18T01:15:33Z Using obfuscation key for /tmp/test_common_Bitcoin Core/3560114667/chainstate: 5c21e65492dd3c16

CCoinsViewCache memory usage: 32

CCoinsViewCache memory usage: 336

CCoinsViewCache memory usage: 544

CCoinsViewCache memory usage: 752

CCoinsViewCache memory usage: 960

../../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]

CCoinsViewCache memory usage: 1168

2020-02-18T01:15:33Z Cache size (1168) exceeds total space (1024)

2020-02-18T01:15:33Z Cache size (1168) exceeds total space (1024)

CCoinsViewCache memory usage: 1376

CCoinsViewCache memory usage: 1584

CCoinsViewCache memory usage: 1792

CCoinsViewCache memory usage: 2000

CoinsTip usage percentage: 0.976562

2020-02-18T01:15:33Z Cache size (218768) exceeds total space (1024)

CCoinsViewCache memory usage: 8896

2020-02-18T01:15:33Z Cache size (8896) exceeds total space (1024)

../../src/test/validation_flush_tests.cpp(19): Leaving test case "getcoinscachesizestate"; testing time: 32889us

../../src/test/validation_flush_tests.cpp(12): Leaving test suite "validation_flush_tests"; testing time: 32903us

Leaving test module "Bitcoin Core Test Suite"; testing time: 32948us

*** 1 failure is detected in the test module "Bitcoin Core Test Suite"

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.

Agree that the third option to loosen up the test a bit and not depend on compiler or library internals makes sense.