diff --git a/src/coins.cpp b/src/coins.cpp index c403e006c85c..39f2d0cdb1e4 100644 --- a/src/coins.cpp +++ b/src/coins.cpp @@ -14,6 +14,24 @@ TRACEPOINT_SEMAPHORE(utxocache, add); TRACEPOINT_SEMAPHORE(utxocache, spent); TRACEPOINT_SEMAPHORE(utxocache, uncache); + +void CoinsCacheStats::RecordMiss(bool nonexistent) noexcept { + ++m_total; + if (nonexistent) { + ++m_miss_nonexistent; + } else { + ++m_miss; + } +} + +void CoinsCacheStats::Log(std::string_view reason) const +{ + const double miss_rate = m_total > 0 ? 100.0 * m_miss / m_total : 0.0; + const double miss_rate_nonxistent = m_total > 0 ? 100.0 * m_miss_nonexistent / m_total : 0.0; + LogDebug(BCLog::COINDB, "UTXO cache stats: gets=%d miss=%d (%.2f%%) missNE=%d (%.2f%%) logreason=%s\n", + m_total, m_miss, miss_rate, m_miss_nonexistent, miss_rate_nonxistent, reason); +} + CoinsViewEmpty& CoinsViewEmpty::Get() { static CoinsViewEmpty instance; @@ -23,14 +41,18 @@ CoinsViewEmpty& CoinsViewEmpty::Get() std::optional CCoinsViewCache::PeekCoin(const COutPoint& outpoint) const { if (auto it{cacheCoins.find(outpoint)}; it != cacheCoins.end()) { + if (m_log_stats) m_stats.RecordHit(); return it->second.coin.IsSpent() ? std::nullopt : std::optional{it->second.coin}; } - return base->PeekCoin(outpoint); + const auto ret{base->PeekCoin(outpoint)}; + m_stats.RecordMiss(!ret); + return ret; } -CCoinsViewCache::CCoinsViewCache(CCoinsView* in_base, bool deterministic) : +CCoinsViewCache::CCoinsViewCache(CCoinsView* in_base, bool deterministic, bool log_stats) : CCoinsViewBacked(in_base), m_deterministic(deterministic), - cacheCoins(0, SaltedOutpointHasher(/*deterministic=*/deterministic), CCoinsMap::key_equal{}, &m_cache_coins_memory_resource) + cacheCoins(0, SaltedOutpointHasher(/*deterministic=*/deterministic), CCoinsMap::key_equal{}, &m_cache_coins_memory_resource), + m_log_stats(log_stats) { m_sentinel.second.SelfRef(m_sentinel); } @@ -51,10 +73,14 @@ CCoinsMap::iterator CCoinsViewCache::FetchCoin(const COutPoint &outpoint) const ret->second.coin = std::move(*coin); cachedCoinsUsage += ret->second.coin.DynamicMemoryUsage(); Assert(!ret->second.coin.IsSpent()); + if (m_log_stats) m_stats.RecordMiss(false); } else { cacheCoins.erase(ret); + if (m_log_stats) m_stats.RecordMiss(true); return cacheCoins.end(); } + } else { + if (m_log_stats) m_stats.RecordHit(); } return ret; } @@ -184,6 +210,7 @@ uint256 CCoinsViewCache::GetBestBlock() const { void CCoinsViewCache::SetBestBlock(const uint256& in_block_hash) { m_block_hash = in_block_hash; + if (m_log_stats && ++m_stats.m_block_count % 2016 == 0) m_stats.Log("block period"); } void CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256& in_block_hash) @@ -259,6 +286,7 @@ void CCoinsViewCache::BatchWrite(CoinsViewCacheCursor& cursor, const uint256& in void CCoinsViewCache::Flush(bool reallocate_cache) { + if (m_log_stats) m_stats.Log("flush"); auto cursor{CoinsViewCacheCursor(m_dirty_count, m_sentinel, cacheCoins, /*will_erase=*/true)}; base->BatchWrite(cursor, m_block_hash); Assume(m_dirty_count == 0); @@ -271,6 +299,7 @@ void CCoinsViewCache::Flush(bool reallocate_cache) void CCoinsViewCache::Sync() { + if (m_log_stats) m_stats.Log("sync"); auto cursor{CoinsViewCacheCursor(m_dirty_count, m_sentinel, cacheCoins, /*will_erase=*/false)}; base->BatchWrite(cursor, m_block_hash); Assume(m_dirty_count == 0); @@ -282,6 +311,7 @@ void CCoinsViewCache::Sync() void CCoinsViewCache::Reset() noexcept { + if (m_log_stats) m_stats.Log("reset"); cacheCoins.clear(); cachedCoinsUsage = 0; m_dirty_count = 0; diff --git a/src/coins.h b/src/coins.h index ae7f34f46581..2c59262c9766 100644 --- a/src/coins.h +++ b/src/coins.h @@ -20,6 +20,7 @@ #include #include +#include #include #include @@ -389,6 +390,23 @@ class CCoinsViewBacked : public CCoinsView }; +/** + * Cache hit statistics for CCoinsViewCache. + * Record separately misses for: + * - accesses for existing items, where the item was not found in the cache, but it was found in the DB. + * - accesses for non-existing items, checks, where the item was not found in the cache, but neither in the DB. + * */ +struct CoinsCacheStats { + uint64_t m_total{0}; //!< total access calls + uint64_t m_miss{0}; //!< misses for existing items + uint64_t m_miss_nonexistent{0}; //!< missed for non-existing items + uint32_t m_block_count{0}; //!< number of SetBestBlock calls (approximates block height) + + void RecordHit() noexcept { ++m_total; } + void RecordMiss(bool nonexistent) noexcept; + void Log(std::string_view reason) const; +}; + /** CCoinsView that adds a memory cache for transactions to another CCoinsView */ class CCoinsViewCache : public CCoinsViewBacked { @@ -410,6 +428,8 @@ class CCoinsViewCache : public CCoinsViewBacked mutable size_t cachedCoinsUsage{0}; /* Running count of dirty Coin cache entries. */ mutable size_t m_dirty_count{0}; + mutable CoinsCacheStats m_stats; + const bool m_log_stats; /** * Discard all modifications made to this cache without flushing to the base view. @@ -421,7 +441,7 @@ class CCoinsViewCache : public CCoinsViewBacked virtual std::optional FetchCoinFromBase(const COutPoint& outpoint) const; public: - CCoinsViewCache(CCoinsView* in_base, bool deterministic = false); + CCoinsViewCache(CCoinsView* in_base, bool deterministic = false, bool log_stats = false); /** * By deleting the copy constructor, we prevent accidentally using it when one intends to create a cache on top of a base cache. diff --git a/src/validation.cpp b/src/validation.cpp index f85a834f2a4a..e65e371535d5 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -1853,7 +1853,7 @@ CoinsViews::CoinsViews(DBParams db_params, CoinsViewOptions options) void CoinsViews::InitCache() { AssertLockHeld(::cs_main); - m_cacheview = std::make_unique(&m_catcherview); + m_cacheview = std::make_unique(&m_catcherview, /*deterministic=*/false, /*log_stats=*/true); m_connect_block_view = std::make_unique(&*m_cacheview); } @@ -2464,6 +2464,8 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state, if (fEnforceBIP30 || pindex->nHeight >= BIP34_IMPLIES_BIP30_LIMIT) { for (const auto& tx : block.vtx) { for (size_t o = 0; o < tx->vout.size(); o++) { + // Note: there the likely case is that the new TXO doesn't exist, so it will + // result in a cache miss (a miss for an non-existent item). if (view.HaveCoin(COutPoint(tx->GetHash(), o))) { state.Invalid(BlockValidationResult::BLOCK_CONSENSUS, "bad-txns-BIP30", "tried to overwrite transaction");