From faa5c86dbfec1ed7bdcd6a07316315147a7e87a2 Mon Sep 17 00:00:00 2001 From: MarcoFalke <*~=`'#}+{/-|&$^_@721217.xyz> Date: Mon, 22 Jul 2024 12:26:24 +0200 Subject: [PATCH 1/2] refactor: Use untranslated error message in ActivateSnapshot The message is not exposed in the GUI or another translated context, so translating it is useless for now. Also, fix a nit from https://github.com/bitcoin/bitcoin/pull/30395#discussion_r1670972864 --- src/validation.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/validation.cpp b/src/validation.cpp index b90fe48ca5b..b290efc34f1 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -5681,7 +5681,7 @@ util::Result ChainstateManager::ActivateSnapshot( } if (!m_best_header || m_best_header->GetAncestor(base_blockheight) != snapshot_start_block) { - return util::Error{_("A forked headers-chain with more work than the chain with the snapshot base block header exists. Please proceed to sync without AssumeUtxo.")}; + return util::Error{Untranslated("A forked headers-chain with more work than the chain with the snapshot base block header exists. Please proceed to sync without AssumeUtxo.")}; } auto mempool{m_active_chainstate->GetMempool()}; @@ -5735,7 +5735,7 @@ util::Result ChainstateManager::ActivateSnapshot( static_cast(current_coinstip_cache_size * SNAPSHOT_CACHE_PERC)); } - auto cleanup_bad_snapshot = [&](bilingual_str&& reason) EXCLUSIVE_LOCKS_REQUIRED(::cs_main) { + auto cleanup_bad_snapshot = [&](bilingual_str reason) EXCLUSIVE_LOCKS_REQUIRED(::cs_main) { this->MaybeRebalanceCaches(); // PopulateAndValidateSnapshot can return (in error) before the leveldb datadir From fa530ec54386a3fd56b51e50699b424cc8647821 Mon Sep 17 00:00:00 2001 From: MarcoFalke <*~=`'#}+{/-|&$^_@721217.xyz> Date: Mon, 22 Jul 2024 12:21:14 +0200 Subject: [PATCH 2/2] rpc: Return precise loadtxoutset error messages The error messages should never happen in normal operation. However, if they do, they are helpful to return to the user to debug the issue. For example, to notice a truncated file. --- src/validation.cpp | 58 +++++++++++---------------- src/validation.h | 2 +- test/functional/feature_assumeutxo.py | 23 +++++------ 3 files changed, 36 insertions(+), 47 deletions(-) diff --git a/src/validation.cpp b/src/validation.cpp index b290efc34f1..16ef0890348 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -1,5 +1,5 @@ // Copyright (c) 2009-2010 Satoshi Nakamoto -// Copyright (c) 2009-2022 The Bitcoin Core developers +// Copyright (c) 2009-present The Bitcoin Core developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. @@ -5754,9 +5754,9 @@ util::Result ChainstateManager::ActivateSnapshot( return util::Error{std::move(reason)}; }; - if (!this->PopulateAndValidateSnapshot(*snapshot_chainstate, coins_file, metadata)) { + if (auto res{this->PopulateAndValidateSnapshot(*snapshot_chainstate, coins_file, metadata)}; !res) { LOCK(::cs_main); - return cleanup_bad_snapshot(Untranslated("population failed")); + return cleanup_bad_snapshot(strprintf(Untranslated("Population failed: %s"), util::ErrorString(res))); } LOCK(::cs_main); // cs_main required for rest of snapshot activation. @@ -5821,7 +5821,7 @@ static void SnapshotUTXOHashBreakpoint(const util::SignalInterrupt& interrupt) if (interrupt) throw StopHashingException(); } -bool ChainstateManager::PopulateAndValidateSnapshot( +util::Result ChainstateManager::PopulateAndValidateSnapshot( Chainstate& snapshot_chainstate, AutoFile& coins_file, const SnapshotMetadata& metadata) @@ -5837,18 +5837,16 @@ bool ChainstateManager::PopulateAndValidateSnapshot( if (!snapshot_start_block) { // Needed for ComputeUTXOStats to determine the // height and to avoid a crash when base_blockhash.IsNull() - LogPrintf("[snapshot] Did not find snapshot start blockheader %s\n", - base_blockhash.ToString()); - return false; + return util::Error{strprintf(Untranslated("Did not find snapshot start blockheader %s"), + base_blockhash.ToString())}; } int base_height = snapshot_start_block->nHeight; const auto& maybe_au_data = GetParams().AssumeutxoForHeight(base_height); if (!maybe_au_data) { - LogPrintf("[snapshot] assumeutxo height in snapshot metadata not recognized " - "(%d) - refusing to load snapshot\n", base_height); - return false; + return util::Error{strprintf(Untranslated("Assumeutxo height in snapshot metadata not recognized " + "(%d) - refusing to load snapshot"), base_height)}; } const AssumeutxoData& au_data = *maybe_au_data; @@ -5857,8 +5855,7 @@ bool ChainstateManager::PopulateAndValidateSnapshot( // ActivateSnapshot(), but is done so that we avoid doing the long work of staging // a snapshot that isn't actually usable. if (WITH_LOCK(::cs_main, return !CBlockIndexWorkComparator()(ActiveTip(), snapshot_start_block))) { - LogPrintf("[snapshot] activation failed - work does not exceed active chainstate\n"); - return false; + return util::Error{Untranslated("Work does not exceed active chainstate")}; } const uint64_t coins_count = metadata.m_coins_count; @@ -5875,8 +5872,7 @@ bool ChainstateManager::PopulateAndValidateSnapshot( coins_per_txid = ReadCompactSize(coins_file); if (coins_per_txid > coins_left) { - LogPrintf("[snapshot] mismatch in coins count in snapshot metadata and actual snapshot data\n"); - return false; + return util::Error{Untranslated("Mismatch in coins count in snapshot metadata and actual snapshot data")}; } for (size_t i = 0; i < coins_per_txid; i++) { @@ -5888,14 +5884,12 @@ bool ChainstateManager::PopulateAndValidateSnapshot( if (coin.nHeight > base_height || outpoint.n >= std::numeric_limits::max() // Avoid integer wrap-around in coinstats.cpp:ApplyHash ) { - LogPrintf("[snapshot] bad snapshot data after deserializing %d coins\n", - coins_count - coins_left); - return false; + return util::Error{strprintf(Untranslated("Bad snapshot data after deserializing %d coins"), + coins_count - coins_left)}; } if (!MoneyRange(coin.out.nValue)) { - LogPrintf("[snapshot] bad snapshot data after deserializing %d coins - bad tx out value\n", - coins_count - coins_left); - return false; + return util::Error{strprintf(Untranslated("Bad snapshot data after deserializing %d coins - bad tx out value"), + coins_count - coins_left)}; } coins_cache.EmplaceCoinInternalDANGER(std::move(outpoint), std::move(coin)); @@ -5915,7 +5909,7 @@ bool ChainstateManager::PopulateAndValidateSnapshot( // means <5MB of memory imprecision. if (coins_processed % 120000 == 0) { if (m_interrupt) { - return false; + return util::Error{Untranslated("Aborting after an interrupt was requested")}; } const auto snapshot_cache_state = WITH_LOCK(::cs_main, @@ -5933,9 +5927,8 @@ bool ChainstateManager::PopulateAndValidateSnapshot( } } } catch (const std::ios_base::failure&) { - LogPrintf("[snapshot] bad snapshot format or truncated snapshot after deserializing %d coins\n", - coins_processed); - return false; + return util::Error{strprintf(Untranslated("Bad snapshot format or truncated snapshot after deserializing %d coins"), + coins_processed)}; } } @@ -5955,9 +5948,8 @@ bool ChainstateManager::PopulateAndValidateSnapshot( out_of_coins = true; } if (!out_of_coins) { - LogPrintf("[snapshot] bad snapshot - coins left over after deserializing %d coins\n", - coins_count); - return false; + return util::Error{strprintf(Untranslated("Bad snapshot - coins left over after deserializing %d coins"), + coins_count)}; } LogPrintf("[snapshot] loaded %d (%.2f MB) coins from snapshot %s\n", @@ -5980,18 +5972,16 @@ bool ChainstateManager::PopulateAndValidateSnapshot( maybe_stats = ComputeUTXOStats( CoinStatsHashType::HASH_SERIALIZED, snapshot_coinsdb, m_blockman, [&interrupt = m_interrupt] { SnapshotUTXOHashBreakpoint(interrupt); }); } catch (StopHashingException const&) { - return false; + return util::Error{Untranslated("Aborting after an interrupt was requested")}; } if (!maybe_stats.has_value()) { - LogPrintf("[snapshot] failed to generate coins stats\n"); - return false; + return util::Error{Untranslated("Failed to generate coins stats")}; } // Assert that the deserialized chainstate contents match the expected assumeutxo value. if (AssumeutxoHash{maybe_stats->hashSerialized} != au_data.hash_serialized) { - LogPrintf("[snapshot] bad snapshot content hash: expected %s, got %s\n", - au_data.hash_serialized.ToString(), maybe_stats->hashSerialized.ToString()); - return false; + return util::Error{strprintf(Untranslated("Bad snapshot content hash: expected %s, got %s"), + au_data.hash_serialized.ToString(), maybe_stats->hashSerialized.ToString())}; } snapshot_chainstate.m_chain.SetTip(*snapshot_start_block); @@ -6031,7 +6021,7 @@ bool ChainstateManager::PopulateAndValidateSnapshot( LogPrintf("[snapshot] validated snapshot (%.2f MB)\n", coins_cache.DynamicMemoryUsage() / (1000 * 1000)); - return true; + return {}; } // Currently, this function holds cs_main for its duration, which could be for diff --git a/src/validation.h b/src/validation.h index 08e672c6209..eb43892b1a9 100644 --- a/src/validation.h +++ b/src/validation.h @@ -918,7 +918,7 @@ private: //! To reduce space the serialization format of the snapshot avoids //! duplication of tx hashes. The code takes advantage of the guarantee by //! leveldb that keys are lexicographically sorted. - [[nodiscard]] bool PopulateAndValidateSnapshot( + [[nodiscard]] util::Result PopulateAndValidateSnapshot( Chainstate& snapshot_chainstate, AutoFile& coins_file, const node::SnapshotMetadata& metadata); diff --git a/test/functional/feature_assumeutxo.py b/test/functional/feature_assumeutxo.py index da7cabf87c1..0acd4244a55 100755 --- a/test/functional/feature_assumeutxo.py +++ b/test/functional/feature_assumeutxo.py @@ -60,9 +60,8 @@ class AssumeutxoTest(BitcoinTestFramework): bad_snapshot_path = valid_snapshot_path + '.mod' node = self.nodes[1] - def expected_error(log_msg="", rpc_details=""): - with node.assert_debug_log([log_msg]): - assert_raises_rpc_error(-32603, f"Unable to load UTXO snapshot{rpc_details}", node.loadtxoutset, bad_snapshot_path) + def expected_error(msg): + assert_raises_rpc_error(-32603, f"Unable to load UTXO snapshot: Population failed: {msg}", node.loadtxoutset, bad_snapshot_path) self.log.info(" - snapshot file with invalid file magic") parsing_error_code = -22 @@ -114,19 +113,19 @@ class AssumeutxoTest(BitcoinTestFramework): f.write(valid_snapshot_contents[:47]) f.write((valid_num_coins + off).to_bytes(8, "little")) f.write(valid_snapshot_contents[47 + 8:]) - expected_error(log_msg=f"bad snapshot - coins left over after deserializing 298 coins" if off == -1 else f"bad snapshot format or truncated snapshot after deserializing 299 coins") + expected_error(msg="Bad snapshot - coins left over after deserializing 298 coins." if off == -1 else "Bad snapshot format or truncated snapshot after deserializing 299 coins.") self.log.info(" - snapshot file with alternated but parsable UTXO data results in different hash") cases = [ # (content, offset, wrong_hash, custom_message) [b"\xff" * 32, 0, "7d52155c9a9fdc4525b637ef6170568e5dad6fabd0b1fdbb9432010b8453095b", None], # wrong outpoint hash - [(2).to_bytes(1, "little"), 32, None, "[snapshot] bad snapshot data after deserializing 1 coins"], # wrong txid coins count - [b"\xfd\xff\xff", 32, None, "[snapshot] mismatch in coins count in snapshot metadata and actual snapshot data"], # txid coins count exceeds coins left + [(2).to_bytes(1, "little"), 32, None, "Bad snapshot data after deserializing 1 coins."], # wrong txid coins count + [b"\xfd\xff\xff", 32, None, "Mismatch in coins count in snapshot metadata and actual snapshot data"], # txid coins count exceeds coins left [b"\x01", 33, "9f4d897031ab8547665b4153317ae2fdbf0130c7840b66427ebc48b881cb80ad", None], # wrong outpoint index [b"\x81", 34, "3da966ba9826fb6d2604260e01607b55ba44e1a5de298606b08704bc62570ea8", None], # wrong coin code VARINT [b"\x80", 34, "091e893b3ccb4334378709578025356c8bcb0a623f37c7c4e493133c988648e5", None], # another wrong coin code - [b"\x84\x58", 34, None, "[snapshot] bad snapshot data after deserializing 0 coins"], # wrong coin case with height 364 and coinbase 0 - [b"\xCA\xD2\x8F\x5A", 39, None, "[snapshot] bad snapshot data after deserializing 0 coins - bad tx out value"], # Amount exceeds MAX_MONEY + [b"\x84\x58", 34, None, "Bad snapshot data after deserializing 0 coins"], # wrong coin case with height 364 and coinbase 0 + [b"\xCA\xD2\x8F\x5A", 39, None, "Bad snapshot data after deserializing 0 coins - bad tx out value"], # Amount exceeds MAX_MONEY ] for content, offset, wrong_hash, custom_message in cases: @@ -136,8 +135,8 @@ class AssumeutxoTest(BitcoinTestFramework): f.write(content) f.write(valid_snapshot_contents[(5 + 2 + 4 + 4 + 32 + 8 + offset + len(content)):]) - log_msg = custom_message if custom_message is not None else f"[snapshot] bad snapshot content hash: expected a4bf3407ccb2cc0145c49ebba8fa91199f8a3903daf0883875941497d2493c27, got {wrong_hash}" - expected_error(log_msg=log_msg) + msg = custom_message if custom_message is not None else f"Bad snapshot content hash: expected a4bf3407ccb2cc0145c49ebba8fa91199f8a3903daf0883875941497d2493c27, got {wrong_hash}." + expected_error(msg) def test_headers_not_synced(self, valid_snapshot_path): for node in self.nodes[1:]: @@ -188,8 +187,8 @@ class AssumeutxoTest(BitcoinTestFramework): def test_snapshot_with_less_work(self, dump_output_path): self.log.info("Test bitcoind should fail when snapshot has less accumulated work than this node.") node = self.nodes[0] - with node.assert_debug_log(expected_msgs=["[snapshot] activation failed - work does not exceed active chainstate"]): - assert_raises_rpc_error(-32603, "Unable to load UTXO snapshot", node.loadtxoutset, dump_output_path) + msg = "Unable to load UTXO snapshot: Population failed: Work does not exceed active chainstate." + assert_raises_rpc_error(-32603, msg, node.loadtxoutset, dump_output_path) def test_snapshot_block_invalidated(self, dump_output_path): self.log.info("Test snapshot is not loaded when base block is invalid.")