Page MenuHomePhabricator

CheckBlockIndex before unlocking cs_main
Changes PlannedPublic

Authored by markblundeberg on Jan 18 2020, 03:06.

Details

Reviewers
fpelliccioni
Fabien
deadalnix
Group Reviewers
Restricted Project
Summary

probes the bug introduced during D4802. should be fixed after D4929.

Note: It's not a serious problem, only would affect regtest nodes having a race during reconsiderblock or parkblock RPC commands which basically nobody uses.

Depends on D4929.

Test Plan

ninja check-all

Diff Detail

Repository
rABC Bitcoin ABC
Branch
crashy
Lint
Lint Passed
Unit
No Test Coverage
Build Status
Buildable 9046
Build 16054: Default Diff Build & Tests
Build 16053: arc lint + arc unit

Event Timeline

Snippet of first build failure:

[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_keypool_topup.py                 | ✓ Passed  | 3 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_labels.py                        | ✓ Passed  | 3 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_listreceivedby.py                | ✓ Passed  | 9 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_listsinceblock.py                | ✓ Passed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_listtransactions.py              | ✓ Passed  | 11 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_multiwallet.py                   | ✓ Passed  | 7 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_multiwallet.py --usecli          | ✓ Passed  | 8 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_resendwallettransactions.py      | ✓ Passed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_txn_clone.py                     | ✓ Passed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_txn_clone.py --mineblock         | ✓ Passed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_txn_doublespend.py               | ✓ Passed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_txn_doublespend.py --mineblock   | ✓ Passed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;34mwallet_zapwallettxes.py                 | ✓ Passed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-finalize-block.py                   | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-get-invalid-block.py                | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-invalid-chains.py                   | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-mempool-coherence-on-activations.py | ✖ Failed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-parkedchain.py                      | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mabc-replay-protection.py                | ✖ Failed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mfeature_bip68_sequence.py               | ✖ Failed  | 18 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mfeature_csv_activation.py               | ✖ Failed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mfeature_notifications.py                | ✖ Failed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mmempool_packages.py                     | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mmempool_reorg.py                        | ✖ Failed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mmempool_resurrect.py                    | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mmining_prioritisetransaction.py         | ✖ Failed  | 2 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mp2p_sendheaders.py                      | ✖ Failed  | 4 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mrpc_blockchain.py                       | ✖ Failed  | 1 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mrpc_invalidateblock.py                  | ✖ Failed  | 0 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mrpc_rawtransaction.py                   | ✖ Failed  | 4 s
[03:11:23] :	 [Step 1/1]  [0m [0;31mwallet_abandonconflict.py               | ✖ Failed  | 5 s
[03:11:23] :	 [Step 1/1]  [0m [0;31m [1m
[03:11:23] :	 [Step 1/1] ALL                                     | ✖ Failed  | 352 s (accumulated) 
[03:11:23]W:	 [Step 1/1] ++ print_sanitizers_log
[03:11:23]W:	 [Step 1/1] ++ for log in "${SAN_LOG_DIR}"/*.log.*
[03:11:23] :	 [Step 1/1]  [0m [0mRuntime: 203 s
[03:11:23]W:	 [Step 1/1] ++ echo '*** Output of /tmp/sanitizer_logs/*.log.* ***'
[03:11:23] :	 [Step 1/1] 
[03:11:23]W:	 [Step 1/1] ++ cat '/tmp/sanitizer_logs/*.log.*'
[03:11:23] :	 [Step 1/1] [239/352] Running bitcoin-qt test suite
[03:11:23] :	 [Step 1/1] PASSED: bitcoin-qt test suite
[03:11:23] :	 [Step 1/1] [240/352] cd /home/teamcity/buildAgent/work/c4a5708f2bae7929/contrib/devtools/chainparams && /usr/bin/python3 ./test_make_chainparams.py
[03:11:23] :	 [Step 1/1] .....
[03:11:23] :	 [Step 1/1] ----------------------------------------------------------------------
[03:11:23] :	 [Step 1/1] Ran 5 tests in 0.001s
[03:11:23] :	 [Step 1/1] 
[03:11:23] :	 [Step 1/1] OK
[03:11:23] :	 [Step 1/1] [287/352] Running secp256k1 test suite
[03:11:23] :	 [Step 1/1] PASSED: secp256k1 test suite
[03:11:23] :	 [Step 1/1] [349/352] Running bitcoin test suite
[03:11:23] :	 [Step 1/1] PASSED: bitcoin test suite
[03:11:23] :	 [Step 1/1] [351/352] Running leveldb test suite
[03:11:23] :	 [Step 1/1] PASSED: leveldb test suite
[03:11:23] :	 [Step 1/1] FAILED: test/CMakeFiles/check-functional 
[03:11:23] :	 [Step 1/1] cd /home/teamcity/buildAgent/work/c4a5708f2bae7929/build/test && /usr/bin/python3 ./functional/test_runner.py
[03:11:23] :	 [Step 1/1] ninja: build stopped: subcommand failed.
[03:11:23] :	 [Step 1/1] *** Output of /tmp/sanitizer_logs/*.log.* ***
[03:11:23]W:	 [Step 1/1] cat: '/tmp/sanitizer_logs/*.log.*': No such file or directory
[03:11:23]W:	 [Step 1/1] Process exited with code 1
[03:11:23]E:	 [Step 1/1] Process exited with code 1 (Step: Command Line)

Each failure log is accessible here:
bitcoin_abc_tests: abc-finalize-block.py
bitcoin_abc_tests: abc-get-invalid-block.py
bitcoin_abc_tests: abc-invalid-chains.py
bitcoin_abc_tests: abc-mempool-coherence-on-activations.py
bitcoin_abc_tests: abc-parkedchain.py
bitcoin_abc_tests: abc-replay-protection.py
bitcoin_abc_tests: feature_bip68_sequence.py
bitcoin_abc_tests: feature_csv_activation.py
bitcoin_abc_tests: feature_notifications.py
bitcoin_abc_tests: mempool_packages.py
bitcoin_abc_tests: mempool_reorg.py
bitcoin_abc_tests: mempool_resurrect.py
bitcoin_abc_tests: mining_prioritisetransaction.py
bitcoin_abc_tests: p2p_sendheaders.py
bitcoin_abc_tests: rpc_blockchain.py
bitcoin_abc_tests: rpc_invalidateblock.py
bitcoin_abc_tests: rpc_rawtransaction.py
bitcoin_abc_tests: wallet_abandonconflict.py

Above failures on master, now will try rebased.

Snippet of first build failure:

[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_basic.py                         | ✓ Passed  | 26 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_createwallet.py                  | ✓ Passed  | 1 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_createwallet.py --usecli         | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_disable.py                       | ✓ Passed  | 0 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_dump.py                          | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_encryption.py                    | ✓ Passed  | 4 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_groups.py                        | ✓ Passed  | 7 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_hd.py                            | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_import_rescan.py                 | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_importmulti.py                   | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_importprunedfunds.py             | ✓ Passed  | 1 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_keypool.py                       | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_keypool_topup.py                 | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_labels.py                        | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_listreceivedby.py                | ✓ Passed  | 11 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_listsinceblock.py                | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_listtransactions.py              | ✓ Passed  | 8 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_multiwallet.py                   | ✓ Passed  | 9 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_multiwallet.py --usecli          | ✓ Passed  | 9 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_resendwallettransactions.py      | ✓ Passed  | 1 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_txn_clone.py                     | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_txn_clone.py --mineblock         | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_txn_doublespend.py               | ✓ Passed  | 3 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_txn_doublespend.py --mineblock   | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;34mwallet_zapwallettxes.py                 | ✓ Passed  | 2 s
[03:25:08] :	 [Step 1/1]  [0m [0;31mabc-finalize-block.py                   | ✖ Failed  | 0 s
[03:25:08] :	 [Step 1/1]  [0m [0;31mabc-invalid-chains.py                   | ✖ Failed  | 0 s
[03:25:08] :	 [Step 1/1]  [0m [0;31mfeature_bip68_sequence.py               | ✖ Failed  | 17 s
[03:25:08] :	 [Step 1/1]  [0m [0;31mrpc_invalidateblock.py                  | ✖ Failed  | 0 s
[03:25:08] :	 [Step 1/1]  [0m [0;31m [1m
[03:25:08] :	 [Step 1/1] ALL                                     | ✖ Failed  | 463 s (accumulated) 
[03:25:08] :	 [Step 1/1]  [0m [0mRuntime: 104 s
[03:25:08] :	 [Step 1/1] 
[03:25:08] :	 [Step 1/1] [216/352] cd /home/teamcity/buildAgent/work/c4a5708f2bae7929/contrib/devtools/chainparams && /usr/bin/python3 ./test_make_chainparams.py
[03:25:08] :	 [Step 1/1] .....
[03:25:08] :	 [Step 1/1] ----------------------------------------------------------------------
[03:25:08] :	 [Step 1/1] Ran 5 tests in 0.001s
[03:25:08] :	 [Step 1/1] 
[03:25:08] :	 [Step 1/1] OK
[03:25:08] :	 [Step 1/1] [219/352] Running bitcoin-seeder test suite
[03:25:08] :	 [Step 1/1] PASSED: bitcoin-seeder test suite
[03:25:08] :	 [Step 1/1] [336/352] Running bitcoin-qt test suite
[03:25:08] :	 [Step 1/1] PASSED: bitcoin-qt test suite
[03:25:08] :	 [Step 1/1] [346/352] Running bitcoin test suite
[03:25:08] :	 [Step 1/1] PASSED: bitcoin test suite
[03:25:08] :	 [Step 1/1] [349/352] Running secp256k1 test suite
[03:25:08] :	 [Step 1/1] PASSED: secp256k1 test suite
[03:25:08] :	 [Step 1/1] [351/352] Running leveldb test suite
[03:25:08] :	 [Step 1/1] PASSED: leveldb test suite
[03:25:08] :	 [Step 1/1] FAILED: test/CMakeFiles/check-functional 
[03:25:08] :	 [Step 1/1] cd /home/teamcity/buildAgent/work/c4a5708f2bae7929/build/test && /usr/bin/python3 ./functional/test_runner.py
[03:25:08] :	 [Step 1/1] ninja: build stopped: subcommand failed.
[03:25:08]W:	 [Step 1/1] ++ print_sanitizers_log
[03:25:08]W:	 [Step 1/1] ++ for log in "${SAN_LOG_DIR}"/*.log.*
[03:25:08]W:	 [Step 1/1] ++ echo '*** Output of /tmp/sanitizer_logs/*.log.* ***'
[03:25:08]W:	 [Step 1/1] ++ cat '/tmp/sanitizer_logs/*.log.*'
[03:25:08] :	 [Step 1/1] *** Output of /tmp/sanitizer_logs/*.log.* ***
[03:25:08]W:	 [Step 1/1] cat: '/tmp/sanitizer_logs/*.log.*': No such file or directory
[03:25:08]W:	 [Step 1/1] Process exited with code 1
[03:25:08]E:	 [Step 1/1] Process exited with code 1 (Step: Command Line)

Each failure log is accessible here:
bitcoin_abc_tests: abc-finalize-block.py
bitcoin_abc_tests: abc-invalid-chains.py
bitcoin_abc_tests: feature_bip68_sequence.py
bitcoin_abc_tests: rpc_invalidateblock.py

OK, just a few failures remaining now, so it's better with that parent but something still wrong...

The remaining inconsistencies are probably related to this fix:

https://github.com/bitcoin/bitcoin/pull/16849

src/validation.cpp
3052

Essentially, every time we call DisconnectTip we ought to rescan the entire block index and find blocks that have enough chainwork and add them to setBlockIndexCandidates, before we unlock cs_main.

This unfortunately seems to be a very time consuming thing if we are rewinding many blocks, but on the other hand, hardly anyone ever calls invalidateblock / parkblock RPCs so it's more important to be correct than to be broken and efficient.