Repository: bitcoin/bitcoin (language: cpp)

Issue:
verifychain 4 111000 aborts with assertion "hashPrevBlock == view.GetBestBlock()" failed
Providing a low number of blocks works, however, it just crashed for me with 111000 blocks.

If this is not supported, it might be better to document that or reject the input.

Commit 691a08718beff31d1b821b192609ea3bfdb24d41

Output:

```
bitcoin-qt: validation.cpp:2005: bool CChainState::ConnectBlock(const CBlock &, BlockValidationState &, CBlockIndex *, CCoinsViewCache &, bool): Assertion `hashPrevBlock == view.GetBestBlock()' failed.



Discussion / hints:
The debug log:

```
2022-07-07T07:57:50Z [qt-rpcconsole] [validation.cpp:3925] [VerifyDB] Verifying last 111000 blocks at level 4
2022-07-07T07:57:50Z [qt-rpcconsole] [validation.cpp:3932] [VerifyDB] [0%]...Selected []:8333 from tried
2022-07-07T07:57:50Z [opencon] [net.cpp:460] [ConnectNode] [net:debug] trying connection []:8333 lastseen=713.5hrs
2022-07-07T07:57:50Z [opencon] [net.cpp:2959] [CNode] [net] Added connection peer=4
2022-07-07T07:57:56Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T07:57:56Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T07:57:57Z [dnsseed] [net.cpp:1670] [ThreadDNSAddressSeed] P2P peers available. Skipped DNS seeding.
2022-07-07T07:57:57Z [dnsseed] [util/thread.cpp:19] [TraceThread] dnsseed thread exit
2022-07-07T07:58:07Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T07:58:07Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T07:58:24Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T07:58:24Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T07:58:50Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T07:58:50Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T07:59:29Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T07:59:29Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T07:59:50Z [net] [net.cpp:1547] [SocketHandlerConnected] [net] socket closed for peer=3
2022-07-07T07:59:50Z [net] [net.cpp:568] [CloseSocketDisconnect] [net] disconnecting peer=3
2022-07-07T08:00:26Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:00:26Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:01:53Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:01:53Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:04:03Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:04:03Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:07:17Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:07:17Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:12:09Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:12:09Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:17:37Z [net] [net.cpp:1390] [InactivityCheck] [net] socket sending timeout: 1201s peer=1
2022-07-07T08:17:37Z [net] [net.cpp:568] [CloseSocketDisconnect] [net] disconnecting peer=1
2022-07-07T08:19:27Z [torcontrol] [torcontrol.cpp:120] [eventcb] [tor] Error connecting to Tor control socket
2022-07-07T08:19:27Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:21:48Z [qt-rpcconsole] [validation.cpp:3940] [VerifyDB] [10%]...Error connecting to Tor control socket
2022-07-07T08:30:24Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:31:12Z [qt-rpcconsole] [validation.cpp:3940] [VerifyDB] [20%]...[30%]...Error connecting to Tor control socket
2022-07-07T08:46:50Z [torcontrol] [torcontrol.cpp:618] [disconnected_cb] [tor] Not connected to Tor control port 127.0.0.1:9051, trying to reconnect
2022-07-07T08:49:53Z [qt-rpcconsole] [validation.cpp:3940] [VerifyDB] [40%]...[50%]...

How to reproduce this issue?
This can be reproduced by lowering the dbcache (e.g. with `-dbcache=10`, `verifychain 4 1000` aborts on signet):
The level 3 checks do in-memory disconnect of blocks - and skip these if the memory exhausted ([code](https://github.com/bitcoin/bitcoin/blob/194710d8ff398838e4e5bb87b56e19ebed1d6c52/src/validation.cpp#L3976-L3978))
Then, the level 4 checks try to reconnect the blocks again in memory, and ConnectBlock() asserts because the coinsview best block and the block to be connected are out of sync.
I'm working on a fix, I think that if we run out of cache memory we should issue a warning and not attempt the level 4 checks.

Fix patch:
diff --git a/src/validation.cpp b/src/validation.cpp
index 62ce1f116244d..f0ffb748dd616 100644
--- a/src/validation.cpp
+++ b/src/validation.cpp
@@ -4081,7 +4081,8 @@ bool CVerifyDB::VerifyDB(
     int nGoodTransactions = 0;
     BlockValidationState state;
     int reportDone = 0;
-    LogPrintf("[0%%]..."); /* Continued */
+    bool skipped_l3_checks{false};
+    LogPrintf("Verification progress: 0%%\n");
 
     const bool is_snapshot_cs{!chainstate.m_from_snapshot_blockhash};
 
@@ -4089,7 +4090,7 @@ bool CVerifyDB::VerifyDB(
         const int percentageDone = std::max(1, std::min(99, (int)(((double)(chainstate.m_chain.Height() - pindex->nHeight)) / (double)nCheckDepth * (nCheckLevel >= 4 ? 50 : 100))));
         if (reportDone < percentageDone / 10) {
             // report every 10% step
-            LogPrintf("[%d%%]...", percentageDone); /* Continued */
+            LogPrintf("Verification progress: %d%%\n", percentageDone);
             reportDone = percentageDone / 10;
         }
         uiInterface.ShowProgress(_("Verifying blocks…").translated, percentageDone, false);
@@ -4124,17 +4125,21 @@ bool CVerifyDB::VerifyDB(
         // check level 3: check for inconsistencies during memory-only disconnect of tip blocks
         size_t curr_coins_usage = coins.DynamicMemoryUsage() + chainstate.CoinsTip().DynamicMemoryUsage();
 
-        if (nCheckLevel >= 3 && curr_coins_usage <= chainstate.m_coinstip_cache_size_bytes) {
-            assert(coins.GetBestBlock() == pindex->GetBlockHash());
-            DisconnectResult res = chainstate.DisconnectBlock(block, pindex, coins);
-            if (res == DISCONNECT_FAILED) {
-                return error("VerifyDB(): *** irrecoverable inconsistency in block data at %d, hash=%s", pindex->nHeight, pindex->GetBlockHash().ToString());
-            }
-            if (res == DISCONNECT_UNCLEAN) {
-                nGoodTransactions = 0;
-                pindexFailure = pindex;
+        if (nCheckLevel >= 3) {
+            if (curr_coins_usage <= chainstate.m_coinstip_cache_size_bytes) {
+                assert(coins.GetBestBlock() == pindex->GetBlockHash());
+                DisconnectResult res = chainstate.DisconnectBlock(block, pindex, coins);
+                if (res == DISCONNECT_FAILED) {
+                    return error("VerifyDB(): *** irrecoverable inconsistency in block data at %d, hash=%s", pindex->nHeight, pindex->GetBlockHash().ToString());
+                }
+                if (res == DISCONNECT_UNCLEAN) {
+                    nGoodTransactions = 0;
+                    pindexFailure = pindex;
+                } else {
+                    nGoodTransactions += block.vtx.size();
+                }
             } else {
-                nGoodTransactions += block.vtx.size();
+                skipped_l3_checks = true;
             }
         }
         if (ShutdownRequested()) return true;
@@ -4142,17 +4147,19 @@ bool CVerifyDB::VerifyDB(
     if (pindexFailure) {
         return error("VerifyDB(): *** coin database inconsistencies found (last %i blocks, %i good transactions before that)\n", chainstate.m_chain.Height() - pindexFailure->nHeight + 1, nGoodTransactions);
     }
-
+    if (skipped_l3_checks) {
+        LogPrintf("Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.\n");
+    }
     // store block count as we move pindex at check level >= 4
     int block_count = chainstate.m_chain.Height() - pindex->nHeight;
 
     // check level 4: try reconnecting blocks
-    if (nCheckLevel >= 4) {
+    if (nCheckLevel >= 4 && !skipped_l3_checks) {
         while (pindex != chainstate.m_chain.Tip()) {
             const int percentageDone = std::max(1, std::min(99, 100 - (int)(((double)(chainstate.m_chain.Height() - pindex->nHeight)) / (double)nCheckDepth * 50)));
             if (reportDone < percentageDone / 10) {
                 // report every 10% step
-                LogPrintf("[%d%%]...", percentageDone); /* Continued */
+                LogPrintf("Verification progress: %d%%\n", percentageDone);
                 reportDone = percentageDone / 10;
             }
             uiInterface.ShowProgress(_("Verifying blocks…").translated, percentageDone, false);
@@ -4167,8 +4174,7 @@ bool CVerifyDB::VerifyDB(
         }
     }
 
-    LogPrintf("[DONE].\n");
-    LogPrintf("No coin database inconsistencies in last %i blocks (%i transactions)\n", block_count, nGoodTransactions);
+    LogPrintf("Verification: No coin database inconsistencies in last %i blocks (%i transactions)\n", block_count, nGoodTransactions);
 
     return true;
 }


Test patch: