Assertion `setBlockIndexCandidates.count(pindex)’ failed #16444

issue MarcoFalke openend this issue on July 23, 2019
  1. MarcoFalke commented at 7:44 pm on July 23, 2019: member

    This happened on travis as part of a pull request that only modified ATMP logic. So the assertion can likely also be hit on a clean master.

    https://travis-ci.org/bitcoin/bitcoin/jobs/562128739#L4513 (in rpc_invalidateblock.py)

  2. MarcoFalke commented at 8:12 pm on July 23, 2019: member
    Rerunning on the same commit passes: https://travis-ci.org/bitcoin/bitcoin/jobs/562756024, so this is indeed intermittent.
  3. MarcoFalke commented at 6:54 pm on July 24, 2019: member

    More of those assertions incoming: https://travis-ci.org/bitcoin/bitcoin/jobs/563191235#L4660

    So this happened in a recent commit, it seems.

  4. sdaftuar commented at 9:11 pm on July 24, 2019: member

    Hypothesis: #15402 broke the consistency requirements of setBlockIndexCandidates in InvalidateBlock, because we let go of cs_main between disconnecting blocks and adding entries to setBlockIndexCandidates. So CheckBlockIndex() could fail if invoked in-between those two things happening. Then #16194 came along and added a CheckBlockIndex() call to a place it didn’t exist before, namely when an invalid header is received from a peer. This can happen in a race with InvalidateBlock() in the rpc_invalidateblock test, because we use connect_nodes_bi to connect node0 with node1, resulting in two block announcements for the same set of blocks from node1 to node0.

    If that guess is correct, then I think we should either decide on some new relaxed consistency requirement, if someone can come up with a reasonable justification (I haven’t tried yet), or re-work InvalidateBlock() to keep setBlockIndexCandidates in sync with the current chain tip at all times (perhaps by adding things that will eventually need to be added at the beginning, rather than at the end, but I’d need to give that more thought as well).

  5. MarcoFalke added this to the milestone 0.19.0 on Aug 24, 2019
  6. MarcoFalke added the label Bug on Aug 24, 2019
  7. MarcoFalke added the label Validation on Aug 24, 2019
  8. laanwj referenced this in commit cd737214ce on Sep 16, 2019
  9. sidhujag referenced this in commit f9a3ff0065 on Sep 16, 2019
  10. Sjors commented at 10:12 am on September 30, 2019: member

    I hit a different assertion recently while testing #16899 (utxo snapshots): Assertion failed: (!setBlockIndexCandidates.empty()), function PruneBlockIndexCandidates, file validation.cpp, line 2658.

    This happened after I wound back the chain to block 570000, and then somehow the chain started moving forward to the tip, which I interrupted by calling invalidate again, etc. Not entirely sure what happened, I also got the timeout error described in #16979. But the end result was that gettxoutsetinfo returned when it reached the tip. And the next time I started the node I got this assertion.

    I’m not sure if this is related, so I created #16993.

  11. Sjors commented at 2:48 pm on September 30, 2019: member
    I was hoping to test @sdaftuar’s hypothesis in the wild by having a mainnet node with lots of peers run with -checkblockindex=1 and then rewinding the chain. However this is non trivial. Peers get banned during the rollback (whitelist=0.0.0.0/0 doesn’t help) and -checkblockindex=1 causes the node to freeze when I go back to tip, see #16998.
  12. MarcoFalke closed this on Oct 2, 2019
  13. MarcoFalke commented at 2:11 pm on March 11, 2020: member

    This is still happening in rpc_invalidateblock:

    https://travis-ci.org/github/bitcoin/bitcoin/jobs/660672084#L6188

    0 node1 stderr bitcoind: validation.cpp:4854: void CChainState::CheckBlockIndex(const Consensus::Params &): Assertion `setBlockIndexCandidates.count(pindex)' failed.
  14. MarcoFalke reopened this on Mar 11, 2020
  15. MarcoFalke removed this from the milestone 0.19.0 on Apr 24, 2020
  16. MarcoFalke commented at 2:38 pm on May 14, 2020: member

    Still failing:

    0 node1 stderr bitcoind: validation.cpp:4859: void CChainState::CheckBlockIndex(const Consensus::Params &): Assertion `setBlockIndexCandidates.count(pindex)' failed.
  17. MarcoFalke closed this on Mar 8, 2021
  18. vijaydasmp referenced this in commit c1060026d1 on Dec 6, 2021
  19. vijaydasmp referenced this in commit 63b39a1f65 on Dec 10, 2021
  20. vijaydasmp referenced this in commit 68a010f4ff on Dec 13, 2021
  21. vijaydasmp referenced this in commit 3bc73a2abf on Dec 13, 2021
  22. vijaydasmp referenced this in commit bff9273316 on Dec 15, 2021
  23. DrahtBot locked this on Aug 18, 2022
  24. MarcoFalke unlocked this on Jan 4, 2023
  25. MarcoFalke commented at 11:32 am on January 4, 2023: member

    On master as of last week https://cirrus-ci.com/task/6436681495085056?logs=ci#L5232 :

     0 node1 2022-12-25T10:45:50.907549Z [httpworker.3] [validationinterface.cpp:242] [BlockDisconnected] [validation] Enqueuing BlockDisconnected: block hash=16f088ff4289a960faf08c7579c9f21d51bf3badc7f791bb793a6911ea649ebb block height=14 
 1 node1 2022-12-25T10:45:50.907585Z [httpworker.3] [validation.cpp:1601] [InvalidChainFound] InvalidChainFound: invalid block=16f088ff4289a960faf08c7579c9f21d51bf3badc7f791bb793a6911ea649ebb  height=14  log2_work=4.906891  date=2022-12-25T10:45:54Z 
 2 node1 2022-12-25T10:45:50.907593Z [httpworker.3] [validation.cpp:1606] [InvalidChainFound] InvalidChainFound:  current best=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da  height=13  log2_work=4.807355  date=2022-12-25T10:45:53Z 
 3 node1 2022-12-25T10:45:50.907954Z [http] [httpserver.cpp:239] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:53444 
 4 node1 2022-12-25T10:45:50.907988Z [httpworker.1] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=invalidateblock user=__cookie__ 
 5 node1 2022-12-25T10:45:50.908059Z [httpworker.1] [validation.cpp:2632] [DisconnectTip] [bench] - Disconnect block: 0.02ms 
 6 node1 2022-12-25T10:45:50.908076Z [httpworker.1] [validation.cpp:2546] [UpdateTipLog] UpdateTip: new best=2bd6394602012af268e92aa096393c635970ef1236801a57e66595dfdc53d90e height=12 version=0x20000000 log2_work=4.700440 tx=13 date='2022-12-25T10:45:53Z' progress=1.000000 cache=0.0MiB(16txo) 
 7 node1 2022-12-25T10:45:50.908084Z [httpworker.1] [validationinterface.cpp:242] [BlockDisconnected] [validation] Enqueuing BlockDisconnected: block hash=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da block height=13 
 8 node1 2022-12-25T10:45:50.908102Z [httpworker.1] [validation.cpp:1601] [InvalidChainFound] InvalidChainFound: invalid block=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da  height=13  log2_work=4.807355  date=2022-12-25T10:45:53Z 
 9 node1 2022-12-25T10:45:50.908110Z [httpworker.1] [validation.cpp:1606] [InvalidChainFound] InvalidChainFound:  current best=2bd6394602012af268e92aa096393c635970ef1236801a57e66595dfdc53d90e  height=12  log2_work=4.700440  date=2022-12-25T10:45:53Z 
10 node1 2022-12-25T10:45:50.908487Z [http] [httpserver.cpp:239] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:53444 
11 node1 2022-12-25T10:45:50.908518Z [httpworker.2] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__ 
12 node1 2022-12-25T10:45:50.908855Z [http] [httpserver.cpp:239] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:53444 
13 node1 2022-12-25T10:45:50.908886Z [httpworker.0] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=reconsiderblock user=__cookie__ 
14 node1 2022-12-25T10:45:50.908940Z [httpworker.0] [validation.cpp:2751] [ConnectTip] [bench]   - Load block from disk: 0.03ms [0.00s (0.01ms/blk)] 
15 node1 2022-12-25T10:45:50.908952Z [httpworker.0] [validation.cpp:2068] [ConnectBlock] [bench]     - Sanity checks: 0.00ms [0.00s (0.00ms/blk)] 
16 node1 2022-12-25T10:45:50.908962Z [httpworker.0] [validation.cpp:2170] [ConnectBlock] [bench]     - Fork checks: 0.01ms [0.00s (0.01ms/blk)] 
17 node1 2022-12-25T10:45:50.908971Z [httpworker.0] [validation.cpp:2260] [ConnectBlock] [bench]       - Connect 1 transactions: 0.01ms (0.007ms/tx, 0.000ms/txin) [0.00s (0.01ms/blk)] 
18 node1 2022-12-25T10:45:50.908988Z [httpworker.0] [validation.cpp:2278] [ConnectBlock] [bench]     - Verify 0 txins: 0.03ms (0.000ms/txin) [0.00s (0.02ms/blk)] 
19 node1 2022-12-25T10:45:50.908995Z [httpworker.0] [validation.cpp:2292] [ConnectBlock] [bench]     - Write undo data: 0.01ms [0.00s (0.01ms/blk)] 
20 node1 2022-12-25T10:45:50.909001Z [httpworker.0] [validation.cpp:2307] [ConnectBlock] [bench]     - Index writing: 0.01ms [0.00s (0.00ms/blk)] 
21 node1 2022-12-25T10:45:50.909008Z [httpworker.0] [validationinterface.cpp:255] [BlockChecked] [validation] BlockChecked: block hash=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da state=Valid 
22 node1 2022-12-25T10:45:50.909015Z [httpworker.0] [validation.cpp:2767] [ConnectTip] [bench]   - Connect total: 0.08ms [0.00s (0.04ms/blk)] 
23 node1 2022-12-25T10:45:50.909021Z [httpworker.0] [validation.cpp:2776] [ConnectTip] [bench]   - Flush: 0.01ms [0.00s (0.00ms/blk)] 
24 node1 2022-12-25T10:45:50.909028Z [httpworker.0] [validation.cpp:2786] [ConnectTip] [bench]   - Writing chainstate: 0.01ms [0.00s (0.00ms/blk)] 
25 node1 2022-12-25T10:45:50.909042Z [httpworker.0] [validation.cpp:2546] [UpdateTipLog] UpdateTip: new best=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da height=13 version=0x20000000 log2_work=4.807355 tx=14 date='2022-12-25T10:45:53Z' progress=1.000000 cache=0.0MiB(16txo) 
26 node1 2022-12-25T10:45:50.909048Z [httpworker.0] [validation.cpp:2802] [ConnectTip] [bench]   - Connect postprocess: 0.02ms [0.01s (0.24ms/blk)] 
27 node1 2022-12-25T10:45:50.909054Z [httpworker.0] [validation.cpp:2806] [ConnectTip] [bench] - Connect block: 0.14ms [0.01s (0.29ms/blk)] 
28 node1 2022-12-25T10:45:50.909060Z [httpworker.0] [txmempool.cpp:658] [check] [mempool] Checking mempool with 0 transactions and 0 inputs 
29 node1 2022-12-25T10:45:50.909068Z [httpworker.0] [validationinterface.cpp:232] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da block height=13 
30 node1 2022-12-25T10:45:50.909076Z [httpworker.0] [validationinterface.cpp:204] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=1d468aa9111562d5eea05da733b4f1ad848ba19d64a48a922b9bb9e2cdf469da fork block hash=2bd6394602012af268e92aa096393c635970ef1236801a57e66595dfdc53d90e (in IBD=false) 
31
32 node1 stderr bitcoind: validation.cpp:4648: void Chainstate::CheckBlockIndex(): Assertion `setBlockIndexCandidates.count(pindex)' failed.
  26. MarcoFalke reopened this on Jan 4, 2023


MarcoFalke sdaftuar Sjors

Labels
Bug Validation

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