Repository: bitcoin/bitcoin (language: cpp)

Issue:
coinstatsindex way more fragile than any other data w.r.t. power loss

<!-- This issue tracker is only for technical issues related to Bitcoin Core.

General bitcoin questions and/or support requests are best directed to the Bitcoin StackExchange at https://bitcoin.stackexchange.com.

For reporting security issues, please read instructions at https://bitcoincore.org/en/contact/.

If the node is "stuck" during sync or giving "block checksum mismatch" errors, please ensure your hardware is stable by running memtest and observe CPU temperature with a load-test tool such as linpack before creating an issue! -->

<!-- Describe the issue -->

**Two times since a fresh 22.0 installation I've had a power loss event (artifically produced to test system behavior), and each time I've started getting incorrect muhash values for block heights since approximately that moment**

"Approximately", as in I've not taken care to record the exact time of events because I've expecting nothing of interest from bitcoind in particular; "incorrect", as in compared to my another long-running nodes running with coinstatsindex without power outages, **and** to its own muhash for the current tip calculated without using the index, `gettxoutsetinfo muhash null false`.

**Expected behavior**

As usual when testing power outage behavior, I've expected pretty much anything **except** silently returning incorrect data. Most desirable would be checking several recent block muhashes on restart and auto-correcting the problem.
 
**To reproduce**

Unsure if it can be reproduced reliably, but 2/2 times are rather good indicator that it may not be uncommon 

**System information**

Ubuntu Linux 20.04, `~/.bitcoin` on /dev/md raid1 over two HDDs, ext4 fs with default mount options

Running bitcoind 22.0 prebuilt binaries from bitcoincore (amd64).

Here's debug.log from a typical restart (I see nothing interesting there, just in case if some configured or autodetected parameters are relevant):
```
 2022-01-14T17:10:34Z Bitcoin Core version v22.0.0 (release build)
2022-01-14T17:10:34Z Assuming ancestors of block 00000000000000000008a89e854d57e5667df88f1cdef6fde2fbca1de5b639ad have valid signatures.
2022-01-14T17:10:34Z Setting nMinimumChainWork=00000000000000000000000000000000000000001fa4663bbbe19f82de910280
2022-01-14T17:10:34Z Using the 'shani(1way,2way)' SHA256 implementation
2022-01-14T17:10:34Z Using RdSeed as additional entropy source
2022-01-14T17:10:34Z Using RdRand as an additional entropy source
2022-01-14T17:10:34Z Default data directory /home/bitnode/.bitcoin
2022-01-14T17:10:34Z Using data directory /srv/slow/dot-bitcoin
2022-01-14T17:10:34Z Config file: /etc/bitcoin/bitcoin.conf
2022-01-14T17:10:34Z Config file arg: blockfilterindex="1"
2022-01-14T17:10:34Z Config file arg: coinstatsindex="1"
2022-01-14T17:10:34Z Config file arg: dbcache="2000"
2022-01-14T17:10:34Z Config file arg: listen="1"
2022-01-14T17:10:34Z Config file arg: maxuploadtarget="450"
2022-01-14T17:10:34Z Config file arg: peerblockfilters="1"
2022-01-14T17:10:34Z Config file arg: server="1"
2022-01-14T17:10:34Z Config file arg: txindex="1"
2022-01-14T17:10:34Z Config file arg: upnp="0"
2022-01-14T17:10:34Z Config file arg: whitelist="download@127.0.0.1"
2022-01-14T17:10:34Z Config file arg: whitelist="download@192.168.1.0/24"
2022-01-14T17:10:34Z Config file arg: zmqpubrawblock="tcp://127.0.0.1:28332"
2022-01-14T17:10:34Z Config file arg: zmqpubrawtx="tcp://127.0.0.1:28333"
2022-01-14T17:10:34Z Command-line arg: conf="/etc/bitcoin/bitcoin.conf"
2022-01-14T17:10:34Z Command-line arg: daemonwait=""
2022-01-14T17:10:34Z Command-line arg: datadir="/srv/slow/dot-bitcoin/"
2022-01-14T17:10:34Z Command-line arg: pid="/run/bitcoind/bitcoind.pid"
2022-01-14T17:10:34Z Using at most 125 automatic connections (1024 file descriptors available)
2022-01-14T17:10:34Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2022-01-14T17:10:34Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2022-01-14T17:10:34Z Script verification uses 15 additional threads
2022-01-14T17:10:34Z scheduler thread start
2022-01-14T17:10:34Z HTTP: creating work queue of depth 16
2022-01-14T17:10:34Z Using random cookie authentication.
2022-01-14T17:10:34Z Generated RPC authentication cookie /srv/slow/dot-bitcoin/.cookie
2022-01-14T17:10:34Z HTTP: starting 4 worker threads
2022-01-14T17:10:34Z Using wallet directory /srv/slow/dot-bitcoin/wallets
2022-01-14T17:10:34Z init message: Verifying wallet(s)…
2022-01-14T17:10:34Z init message: Loading banlist…
2022-01-14T17:10:34Z SetNetworkActive: true
2022-01-14T17:10:34Z Using /16 prefix for IP bucketing
2022-01-14T17:10:34Z Cache configuration:
2022-01-14T17:10:34Z * Using 2.0 MiB for block index database
2022-01-14T17:10:34Z * Using 249.8 MiB for transaction index database
2022-01-14T17:10:34Z * Using 218.5 MiB for basic block filter index database
2022-01-14T17:10:34Z * Using 8.0 MiB for chain state database
2022-01-14T17:10:34Z * Using 1521.7 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
2022-01-14T17:10:34Z init message: Loading block index…
2022-01-14T17:10:34Z Switching active chainstate to Chainstate [ibd] @ height -1 (null)
2022-01-14T17:10:34Z Opening LevelDB in /srv/slow/dot-bitcoin/blocks/index
2022-01-14T17:10:34Z Opened LevelDB successfully
2022-01-14T17:10:34Z Using obfuscation key for /srv/slow/dot-bitcoin/blocks/index: 0000000000000000
2022-01-14T17:10:38Z LoadBlockIndexDB: last block file = 2883
2022-01-14T17:10:38Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=17, size=20113255, heights=718645...718661, time=2022-01-14...2022-01-14)
2022-01-14T17:10:38Z Checking all blk files are present...
2022-01-14T17:10:38Z Opening LevelDB in /srv/slow/dot-bitcoin/chainstate
2022-01-14T17:10:39Z Opened LevelDB successfully
2022-01-14T17:10:39Z Using obfuscation key for /srv/slow/dot-bitcoin/chainstate: d57f45de91bd35fa
2022-01-14T17:10:39Z Loaded best chain: hashBestChain=000000000000000000001cab1821f8b5ce71faccfde4d9ae11ab444c0dff979f height=718643 date=2022-01-14T14:19:04Z progress=0.999964
2022-01-14T17:10:39Z init message: Verifying blocks…
2022-01-14T17:10:39Z Verifying last 6 blocks at level 3
2022-01-14T17:10:39Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2022-01-14T17:12:34Z No coin database inconsistencies in last 6 blocks (9259 transactions)
2022-01-14T17:12:34Z  block index          120309ms
2022-01-14T17:12:34Z Opening LevelDB in /srv/slow/dot-bitcoin/indexes/txindex
2022-01-14T17:12:35Z Opened LevelDB successfully
2022-01-14T17:12:35Z Using obfuscation key for /srv/slow/dot-bitcoin/indexes/txindex: 0000000000000000
2022-01-14T17:12:35Z txindex thread start
2022-01-14T17:12:35Z txindex is enabled at height 718643
2022-01-14T17:12:35Z txindex thread exit
2022-01-14T17:12:35Z Opening LevelDB in /srv/slow/dot-bitcoin/indexes/blockfilter/basic/db
2022-01-14T17:12:35Z Opened LevelDB successfully
2022-01-14T17:12:35Z Using obfuscation key for /srv/slow/dot-bitcoin/indexes/blockfilter/basic/db: 0000000000000000
2022-01-14T17:12:35Z basic block filter index thread start
2022-01-14T17:12:35Z basic block filter index is enabled at height 718643
2022-01-14T17:12:35Z basic block filter index thread exit
2022-01-14T17:12:35Z Opening LevelDB in /srv/slow/dot-bitcoin/indexes/coinstats/db
2022-01-14T17:12:36Z Opened LevelDB successfully
2022-01-14T17:12:36Z Using obfuscation key for /srv/slow/dot-bitcoin/indexes/coinstats/db: 0000000000000000
2022-01-14T17:12:36Z coinstatsindex thread start
2022-01-14T17:12:36Z coinstatsindex is enabled at height 718643
2022-01-14T17:12:36Z coinstatsindex thread exit
2022-01-14T17:12:36Z block tree size = 718667
2022-01-14T17:12:36Z nBestHeight = 718643
2022-01-14T17:12:36Z loadblk thread start
....
```
<!-- What version of Bitcoin Core are you using, where did you get it (website, self-compiled, etc)? -->

<!-- What type of machine are you observing the error on (OS/CPU and disk type)? -->

<!-- GUI-related issue? What is your operating system and its version? If Linux, what is your desktop environment and graphical shell? -->

<!-- Any extra information that might be useful in the debugging process. -->
<!--- This is normally the contents of a `debug.log` or `config.log` file. Raw text or a link to a pastebin type site are preferred. -->



Discussion / hints:
cc @fjahr: can we add a test for an unclean shutdown to the indexer? 
Not sure if that is the same cause because the unclean shutdown is initiated already during init there, but if I use `-coinstatsindex` instead of `-txindex` in `feature_init.py`, that test fails for me.
Oh, interesting, I am investigating, thanks for tagging me @Sjors 
just fyi, the `feature_init` fail I mentioned is unrelated to this and not so serious.
(The problem there is that `BaseIndex::CommitInternal` doesn't check if `m_best_block_index == nullptr`, which can happen if init is interrupted very early before indexing anything. In that case, DB_BEST_BLOCK is written with a block locator corresponding to the [tip](https://github.com/bitcoin/bitcoin/blob/06b6369766137756648b3cb62c8f385cca234e69/src/chain.cpp#L31-L32), and on the next start we think the index is fully synced when we actually aren't synced at all. Might still open a small fix for this in the next days.)
I have tried to reproduce this by `kill -9`ing the process but was not successful so far. I think something like this is also the best we could do in an automated test. However I opened #24133 that should address the issue by failing loudly if the restart is indeed the source of the issue.

@akovalenko Thanks a lot for reporting, you have already given a lot of information but since I couldn't reproduce the issue yet it would be great if you could give me more details. Any of the following would be very helpful:

- Was only the `muhash` value out of sync or also the other outputs of the index that are also returned with the non index `gettxoutsetinfo muhash null false`?
- If you have any real outputs of the `gettxoutsetinfo` calls after it got out of sync that would be great!
- If you could dissect or observe the next time if the index got indeed out of sync at the restart or at another point that would be even better. If you still have the corrupted index you could use https://github.com/bitcoin/bitcoin/pull/19792 to dump the whole index and upload the result, then I could go search for the offending height as well.
- If you do these planned failures regularly you could also maybe run #24133 with one of them to see if that catches the issue.

Fix patch:
diff --git a/src/index/coinstatsindex.cpp b/src/index/coinstatsindex.cpp
index a1c8a5937cd10..386eb67ce9fd6 100644
--- a/src/index/coinstatsindex.cpp
+++ b/src/index/coinstatsindex.cpp
@@ -228,10 +228,9 @@ bool CoinStatsIndex::WriteBlock(const CBlock& block, const CBlockIndex* pindex)
     m_muhash.Finalize(out);
     value.second.muhash = out;
 
-    CDBBatch batch(*m_db);
-    batch.Write(DBHeightKey(pindex->nHeight), value);
-    batch.Write(DB_MUHASH, m_muhash);
-    return m_db->WriteBatch(batch);
+    // Intentionally do not update DB_MUHASH here so it stays in sync with
+    // DB_BEST_BLOCK, and the index is not corrupted if there is an unclean shutdown.
+    return m_db->Write(DBHeightKey(pindex->nHeight), value);
 }
 
 static bool CopyHeightIndexToHashIndex(CDBIterator& db_it, CDBBatch& batch,
@@ -388,6 +387,14 @@ bool CoinStatsIndex::Init()
     return true;
 }
 
+bool CoinStatsIndex::CommitInternal(CDBBatch& batch)
+{
+    // DB_MUHASH should always be committed in a batch together with DB_BEST_BLOCK
+    // to prevent an inconsistent state of the DB.
+    batch.Write(DB_MUHASH, m_muhash);
+    return BaseIndex::CommitInternal(batch);
+}
+
 // Reverse a single block as part of a reorg
 bool CoinStatsIndex::ReverseBlock(const CBlock& block, const CBlockIndex* pindex)
 {
@@ -489,5 +496,5 @@ bool CoinStatsIndex::ReverseBlock(const CBlock& block, const CBlockIndex* pindex
     Assert(m_total_unspendables_scripts == read_out.second.total_unspendables_scripts);
     Assert(m_total_unspendables_unclaimed_rewards == read_out.second.total_unspendables_unclaimed_rewards);
 
-    return m_db->Write(DB_MUHASH, m_muhash);
+    return true;
 }
diff --git a/src/index/coinstatsindex.h b/src/index/coinstatsindex.h
index d2a6c9c9646da..24190ac13768e 100644
--- a/src/index/coinstatsindex.h
+++ b/src/index/coinstatsindex.h
@@ -39,6 +39,8 @@ class CoinStatsIndex final : public BaseIndex
 protected:
     bool Init() override;
 
+    bool CommitInternal(CDBBatch& batch) override;
+
     bool WriteBlock(const CBlock& block, const CBlockIndex* pindex) override;
 
     bool Rewind(const CBlockIndex* current_tip, const CBlockIndex* new_tip) override;
diff --git a/src/validationinterface.h b/src/validationinterface.h
index 7c3ce00fbcc2a..ac62f8b467d6e 100644
--- a/src/validationinterface.h
+++ b/src/validationinterface.h
@@ -174,6 +174,7 @@ class CValidationInterface {
      * has been received and connected to the headers tree, though not validated yet */
     virtual void NewPoWValidBlock(const CBlockIndex *pindex, const std::shared_ptr<const CBlock>& block) {};
     friend class CMainSignals;
+    friend class ValidationInterfaceTest;
 };
 
 struct MainSignalsInstance;


Test patch:
diff --git a/src/test/coinstatsindex_tests.cpp b/src/test/coinstatsindex_tests.cpp
index 92de4ec7ba975..5b73481bc1e72 100644
--- a/src/test/coinstatsindex_tests.cpp
+++ b/src/test/coinstatsindex_tests.cpp
@@ -2,8 +2,10 @@
 // Distributed under the MIT software license, see the accompanying
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
+#include <chainparams.h>
 #include <index/coinstatsindex.h>
 #include <test/util/setup_common.h>
+#include <test/util/validation.h>
 #include <util/time.h>
 #include <validation.h>
 
@@ -16,6 +18,17 @@ using node::CoinStatsHashType;
 
 BOOST_AUTO_TEST_SUITE(coinstatsindex_tests)
 
+static void IndexWaitSynced(BaseIndex& index)
+{
+    // Allow the CoinStatsIndex to catch up with the block index that is syncing
+    // in a background thread.
+    const auto timeout = GetTime<std::chrono::seconds>() + 120s;
+    while (!index.BlockUntilSyncedToCurrentChain()) {
+        BOOST_REQUIRE(timeout > GetTime<std::chrono::milliseconds>());
+        UninterruptibleSleep(100ms);
+    }
+}
+
 BOOST_FIXTURE_TEST_CASE(coinstatsindex_initial_sync, TestChain100Setup)
 {
     CoinStatsIndex coin_stats_index{1 << 20, true};
@@ -36,13 +49,7 @@ BOOST_FIXTURE_TEST_CASE(coinstatsindex_initial_sync, TestChain100Setup)
 
     BOOST_REQUIRE(coin_stats_index.Start(m_node.chainman->ActiveChainstate()));
 
-    // Allow the CoinStatsIndex to catch up with the block index that is syncing
-    // in a background thread.
-    const auto timeout = GetTime<std::chrono::seconds>() + 120s;
-    while (!coin_stats_index.BlockUntilSyncedToCurrentChain()) {
-        BOOST_REQUIRE(timeout > GetTime<std::chrono::milliseconds>());
-        UninterruptibleSleep(100ms);
-    }
+    IndexWaitSynced(coin_stats_index);
 
     // Check that CoinStatsIndex works for genesis block.
     const CBlockIndex* genesis_block_index;
@@ -78,4 +85,44 @@ BOOST_FIXTURE_TEST_CASE(coinstatsindex_initial_sync, TestChain100Setup)
     // Rest of shutdown sequence and destructors happen in ~TestingSetup()
 }
 
+// Test shutdown between BlockConnected and ChainStateFlushed notifications,
+// make sure index is not corrupted and is able to reload.
+BOOST_FIXTURE_TEST_CASE(coinstatsindex_unclean_shutdown, TestChain100Setup)
+{
+    CChainState& chainstate = Assert(m_node.chainman)->ActiveChainstate();
+    const CChainParams& params = Params();
+    {
+        CoinStatsIndex index{1 << 20};
+        BOOST_REQUIRE(index.Start(chainstate));
+        IndexWaitSynced(index);
+        std::shared_ptr<const CBlock> new_block;
+        CBlockIndex* new_block_index = nullptr;
+        {
+            const CScript script_pub_key{CScript() << ToByteVector(coinbaseKey.GetPubKey()) << OP_CHECKSIG};
+            const CBlock block = this->CreateBlock({}, script_pub_key, chainstate);
+
+            new_block = std::make_shared<CBlock>(block);
+
+            LOCK(cs_main);
+            BlockValidationState state;
+            BOOST_CHECK(CheckBlock(block, state, params.GetConsensus()));
+            BOOST_CHECK(chainstate.AcceptBlock(new_block, state, &new_block_index, true, nullptr, nullptr));
+            CCoinsViewCache view(&chainstate.CoinsTip());
+            BOOST_CHECK(chainstate.ConnectBlock(block, state, new_block_index, view));
+        }
+        // Send block connected notification, then stop the index without
+        // sending a chainstate flushed notification. Prior to #24138, this
+        // would cause the index to be corrupted and fail to reload.
+        ValidationInterfaceTest::BlockConnected(index, new_block, new_block_index);
+        index.Stop();
+    }
+
+    {
+        CoinStatsIndex index{1 << 20};
+        // Make sure the index can be loaded.
+        BOOST_REQUIRE(index.Start(chainstate));
+        index.Stop();
+    }
+}
+
 BOOST_AUTO_TEST_SUITE_END()
diff --git a/src/test/util/validation.cpp b/src/test/util/validation.cpp
index 1aed492c3c037..49535855f9884 100644
--- a/src/test/util/validation.cpp
+++ b/src/test/util/validation.cpp
@@ -7,6 +7,7 @@
 #include <util/check.h>
 #include <util/time.h>
 #include <validation.h>
+#include <validationinterface.h>
 
 void TestChainState::ResetIbd()
 {
@@ -20,3 +21,8 @@ void TestChainState::JumpOutOfIbd()
     m_cached_finished_ibd = true;
     Assert(!IsInitialBlockDownload());
 }
+
+void ValidationInterfaceTest::BlockConnected(CValidationInterface& obj, const std::shared_ptr<const CBlock>& block, const CBlockIndex* pindex)
+{
+    obj.BlockConnected(block, pindex);
+}
diff --git a/src/test/util/validation.h b/src/test/util/validation.h
index b13aa0be60d55..b0bc717b6c227 100644
--- a/src/test/util/validation.h
+++ b/src/test/util/validation.h
@@ -7,6 +7,8 @@
 
 #include <validation.h>
 
+class CValidationInterface;
+
 struct TestChainState : public CChainState {
     /** Reset the ibd cache to its initial state */
     void ResetIbd();
@@ -14,4 +16,10 @@ struct TestChainState : public CChainState {
     void JumpOutOfIbd();
 };
 
+class ValidationInterfaceTest
+{
+public:
+    static void BlockConnected(CValidationInterface& obj, const std::shared_ptr<const CBlock>& block, const CBlockIndex* pindex);
+};
+
 #endif // BITCOIN_TEST_UTIL_VALIDATION_H