Compare commits

...

7 Commits

Author SHA1 Message Date
Pieter Wuille
5fd9927a7d
Merge 15619a1c99f6cc815291adf150bb8049c75a91cc into 5f4422d68dc3530c353af1f87499de1c864b60ad 2025-03-17 03:54:48 +01:00
merge-script
5f4422d68d
Merge bitcoin/bitcoin#32010: qa: Fix TxIndex race conditions
3301d2cbe8c3b76c97285d75fa59637cb6952d0b qa: Wait for txindex to avoid race condition (Hodlinator)
9bfb0d75ba10591cc6c9620f9fd1ecc0e55e7a48 qa: Remove unnecessary -txindex args (Hodlinator)
7ac281c19cd3d11f316dbbb3308eabf1ad4f26d6 qa: Add missing coverage of corrupt indexes (Hodlinator)

Pull request description:

  - Add synchronization in 3 places where if the Transaction Index happens to be slow, we get rare test failures when querying it for transactions (one such case experienced on Windows, prompting investigation).
  - Remove unnecessary TxIndex initialization in some tests.
  - Add some test coverage where TxIndex aspect could be tested in feature_init.py.

ACKs for top commit:
  fjahr:
    re-ACK 3301d2cbe8c3b76c97285d75fa59637cb6952d0b
  mzumsande:
    Code Review ACK 3301d2cbe8c3b76c97285d75fa59637cb6952d0b
  furszy:
    Code review ACK 3301d2cbe8c3b76c97285d75fa59637cb6952d0b
  Prabhat1308:
    Concept ACK [`3301d2c`](3301d2cbe8)

Tree-SHA512: 7c2019e38455f344856aaf6b381faafbd88d53dc88d13309deb718c1dcfbee4ccca7c7f1b66917395503a6f94c3b216a007ad432cc8b93d0309db9805f38d602
2025-03-17 10:28:14 +08:00
Hodlinator
3301d2cbe8
qa: Wait for txindex to avoid race condition
Can be verified to be necessary through adding std::this_thread::sleep_for(0.5s) at the beginning of TxIndex::CustomAppend.
2025-03-10 15:24:16 +01:00
Hodlinator
9bfb0d75ba
qa: Remove unnecessary -txindex args
(Parent commit ensured indexes in feature_init.py are actually used, otherwise they would be removed here as well).
2025-03-07 22:22:31 +01:00
Hodlinator
7ac281c19c
qa: Add missing coverage of corrupt indexes 2025-03-07 22:22:31 +01:00
Pieter Wuille
15619a1c99 validation: use dirty coins count in flush warnings 2025-01-22 14:15:52 -05:00
Pieter Wuille
586f2a6b1b coins: keep track of number of dirty entries in cache 2025-01-22 14:15:52 -05:00
11 changed files with 81 additions and 24 deletions

View File

@ -78,6 +78,7 @@ void CCoinsViewCache::AddCoin(const COutPoint &outpoint, Coin&& coin, bool possi
bool fresh = false;
if (!inserted) {
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
m_dirty_count -= it->second.IsDirty();
}
if (!possible_overwrite) {
if (!it->second.coin.IsSpent()) {
@ -100,6 +101,7 @@ void CCoinsViewCache::AddCoin(const COutPoint &outpoint, Coin&& coin, bool possi
}
it->second.coin = std::move(coin);
CCoinsCacheEntry::SetDirty(*it, m_sentinel);
++m_dirty_count;
if (fresh) CCoinsCacheEntry::SetFresh(*it, m_sentinel);
cachedCoinsUsage += it->second.coin.DynamicMemoryUsage();
TRACEPOINT(utxocache, add,
@ -113,7 +115,10 @@ void CCoinsViewCache::AddCoin(const COutPoint &outpoint, Coin&& coin, bool possi
void CCoinsViewCache::EmplaceCoinInternalDANGER(COutPoint&& outpoint, Coin&& coin) {
cachedCoinsUsage += coin.DynamicMemoryUsage();
auto [it, inserted] = cacheCoins.try_emplace(std::move(outpoint), std::move(coin));
if (inserted) CCoinsCacheEntry::SetDirty(*it, m_sentinel);
if (inserted) {
CCoinsCacheEntry::SetDirty(*it, m_sentinel);
++m_dirty_count;
}
}
void AddCoins(CCoinsViewCache& cache, const CTransaction &tx, int nHeight, bool check_for_overwrite) {
@ -131,6 +136,7 @@ bool CCoinsViewCache::SpendCoin(const COutPoint &outpoint, Coin* moveout) {
CCoinsMap::iterator it = FetchCoin(outpoint);
if (it == cacheCoins.end()) return false;
cachedCoinsUsage -= it->second.coin.DynamicMemoryUsage();
m_dirty_count -= it->second.IsDirty();
TRACEPOINT(utxocache, spent,
outpoint.hash.data(),
(uint32_t)outpoint.n,
@ -144,6 +150,7 @@ bool CCoinsViewCache::SpendCoin(const COutPoint &outpoint, Coin* moveout) {
cacheCoins.erase(it);
} else {
CCoinsCacheEntry::SetDirty(*it, m_sentinel);
++m_dirty_count;
it->second.coin.Clear();
}
return true;
@ -204,6 +211,7 @@ bool CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256 &ha
}
cachedCoinsUsage += entry.coin.DynamicMemoryUsage();
CCoinsCacheEntry::SetDirty(*itUs, m_sentinel);
++m_dirty_count;
// We can mark it FRESH in the parent if it was FRESH in the child
// Otherwise it might have just been flushed from the parent's cache
// and already exist in the grandparent
@ -223,6 +231,7 @@ bool CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256 &ha
// The grandparent cache does not have an entry, and the coin
// has been spent. We can just delete it from the parent cache.
cachedCoinsUsage -= itUs->second.coin.DynamicMemoryUsage();
m_dirty_count -= itUs->second.IsDirty();
cacheCoins.erase(itUs);
} else {
// A normal modification.
@ -235,7 +244,10 @@ bool CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256 &ha
itUs->second.coin = it->second.coin;
}
cachedCoinsUsage += itUs->second.coin.DynamicMemoryUsage();
CCoinsCacheEntry::SetDirty(*itUs, m_sentinel);
if (!itUs->second.IsDirty()) {
++m_dirty_count;
CCoinsCacheEntry::SetDirty(*itUs, m_sentinel);
}
// NOTE: It isn't safe to mark the coin as FRESH in the parent
// cache. If it already existed and was spent in the parent
// cache then marking it FRESH would prevent that spentness
@ -248,19 +260,20 @@ bool CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256 &ha
}
bool CCoinsViewCache::Flush() {
auto cursor{CoinsViewCacheCursor(cachedCoinsUsage, m_sentinel, cacheCoins, /*will_erase=*/true)};
auto cursor{CoinsViewCacheCursor(cachedCoinsUsage, m_dirty_count, m_sentinel, cacheCoins, /*will_erase=*/true)};
bool fOk = base->BatchWrite(cursor, hashBlock);
if (fOk) {
cacheCoins.clear();
ReallocateCache();
}
cachedCoinsUsage = 0;
m_dirty_count = 0;
return fOk;
}
bool CCoinsViewCache::Sync()
{
auto cursor{CoinsViewCacheCursor(cachedCoinsUsage, m_sentinel, cacheCoins, /*will_erase=*/false)};
auto cursor{CoinsViewCacheCursor(cachedCoinsUsage, m_dirty_count, m_sentinel, cacheCoins, /*will_erase=*/false)};
bool fOk = base->BatchWrite(cursor, hashBlock);
if (fOk) {
if (m_sentinel.second.Next() != &m_sentinel) {
@ -306,6 +319,7 @@ void CCoinsViewCache::ReallocateCache()
{
// Cache should be empty when we're calling this.
assert(cacheCoins.size() == 0);
Assume(m_dirty_count == 0);
cacheCoins.~CCoinsMap();
m_cache_coins_memory_resource.~CCoinsMapMemoryResource();
::new (&m_cache_coins_memory_resource) CCoinsMapMemoryResource{};
@ -316,6 +330,7 @@ void CCoinsViewCache::SanityCheck() const
{
size_t recomputed_usage = 0;
size_t count_flagged = 0;
size_t dirty_count = 0;
for (const auto& [_, entry] : cacheCoins) {
unsigned attr = 0;
if (entry.IsDirty()) attr |= 1;
@ -327,6 +342,9 @@ void CCoinsViewCache::SanityCheck() const
// Recompute cachedCoinsUsage.
recomputed_usage += entry.coin.DynamicMemoryUsage();
// Recompute m_num_dirty;
dirty_count += entry.IsDirty();
// Count the number of entries we expect in the linked list.
if (entry.IsDirty() || entry.IsFresh()) ++count_flagged;
}
@ -343,6 +361,7 @@ void CCoinsViewCache::SanityCheck() const
}
assert(count_linked == count_flagged);
assert(recomputed_usage == cachedCoinsUsage);
assert(dirty_count == m_dirty_count);
}
static const size_t MIN_TRANSACTION_OUTPUT_WEIGHT = WITNESS_SCALE_FACTOR * ::GetSerializeSize(CTxOut());

View File

@ -272,10 +272,11 @@ struct CoinsViewCacheCursor
//! Calling CCoinsMap::clear() afterwards is faster because a CoinsCachePair cannot be coerced back into a
//! CCoinsMap::iterator to be erased, and must therefore be looked up again by key in the CCoinsMap before being erased.
CoinsViewCacheCursor(size_t& usage LIFETIMEBOUND,
size_t& dirty LIFETIMEBOUND,
CoinsCachePair& sentinel LIFETIMEBOUND,
CCoinsMap& map LIFETIMEBOUND,
bool will_erase) noexcept
: m_usage(usage), m_sentinel(sentinel), m_map(map), m_will_erase(will_erase) {}
: m_usage(usage), m_dirty(dirty), m_sentinel(sentinel), m_map(map), m_will_erase(will_erase) {}
inline CoinsCachePair* Begin() const noexcept { return m_sentinel.second.Next(); }
inline CoinsCachePair* End() const noexcept { return &m_sentinel; }
@ -284,6 +285,7 @@ struct CoinsViewCacheCursor
inline CoinsCachePair* NextAndMaybeErase(CoinsCachePair& current) noexcept
{
const auto next_entry{current.second.Next()};
m_dirty -= current.second.IsDirty();
// If we are not going to erase the cache, we must still erase spent entries.
// Otherwise, clear the state of the entry.
if (!m_will_erase) {
@ -300,6 +302,7 @@ struct CoinsViewCacheCursor
inline bool WillErase(CoinsCachePair& current) const noexcept { return m_will_erase || current.second.coin.IsSpent(); }
private:
size_t& m_usage;
size_t& m_dirty;
CoinsCachePair& m_sentinel;
CCoinsMap& m_map;
bool m_will_erase;
@ -377,6 +380,8 @@ protected:
/* Cached dynamic memory usage for the inner Coin objects. */
mutable size_t cachedCoinsUsage{0};
/* Running count of dirty Coin cache entries. */
mutable size_t m_dirty_count{0};
public:
CCoinsViewCache(CCoinsView *baseIn, bool deterministic = false);
@ -463,6 +468,9 @@ public:
//! Calculate the size of the cache (in number of transaction outputs)
unsigned int GetCacheSize() const;
//! Calculate the number of dirty cache entries (transaction outputs)
size_t GetDirtyCount() const noexcept { return m_dirty_count; }
//! Calculate the size of the cache (in bytes)
size_t DynamicMemoryUsage() const;

View File

@ -100,6 +100,7 @@ public:
CCoinsMap& map() const { return cacheCoins; }
CoinsCachePair& sentinel() const { return m_sentinel; }
size_t& usage() const { return cachedCoinsUsage; }
size_t& GetDirtyCount() const { return m_dirty_count; }
};
} // namespace
@ -652,7 +653,8 @@ static void WriteCoinsViewEntry(CCoinsView& view, const MaybeCoin& cache_coin)
CCoinsMapMemoryResource resource;
CCoinsMap map{0, CCoinsMap::hasher{}, CCoinsMap::key_equal{}, &resource};
auto usage{cache_coin ? InsertCoinsMapEntry(map, sentinel, *cache_coin) : 0};
auto cursor{CoinsViewCacheCursor(usage, sentinel, map, /*will_erase=*/true)};
size_t dirty = cache_coin ? cache_coin->IsDirty() : 0;
auto cursor{CoinsViewCacheCursor(usage, dirty, sentinel, map, /*will_erase=*/true)};
BOOST_CHECK(view.BatchWrite(cursor, {}));
}
@ -663,7 +665,10 @@ public:
{
auto base_cache_coin{base_value == ABSENT ? MISSING : CoinEntry{base_value, CoinEntry::State::DIRTY}};
WriteCoinsViewEntry(base, base_cache_coin);
if (cache_coin) cache.usage() += InsertCoinsMapEntry(cache.map(), cache.sentinel(), *cache_coin);
if (cache_coin) {
cache.usage() += InsertCoinsMapEntry(cache.map(), cache.sentinel(), *cache_coin);
cache.GetDirtyCount() += cache_coin->IsDirty();
}
}
CCoinsView root;

View File

@ -123,6 +123,7 @@ FUZZ_TARGET(coins_view, .init = initialize_coins_view)
CoinsCachePair sentinel{};
sentinel.second.SelfRef(sentinel);
size_t usage{0};
size_t num_dirty{0};
CCoinsMapMemoryResource resource;
CCoinsMap coins_map{0, SaltedOutpointHasher{/*deterministic=*/true}, CCoinsMap::key_equal{}, &resource};
LIMITED_WHILE(good_data && fuzzed_data_provider.ConsumeBool(), 10'000)
@ -144,10 +145,11 @@ FUZZ_TARGET(coins_view, .init = initialize_coins_view)
if (dirty) CCoinsCacheEntry::SetDirty(*it, sentinel);
if (fresh) CCoinsCacheEntry::SetFresh(*it, sentinel);
usage += it->second.coin.DynamicMemoryUsage();
num_dirty += dirty;
}
bool expected_code_path = false;
try {
auto cursor{CoinsViewCacheCursor(usage, sentinel, coins_map, /*will_erase=*/true)};
auto cursor{CoinsViewCacheCursor(usage, num_dirty, sentinel, coins_map, /*will_erase=*/true)};
coins_view_cache.BatchWrite(cursor, fuzzed_data_provider.ConsumeBool() ? ConsumeUInt256(fuzzed_data_provider) : coins_view_cache.GetBestBlock());
expected_code_path = true;
} catch (const std::logic_error& e) {

View File

@ -88,8 +88,8 @@ using node::CBlockIndexHeightOnlyComparator;
using node::CBlockIndexWorkComparator;
using node::SnapshotMetadata;
/** Size threshold for warning about slow UTXO set flush to disk. */
static constexpr size_t WARN_FLUSH_COINS_SIZE = 1 << 30; // 1 GiB
/** Threshold for warning when writing this many dirty cache entries to disk. */
static constexpr size_t WARN_FLUSH_COINS_COUNT = 10'000'000;
/** Time to wait between writing blocks/block index to disk. */
static constexpr std::chrono::hours DATABASE_WRITE_INTERVAL{1};
/** Time to wait between flushing chainstate to disk. */
@ -2828,7 +2828,8 @@ bool Chainstate::FlushStateToDisk(
bool full_flush_completed = false;
const size_t coins_count = CoinsTip().GetCacheSize();
const size_t coins_mem_usage = CoinsTip().DynamicMemoryUsage();
[[maybe_unused]] const size_t coins_mem_usage = CoinsTip().DynamicMemoryUsage();
const size_t coins_dirty_count = CoinsTip().GetDirtyCount();
try {
{
@ -2931,16 +2932,16 @@ bool Chainstate::FlushStateToDisk(
}
// Flush best chain related state. This can only be done if the blocks / block index write was also done.
if (fDoFullFlush && !CoinsTip().GetBestBlock().IsNull()) {
if (coins_mem_usage >= WARN_FLUSH_COINS_SIZE) LogWarning("Flushing large (%d GiB) UTXO set to disk, it may take several minutes", coins_mem_usage >> 30);
LOG_TIME_MILLIS_WITH_CATEGORY(strprintf("write coins cache to disk (%d coins, %.2fKiB)",
coins_count, coins_mem_usage >> 10), BCLog::BENCH);
if (coins_dirty_count >= WARN_FLUSH_COINS_COUNT) LogWarning("Flushing large (%d entries) UTXO set to disk, it may take several minutes", coins_dirty_count);
LOG_TIME_MILLIS_WITH_CATEGORY(strprintf("write coins cache to disk (%d out of %d cached coins)",
coins_dirty_count, coins_count), BCLog::BENCH);
// Typical Coin structures on disk are around 48 bytes in size.
// Pushing a new one to the database can cause it to be written
// twice (once in the log, and once in the tables). This is already
// an overestimation, as most will delete an existing entry or
// overwrite one. Still, use a conservative safety factor of 2.
if (!CheckDiskSpace(m_chainman.m_options.datadir, 48 * 2 * 2 * CoinsTip().GetCacheSize())) {
if (!CheckDiskSpace(m_chainman.m_options.datadir, 2 * 2 * 48 * coins_dirty_count)) {
return FatalError(m_chainman.GetNotifications(), state, _("Disk space is too low!"));
}
// Flush the chainstate (which may refer to block index entries).

View File

@ -88,7 +88,7 @@ class InitTest(BitcoinTestFramework):
args = ['-txindex=1', '-blockfilterindex=1', '-coinstatsindex=1']
for terminate_line in lines_to_terminate_after:
self.log.info(f"Starting node and will exit after line {terminate_line}")
self.log.info(f"Starting node and will terminate after line {terminate_line}")
with node.busy_wait_for_debug_log([terminate_line]):
if platform.system() == 'Windows':
# CREATE_NEW_PROCESS_GROUP is required in order to be able
@ -108,12 +108,22 @@ class InitTest(BitcoinTestFramework):
'blocks/index/*.ldb': 'Error opening block database.',
'chainstate/*.ldb': 'Error opening coins database.',
'blocks/blk*.dat': 'Error loading block database.',
'indexes/txindex/MANIFEST*': 'LevelDB error: Corruption: CURRENT points to a non-existent file',
# Removing these files does not result in a startup error:
# 'indexes/blockfilter/basic/*.dat', 'indexes/blockfilter/basic/db/*.*', 'indexes/coinstats/db/*.*',
# 'indexes/txindex/*.log', 'indexes/txindex/CURRENT', 'indexes/txindex/LOCK'
}
files_to_perturb = {
'blocks/index/*.ldb': 'Error loading block database.',
'chainstate/*.ldb': 'Error opening coins database.',
'blocks/blk*.dat': 'Corrupted block database detected.',
'indexes/blockfilter/basic/db/*.*': 'LevelDB error: Corruption',
'indexes/coinstats/db/*.*': 'LevelDB error: Corruption',
'indexes/txindex/*.log': 'LevelDB error: Corruption',
'indexes/txindex/CURRENT': 'LevelDB error: Corruption',
# Perturbing these files does not result in a startup error:
# 'indexes/blockfilter/basic/*.dat', 'indexes/txindex/MANIFEST*', 'indexes/txindex/LOCK'
}
for file_patt, err_fragment in files_to_delete.items():
@ -135,9 +145,10 @@ class InitTest(BitcoinTestFramework):
self.stop_node(0)
self.log.info("Test startup errors after perturbing certain essential files")
dirs = ["blocks", "chainstate", "indexes"]
for file_patt, err_fragment in files_to_perturb.items():
shutil.copytree(node.chain_path / "blocks", node.chain_path / "blocks_bak")
shutil.copytree(node.chain_path / "chainstate", node.chain_path / "chainstate_bak")
for dir in dirs:
shutil.copytree(node.chain_path / dir, node.chain_path / f"{dir}_bak")
target_files = list(node.chain_path.glob(file_patt))
for target_file in target_files:
@ -151,10 +162,9 @@ class InitTest(BitcoinTestFramework):
start_expecting_error(err_fragment)
shutil.rmtree(node.chain_path / "blocks")
shutil.rmtree(node.chain_path / "chainstate")
shutil.move(node.chain_path / "blocks_bak", node.chain_path / "blocks")
shutil.move(node.chain_path / "chainstate_bak", node.chain_path / "chainstate")
for dir in dirs:
shutil.rmtree(node.chain_path / dir)
shutil.move(node.chain_path / f"{dir}_bak", node.chain_path / dir)
def init_pid_test(self):
BITCOIN_PID_FILENAME_CUSTOM = "my_fancy_bitcoin_pid_file.foobar"

View File

@ -45,6 +45,7 @@ from test_framework.util import (
assert_equal,
assert_greater_than,
assert_raises_rpc_error,
sync_txindex,
)
from test_framework.wallet import MiniWallet
from test_framework.wallet_util import generate_keypair
@ -270,6 +271,7 @@ class MempoolAcceptanceTest(BitcoinTestFramework):
self.log.info('A coinbase transaction')
# Pick the input of the first tx we created, so it has to be a coinbase tx
sync_txindex(self, node)
raw_tx_coinbase_spent = node.getrawtransaction(txid=node.decoderawtransaction(hexstring=raw_tx_in_block)['vin'][0]['txid'])
tx = tx_from_hex(raw_tx_coinbase_spent)
self.check_mempool_result(

View File

@ -34,6 +34,7 @@ from test_framework.util import (
assert_equal,
assert_greater_than,
assert_raises_rpc_error,
sync_txindex,
)
from test_framework.wallet import (
getnewdestination,
@ -70,7 +71,7 @@ class RawTransactionsTest(BitcoinTestFramework):
self.num_nodes = 3
self.extra_args = [
["-txindex"],
["-txindex"],
[],
["-fastprune", "-prune=1"],
]
# whitelist peers to speed up tx relay / mempool sync
@ -109,6 +110,7 @@ class RawTransactionsTest(BitcoinTestFramework):
self.log.info(f"Test getrawtransaction {'with' if n == 0 else 'without'} -txindex")
if n == 0:
sync_txindex(self, self.nodes[n])
# With -txindex.
# 1. valid parameters - only supply txid
assert_equal(self.nodes[n].getrawtransaction(txId), tx['hex'])

View File

@ -12,6 +12,7 @@ from test_framework.test_framework import BitcoinTestFramework
from test_framework.util import (
assert_equal,
assert_raises_rpc_error,
sync_txindex,
)
from test_framework.wallet import MiniWallet
@ -77,6 +78,7 @@ class MerkleBlockTest(BitcoinTestFramework):
assert_equal(sorted(self.nodes[0].verifytxoutproof(self.nodes[0].gettxoutproof([txid1, txid2]))), sorted(txlist))
assert_equal(sorted(self.nodes[0].verifytxoutproof(self.nodes[0].gettxoutproof([txid2, txid1]))), sorted(txlist))
# We can always get a proof if we have a -txindex
sync_txindex(self, self.nodes[1])
assert_equal(self.nodes[0].verifytxoutproof(self.nodes[1].gettxoutproof([txid_spent])), [txid_spent])
# We can't get a proof if we specify transactions from different blocks
assert_raises_rpc_error(-5, "Not all transactions found in specified or retrieved block", self.nodes[0].gettxoutproof, [txid1, txid3])

View File

@ -592,3 +592,10 @@ def find_vout_for_address(node, txid, addr):
if addr == tx["vout"][i]["scriptPubKey"]["address"]:
return i
raise RuntimeError("Vout not found for address: txid=%s, addr=%s" % (txid, addr))
def sync_txindex(test_framework, node):
test_framework.log.debug("Waiting for node txindex to sync")
sync_start = int(time.time())
test_framework.wait_until(lambda: node.getindexinfo("txindex")["txindex"]["synced"])
test_framework.log.debug(f"Synced in {time.time() - sync_start} seconds")

View File

@ -117,7 +117,6 @@ class AddressInputTypeGrouping(BitcoinTestFramework):
self.extra_args = [
[
"-addresstype=bech32",
"-txindex",
],
[
"-addresstype=p2sh-segwit",