From 7b622d817eae69b4e7250d55ca428b04f13e9df7 Mon Sep 17 00:00:00 2001 From: kevin Heifner Date: Wed, 26 Aug 2026 07:57:58 -0500 Subject: [PATCH] Add spring-util ship-log utilities and nodeos state-history-force-write Give node operators in-box tooling for state history (SHiP) logs, which previously could only be touched by letting state_history_log's constructor auto-mutate them at nodeos startup, with anything beyond tail corruption being fatal (the capabilities requested in AntelopeIO/leap#1664, motivated by AntelopeIO/leap#1593). New primitives in libraries/state_history/log_utils.{hpp,cpp}: a genuinely read-only scanner that validates every entry's header, payload bounds, block continuity, and position trailer, optionally decompresses every payload (zlib's adler32 detects bit rot the structural checks cannot see), and resynchronizes past damage so one pass maps every valid and damaged region of a file; index verification and a sequential forward index builder that produces byte-identical output to the library's backward regeneration; and truncate, trim-front, extract, split, merge, and repair operations that rewrite the absolute position trailers wherever entries move. New spring-util subcommands built on them: ship-log info, block-id, smoke-test [--deep], make-index, trim, extract-blocks, repair [--keep-tail] [--dry-run] [--deep] [--output-dir], vacuum, split, and merge. repair's default truncates at the first damage like nodeos's automatic recovery, but offline, previewable, and able to rebuild the index; --keep-tail instead salvages the last valid range, starting at its canonical entry so fork-superseded prefixes are excluded, for the case where damage is early in a large log and recent history matters more. split produces rotation-compatible retained bundles that load directly into a log_catalog; merge reverses it. block-id prints the id a log records for any block number, trusting the on-disk index only after verifying it really holds that block, which is what diagnosing a "missed a fork change" failure needs. New nodeos option state-history-force-write: never let damaged or inconsistent ship logs stop the node. An index that disagrees with its log is regenerated instead of fatal; a head log that fails its startup checks or cannot accept the next block (a gap after a snapshot restore, divergent fork history) is renamed aside to -corrupt- -- kept on disk, never deleted -- and writing continues into a fresh log, escalating to setting aside the retained bundles only when a write predates the whole catalog. Holes in the retained set are tolerated with a warning, leaving just those blocks unserved. The bundles this sets aside remain valid logs that ship-log can inspect, trim, and merge back. The three fork-change asserts in state_history_log::pack_and_write_entry now report the block being written, the previous id it carries, and the id actually recorded for the prior block; the index-backed path additionally decodes the recorded id's own block number and states that a block number mismatch means a corrupt index rather than a fork, pointing at 'spring-util ship-log block-id' and 'make-index'. ~state_history_log no longer lets a vacuum-on-close failure throw out of the destructor (which would std::terminate). Also fixes spring-util block-log print-log --print-from to be an option rather than a flag: a CLI11 flag only accepts its value in --print-from= form, so the conventional space-separated spelling failed validation. And marks log_config.hpp's boost_test_print_type inline -- it is defined in a header that now reaches more than one translation unit per binary, which without inline is a multiple-definition link error. Tested by tests/ship_log_utils.cpp (33 cases: torn tails, mid-file damage, payload bit flips, fork-overwritten entries, pruned logs, index corruption variants, trim/extract/split/merge round-trips all verified through real state_history_log/log_catalog reopens, and every force-write tier) and tests/ship_log_util_test.py (against a real nodeos: corrupt, repair with spring-util, byte-compare against pristine files, relaunch, plus both force-write scenarios). Ported from Wire-Network/wire-sysio#392, where the same code was also validated against a 61 GB / 8.05M-block production chain_state log. --- libraries/state_history/CMakeLists.txt | 1 + .../include/eosio/state_history/log.hpp | 56 +- .../eosio/state_history/log_catalog.hpp | 163 ++- .../eosio/state_history/log_config.hpp | 3 +- .../include/eosio/state_history/log_utils.hpp | 281 ++++ libraries/state_history/log_utils.cpp | 1284 +++++++++++++++++ .../state_history_plugin.cpp | 20 +- programs/spring-util/CMakeLists.txt | 4 +- programs/spring-util/actions/blocklog.cpp | 6 +- programs/spring-util/actions/shiplog.cpp | 397 +++++ programs/spring-util/actions/shiplog.hpp | 56 + programs/spring-util/main.cpp | 5 + tests/CMakeLists.txt | 2 + tests/ship_log_util_test.py | 325 +++++ tests/ship_log_utils.cpp | 1010 +++++++++++++ 15 files changed, 3584 insertions(+), 29 deletions(-) create mode 100644 libraries/state_history/include/eosio/state_history/log_utils.hpp create mode 100644 libraries/state_history/log_utils.cpp create mode 100644 programs/spring-util/actions/shiplog.cpp create mode 100644 programs/spring-util/actions/shiplog.hpp create mode 100755 tests/ship_log_util_test.py create mode 100644 tests/ship_log_utils.cpp diff --git a/libraries/state_history/CMakeLists.txt b/libraries/state_history/CMakeLists.txt index 707d42c407..343e431bec 100644 --- a/libraries/state_history/CMakeLists.txt +++ b/libraries/state_history/CMakeLists.txt @@ -3,6 +3,7 @@ file(GLOB HEADERS "include/eosio/state-history/*.hpp") add_library( state_history abi.cpp create_deltas.cpp + log_utils.cpp trace_converter.cpp ${HEADERS} ) diff --git a/libraries/state_history/include/eosio/state_history/log.hpp b/libraries/state_history/include/eosio/state_history/log.hpp index f1b127b614..54de1c8247 100644 --- a/libraries/state_history/include/eosio/state_history/log.hpp +++ b/libraries/state_history/include/eosio/state_history/log.hpp @@ -118,9 +118,14 @@ class state_history_log { state_history_log(state_history_log&&) = default; state_history_log& operator=(state_history_log&&) = default; + /** + * @param force_write when set, an index that disagrees with its log is regenerated instead of + * being a fatal error (the log itself still auto-recovers exactly as before) + */ state_history_log(const std::filesystem::path& log_dir_and_stem, non_local_get_block_id_func non_local_get_block_id = no_non_local_get_block_id_func, - const std::optional& prune_conf = std::nullopt) : + const std::optional& prune_conf = std::nullopt, + bool force_write = false) : prune_config(prune_conf), non_local_get_block_id(non_local_get_block_id), log(std::filesystem::path(log_dir_and_stem).replace_extension("log")), index(std::filesystem::path(log_dir_and_stem).replace_extension("index")) { @@ -135,7 +140,19 @@ class state_history_log { check_log_on_init(); check_index_on_init(); - check_log_and_index_on_init(); + try { + check_log_and_index_on_init(); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + if(!force_write) + throw; + wlog("${name} disagrees with its log (${e}); force-write is set so it will be regenerated", + ("name", index.display_path())("e", e.what())); + index.resize(0); + check_index_on_init(); + check_log_and_index_on_init(); + } //check for conversions to/from pruned log, as long as log contains something if(!empty()) { @@ -171,8 +188,18 @@ class state_history_log { const size_t first_data_pos = get_pos(_begin_block); const size_t last_data_pos = log.size(); - if(last_data_pos - first_data_pos < *prune_config->vacuum_on_close) - vacuum(); + //vacuum-on-close is a best-effort space reclamation; the log is fully valid whether or not it + // runs. Never let it throw out of the destructor (which would std::terminate): this also keeps + // force-write's head_log.reset() safe when it sets a damaged pruned log aside. + try { + if(last_data_pos - first_data_pos < *prune_config->vacuum_on_close) + vacuum(); + } catch(const std::exception& e) { + wlog("vacuum-on-close of ${name} failed (${e}); leaving the log un-vacuumed", + ("name", log.display_path())("e", e.what())); + } catch(...) { + wlog("vacuum-on-close of ${name} failed; leaving the log un-vacuumed", ("name", log.display_path())); + } } // begin end @@ -221,14 +248,29 @@ class state_history_log { EOS_ASSERT(block_num <= _end_block, chain::plugin_exception, "block ${b} skips over block ${e} in ${name}", ("b", block_num)("e", _end_block)("name", log.display_path())); EOS_ASSERT(block_num >= _index_begin_block, chain::plugin_exception, "block ${b} is before start block ${s} of ${name}", ("b", block_num)("s", _begin_block)("name", log.display_path())); if(block_num == _end_block) //appending at the end of known blocks; can shortcut some checks since we have last_block_id readily available - EOS_ASSERT(prev_id == last_block_id, chain::plugin_exception, "missed a fork change in ${name}", ("name", log.display_path())); + EOS_ASSERT(prev_id == last_block_id, chain::plugin_exception, + "missed a fork change in ${name}; appending block ${b} with previous id ${pid} but the log's last " + "entry is block ${lb} with id ${lid}", + ("name", log.display_path())("b", block_num)("pid", prev_id)("lb", _end_block - 1)("lid", last_block_id)); else { //seeing a block num we've seen before OR first block in the log; prepare some extra checks //find the previous block id as a sanity check. This might not be in our log due to log splitting. It also might not be present at all if this is the first // block written, so don't require this lookup to succeed, just require the id to match if the lookup succeeded. if(std::optional local_id_found = get_block_id(block_num-1)) - EOS_ASSERT(local_id_found == prev_id, chain::plugin_exception, "missed a fork change in ${name}", ("name", log.display_path())); + //spelling out both ids and the recorded id's own block number makes a damaged index distinguishable + // from a genuine fork at a glance: an id for some unrelated block means the index is misdirecting reads + EOS_ASSERT(local_id_found == prev_id, chain::plugin_exception, + "missed a fork change in ${name}; block ${b} has previous id ${pid} but the index resolves " + "block ${pb} to id ${fid}, an id for block ${fb} (a block number mismatch means a corrupt " + "index, not a fork; verify with 'spring-util ship-log block-id' and rebuild with " + "'spring-util ship-log make-index')", + ("name", log.display_path())("b", block_num)("pid", prev_id)("pb", block_num - 1) + ("fid", *local_id_found)("fb", chain::block_header::num_from_id(*local_id_found))); else if(std::optional non_local_id_found = non_local_get_block_id(block_num-1)) - EOS_ASSERT(non_local_id_found == prev_id, chain::plugin_exception, "missed a fork change in ${name}", ("name", log.display_path())); + EOS_ASSERT(non_local_id_found == prev_id, chain::plugin_exception, + "missed a fork change in ${name}; block ${b} has previous id ${pid} but block ${pb} is " + "recorded as ${fid} elsewhere in the catalog or chain", + ("name", log.display_path())("b", block_num)("pid", prev_id)("pb", block_num - 1) + ("fid", *non_local_id_found)); //we don't want to re-write blocks that we already have, so check if the existing block_id recorded in the log matches and if so, bail if(get_block_id(block_num) == id) return; diff --git a/libraries/state_history/include/eosio/state_history/log_catalog.hpp b/libraries/state_history/include/eosio/state_history/log_catalog.hpp index 69450168cc..8d60574ecf 100644 --- a/libraries/state_history/include/eosio/state_history/log_catalog.hpp +++ b/libraries/state_history/include/eosio/state_history/log_catalog.hpp @@ -2,6 +2,7 @@ #include #include +#include #include #include @@ -16,6 +17,10 @@ namespace eosio::state_history { using namespace boost::multi_index; +/// suffix given to bundles force-write moves aside; deliberately matches neither the retained-file +/// regex nor any name this code opens, so orphaned bundles are inert until an operator acts on them +inline constexpr std::string_view orphaned_bundle_infix = "-corrupt-"; + struct catalogued_log_file { chain::block_num_type begin_block_num = 0; chain::block_num_type end_block_num = 0; @@ -44,6 +49,13 @@ class log_catalog { const state_history_log::non_local_get_block_id_func non_local_get_block_id; + //when set, conditions that would otherwise prevent the node from running -- a head log that + // fails its startup checks or cannot accept the next block, or an inconsistent retained set -- + // are handled by moving the offending bundle aside (never deleting data) and continuing with a + // fresh log. see the state-history-force-write option. + const bool force_write = false; + std::optional head_log_prune_conf; + struct by_mru {}; typedef multi_index_container< catalogued_log_file, @@ -63,14 +75,17 @@ class log_catalog { log_catalog& operator=(log_catalog&) = delete; log_catalog(const std::filesystem::path& log_dir, const state_history::state_history_log_config& config, const std::string& log_name, - state_history_log::non_local_get_block_id_func non_local_get_block_id = state_history_log::no_non_local_get_block_id_func) : - non_local_get_block_id(non_local_get_block_id), head_log_path_and_basename(log_dir / log_name) { + state_history_log::non_local_get_block_id_func non_local_get_block_id = state_history_log::no_non_local_get_block_id_func, + bool force_write = false) : + non_local_get_block_id(non_local_get_block_id), force_write(force_write), + head_log_path_and_basename(log_dir / log_name) { std::visit(chain::overloaded { [this](const std::monostate&) { open_head_log(); }, [this](const state_history::prune_config& prune) { - open_head_log(prune); + head_log_prune_conf = prune; + open_head_log(); }, [this, &log_dir, &log_name](const state_history::partition_config& partition_config) { open_head_log(); @@ -83,6 +98,62 @@ class log_catalog { template void pack_and_write_entry(const chain::block_id_type& id, const chain::block_id_type& prev_id, F&& pack_to) { + if(!force_write) + return do_pack_and_write_entry(id, prev_id, pack_to); + + //force-write: never let the existing logs stop the node from running. First try the normal + // write; if the head log cannot accept the block (a gap after a snapshot restore, a missed + // fork change from divergent history, ...), move the head bundle aside and retry with a fresh + // one. The retry can unrotate a retained bundle into the head and fail on it for the same + // reason; in that case the whole catalog is moved aside and writing restarts from scratch. + // Bundles are renamed (kept on disk), never deleted. + try { + return do_pack_and_write_entry(id, prev_id, pack_to); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + elog("Failed to write block ${b} to ${name}.log (${e}); state-history-force-write is set: moving the head " + "log aside and retrying with a fresh one", + ("b", chain::block_header::num_from_id(id))("name", head_log_path_and_basename.string())("e", e.what())); + } + head_log.reset(); + orphan_bundle(head_log_path_and_basename); + open_head_log(); + try { + return do_pack_and_write_entry(id, prev_id, pack_to); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + elog("Still failed to write block ${b} (${e}); moving all retained logs aside and starting over", + ("b", chain::block_header::num_from_id(id))("e", e.what())); + } + while(!retained_log_files.empty()) { + catalog_t::node_type n = retained_log_files.extract(retained_log_files.begin()); + n.value().log.reset(); + orphan_bundle(n.value().path_and_basename); + } + head_log.reset(); + orphan_bundle(head_log_path_and_basename); + open_head_log(); + //With no retained logs and an empty head log there is nothing left in the catalog for the write + // to conflict with. It can still be rejected by a disagreement with the chain itself -- the + // non-local block-id lookup says block-1 has an id other than prev_id -- which no amount of log + // rewriting can resolve. Honor force-write's promise to keep the node running by skipping the + // block (it cannot be represented in the state history) rather than throwing. + try { + do_pack_and_write_entry(id, prev_id, pack_to); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + elog("state-history-force-write could not write block ${b} even into a fresh empty log (${e}); the block " + "conflicts with the chain rather than the log, so it is skipped and will not be served in the state " + "history", ("b", chain::block_header::num_from_id(id))("e", e.what())); + } + } + +private: + template + void do_pack_and_write_entry(const chain::block_id_type& id, const chain::block_id_type& prev_id, F&& pack_to) { const uint32_t block_num = chain::block_header::num_from_id(id); if(!retained_log_files.empty()) { @@ -120,6 +191,7 @@ class log_catalog { rotate_logs(); } +public: std::optional get_entry(uint32_t block_num) { return call_for_log(block_num, [&](state_history_log&& l) { return l.get_entry(block_num); @@ -206,25 +278,50 @@ class log_catalog { const std::filesystem::path path_and_basename = dir_entry.path().parent_path() / dir_entry.path().stem(); - state_history_log log(path_and_basename, [](chain::block_num_type) {return std::nullopt;}); - if(log.empty()) - continue; - const auto [begin_bnum, end_bnum] = log.block_range(); - retained_log_files.emplace(begin_bnum, end_bnum, path_and_basename); + try { + state_history_log log(path_and_basename, [](chain::block_num_type) {return std::nullopt;}); + if(log.empty()) + continue; + const auto [begin_bnum, end_bnum] = log.block_range(); + retained_log_files.emplace(begin_bnum, end_bnum, path_and_basename); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + if(!force_write) + throw; + elog("Failed to open retained log ${name}.log (${e}); state-history-force-write is set: leaving it out " + "of the catalog, its blocks will not be served", + ("name", path_and_basename.string())("e", e.what())); + } } + //a gap or overlap between retained files is normally fatal; with force-write the files stay in + // place and the catalog simply cannot serve the missing blocks if(retained_log_files.size() > 1) - for(catalog_t::iterator it = retained_log_files.begin(); it != std::prev(retained_log_files.end()); ++it) - EOS_ASSERT(it->end_block_num == std::next(it)->begin_block_num, chain::plugin_exception, + for(catalog_t::iterator it = retained_log_files.begin(); it != std::prev(retained_log_files.end()); ++it) { + if(it->end_block_num == std::next(it)->begin_block_num) + continue; + EOS_ASSERT(force_write, chain::plugin_exception, "retained log file ${sf}.log has block range ${sb}-${se} but ${ef}.log has range ${eb}-${ee} which results in a hole", ("sf", it->path_and_basename.native())("sb", it->begin_block_num)("se", it->end_block_num-1) ("ef", std::next(it)->path_and_basename.native())("eb", std::next(it)->begin_block_num)("ee", std::next(it)->end_block_num-1)); + elog("retained log file ${sf}.log has block range ${sb}-${se} but ${ef}.log has range ${eb}-${ee} which " + "results in a hole; state-history-force-write is set: blocks in the hole will not be served", + ("sf", it->path_and_basename.native())("sb", it->begin_block_num)("se", it->end_block_num-1) + ("ef", std::next(it)->path_and_basename.native())("eb", std::next(it)->begin_block_num)("ee", std::next(it)->end_block_num-1)); + } - if(!retained_log_files.empty() && !head_log->empty()) - EOS_ASSERT(retained_log_files.rbegin()->end_block_num == head_log->block_range().first, chain::plugin_exception, + if(!retained_log_files.empty() && !head_log->empty() && + retained_log_files.rbegin()->end_block_num != head_log->block_range().first) { + EOS_ASSERT(force_write, chain::plugin_exception, "retained log file ${sf}.log has block range ${sb}-${se} but head log has range ${eb}-${ee} which results in a hole", ("sf", retained_log_files.rbegin()->path_and_basename.native())("sb", retained_log_files.rbegin()->begin_block_num)("se", retained_log_files.rbegin()->end_block_num-1) ("eb", head_log->block_range().first)("ee", head_log->block_range().second-1)); + elog("retained log file ${sf}.log has block range ${sb}-${se} but head log has range ${eb}-${ee} which " + "results in a hole; state-history-force-write is set: blocks in the hole will not be served", + ("sf", retained_log_files.rbegin()->path_and_basename.native())("sb", retained_log_files.rbegin()->begin_block_num)("se", retained_log_files.rbegin()->end_block_num-1) + ("eb", head_log->block_range().first)("ee", head_log->block_range().second-1)); + } } void unrotate_log() { @@ -276,8 +373,46 @@ class log_catalog { } } - void open_head_log(std::optional prune_config = std::nullopt) { - head_log.emplace(head_log_path_and_basename, non_local_get_block_id, prune_config); + void open_head_log() { + try { + head_log.emplace(head_log_path_and_basename, non_local_get_block_id, head_log_prune_conf, force_write); + } catch(const std::bad_alloc&) { + throw; + } catch(const std::exception& e) { + if(!force_write) + throw; + elog("Failed to open ${name}.log (${e}); state-history-force-write is set: moving it aside and starting a " + "fresh log", ("name", head_log_path_and_basename.string())("e", e.what())); + head_log.reset(); + orphan_bundle(head_log_path_and_basename); + head_log.emplace(head_log_path_and_basename, non_local_get_block_id, head_log_prune_conf, force_write); + } + } + + /** + * Move a bundle out of the way to `-corrupt-` (a name neither the retained-file scan + * nor this class will ever pick up) so a fresh log can take its place without destroying data. + * An empty bundle has nothing worth keeping and is simply deleted. + */ + void orphan_bundle(const std::filesystem::path& path_and_basename) { + const std::filesystem::path log_file = std::filesystem::path(path_and_basename).replace_extension("log"); + if(!std::filesystem::exists(log_file) || std::filesystem::file_size(log_file) == 0) { + delete_bundle(path_and_basename); + return; + } + unsigned n = 0; + std::filesystem::path orphan_base; + do { + orphan_base = path_and_basename; + orphan_base += std::string(orphaned_bundle_infix) + std::to_string(++n); + } while(std::filesystem::exists(std::filesystem::path(orphan_base).replace_extension("log"))); + wlog("Moving ${from}.log aside to ${to}.log", + ("from", path_and_basename.string())("to", orphan_base.string())); + for(const char* ext : {"log", "index"}) { + const std::filesystem::path from = std::filesystem::path(path_and_basename).replace_extension(ext); + if(std::filesystem::exists(from)) + std::filesystem::rename(from, std::filesystem::path(orphan_base).replace_extension(ext)); + } } void delete_head_log() { diff --git a/libraries/state_history/include/eosio/state_history/log_config.hpp b/libraries/state_history/include/eosio/state_history/log_config.hpp index 7939e8a655..2642ddb721 100644 --- a/libraries/state_history/include/eosio/state_history/log_config.hpp +++ b/libraries/state_history/include/eosio/state_history/log_config.hpp @@ -23,7 +23,8 @@ struct partition_config { using state_history_log_config = std::variant; -std::ostream& boost_test_print_type(std::ostream& os, const state_history_log_config& conf) { +//defined in a header included by more than one translation unit, so it must be inline +inline std::ostream& boost_test_print_type(std::ostream& os, const state_history_log_config& conf) { std::visit(chain::overloaded { [&os](const std::monostate&) { os << "flat"; diff --git a/libraries/state_history/include/eosio/state_history/log_utils.hpp b/libraries/state_history/include/eosio/state_history/log_utils.hpp new file mode 100644 index 0000000000..83fc83b7f0 --- /dev/null +++ b/libraries/state_history/include/eosio/state_history/log_utils.hpp @@ -0,0 +1,281 @@ +#pragma once + +#include + +#include +#include +#include +#include +#include +#include +#include +#include + +/** + * Offline inspection and repair utilities for state history (SHiP) log bundles. + * + * A "bundle" is a `.log` / `.index` file pair as written by state_history_log + * (e.g. `trace_history.log` + `trace_history.index`, or a retained `trace_history-2-1000.log` + * pair produced by log rotation). + * + * Unlike state_history_log -- whose constructor auto-repairs (truncates a corrupt tail, + * regenerates a bad index, vacuums a pruned log) -- everything here that promises to be + * read-only really is read-only, so a damaged log can be inspected before deciding how to + * act on it. All functions take the bundle's *stem* path; a trailing ".log" or ".index" + * extension is tolerated and stripped. + */ +namespace eosio::state_history::log_utils { + +/// Periodic progress callback for long-running operations: (bytes_processed, bytes_total). +using progress_func = std::function; + +/// Strip a trailing ".log" or ".index" extension so users may pass either the stem or a file path. +std::filesystem::path normalize_stem(const std::filesystem::path& p); + +/// A contiguous run of structurally valid entries found by scan_log(). +struct entry_range { + uint32_t first_block = 0; ///< block number of the run's first entry + uint32_t last_block = 0; ///< block number of the run's last entry + uint64_t begin_pos = 0; ///< file offset of the first entry's header + uint64_t end_pos = 0; ///< one past the last byte of the run (end of the last entry's position trailer) + uint64_t entry_count = 0; ///< entries in the run, including entries superseded by fork switches + + /// Earliest entry in the run not later superseded by a fork switch. A run normally starts at + /// such an entry, but when a scan resynchronizes inside a cluster of fork-overwritten blocks it + /// can begin at an entry a later fork switch replaced; a bundle salvaged from this run must + /// start here instead so its first entry's block number is a floor for everything after it, + /// which is what state_history_log requires of a log's first entry. + uint64_t canonical_begin_pos = 0; + uint32_t canonical_first_block = 0; ///< block number of the entry at canonical_begin_pos +}; + +/// A byte range that failed validation during scan_log(). +struct damaged_range { + uint64_t begin_pos = 0; ///< file offset where validation first failed + uint64_t end_pos = 0; ///< file offset where the next valid entry begins (or the file size) + std::string reason; ///< description of the first validation failure in this range +}; + +/// Result of a full scan of one ship log file. +struct scan_result { + uint64_t file_size = 0; + uint16_t version = 0; ///< ship format version from the first header; meaningful only when + ///< at least one valid_range exists (stays 0 -- itself a valid version + ///< -- for a file whose first header is not a ship header) + bool pruned = false; ///< first header carries the pruned-log feature flag + std::optional pruned_block_count; ///< trailing block count, present only for pruned logs + uint64_t entries_scanned = 0; + uint64_t payloads_validated = 0; ///< number of payloads decompressed (deep scans only) + + std::vector valid_ranges; + std::vector damaged_ranges; + + /// True when the whole file is one valid run of entries (or the file is empty). + bool intact() const { return damaged_ranges.empty() && valid_ranges.size() <= 1; } +}; + +/** + * Read-only structural scan of a ship log. + * + * Walks the entry chain from the start of the file validating each entry's header magic, version, + * payload bounds, block-number monotonicity, and position trailer. After a validation failure the + * scanner searches forward for the next valid entry, so a single scan maps every undamaged region + * of the file, not just the prefix. + * + * With @p deep set, every entry's compressed payload is additionally decompressed (zlib's adler32 + * makes this detect payload bit-rot that the structural walk cannot see) and, for entries that + * record an uncompressed size, the decompressed size is checked against it. A payload failure in a + * structurally valid entry is reported as a damaged range covering exactly that entry. + * + * Pruned logs are scanned backward through the position-trailer chain (the punched-out hole after + * the first header makes a forward walk meaningless); @p deep applies to the entries that remain. + * + * @throws chain::plugin_exception if the file cannot be read or its version is unsupported + */ +scan_result scan_log(const std::filesystem::path& stem, bool deep, const progress_func& progress = {}); + +/// Index health, as judged against the log it belongs to. See to_string() for a human-readable +/// spelling. +enum class index_status { + ok, ///< present, expected size, and consistent with the log + missing, ///< no index file exists + wrong_size, ///< size does not match the log's block range + mismatched, ///< right size but at least one position disagrees with the log + log_damaged ///< the log itself is damaged, so the index cannot be judged +}; + +/// Human-readable spelling of an index_status, for reports and error messages. +std::string_view to_string(index_status s); + +/** + * Check a bundle's index against its log. + * + * The shallow check (@p full = false) mirrors state_history_log's open-time validation: the index + * must exist, have the size implied by the log's first and last entries, and its final position + * must point at the log's last entry. The full check forward-walks the entire log and verifies + * every index slot points at the latest entry written for its block. Read-only. + * + * @throws chain::plugin_exception if the log's first header is unreadable or of unsupported version + */ +index_status check_index(const std::filesystem::path& stem, bool full, const progress_func& progress = {}); + +/** + * Build (or rebuild) a bundle's index from its log, replacing any existing index file. + * + * Equivalent to the regeneration state_history_log performs when it sees a bad index, but + * standalone, and implemented as a sequential forward walk for non-pruned logs (a backward + * trailer-chain walk, matching the library, for pruned ones). The log must be undamaged. + * + * @return the (first, last) block range the index covers + * @throws chain::plugin_exception if the log is damaged (run repair_log first) + */ +std::pair build_index(const std::filesystem::path& stem, const progress_func& progress = {}); + +/** + * Trim the end of a bundle in place so that @p last_block_to_keep is its final block. + * + * The log file is truncated at the end of the latest entry written for @p last_block_to_keep and + * the index is shrunk (or rebuilt when it was unusable) to match. Refuses pruned logs. The kept + * prefix is not re-validated when the existing index is usable -- run smoke-test for that. + * + * @return bytes removed from the log file + * @throws chain::plugin_exception if the block is outside the log's range or the log's endpoints + * are damaged + */ +uint64_t truncate_log(const std::filesystem::path& stem, uint32_t last_block_to_keep, + const progress_func& progress = {}); + +/** + * Copy blocks [@p first_block, @p last_block] of @p src_stem into a freshly created bundle at + * @p dst_stem, rewriting each copied entry's position trailer for its new offset and building the + * new bundle's index. The source is not modified. Refuses pruned logs; the destination files must + * not already exist. + * + * @return the number of log bytes copied + * @throws chain::plugin_exception on range errors, damage, or pre-existing destination files + */ +uint64_t extract_blocks(const std::filesystem::path& src_stem, const std::filesystem::path& dst_stem, + uint32_t first_block, uint32_t last_block, const progress_func& progress = {}); + +/** + * Trim the front of a bundle in place so that @p first_block_to_keep is its first block. + * + * Implemented as extract_blocks() into temporary files in the bundle's directory followed by an + * atomic rename over the originals, so roughly the retained tail's size in free disk space is + * required. Refuses pruned logs (vacuum them first). + * + * @return bytes removed from the log file + * @throws chain::plugin_exception if the block is outside the log's range or the log is damaged + */ +uint64_t trim_front(const std::filesystem::path& stem, uint32_t first_block_to_keep, + const progress_func& progress = {}); + +/** + * Split a bundle into retained-style bundles named `--` in @p dst_dir, plus a + * head bundle `` holding the remainder, mirroring the boundaries log rotation would have + * produced: every output bundle except the head ends on a multiple of @p stride. Any `-N-M` + * suffix already on the source stem is dropped when naming outputs. The source is not modified. + * + * @return the stems (without extension) of every bundle created, in block order, head last + * @throws chain::plugin_exception if the log is damaged, pruned, or empty, or outputs already exist + */ +std::vector split_log(const std::filesystem::path& src_stem, + const std::filesystem::path& dst_dir, uint32_t stride, + const progress_func& progress = {}); + +/** + * Merge every retained bundle in @p src_dir matching `-N-M` into a single head-style + * bundle `` in @p dst_dir. The sources' block ranges (read from file content, not file + * names) must be contiguous. Sources are not modified. + * + * @return the (first, last) block range of the merged bundle + * @throws chain::plugin_exception if no bundles match, ranges have gaps or overlap, a source is + * damaged, or the destination files already exist + */ +std::pair merge_logs(const std::filesystem::path& src_dir, const std::string& log_name, + const std::filesystem::path& dst_dir, const progress_func& progress = {}); + +/// What repair_log() should do with the undamaged data it finds. +enum class repair_mode { + truncate, ///< keep the valid prefix: truncate the log at the first damage, like nodeos's auto-recovery + keep_tail ///< keep the last valid range instead: salvage recent history when damage is early in the file +}; + +/// Outcome of repair_log(). +struct repair_report { + scan_result scan; ///< the damage map the decision was based on + bool acted = false; ///< true when files were modified (always false for dry runs) + bool index_rebuilt = false; ///< true when (re)building the index was part of the action + uint32_t first_block = 0; ///< first block of the resulting (or would-be resulting) bundle + uint32_t last_block = 0; ///< last block of the resulting (or would-be resulting) bundle + uint64_t bytes_kept = 0; + uint64_t bytes_discarded = 0; +}; + +/** + * Repair a damaged bundle, or fix up its index when the log itself is intact. + * + * The log is scanned first (see scan_log(); @p deep extends the scan to payloads). Then: + * - intact log, healthy index: nothing to do. + * - intact log, missing/bad index: the index is rebuilt. + * - damaged log, repair_mode::truncate: the log is truncated at the end of the valid range that + * starts at offset 0 and the index is rebuilt -- the offline equivalent of nodeos's automatic + * tail recovery. Fails if the damage starts at offset 0 (nothing to keep; consider keep_tail). + * - damaged log, repair_mode::keep_tail: the last valid range is copied into a fresh bundle + * (trailers rewritten, index built) which replaces the original via rename, or is written to + * @p dst_stem when given, leaving the original untouched. The copy begins at the range's + * canonical start: the earliest entry not later superseded by a fork switch, so the resulting + * bundle is exactly what state_history_log expects. + * + * With @p dry_run the damage map and would-be outcome are reported but nothing is written. + * Pruned logs are refused: the format cannot locate entries past damage in a log with a hole. + * + * @throws chain::plugin_exception if the log is pruned, unreadable, or has nothing salvageable + */ +repair_report repair_log(const std::filesystem::path& stem, repair_mode mode, bool dry_run, bool deep, + const std::optional& dst_stem = std::nullopt, + const progress_func& progress = {}); + +/// Endpoint-only inspection of one bundle, cheap enough for an `info` listing. Read-only. +struct log_summary { + uint64_t log_size = 0; + bool valid_first_header = false; ///< first header parses with ship magic + supported version + uint16_t version = 0; + bool pruned = false; + std::optional pruned_block_count; + uint32_t first_block = 0; ///< from the first header (valid_first_header only) + bool tail_ok = false; ///< trailing position trailer leads to a coherent last entry + uint32_t last_block = 0; ///< from the last entry (tail_ok only) + uint64_t index_size = 0; ///< bytes; 0 when the index file is missing + index_status index = index_status::missing; ///< shallow assessment only + + std::optional first_block_id; ///< id recorded for first_block (valid_first_header only) + std::optional last_block_id; ///< id recorded for last_block (tail_ok only) +}; + +/** + * Summarize a bundle by examining only its endpoints: first header, trailing position trailer, and + * index size/final slot. Damage in the middle of the file is not detected -- use scan_log() for + * that. Never throws on corruption; problems are reported through the summary's flags. + */ +log_summary summarize_log(const std::filesystem::path& stem); + +/** + * Read the block id the log records for @p block_num. The on-disk index is used only after it + * passes the same shallow checks state_history_log applies on open AND its slot's entry is + * verified to actually hold @p block_num; on any disagreement the answer comes from a read-only + * walk of the log instead, so a stale or corrupt index can never misattribute an id. When a fork + * switch left multiple entries for @p block_num the id of the latest-written (canonical) entry is + * returned, matching what the library serves. Read-only. + * + * This is the tool for diagnosing nodeos's "missed a fork change" error: it prints which history + * the log actually recorded so it can be compared against the block log or another node. + * + * @return the recorded id, or nullopt when the log does not contain @p block_num (outside its + * block range, or pruned away) + * @throws chain::plugin_exception if the log's endpoints are damaged (run repair first) + */ +std::optional find_block_id(const std::filesystem::path& stem, uint32_t block_num, + const progress_func& progress = {}); + +} // namespace eosio::state_history::log_utils diff --git a/libraries/state_history/log_utils.cpp b/libraries/state_history/log_utils.cpp new file mode 100644 index 0000000000..5d00f8e87d --- /dev/null +++ b/libraries/state_history/log_utils.cpp @@ -0,0 +1,1284 @@ +#include +#include + +#include + +#include + +#include +#include +#include + +namespace eosio::state_history::log_utils { + +namespace { + +namespace bio = boost::iostreams; + +constexpr size_t default_window_size = 8 * 1024 * 1024; + +/// progress callbacks fire after at least this many bytes of new work +constexpr uint64_t progress_granularity = 256 * 1024 * 1024; + +/// in-memory index construction refuses block ranges larger than this (2 GiB of slots); no real +/// chain's ship log is within orders of magnitude of such a range +constexpr uint64_t max_in_memory_index_blocks = uint64_t(1) << 28; + +const size_t packed_header_size = fc::raw::pack_size(log_header()); + +constexpr size_t marker_size = sizeof(log_header_with_sizes::compressed_size); +constexpr size_t trailer_size = sizeof(uint64_t); +const size_t min_entry_size = packed_header_size + marker_size + trailer_size; + +/// payload preamble layout markers (see state_history_log::get_entry() for the format history) +constexpr uint32_t leap4_compressed_marker = 1; +const size_t leap4_preamble_size = marker_size + sizeof(log_header_with_sizes::uncompressed_size); + +constexpr std::string_view log_extension = "log"; +constexpr std::string_view index_extension = "index"; +//deliberately dot-free: log_path_of/index_path_of use replace_extension, and a dotted suffix would +// be treated as an extension and replaced, making the temporary paths collide with the originals +constexpr std::string_view tmp_suffix = "-repair-tmp"; ///< temporary bundle suffix used before atomic rename + +//extension handling matches state_history_log's constructor (replace_extension), so a stem of +// "trace_history" or a retained "trace_history-2-1000" maps to the same files the library opens +std::filesystem::path log_path_of(const std::filesystem::path& stem) { + return std::filesystem::path(stem).replace_extension(log_extension); +} +std::filesystem::path index_path_of(const std::filesystem::path& stem) { + return std::filesystem::path(stem).replace_extension(index_extension); +} + +/// Sliding read window over a random_access_file so entry-chain walks do sequential bulk reads +/// instead of one small pread per header and trailer. +struct window_reader { + window_reader(fc::random_access_file& f, uint64_t file_size, size_t window_size = default_window_size) + : dev(f.seekable_device()), file_size(file_size), buf(window_size) {} + + /// pointer to `need` contiguous bytes at file offset `pos`; `need` must fit the window and the file + const char* view(uint64_t pos, size_t need) { + assert(need <= buf.size()); + assert(pos + need <= file_size); + if(pos < base || pos + need > base + len) { + base = pos; + len = static_cast(std::min(buf.size(), file_size - pos)); + dev.seek(base, std::ios_base::beg); + size_t got = 0; + while(got < len) { + const std::streamsize red = dev.read(buf.data() + got, len - got); + EOS_ASSERT(red > 0, chain::plugin_exception, "unexpected end of file reading at offset ${pos}", + ("pos", base + got)); + got += static_cast(red); + } + } + return buf.data() + (pos - base); + } + + fc::random_access_file::device dev; + uint64_t file_size; + std::vector buf; + uint64_t base = 0; + size_t len = 0; +}; + +/// rate-limited progress reporting +struct progress_ticker { + progress_ticker(const progress_func& f, uint64_t total) : f(f), total(total) {} + void tick(uint64_t done) { + if(f && done - last >= progress_granularity) { + last = done; + f(done, total); + } + } + const progress_func& f; + uint64_t total; + uint64_t last = 0; +}; + +template +T parse_at(const char* p, size_t len) { + T t; + fc::datastream ds(p, len); + fc::raw::unpack(ds, t); + return t; +} + +/// outcome of validating a single entry at a given offset +struct entry_check { + bool ok = false; + bool structurally_ok = false; ///< header/bounds/trailer fine; the deep payload check may still have failed + uint32_t block_num = 0; ///< meaningful when structurally_ok + uint64_t end_pos = 0; ///< one past the entry's position trailer; meaningful when structurally_ok + std::string reason; ///< first validation failure when !ok +}; + +/** + * Validate the entry at `pos`: ship magic with the supported version and no feature flags, payload + * preamble coherent with its format marker, payload within bounds, block number plausible against + * `prev_block`/`floor_block` when provided, and the position trailer pointing back at `pos`. With + * `deep`, additionally decompress the payload and, for entries that record an uncompressed size, + * compare against it. + */ +entry_check check_entry(window_reader& w, fc::random_access_file& f, uint64_t pos, uint64_t file_size, + std::optional prev_block, std::optional floor_block, bool deep) { + entry_check r; + if(pos + min_entry_size > file_size) { + r.reason = "remaining bytes are too few to hold an entry"; + return r; + } + + const log_header hdr = parse_at(w.view(pos, packed_header_size), packed_header_size); + if(!is_ship(hdr.magic)) { + r.reason = "header magic missing"; + return r; + } + if(!is_ship_supported_version(hdr.magic) || get_ship_features(hdr.magic) != 0) { + r.reason = "unexpected version or feature flags in header magic"; + return r; + } + + r.block_num = chain::block_header::num_from_id(hdr.block_id); + if(r.block_num == 0) { + r.reason = "block number 0 is not valid"; + return r; + } + if(prev_block && r.block_num > *prev_block + 1) { + r.reason = "block " + std::to_string(r.block_num) + " skips over block " + std::to_string(*prev_block + 1); + return r; + } + if(floor_block && r.block_num < *floor_block) { + r.reason = "block " + std::to_string(r.block_num) + " is before the log's first block " + + std::to_string(*floor_block); + return r; + } + + if(hdr.payload_size < marker_size || hdr.payload_size > file_size || + pos + packed_header_size + hdr.payload_size + trailer_size > file_size) { + r.reason = "payload size " + std::to_string(hdr.payload_size) + " does not fit in the file"; + return r; + } + + const uint32_t marker = parse_at(w.view(pos + packed_header_size, marker_size), marker_size); + size_t preamble = marker_size; + std::optional recorded_uncompressed; + if(marker == leap4_compressed_marker) { + if(hdr.payload_size < leap4_preamble_size) { + r.reason = "payload too small for its format"; + return r; + } + preamble = leap4_preamble_size; + recorded_uncompressed = + parse_at(w.view(pos + packed_header_size + marker_size, sizeof(uint64_t)), sizeof(uint64_t)); + } else if(marker != 0 && marker != hdr.payload_size - marker_size) { + //pre-Leap-3 entries recorded the actual compressed size here; anything else is damage + r.reason = "payload format marker is incoherent with the payload size"; + return r; + } + + const uint64_t trailer_pos = pos + packed_header_size + hdr.payload_size; + if(parse_at(w.view(trailer_pos, trailer_size), trailer_size) != pos) { + r.reason = "position trailer does not point back at the entry"; + return r; + } + + r.structurally_ok = true; + r.end_pos = trailer_pos + trailer_size; + + if(deep) { + try { + bio::filtering_istreambuf strm(bio::zlib_decompressor() | + bio::restrict(f.seekable_device(), pos + packed_header_size + preamble, + hdr.payload_size - preamble)); + const uint64_t decompressed = bio::copy(strm, bio::null_sink()); + if(recorded_uncompressed && decompressed != *recorded_uncompressed) { + r.reason = "payload decompressed to " + std::to_string(decompressed) + " bytes but the entry recorded " + + std::to_string(*recorded_uncompressed); + return r; + } + } catch(const std::exception& e) { + r.reason = std::string("payload decompression failed: ") + e.what(); + return r; + } + } + + r.ok = true; + return r; +} + +/** + * Search forward from `from` for the next offset holding a structurally valid entry. Entries of a + * forward-scannable (non-pruned) log always bear the current version with no feature flags, so the + * serialized magic is a fixed 8-byte needle; candidates are then fully validated, making a false + * resynchronization on payload bytes that happen to contain the needle all but impossible (the + * candidate's position trailer would have to point back at it exactly). + */ +std::optional find_next_entry(window_reader& w, fc::random_access_file& f, uint64_t from, + uint64_t file_size, std::optional floor_block) { + char needle[sizeof(uint64_t)]; + fc::datastream nds(needle, sizeof(needle)); + fc::raw::pack(nds, ship_magic(ship_current_version, 0)); + + uint64_t pos = from; + while(pos + min_entry_size <= file_size) { + const size_t span = static_cast(std::min(w.buf.size(), file_size - pos)); + const char* p = w.view(pos, span); + const char* hit = std::search(p, p + span, needle, needle + sizeof(needle)); + if(hit != p + span) { + const uint64_t cand = pos + (hit - p); + if(check_entry(w, f, cand, file_size, std::nullopt, floor_block, false).structurally_ok) + return cand; + pos = cand + 1; + } else { + if(pos + span == file_size) + break; + pos += span - (sizeof(needle) - 1); //overlap windows so a needle straddling them is still found + } + } + return std::nullopt; +} + +/// incrementally builds scan_result valid_ranges from entries visited in file order +struct range_builder { + explicit range_builder(scan_result& r) : r(r) {} + + void good(const entry_check& c, uint64_t pos) { + if(!cur) { + cur = entry_range{c.block_num, c.block_num, pos, c.end_pos, 1, pos, c.block_num}; + } else { + cur->last_block = c.block_num; + cur->end_pos = c.end_pos; + ++cur->entry_count; + //an entry at-or-below the current canonical start supersedes it: everything before this + // entry is now on an abandoned fork + if(c.block_num <= cur->canonical_first_block) { + cur->canonical_first_block = c.block_num; + cur->canonical_begin_pos = pos; + } + } + } + + void close() { + if(cur) { + r.valid_ranges.push_back(*cur); + cur.reset(); + } + } + + scan_result& r; + std::optional cur; +}; + +/// endpoint-only probe shared by summarize_log() and the mutating operations' sanity checks +struct endpoints { + bool valid_first = false; ///< first header parses with ship magic and supported version + uint16_t version = 0; + bool pruned = false; + std::optional pruned_count; + uint32_t first_block = 0; + bool tail_ok = false; ///< trailing position trailer leads to a coherent last entry + uint32_t last_block = 0; + uint64_t last_entry_pos = 0; + chain::block_id_type first_id; ///< id recorded for first_block (valid_first only) + chain::block_id_type last_id; ///< id recorded for last_block (tail_ok only) +}; + +endpoints probe_endpoints(fc::random_access_file& log, uint64_t size) { + endpoints e; + if(size < min_entry_size) + return e; + try { + const log_header first = log.unpack_from(0); + if(!is_ship(first.magic) || !is_ship_supported_version(first.magic)) + return e; + e.valid_first = true; + e.version = get_ship_version(first.magic); + e.pruned = is_ship_log_pruned(first.magic); + e.first_block = chain::block_header::num_from_id(first.block_id); + e.first_id = first.block_id; + if(e.pruned) + e.pruned_count = log.unpack_from(size - sizeof(uint32_t)); + + const uint64_t end_of_entries = size - (e.pruned ? sizeof(uint32_t) : 0); + const uint64_t last_pos = log.unpack_from(end_of_entries - trailer_size); + if(last_pos + packed_header_size + trailer_size > end_of_entries) + return e; + const log_header last = log.unpack_from(last_pos); + if(!is_ship(last.magic) || !is_ship_supported_version(last.magic)) + return e; + if(last_pos + packed_header_size + last.payload_size + trailer_size != end_of_entries) + return e; + e.tail_ok = true; + e.last_block = chain::block_header::num_from_id(last.block_id); + e.last_entry_pos = last_pos; + e.last_id = last.block_id; + } catch(const std::exception&) { + //treat any short read or parse failure as "endpoint not OK"; the flags already say so + } + return e; +} + +/// expected index content computed from the log itself +struct computed_index { + uint32_t index_first = 0; ///< block number slot 0 corresponds to + uint32_t first_block = 0; ///< first servable block (> index_first only for pruned logs) + uint32_t last_block = 0; + std::vector slots; ///< latest entry position per block, 0 for pruned-away slots +}; + +void grow_slots(std::vector& slots, uint32_t index_first, uint32_t block_num, + const std::filesystem::path& stem) { + //callers guarantee block_num >= index_first via check_entry's floor check; spell the precondition + // out so the unsigned subtraction below can never silently wrap into a huge allocation request + assert(block_num >= index_first); + const uint64_t needed = uint64_t(block_num) - index_first + 1; + EOS_ASSERT(needed <= max_in_memory_index_blocks, chain::plugin_exception, + "${stem}.log spans more than ${mimib} blocks which exceeds what this tool supports", + ("stem", stem.string())("mimib", max_in_memory_index_blocks)); + if(slots.size() < needed) + slots.resize(needed, 0); +} + +/** + * Forward-walk a non-pruned log computing every block's latest entry position. Equivalent to the + * backward regeneration state_history_log performs on open, but sequential (and so considerably + * faster on most storage). Throws on the first sign of damage. + */ +computed_index compute_index_forward(fc::random_access_file& log, uint64_t size, const std::filesystem::path& stem, + const progress_func& progress) { + computed_index ci; + window_reader w(log, size); + progress_ticker ticker(progress, size); + + uint64_t pos = 0; + std::optional prev, floor; + while(pos < size) { + const entry_check c = check_entry(w, log, pos, size, prev, floor, false); + EOS_ASSERT(c.ok, chain::plugin_exception, "${stem}.log is damaged at offset ${pos} (${reason}); repair it first", + ("stem", stem.string())("pos", pos)("reason", c.reason)); + if(!floor) { + floor = c.block_num; + ci.index_first = ci.first_block = c.block_num; + } + grow_slots(ci.slots, ci.index_first, c.block_num, stem); + ci.slots[c.block_num - ci.index_first] = pos; + ci.last_block = c.block_num; + prev = c.block_num; + pos = c.end_pos; + ticker.tick(pos); + } + //a fork switch near the end can leave entries for blocks past the final head; those slots are stale + ci.slots.resize(uint64_t(ci.last_block) - ci.index_first + 1); + return ci; +} + +/// where and why a backward pruned-chain walk stopped short of its begin block +struct chain_break { + uint64_t at_pos; ///< offset the walk could not get past + std::string reason; +}; + +/** + * Walk a pruned log's position-trailer chain from its tail entry back toward `begin_block` (the + * oldest retained block), invoking `visit(pos, entry_check&&)` for every entry, newest first. This + * is the one place the pruned trailer chain is validated; both index regeneration and the smoke-test + * scanner drive it so they cannot drift apart. It mirrors the library's pruned-index regeneration in + * state_history_log::check_index_on_init: entries must abut their successors and the chain is + * followed strictly backward. + * + * `floor_block` is the lowest block the log can describe — slot 0 of its index. A decoded block + * number below it cannot occur in a healthy log (nothing is ever written before the log's first + * block), so check_entry rejects it and the walk stops as damage, never indexing below slot 0. No + * upper bound is imposed: a deep fork switch in the retained tail legitimately leaves superseded + * entries whose block number exceeds the head's (the library's "we see block 7 and 6 when reading" + * case), so a caller that uses block_num as a slot index must range-check the high side itself. + * + * Returns std::nullopt once an entry for `begin_block` is visited, otherwise a chain_break naming the + * offset and reason the walk stopped early. With `deep`, each entry's payload is also validated; a + * payload-only failure does not stop the walk (the entry is still visited, with entry_check::ok + * false) so the caller can report it as a damaged region. + */ +template +std::optional walk_pruned_chain(window_reader& w, fc::random_access_file& log, uint64_t file_size, + uint64_t last_entry_pos, uint32_t begin_block, uint32_t floor_block, + bool deep, Visit&& visit) { + uint64_t next_begin = file_size - sizeof(uint32_t); //the pruned block-count trailer occupies the final 4 bytes + uint64_t pos = last_entry_pos; + while(true) { + entry_check c = check_entry(w, log, pos, file_size, std::nullopt, floor_block, deep); + if(!c.structurally_ok || c.end_pos != next_begin) + return chain_break{pos, c.reason.empty() ? std::string("entry does not abut its successor") : c.reason}; + const uint32_t block_num = c.block_num; + visit(pos, std::move(c)); + if(block_num == begin_block) + return std::nullopt; + if(pos < packed_header_size + trailer_size) + return chain_break{pos, "ran out of entries before reaching block " + std::to_string(begin_block)}; + const uint64_t trailer_at = pos - trailer_size; + next_begin = pos; + pos = parse_at(w.view(trailer_at, trailer_size), trailer_size); + if(pos + min_entry_size > next_begin) + return chain_break{trailer_at, "position trailer points outside the file"}; + } +} + +/** + * Backward-walk a pruned log through its position-trailer chain, mirroring the library's index + * regeneration: only the first-seen (i.e. latest-written) entry per block counts, and the walk ends + * at the first entry seen for the begin block. Throws if the chain cannot be walked. + */ +computed_index compute_index_pruned(fc::random_access_file& log, uint64_t size, const endpoints& e, + const std::filesystem::path& stem, const progress_func& progress) { + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, + "pruned log ${stem}.log is damaged and cannot be repaired", ("stem", stem.string())); + EOS_ASSERT(*e.pruned_count > 0 && *e.pruned_count <= e.last_block, chain::plugin_exception, + "pruned log ${stem}.log has an implausible trailing block count ${pc}", + ("stem", stem.string())("pc", *e.pruned_count)); + + computed_index ci; + ci.index_first = e.first_block; + ci.first_block = e.last_block - *e.pruned_count + 1; + ci.last_block = e.last_block; + EOS_ASSERT(ci.first_block >= ci.index_first, chain::plugin_exception, + "pruned log ${stem}.log has a trailing block count ${pc} reaching before its first block ${if}", + ("stem", stem.string())("pc", *e.pruned_count)("if", ci.index_first)); + grow_slots(ci.slots, ci.index_first, ci.last_block, stem); + + window_reader w(log, size); + progress_ticker ticker(progress, size); + const std::optional stop = walk_pruned_chain( + w, log, size, e.last_entry_pos, ci.first_block, ci.index_first, false, [&](uint64_t pos, entry_check&& c) { + //a deep fork switch in the retained tail can leave superseded entries above the head; the + // library skips them when regenerating the index (read_block_num < _end_block), so do the same + // here rather than index past the slot vector — they are valid data, not damage. The chain + // walk's floor check already guarantees c.block_num >= ci.index_first. + if(c.block_num <= ci.last_block && ci.slots[c.block_num - ci.index_first] == 0) + ci.slots[c.block_num - ci.index_first] = pos; + ticker.tick(size - pos); + }); + EOS_ASSERT(!stop, chain::plugin_exception, + "pruned log ${stem}.log is damaged at offset ${pos} (${why}) and cannot be repaired", + ("stem", stem.string())("pos", stop ? stop->at_pos : 0)("why", stop ? stop->reason : std::string{})); + return ci; +} + +/// write a computed index to disk, replacing whatever was there +void write_index_file(const std::filesystem::path& index_path, const computed_index& ci) { + fc::random_access_file index(index_path); + index.resize(0); + fc::random_access_file::write_datastream ds = index.write_ds(0); + //slot values are written with fc::raw's little-endian encoding, matching the library's index format + for(const uint64_t pos : ci.slots) + fc::raw::pack(ds, pos); + ds.flush(); +} + +/// open a log read-only with a friendlier error than the raw open failure +fc::random_access_file open_log_readonly(const std::filesystem::path& stem) { + const std::filesystem::path lp = log_path_of(stem); + EOS_ASSERT(std::filesystem::exists(lp), chain::plugin_exception, "${lp} does not exist", ("lp", lp.string())); + return fc::random_access_file(lp, fc::random_access_file::read_only); +} + +/** + * True iff the entry at `pos` is a structurally valid ship header for exactly `block_num`. This is the + * shared "does this slot really hold the block we asked for" check behind every index lookup. An + * on-disk index can be stale, and a computed index legitimately carries zero slots for blocks a + * (possibly damaged) log does not retain; a zero or otherwise wrong slot would unpack the header at + * the wrong offset -- offset 0 is the log's first/stub header -- and silently misattribute a + * neighbouring block's id. A slot is therefore trusted only after its entry is read back and confirmed + * to decode to the requested block. + */ +bool slot_holds_block(fc::random_access_file& log, uint64_t log_size, uint64_t pos, uint32_t block_num) { + if(pos + packed_header_size > log_size) + return false; + const log_header hdr = log.unpack_from(pos); + return is_ship(hdr.magic) && is_ship_supported_version(hdr.magic) && + chain::block_header::num_from_id(hdr.block_id) == block_num; +} + +/// positions of blocks in a log, from its index file when that is usable, otherwise from a forward walk +struct position_lookup { + position_lookup(fc::random_access_file& log, uint64_t log_size, const endpoints& e, + const std::filesystem::path& stem, const progress_func& progress) + : log(log), log_size(log_size), stem(stem), first_block(e.first_block) { + const std::filesystem::path ip = index_path_of(stem); + const uint64_t expected_size = (uint64_t(e.last_block) - e.first_block + 1) * sizeof(uint64_t); + if(std::filesystem::exists(ip) && std::filesystem::file_size(ip) == expected_size) { + index.emplace(ip, fc::random_access_file::read_only); + if(index->unpack_from(expected_size - sizeof(uint64_t)) == e.last_entry_pos) + return; + index.reset(); + } + computed = compute_index_forward(log, log_size, stem, progress); + first_block = computed->index_first; + } + + /// position of the latest entry for block_num, validated to actually hold that block + uint64_t entry_pos_of(uint32_t block_num) { + uint64_t pos; + if(index) + pos = index->unpack_from((uint64_t(block_num) - first_block) * sizeof(uint64_t)); + else + pos = computed->slots[block_num - first_block]; + EOS_ASSERT(slot_holds_block(log, log_size, pos, block_num), chain::plugin_exception, + "index entry for block ${bn} of ${stem}.log does not point at that block; run make-index first", + ("bn", block_num)("stem", stem.string())); + return pos; + } + + /// one past the end of the latest entry for block_num (including its position trailer) + uint64_t entry_end_of(uint32_t block_num) { + const uint64_t pos = entry_pos_of(block_num); + const log_header hdr = log.unpack_from(pos); + const uint64_t end = pos + packed_header_size + hdr.payload_size + trailer_size; + EOS_ASSERT(end <= log_size, chain::plugin_exception, + "entry for block ${bn} of ${stem}.log extends past the end of the log", + ("bn", block_num)("stem", stem.string())); + return end; + } + + bool used_file_index() const { return !!index; } + + fc::random_access_file& log; + uint64_t log_size; + std::filesystem::path stem; + uint32_t first_block; + std::optional index; ///< fast path: shallow-validated on-disk index + std::optional computed; ///< fallback: in-memory forward walk +}; + +/// accumulates the index of a bundle being written by append_entries() +struct index_accumulator { + uint32_t first = 0; + uint32_t last = 0; + bool any = false; + std::vector slots; +}; + +/** + * Copy the entries occupying [begin, end) of src onto dst's write stream, which must be positioned + * at dst_base, rewriting each entry's position trailer for its new offset and recording new index + * slots in acc. Every entry is re-validated during the copy. prev_block carries the block-number + * chain across consecutive calls (merging) and must start empty for a bundle's first range. + */ +void append_entries(fc::random_access_file& src, uint64_t src_size, uint64_t begin, uint64_t end, + fc::random_access_file::write_datastream& dst, uint64_t dst_base, + const std::filesystem::path& src_stem, const std::filesystem::path& dst_stem, + index_accumulator& acc, std::optional& prev_block, progress_ticker& ticker) { + window_reader w(src, src_size); + uint64_t pos = begin; + while(pos < end) { + const entry_check c = check_entry(w, src, pos, src_size, prev_block, + acc.any ? std::optional(acc.first) : std::nullopt, false); + EOS_ASSERT(c.ok, chain::plugin_exception, "${ss}.log is damaged at offset ${pos} (${reason}); repair it first", + ("ss", src_stem.string())("pos", pos)("reason", c.reason)); + EOS_ASSERT(c.end_pos <= end, chain::plugin_exception, + "entry at offset ${pos} of ${ss}.log crosses the end of the requested range", + ("pos", pos)("ss", src_stem.string())); + + if(!acc.any) { + acc.any = true; + acc.first = c.block_num; + } + const uint64_t dst_pos = dst_base + (pos - begin); + grow_slots(acc.slots, acc.first, c.block_num, dst_stem); + acc.slots[c.block_num - acc.first] = dst_pos; + acc.last = c.block_num; + + //copy the header and payload bytes verbatim, then write the rebased position trailer + uint64_t remaining = (c.end_pos - trailer_size) - pos; + uint64_t at = pos; + while(remaining) { + const size_t n = static_cast(std::min(remaining, w.buf.size())); + dst.write(w.view(at, n), n); + at += n; + remaining -= n; + } + fc::raw::pack(dst, dst_pos); + + prev_block = c.block_num; + pos = c.end_pos; + ticker.tick(dst_base + (pos - begin)); + } + EOS_ASSERT(pos == end, chain::plugin_exception, "range of ${ss}.log does not end on an entry boundary", + ("ss", src_stem.string())); +} + +/// assert that neither file of a destination bundle exists yet +void assert_bundle_creatable(const std::filesystem::path& stem) { + EOS_ASSERT(!std::filesystem::exists(log_path_of(stem)), chain::plugin_exception, "${path} already exists", + ("path", log_path_of(stem).string())); + EOS_ASSERT(!std::filesystem::exists(index_path_of(stem)), chain::plugin_exception, "${path} already exists", + ("path", index_path_of(stem).string())); +} + +/// finalize an index_accumulator into a computed_index (drops slots past the final head block) +computed_index finalize_accumulator(index_accumulator&& acc) { + computed_index ci; + ci.index_first = ci.first_block = acc.first; + ci.last_block = acc.last; + acc.slots.resize(uint64_t(acc.last) - acc.first + 1); + ci.slots = std::move(acc.slots); + return ci; +} + +/// escape a literal string for interpolation into a std::regex pattern +std::string regex_escape(const std::string& s) { + static const std::regex special(R"([.^$|()\[\]{}*+?\\])"); + return std::regex_replace(s, special, R"(\$&)"); +} + +/// remove both files of a partially written destination bundle after a failure +void remove_bundle(const std::filesystem::path& stem) noexcept { + std::error_code ec; + std::filesystem::remove(log_path_of(stem), ec); + std::filesystem::remove(index_path_of(stem), ec); +} + +/** + * Create a fresh bundle at dst_stem from the entries occupying [begin, end) of the log at + * src_stem, cleaning up the partial bundle if anything fails. + * + * @return (first block, last block) of the created bundle + */ +std::pair extract_byte_range(const std::filesystem::path& src_stem, uint64_t begin, uint64_t end, + const std::filesystem::path& dst_stem, + const progress_func& progress) { + assert_bundle_creatable(dst_stem); + try { + fc::random_access_file src = open_log_readonly(src_stem); + fc::random_access_file dst(log_path_of(dst_stem)); + fc::random_access_file::write_datastream ds = dst.write_ds(0); + index_accumulator acc; + std::optional prev; + progress_ticker ticker(progress, end - begin); + append_entries(src, src.size(), begin, end, ds, 0, src_stem, dst_stem, acc, prev, ticker); + ds.flush(); + EOS_ASSERT(acc.any, chain::plugin_exception, "no entries found in the requested range of ${ss}.log", + ("ss", src_stem.string())); + const uint32_t got_first = acc.first; + const uint32_t got_last = acc.last; + write_index_file(index_path_of(dst_stem), finalize_accumulator(std::move(acc))); + return {got_first, got_last}; + } catch(...) { + remove_bundle(dst_stem); + throw; + } +} + +} //anonymous namespace + +std::filesystem::path normalize_stem(const std::filesystem::path& p) { + const std::string ext = p.extension().string(); + if(ext == std::string(".").append(log_extension) || ext == std::string(".").append(index_extension)) { + std::filesystem::path r = p; + r.replace_extension(); + return r; + } + return p; +} + +scan_result scan_log(const std::filesystem::path& stem_in, bool deep, const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + + scan_result r; + r.file_size = log.size(); + if(r.file_size == 0) + return r; + + if(r.file_size < min_entry_size) { + r.damaged_ranges.push_back({0, r.file_size, "file is too small to hold an entry"}); + return r; + } + + //a first header without ship magic gets no special treatment: the forward scan below reports it + // as damage and resynchronizes, which both diagnoses a destroyed first header and yields one + // whole-file damaged range for a file that is not a ship log at all + const log_header first = log.unpack_from(0); + if(is_ship(first.magic)) { + EOS_ASSERT(is_ship_supported_version(first.magic), chain::plugin_exception, "${stem}.log has an unsupported version", + ("stem", stem.string())); + r.version = get_ship_version(first.magic); + r.pruned = is_ship_log_pruned(first.magic); + } + + window_reader w(log, r.file_size); + progress_ticker ticker(progress, r.file_size); + range_builder rb(r); + + if(r.pruned) { + //pruned logs have a punched-out hole after the first header, so they are walked backward + // through the position-trailer chain; entries the chain cannot reach are beyond what the + // format can describe, which is also why the library refuses to repair a damaged pruned log + r.pruned_block_count = log.unpack_from(r.file_size - sizeof(uint32_t)); + const endpoints e = probe_endpoints(log, r.file_size); + if(!e.tail_ok || *r.pruned_block_count == 0 || *r.pruned_block_count > e.last_block) { + r.damaged_ranges.push_back({0, r.file_size, "pruned log's trailing entry or block count is damaged"}); + return r; + } + const uint32_t begin_block = e.last_block - *r.pruned_block_count + 1; + + //collect entries newest to oldest (bounded by the log's retained-block count) via the shared + // chain walk, then build ranges in file order. e.first_block is the index floor: a block number + // below it is corruption, not a valid (superseded) entry, so the walk reports it as damage. + struct seen_entry { + uint64_t pos; + entry_check check; + }; + std::vector entries; + const std::optional stop = walk_pruned_chain( + w, log, r.file_size, e.last_entry_pos, begin_block, e.first_block, deep, + [&](uint64_t pos, entry_check&& c) { + ++r.entries_scanned; + if(deep) + ++r.payloads_validated; + entries.push_back({pos, std::move(c)}); + ticker.tick(r.file_size - pos); + }); + if(stop) + r.damaged_ranges.push_back( + {0, entries.empty() ? r.file_size : entries.back().pos, "backward chain broken: " + stop->reason}); + + for(auto it = entries.rbegin(); it != entries.rend(); ++it) { + if(it->check.ok) { + rb.good(it->check, it->pos); + } else { //structurally fine, deep payload check failed + rb.close(); + r.damaged_ranges.push_back({it->pos, it->check.end_pos, it->check.reason}); + } + } + rb.close(); + return r; + } + + uint64_t pos = 0; + std::optional prev_block, floor_block; + while(pos + min_entry_size <= r.file_size) { + entry_check c = check_entry(w, log, pos, r.file_size, prev_block, floor_block, deep); + if(c.structurally_ok) { + ++r.entries_scanned; + if(deep) + ++r.payloads_validated; + if(pos == 0) + floor_block = c.block_num; + } + if(c.ok) { + rb.good(c, pos); + prev_block = c.block_num; + pos = c.end_pos; + ticker.tick(pos); + continue; + } + if(c.structurally_ok) { //payload damage confined to one entry + rb.close(); + r.damaged_ranges.push_back({pos, c.end_pos, c.reason}); + prev_block = c.block_num; + pos = c.end_pos; + continue; + } + //structural damage: extent unknown, search for the next valid entry + rb.close(); + const std::optional next = find_next_entry(w, log, pos + 1, r.file_size, floor_block); + r.damaged_ranges.push_back({pos, next.value_or(r.file_size), c.reason}); + if(!next) { + pos = r.file_size; + break; + } + pos = *next; + prev_block.reset(); //fresh block-number baseline on the far side of the damage + } + if(pos < r.file_size) { + rb.close(); + r.damaged_ranges.push_back({pos, r.file_size, "trailing bytes too small to hold an entry"}); + } + rb.close(); + return r; +} + +std::string_view to_string(index_status s) { + switch(s) { + case index_status::ok: return "ok"; + case index_status::missing: return "missing"; + case index_status::wrong_size: return "wrong_size"; + case index_status::mismatched: return "mismatched"; + case index_status::log_damaged: return "log_damaged"; + } + return "unknown"; +} + +index_status check_index(const std::filesystem::path& stem_in, bool full, const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + const uint64_t size = log.size(); + const std::filesystem::path ip = index_path_of(stem); + + if(size == 0) + return !std::filesystem::exists(ip) || std::filesystem::file_size(ip) == 0 ? index_status::ok + : index_status::wrong_size; + + const endpoints e = probe_endpoints(log, size); + if(!e.valid_first || !e.tail_ok) + return index_status::log_damaged; + + if(!std::filesystem::exists(ip)) + return index_status::missing; + const uint64_t expected_size = (uint64_t(e.last_block) - e.first_block + 1) * sizeof(uint64_t); + if(std::filesystem::file_size(ip) != expected_size) + return index_status::wrong_size; + + fc::random_access_file index(ip, fc::random_access_file::read_only); + if(index.unpack_from(expected_size - sizeof(uint64_t)) != e.last_entry_pos) + return index_status::mismatched; + if(!full) + return index_status::ok; + + computed_index ci; + try { + ci = e.pruned ? compute_index_pruned(log, size, e, stem, progress) + : compute_index_forward(log, size, stem, progress); + } catch(const fc::exception&) { + return index_status::log_damaged; + } + if(ci.slots.size() * sizeof(uint64_t) != expected_size) + return index_status::mismatched; + + //pruning punches holes in the log but leaves the index alone, so slots below the first servable + // block legitimately hold either stale positions (organic) or zeros (after a regeneration); only + // the servable slots are comparable + const uint64_t first_comparable = uint64_t(ci.first_block) - ci.index_first; + window_reader iw(index, expected_size, static_cast(std::min(default_window_size, expected_size))); + for(uint64_t i = first_comparable; i < ci.slots.size(); ++i) + if(parse_at(iw.view(i * sizeof(uint64_t), sizeof(uint64_t)), sizeof(uint64_t)) != ci.slots[i]) + return index_status::mismatched; + return index_status::ok; +} + +std::pair build_index(const std::filesystem::path& stem_in, const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + const uint64_t size = log.size(); + + if(size == 0) { + fc::random_access_file index(index_path_of(stem)); + index.resize(0); + return {0, 0}; + } + + const endpoints e = probe_endpoints(log, size); + computed_index ci; + if(e.valid_first && e.pruned) + ci = compute_index_pruned(log, size, e, stem, progress); + else + ci = compute_index_forward(log, size, stem, progress); + write_index_file(index_path_of(stem), ci); + return {ci.first_block, ci.last_block}; +} + +uint64_t truncate_log(const std::filesystem::path& stem_in, uint32_t last_block_to_keep, + const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + const uint64_t size = log.size(); + const endpoints e = probe_endpoints(log, size); + + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, "${stem}.log is damaged; run repair instead of trim", + ("stem", stem.string())); + EOS_ASSERT(!e.pruned, chain::plugin_exception, "${stem}.log is pruned; vacuum it first", ("stem", stem.string())); + EOS_ASSERT(last_block_to_keep >= e.first_block && last_block_to_keep <= e.last_block, chain::plugin_exception, + "block ${lbtk} is outside the ${fb}-${lb} range of ${stem}.log", + ("lbtk", last_block_to_keep)("fb", e.first_block)("lb", e.last_block)("stem", stem.string())); + if(last_block_to_keep == e.last_block) + return 0; + + position_lookup lookup(log, size, e, stem, progress); + const uint64_t new_size = lookup.entry_end_of(last_block_to_keep); + + { + fc::random_access_file rw_log(log_path_of(stem)); + rw_log.resize(new_size); + } + if(lookup.used_file_index()) { + //the on-disk index was validated; kept entries' positions are unchanged, so shrinking suffices + fc::random_access_file index(index_path_of(stem)); + index.resize((uint64_t(last_block_to_keep) - e.first_block + 1) * sizeof(uint64_t)); + } else { + lookup.computed->slots.resize(uint64_t(last_block_to_keep) - lookup.computed->index_first + 1); + lookup.computed->last_block = last_block_to_keep; + write_index_file(index_path_of(stem), *lookup.computed); + } + return size - new_size; +} + +uint64_t extract_blocks(const std::filesystem::path& src_stem_in, const std::filesystem::path& dst_stem_in, + uint32_t first_block, uint32_t last_block, const progress_func& progress) { + const std::filesystem::path src_stem = normalize_stem(src_stem_in); + const std::filesystem::path dst_stem = normalize_stem(dst_stem_in); + EOS_ASSERT(first_block <= last_block, chain::plugin_exception, "first block ${fb} is after last block ${lb}", + ("fb", first_block)("lb", last_block)); + + fc::random_access_file src = open_log_readonly(src_stem); + const uint64_t size = src.size(); + const endpoints e = probe_endpoints(src, size); + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, "${ss}.log is damaged; repair it first", + ("ss", src_stem.string())); + EOS_ASSERT(!e.pruned, chain::plugin_exception, "${ss}.log is pruned; vacuum it first", ("ss", src_stem.string())); + EOS_ASSERT(first_block >= e.first_block && last_block <= e.last_block, chain::plugin_exception, + "blocks ${fb}-${lb} are outside the ${fb1}-${lb1} range of ${ss}.log", + ("fb", first_block)("lb", last_block)("fb1", e.first_block)("lb1", e.last_block)("ss", src_stem.string())); + + position_lookup lookup(src, size, e, src_stem, progress); + const uint64_t begin_pos = lookup.entry_pos_of(first_block); + const uint64_t end_pos = lookup.entry_end_of(last_block); + EOS_ASSERT(begin_pos < end_pos, chain::plugin_exception, + "entry positions of blocks ${fb} and ${lb} of ${ss}.log are out of order; run make-index first", + ("fb", first_block)("lb", last_block)("ss", src_stem.string())); + + const auto [got_first, got_last] = extract_byte_range(src_stem, begin_pos, end_pos, dst_stem, progress); + EOS_ASSERT(got_first == first_block && got_last == last_block, chain::plugin_exception, + "extracted range ${gf}-${gl} does not match requested ${fb}-${lb}", + ("gf", got_first)("gl", got_last)("fb", first_block)("lb", last_block)); + return end_pos - begin_pos; +} + +uint64_t trim_front(const std::filesystem::path& stem_in, uint32_t first_block_to_keep, + const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + + uint32_t last_block; + uint64_t old_size; + { + fc::random_access_file log = open_log_readonly(stem); + old_size = log.size(); + const endpoints e = probe_endpoints(log, old_size); + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, "${stem}.log is damaged; run repair instead of trim", + ("stem", stem.string())); + EOS_ASSERT(!e.pruned, chain::plugin_exception, "${stem}.log is pruned; vacuum it first", ("stem", stem.string())); + EOS_ASSERT(first_block_to_keep >= e.first_block && first_block_to_keep <= e.last_block, chain::plugin_exception, + "block ${fbtk} is outside the ${fb}-${lb} range of ${stem}.log", + ("fbtk", first_block_to_keep)("fb", e.first_block)("lb", e.last_block)("stem", stem.string())); + if(first_block_to_keep == e.first_block) + return 0; + last_block = e.last_block; + } + + std::filesystem::path tmp_stem = stem; + tmp_stem += std::string(tmp_suffix); + remove_bundle(tmp_stem); + + const uint64_t bytes = extract_blocks(stem, tmp_stem, first_block_to_keep, last_block, progress); + + //the .log and .index renames are not atomic as a pair; a crash between them leaves the new log + // beside the old index, but state_history_log regenerates a wrong-sized index on its next open, + // so the bundle self-heals + std::filesystem::rename(log_path_of(tmp_stem), log_path_of(stem)); + std::filesystem::rename(index_path_of(tmp_stem), index_path_of(stem)); + return old_size - bytes; +} + +std::vector split_log(const std::filesystem::path& src_stem_in, + const std::filesystem::path& dst_dir, uint32_t stride, + const progress_func& progress) { + const std::filesystem::path src_stem = normalize_stem(src_stem_in); + EOS_ASSERT(stride > 0, chain::plugin_exception, "stride must be non-zero"); + + fc::random_access_file src = open_log_readonly(src_stem); + const uint64_t size = src.size(); + const endpoints e = probe_endpoints(src, size); + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, "${ss}.log is damaged; repair it first", + ("ss", src_stem.string())); + EOS_ASSERT(!e.pruned, chain::plugin_exception, "${ss}.log is pruned; vacuum it first", ("ss", src_stem.string())); + //each output bundle is extracted separately, so an unusable index would mean one full log walk + // per bundle; require a healthy index up front instead + EOS_ASSERT(summarize_log(src_stem).index == index_status::ok, chain::plugin_exception, + "${ss}.index is missing or unusable; run make-index first", ("ss", src_stem.string())); + + //a retained-style "-N-M" suffix on the source must not leak into output names + const std::string base = std::regex_replace(src_stem.filename().string(), std::regex(R"(-\d+-\d+$)"), ""); + std::filesystem::create_directories(dst_dir); + + std::vector created; + try { + uint32_t b = e.first_block; + while(true) { + //log rotation archives the head right after writing a block divisible by the stride, so + // every retained bundle ends on such a block; the remainder past the last boundary stays + // the head log (empty when the source ends exactly on a boundary, just as after a rotation) + const uint32_t boundary = b % stride == 0 ? b : b - (b % stride) + stride; + if(boundary > e.last_block) + break; + const std::filesystem::path dst = dst_dir / (base + "-" + std::to_string(b) + "-" + std::to_string(boundary)); + extract_blocks(src_stem, dst, b, boundary, progress); + created.push_back(dst); + b = boundary + 1; + if(boundary == e.last_block) + break; + } + + const std::filesystem::path head = dst_dir / base; + if(b <= e.last_block) { + extract_blocks(src_stem, head, b, e.last_block, progress); //self-cleans its partial bundle on throw + created.push_back(head); + } else { + //register the head before creating its files so a throw during the resizes still cleans the + // partial bundle; the order also keeps assert_bundle_creatable from ever marking a + // pre-existing file (which we must not delete) for cleanup + assert_bundle_creatable(head); + created.push_back(head); + fc::random_access_file(log_path_of(head)).resize(0); + fc::random_access_file(index_path_of(head)).resize(0); + } + } catch(...) { + for(const std::filesystem::path& stem : created) + remove_bundle(stem); + throw; + } + return created; +} + +std::pair merge_logs(const std::filesystem::path& src_dir, const std::string& log_name, + const std::filesystem::path& dst_dir, const progress_func& progress) { + EOS_ASSERT(std::filesystem::is_directory(src_dir), chain::plugin_exception, "${sd} is not a directory", + ("sd", src_dir.string())); + + struct source { + uint32_t first; + uint32_t last; + std::filesystem::path stem; + }; + std::vector sources; + const std::regex retained_re("^" + regex_escape(log_name) + R"(-\d+-\d+\.log$)"); + for(const std::filesystem::directory_entry& de : std::filesystem::directory_iterator(src_dir)) { + if(!de.is_regular_file() || !std::regex_search(de.path().filename().string(), retained_re)) + continue; + const std::filesystem::path stem = normalize_stem(de.path()); + fc::random_access_file log = open_log_readonly(stem); + const endpoints e = probe_endpoints(log, log.size()); + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, "${stem}.log is damaged; repair it first", + ("stem", stem.string())); + EOS_ASSERT(!e.pruned, chain::plugin_exception, "${stem}.log is pruned and cannot be merged", ("stem", stem.string())); + sources.push_back({e.first_block, e.last_block, stem}); + } + EOS_ASSERT(!sources.empty(), chain::plugin_exception, "no ${ln}--.log bundles found in ${sd}", + ("ln", log_name)("sd", src_dir.string())); + + std::sort(sources.begin(), sources.end(), [](const source& a, const source& b) { return a.first < b.first; }); + for(size_t i = 1; i < sources.size(); ++i) + EOS_ASSERT(sources[i].first == sources[i - 1].last + 1, chain::plugin_exception, + "${ps}.log ends at block ${pl} but ${ns}.log begins at block ${nf}; bundles must be contiguous to merge", + ("ps", sources[i - 1].stem.string())("pl", sources[i - 1].last) + ("ns", sources[i].stem.string())("nf", sources[i].first)); + + std::filesystem::create_directories(dst_dir); + const std::filesystem::path dst_stem = dst_dir / log_name; + assert_bundle_creatable(dst_stem); + + uint64_t total_bytes = 0; + for(const source& s : sources) + total_bytes += std::filesystem::file_size(log_path_of(s.stem)); + + try { + fc::random_access_file dst(log_path_of(dst_stem)); + fc::random_access_file::write_datastream ds = dst.write_ds(0); + index_accumulator acc; + std::optional prev; + progress_ticker ticker(progress, total_bytes); + uint64_t dst_base = 0; + for(const source& s : sources) { + fc::random_access_file log = open_log_readonly(s.stem); + const uint64_t size = log.size(); + append_entries(log, size, 0, size, ds, dst_base, s.stem, dst_stem, acc, prev, ticker); + dst_base += size; + } + ds.flush(); + write_index_file(index_path_of(dst_stem), finalize_accumulator(std::move(acc))); + } catch(...) { + remove_bundle(dst_stem); + throw; + } + return {sources.front().first, sources.back().last}; +} + +repair_report repair_log(const std::filesystem::path& stem_in, repair_mode mode, bool dry_run, bool deep, + const std::optional& dst_stem_in, const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + repair_report rep; + rep.scan = scan_log(stem, deep, progress); + + EOS_ASSERT(!rep.scan.pruned || rep.scan.intact(), chain::plugin_exception, + "${stem}.log is pruned and damaged; the format cannot locate entries on the far side of a hole, so it " + "cannot be repaired", ("stem", stem.string())); + + if(rep.scan.intact()) { + if(!rep.scan.valid_ranges.empty()) { + rep.first_block = rep.scan.valid_ranges.front().first_block; + rep.last_block = rep.scan.valid_ranges.front().last_block; + } + rep.bytes_kept = rep.scan.file_size; + //the scan says nothing about the index; judge it cheaply first and verify slot-by-slot only + // when the cheap checks pass. The full check (and a rebuild, if needed) each forward-walk the + // log again, so a healthy bundle is walked twice and a same-size-but-wrong index thrice; that + // redundancy is accepted because repair is an offline, infrequent operation + index_status st = check_index(stem, false); + if(st == index_status::ok) + st = check_index(stem, true, progress); + if(st != index_status::ok) { + rep.index_rebuilt = true; + if(!dry_run) { + build_index(stem, progress); + rep.acted = true; + } + } + return rep; + } + + EOS_ASSERT(!rep.scan.valid_ranges.empty(), chain::plugin_exception, "${stem}.log contains no salvageable entries", + ("stem", stem.string())); + + if(mode == repair_mode::truncate) { + EOS_ASSERT(!dst_stem_in, chain::plugin_exception, "an output location only applies to keep-tail repairs"); + const entry_range& r = rep.scan.valid_ranges.front(); + EOS_ASSERT(r.begin_pos == 0, chain::plugin_exception, + "${stem}.log is damaged from its very start so there is no valid prefix to keep; consider a keep-tail " + "repair", ("stem", stem.string())); + rep.first_block = r.first_block; + rep.last_block = r.last_block; + rep.bytes_kept = r.end_pos; + rep.bytes_discarded = rep.scan.file_size - r.end_pos; + rep.index_rebuilt = true; + if(!dry_run) { + { + fc::random_access_file log(log_path_of(stem)); + log.resize(r.end_pos); + } + build_index(stem, progress); + rep.acted = true; + } + return rep; + } + + //keep-tail: salvage the last valid range into a fresh bundle + const entry_range& r = rep.scan.valid_ranges.back(); + rep.first_block = r.canonical_first_block; + rep.last_block = r.last_block; + rep.bytes_kept = r.end_pos - r.canonical_begin_pos; + rep.bytes_discarded = rep.scan.file_size - rep.bytes_kept; + rep.index_rebuilt = true; + if(dry_run) + return rep; + + std::filesystem::path dst_stem; + if(dst_stem_in) { + dst_stem = normalize_stem(*dst_stem_in); + } else { + dst_stem = stem; + dst_stem += std::string(tmp_suffix); + remove_bundle(dst_stem); + } + const auto [got_first, got_last] = + extract_byte_range(stem, r.canonical_begin_pos, r.end_pos, dst_stem, progress); + EOS_ASSERT(got_first == rep.first_block && got_last == rep.last_block, chain::plugin_exception, + "salvaged range ${gf}-${gl} does not match the scan's ${fb}-${lb}", + ("gf", got_first)("gl", got_last)("fb", rep.first_block)("lb", rep.last_block)); + if(!dst_stem_in) { + //as in trim_front, the two renames are not atomic as a pair; a crash between them leaves a + // wrong-sized index that state_history_log regenerates on next open, so the bundle self-heals + std::filesystem::rename(log_path_of(dst_stem), log_path_of(stem)); + std::filesystem::rename(index_path_of(dst_stem), index_path_of(stem)); + } + rep.acted = true; + return rep; +} + +log_summary summarize_log(const std::filesystem::path& stem_in) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + + log_summary s; + s.log_size = log.size(); + + const endpoints e = probe_endpoints(log, s.log_size); + s.valid_first_header = e.valid_first; + s.version = e.version; + s.pruned = e.pruned; + s.pruned_block_count = e.pruned_count; + s.first_block = e.first_block; + s.tail_ok = e.tail_ok; + s.last_block = e.last_block; + if(e.valid_first) + s.first_block_id = e.first_id; + if(e.tail_ok) + s.last_block_id = e.last_id; + + const std::filesystem::path ip = index_path_of(stem); + if(std::filesystem::exists(ip)) + s.index_size = std::filesystem::file_size(ip); + + if(s.log_size == 0) + s.index = (!std::filesystem::exists(ip) || s.index_size == 0) ? index_status::ok : index_status::wrong_size; + else if(!e.valid_first || !e.tail_ok) + s.index = index_status::log_damaged; + else if(!std::filesystem::exists(ip)) + s.index = index_status::missing; + else if(s.index_size != (uint64_t(e.last_block) - e.first_block + 1) * sizeof(uint64_t)) + s.index = index_status::wrong_size; + else { + fc::random_access_file index(ip, fc::random_access_file::read_only); + s.index = index.unpack_from(s.index_size - sizeof(uint64_t)) == e.last_entry_pos + ? index_status::ok + : index_status::mismatched; + } + return s; +} + +std::optional find_block_id(const std::filesystem::path& stem_in, uint32_t block_num, + const progress_func& progress) { + const std::filesystem::path stem = normalize_stem(stem_in); + fc::random_access_file log = open_log_readonly(stem); + const uint64_t size = log.size(); + if(size == 0) + return std::nullopt; + + const endpoints e = probe_endpoints(log, size); + EOS_ASSERT(e.valid_first && e.tail_ok, chain::plugin_exception, + "${stem}.log is damaged; run smoke-test to map the damage or repair it first", ("stem", stem.string())); + + uint32_t first_servable = e.first_block; + if(e.pruned) { + EOS_ASSERT(*e.pruned_count > 0 && *e.pruned_count <= e.last_block, chain::plugin_exception, + "pruned log ${stem}.log has an implausible trailing block count ${pc}", + ("stem", stem.string())("pc", *e.pruned_count)); + first_servable = e.last_block - *e.pruned_count + 1; + } + if(block_num < first_servable || block_num > e.last_block) + return std::nullopt; + + //index fast path: the same shallow validation state_history_log applies on open, plus a check + // that the slot's entry really holds the requested block; any disagreement falls through to + // walking the log so a stale index cannot misattribute an id + const std::filesystem::path ip = index_path_of(stem); + const uint64_t expected_size = (uint64_t(e.last_block) - e.first_block + 1) * sizeof(uint64_t); + if(std::filesystem::exists(ip) && std::filesystem::file_size(ip) == expected_size) { + fc::random_access_file index(ip, fc::random_access_file::read_only); + if(index.unpack_from(expected_size - sizeof(uint64_t)) == e.last_entry_pos) { + const uint64_t pos = index.unpack_from((uint64_t(block_num) - e.first_block) * sizeof(uint64_t)); + if(slot_holds_block(log, size, pos, block_num)) + return log.unpack_from(pos).block_id; + } + } + + //fallback: the on-disk index was missing or untrusted, so walk the log to recompute the slot. A + // computed slot can still be zero for a block the log fails to retain inside its servable range (a + // missing or duplicated entry in a damaged retained chain); validate that it points at the requested + // block before trusting it, exactly as the fast path above does, so a bad slot reports damage rather + // than unpacking offset 0's stub header and returning the wrong block's id. + const computed_index ci = e.pruned ? compute_index_pruned(log, size, e, stem, progress) + : compute_index_forward(log, size, stem, progress); + const uint64_t pos = ci.slots[uint64_t(block_num) - ci.index_first]; + EOS_ASSERT(slot_holds_block(log, size, pos, block_num), chain::plugin_exception, + "${stem}.log is damaged: block ${bn} is within its servable ${fs}-${lb} range but has no valid entry", + ("stem", stem.string())("bn", block_num)("fs", first_servable)("lb", e.last_block)); + return log.unpack_from(pos).block_id; +} + +} // namespace eosio::state_history::log_utils diff --git a/plugins/state_history_plugin/state_history_plugin.cpp b/plugins/state_history_plugin/state_history_plugin.cpp index 3893ba76b4..ab326da7e4 100644 --- a/plugins/state_history_plugin/state_history_plugin.cpp +++ b/plugins/state_history_plugin/state_history_plugin.cpp @@ -250,6 +250,14 @@ void state_history_plugin::set_program_options(options_description& cli, options "the path (relative to data-dir) to create a unix socket upon which to listen for incoming connections."); options("trace-history-debug-mode", bpo::bool_switch()->default_value(false), "enable debug mode for trace history"); options("state-history-log-retain-blocks", bpo::value(), "if set, periodically prune the state history files to store only configured number of most recent blocks"); + options("state-history-force-write", bpo::bool_switch()->default_value(false), + "EMERGENCY RECOVERY option: never let damaged or inconsistent state history logs prevent the node from " + "running. A log that fails its startup checks or cannot accept the next block is moved aside (kept on disk, " + "never deleted) and writing continues into a fresh log. This keeps the node up at the cost of completeness. " + "Blocks held only in the set-aside logs, plus any the node skips while recovering, will be missing from " + "the state history this node serves until those logs are repaired and merged back. Without this option such " + "conditions are fatal. The spring-util ship-log utility can inspect, repair, and trim the logs this sets " + "aside (and merge them once renamed off the -corrupt- suffix)."); } void state_history_plugin_impl::plugin_initialize(const variables_map& options) { @@ -328,12 +336,18 @@ void state_history_plugin_impl::plugin_initialize(const variables_map& options) config.max_retained_files = options.at("max-retained-history-files").as(); } + const bool force_write = options.at("state-history-force-write").as(); + if(force_write) + wlog("state-history-force-write is set (emergency recovery): state history logs that fail their checks will " + "be moved aside rather than stopping the node; the served state history may be incomplete for the " + "affected blocks until those logs are repaired and merged back"); + if(options.at("trace-history").as()) - trace_log.emplace(state_history_dir, ship_log_conf, "trace_history", [this](chain::block_num_type bn) {return get_block_id(bn);}); + trace_log.emplace(state_history_dir, ship_log_conf, "trace_history", [this](chain::block_num_type bn) {return get_block_id(bn);}, force_write); if(options.at("chain-state-history").as()) - chain_state_log.emplace(state_history_dir, ship_log_conf, "chain_state_history", [this](chain::block_num_type bn) {return get_block_id(bn);}); + chain_state_log.emplace(state_history_dir, ship_log_conf, "chain_state_history", [this](chain::block_num_type bn) {return get_block_id(bn);}, force_write); if(options.at("finality-data-history").as()) - finality_data_log.emplace(state_history_dir, ship_log_conf, "finality_data_history", [this](chain::block_num_type bn) {return get_block_id(bn);}); + finality_data_log.emplace(state_history_dir, ship_log_conf, "finality_data_history", [this](chain::block_num_type bn) {return get_block_id(bn);}, force_write); } FC_LOG_AND_RETHROW() } // state_history_plugin::plugin_initialize diff --git a/programs/spring-util/CMakeLists.txt b/programs/spring-util/CMakeLists.txt index 503af0b662..fa52162808 100644 --- a/programs/spring-util/CMakeLists.txt +++ b/programs/spring-util/CMakeLists.txt @@ -1,4 +1,4 @@ -add_executable( ${SPRING_UTIL_EXECUTABLE_NAME} main.cpp actions/subcommand.cpp actions/generic.cpp actions/blocklog.cpp actions/bls.cpp actions/snapshot.cpp actions/chain.cpp) +add_executable( ${SPRING_UTIL_EXECUTABLE_NAME} main.cpp actions/subcommand.cpp actions/generic.cpp actions/blocklog.cpp actions/shiplog.cpp actions/bls.cpp actions/snapshot.cpp actions/chain.cpp) if( UNIX AND NOT APPLE ) set(rt_library rt ) @@ -8,7 +8,7 @@ target_include_directories(${SPRING_UTIL_EXECUTABLE_NAME} PUBLIC ${CMAKE_CURRENT target_link_libraries( ${SPRING_UTIL_EXECUTABLE_NAME} PRIVATE appbase version - PRIVATE eosio_chain chain_plugin fc spring-cli11 producer_plugin ${CMAKE_DL_LIBS} ${PLATFORM_SPECIFIC_LIBS} ) + PRIVATE eosio_chain chain_plugin fc spring-cli11 producer_plugin state_history ${CMAKE_DL_LIBS} ${PLATFORM_SPECIFIC_LIBS} ) copy_bin( ${SPRING_UTIL_EXECUTABLE_NAME} ) install( TARGETS diff --git a/programs/spring-util/actions/blocklog.cpp b/programs/spring-util/actions/blocklog.cpp index c3175c5109..d0f6607c7d 100644 --- a/programs/spring-util/actions/blocklog.cpp +++ b/programs/spring-util/actions/blocklog.cpp @@ -77,9 +77,11 @@ void blocklog_actions::setup(CLI::App& app) { {"block_log", print_from_t::block_log}, {"fork_db", print_from_t::fork_db } }; + //add_option, not add_flag: a flag only accepts its value in --print-from= form, silently + // rejecting the conventional "--print-from " spelling print_log - ->add_flag("--print-from", opt->print_from, - "Whether to print blocks from the block log, fork database, or both. Default is both.") + ->add_option("--print-from", opt->print_from, + "Whether to print blocks from the block log, fork database, or both. Default is both.") ->transform(CLI::CheckedTransformer(print_from_map, CLI::ignore_case)); // subcommand - make index diff --git a/programs/spring-util/actions/shiplog.cpp b/programs/spring-util/actions/shiplog.cpp new file mode 100644 index 0000000000..533602c4a5 --- /dev/null +++ b/programs/spring-util/actions/shiplog.cpp @@ -0,0 +1,397 @@ +#include "shiplog.hpp" + +#include +#include + +#include + + +#include +#include + +using namespace eosio::chain; +namespace log_utils = eosio::state_history::log_utils; + +namespace { + +/// rate-limited progress reporting to the log so multi-minute scans/copies are visibly alive +void report_progress(uint64_t done, uint64_t total) { + ilog("processed ${done} of ${total} bytes (${pct}%)", + ("done", done)("total", total)("pct", total ? done * 100 / total : 100)); +} + +/// one line per valid/damaged region of a scan, in file order +void print_scan(const log_utils::scan_result& scan) { + std::cout << " entries scanned: " << scan.entries_scanned; + if(scan.payloads_validated) + std::cout << ", payloads validated: " << scan.payloads_validated; + std::cout << "\n"; + + //interleave the two range lists by file offset so the report reads start-to-end + size_t vi = 0, di = 0; + while(vi < scan.valid_ranges.size() || di < scan.damaged_ranges.size()) { + const bool take_valid = + vi < scan.valid_ranges.size() && + (di >= scan.damaged_ranges.size() || scan.valid_ranges[vi].begin_pos < scan.damaged_ranges[di].begin_pos); + if(take_valid) { + const log_utils::entry_range& r = scan.valid_ranges[vi++]; + std::cout << " valid: blocks " << r.first_block << "-" << r.last_block << " (" << r.entry_count + << " entries, bytes " << r.begin_pos << "-" << r.end_pos << ")"; + if(r.canonical_first_block != r.first_block) + std::cout << " [salvageable from block " << r.canonical_first_block << "]"; + std::cout << "\n"; + } else { + const log_utils::damaged_range& d = scan.damaged_ranges[di++]; + std::cout << " DAMAGED: bytes " << d.begin_pos << "-" << d.end_pos << ": " << d.reason << "\n"; + } + } +} + +} // namespace + +void shiplog_actions::setup(CLI::App& app) { + // callback helper with error code handling + auto err_guard = [this](int (shiplog_actions::*fun)()) { + try { + initialize(); + int rc = (this->*fun)(); + if(rc) + throw(CLI::RuntimeError(rc)); + } catch(CLI::RuntimeError&) { + throw; + } catch(...) { + print_exception(); + throw(CLI::RuntimeError(-1)); + } + }; + + // main command + auto* sub = app.add_subcommand("ship-log", "State history (SHiP) log utility"); + sub->require_subcommand(); + sub->fallthrough(); + + // fallthrough options + sub->add_option("--state-history-dir", opt->state_history_dir, + "The location of the state-history directory (absolute path or relative to the current directory)."); + sub->add_option("--log", opt->log_name, + "Which log to operate on: trace_history, chain_state_history, finality_data_history, or a path to " + "any .log / retained --.log bundle."); + + // subcommand - info + sub->add_subcommand("info", "Report each log's version, block range, endpoint block ids, size, and index health by " + "examining only its endpoints (fast; does not detect damage in the middle of the " + "file). Without --log, every *.log in the state-history directory is reported.") + ->callback([err_guard]() { err_guard(&shiplog_actions::info); }); + + // subcommand - block-id + auto* bid = sub->add_subcommand("block-id", "Print the block id each log records for a given block number (the " + "canonical entry when a fork switch wrote several). The index is used " + "only after verification, so a stale index cannot misattribute an id. " + "Use when nodeos reports 'missed a fork change': compare what the log " + "recorded against the block log or another node to see which history " + "the log holds. Without --log, every *.log in the directory is " + "queried. Exits 0 when at least one log records the block.") + ->callback([err_guard]() { err_guard(&shiplog_actions::block_id); }); + bid->add_option("--block,-b", opt->block_num, "The block number to look up.")->required(); + + // subcommand - smoke-test + auto* smoke = sub->add_subcommand("smoke-test", "Validate every entry of the log (headers, position trailers, " + "block continuity) and the index, mapping any damaged regions. " + "Read-only. Without --log, every *.log in the directory is tested.") + ->callback([err_guard]() { err_guard(&shiplog_actions::smoke_test); }); + smoke->add_flag("--deep", opt->deep, + "Additionally decompress every entry's payload to detect bit-rot the structural checks cannot see."); + + // subcommand - make-index + sub->add_subcommand("make-index", "Rebuild .index from .log, replacing any existing index. Requires --log.") + ->callback([err_guard]() { err_guard(&shiplog_actions::make_index); }); + + // subcommand - trim + auto* trim = sub->add_subcommand("trim", "Trim the log so it spans only blocks [first, last]. Requires --log and " + "at least one of --first/--last. Trimming the front rewrites the log and " + "needs free disk space roughly equal to the kept portion.") + ->callback([err_guard]() { err_guard(&shiplog_actions::trim); }); + trim->add_option("--first,-f", opt->first_block, "The first block number to keep."); + trim->add_option("--last,-l", opt->last_block, "The last block number to keep."); + + // subcommand - extract-blocks + auto* extract = sub->add_subcommand("extract-blocks", "Copy blocks [first, last] of the log into a fresh bundle " + "in --output-dir, leaving the source untouched. Requires " + "--log.") + ->callback([err_guard]() { err_guard(&shiplog_actions::extract); }); + extract->add_option("--first,-f", opt->first_block, "The first block number to extract.")->required(); + extract->add_option("--last,-l", opt->last_block, "The last block number to extract.")->required(); + extract->add_option("--output-dir", opt->output_dir, "The output directory for the extracted bundle.")->required(); + + // subcommand - repair + auto* repair = sub->add_subcommand("repair", "Repair a damaged log: scan it, then truncate at the first damage " + "(default, like nodeos's automatic recovery) and rebuild the index. " + "An intact log with a bad or missing index just gets the index " + "rebuilt. Requires --log.") + ->callback([err_guard]() { err_guard(&shiplog_actions::repair); }); + repair->add_flag("--keep-tail", opt->keep_tail, + "Salvage the last valid range instead of the first: keeps recent history when the damage is early " + "in the file, discarding everything before it."); + repair->add_flag("--dry-run", opt->dry_run, "Report the damage map and what would be done without writing anything."); + repair->add_flag("--deep", opt->deep, + "Scan payload content too (see smoke-test --deep); entries with rotten payloads count as damage."); + repair->add_option("--output-dir", opt->output_dir, + "For --keep-tail: write the salvaged bundle here instead of replacing the original."); + + // subcommand - vacuum + sub->add_subcommand("vacuum", "Convert a pruned log into an un-pruned log. Requires --log.") + ->callback([err_guard]() { err_guard(&shiplog_actions::do_vacuum); }); + + // subcommand - split + auto* split = sub->add_subcommand("split", "Split the log into retained-style -- bundles of " + "--stride blocks (boundaries at block numbers divisible by the stride, " + "exactly like state-history-stride rotation) plus a head bundle with " + "the remainder, all written to --output-dir. Requires --log.") + ->callback([err_guard]() { err_guard(&shiplog_actions::split); }); + split->add_option("--stride", opt->stride, "The number of blocks per split bundle.")->required(); + split->add_option("--output-dir", opt->output_dir, "The output directory for the split bundles.")->required(); + + // subcommand - merge + auto* merge = sub->add_subcommand("merge", "Merge every contiguous -- retained bundle found " + "directly under --state-history-dir into a single .log/.index " + "bundle in --output-dir (point --state-history-dir at the 'retained' " + "subdirectory if that is where the bundles live). Sources are left " + "unchanged. Requires --log with a plain log name.") + ->callback([err_guard]() { err_guard(&shiplog_actions::merge); }); + merge->add_option("--output-dir", opt->output_dir, "The output directory for the merged bundle.")->required(); +} + +void shiplog_actions::initialize() { + std::filesystem::path dir = opt->state_history_dir; + if(dir.is_relative()) + opt->state_history_dir = (std::filesystem::current_path() / dir).string(); + + if(!opt->output_dir.empty()) { + std::filesystem::path od = opt->output_dir; + if(od.is_relative()) + opt->output_dir = (std::filesystem::current_path() / od).string(); + } +} + +std::filesystem::path shiplog_actions::resolve_stem() const { + EOS_ASSERT(!opt->log_name.empty(), plugin_exception, + "--log is required: one of trace_history, chain_state_history, finality_data_history, or a path to a " + "log bundle"); + std::filesystem::path p(opt->log_name); + if(p.is_relative() && !p.has_parent_path()) + p = std::filesystem::path(opt->state_history_dir) / p; + else if(p.is_relative()) + p = std::filesystem::current_path() / p; + return log_utils::normalize_stem(p); +} + +std::vector shiplog_actions::resolve_stems() const { + if(!opt->log_name.empty()) + return {resolve_stem()}; + + const std::filesystem::path dir(opt->state_history_dir); + EOS_ASSERT(std::filesystem::is_directory(dir), plugin_exception, "${dir} is not a directory", ("dir", dir.string())); + std::vector stems; + for(const std::filesystem::directory_entry& de : std::filesystem::directory_iterator(dir)) + if(de.is_regular_file() && de.path().extension() == ".log") + stems.push_back(log_utils::normalize_stem(de.path())); + std::sort(stems.begin(), stems.end()); + EOS_ASSERT(!stems.empty(), plugin_exception, "no *.log files found in ${dir}", ("dir", dir.string())); + return stems; +} + +int shiplog_actions::info() { + for(const std::filesystem::path& stem : resolve_stems()) { + const log_utils::log_summary s = log_utils::summarize_log(stem); + std::cout << stem.string() << ".log:\n"; + std::cout << " size: " << s.log_size << " bytes\n"; + if(s.log_size == 0) { + std::cout << " empty log\n"; + } else if(!s.valid_first_header) { + std::cout << " NOT A SHIP LOG (or first header is damaged)\n"; + } else { + std::cout << " version: " << s.version << (s.pruned ? " (pruned" : ""); + if(s.pruned) + std::cout << ", " << *s.pruned_block_count << " blocks retained)"; + std::cout << "\n"; + if(s.tail_ok) + std::cout << " blocks: " << (s.pruned ? s.last_block - *s.pruned_block_count + 1 : s.first_block) << "-" + << s.last_block << "\n"; + else + std::cout << " blocks: starts at " << s.first_block << ", tail is DAMAGED (run smoke-test or repair)\n"; + //a pruned log's first id belongs to its pre-prune first block, hence the explicit block numbers + if(s.first_block_id) + std::cout << " first: " << s.first_block_id->str() << " (block " << s.first_block << ")\n"; + if(s.last_block_id) + std::cout << " last: " << s.last_block_id->str() << " (block " << s.last_block << ")\n"; + } + std::cout << " index: " << log_utils::to_string(s.index); + if(s.index_size) + std::cout << " (" << s.index_size << " bytes)"; + std::cout << "\n"; + } + return 0; +} + +int shiplog_actions::block_id() { + bool found = false; + for(const std::filesystem::path& stem : resolve_stems()) { + std::cout << stem.string() << ".log:\n"; + try { + if(const std::optional id = log_utils::find_block_id(stem, opt->block_num, report_progress)) { + std::cout << " block " << opt->block_num << ": " << id->str() << "\n"; + found = true; + } else { + const log_utils::log_summary s = log_utils::summarize_log(stem); + if(s.log_size == 0) + std::cout << " block " << opt->block_num << " not present (log is empty)\n"; + else + std::cout << " block " << opt->block_num << " not present (log spans blocks " + << (s.pruned ? s.last_block - *s.pruned_block_count + 1 : s.first_block) << "-" + << s.last_block << ")\n"; + } + } catch(const fc::exception& e) { + //a damaged log must not end a directory-wide query; report it and keep going + std::cout << " ERROR: " << e.top_message() << "\n"; + } + } + return found ? 0 : 1; +} + +int shiplog_actions::smoke_test() { + int rc = 0; + for(const std::filesystem::path& stem : resolve_stems()) { + std::cout << stem.string() << ".log:\n"; + const log_utils::scan_result scan = log_utils::scan_log(stem, opt->deep, report_progress); + print_scan(scan); + + log_utils::index_status index = log_utils::index_status::log_damaged; + if(scan.intact()) + index = log_utils::check_index(stem, true, report_progress); + std::cout << " index: " << log_utils::to_string(index) << "\n"; + + if(scan.intact() && index == log_utils::index_status::ok) { + std::cout << " result: OK\n"; + } else { + std::cout << " result: PROBLEMS FOUND\n"; + rc = 1; + } + } + return rc; +} + +int shiplog_actions::make_index() { + const std::filesystem::path stem = resolve_stem(); + const auto [first, last] = log_utils::build_index(stem, report_progress); + if(first == 0 && last == 0) + std::cout << "wrote empty " << stem.string() << ".index for empty log\n"; + else + std::cout << "wrote " << stem.string() << ".index covering blocks " << first << "-" << last << "\n"; + return 0; +} + +int shiplog_actions::trim() { + const std::filesystem::path stem = resolve_stem(); + //the option defaults double as "not supplied" sentinels: block 0 and UINT32_MAX are never valid + // ship block numbers, so this can never be confused with a real --first/--last the user passed + const bool has_first = opt->first_block != 0; + const bool has_last = opt->last_block != std::numeric_limits::max(); + EOS_ASSERT(has_first || has_last, plugin_exception, "trim requires --first and/or --last"); + EOS_ASSERT(opt->first_block <= opt->last_block, plugin_exception, + "--first ${f} must not be greater than --last ${l}", ("f", opt->first_block)("l", opt->last_block)); + + //trim the end first: it is a cheap in-place truncation and shrinks the copy a front trim makes + if(has_last) { + const uint64_t removed = log_utils::truncate_log(stem, opt->last_block, report_progress); + std::cout << "trimmed " << removed << " bytes off the end of " << stem.string() << ".log\n"; + } + if(has_first) { + const uint64_t removed = log_utils::trim_front(stem, opt->first_block, report_progress); + std::cout << "trimmed " << removed << " bytes off the front of " << stem.string() << ".log\n"; + } + + const log_utils::log_summary s = log_utils::summarize_log(stem); + std::cout << stem.string() << ".log now spans blocks " << s.first_block << "-" << s.last_block << "\n"; + return 0; +} + +int shiplog_actions::extract() { + const std::filesystem::path stem = resolve_stem(); + std::filesystem::create_directories(opt->output_dir); + const std::filesystem::path dst = std::filesystem::path(opt->output_dir) / stem.filename(); + const uint64_t bytes = log_utils::extract_blocks(stem, dst, opt->first_block, opt->last_block, report_progress); + std::cout << "wrote " << dst.string() << ".log covering blocks " << opt->first_block << "-" << opt->last_block + << " (" << bytes << " bytes)\n"; + return 0; +} + +int shiplog_actions::repair() { + const std::filesystem::path stem = resolve_stem(); + EOS_ASSERT(opt->output_dir.empty() || opt->keep_tail, plugin_exception, + "--output-dir only applies to --keep-tail repairs"); + + std::optional dst; + if(!opt->output_dir.empty()) { + if(!opt->dry_run) + std::filesystem::create_directories(opt->output_dir); + dst = std::filesystem::path(opt->output_dir) / stem.filename(); + } + + const log_utils::repair_report rep = + log_utils::repair_log(stem, opt->keep_tail ? log_utils::repair_mode::keep_tail : log_utils::repair_mode::truncate, + opt->dry_run, opt->deep, dst, report_progress); + + std::cout << stem.string() << ".log:\n"; + print_scan(rep.scan); + + if(rep.scan.intact() && !rep.index_rebuilt) { + std::cout << " log and index are healthy; nothing to do\n"; + return 0; + } + const char* tense = rep.acted ? "" : " (dry run, nothing written)"; + if(rep.scan.intact()) { + std::cout << " log is healthy; index " << (rep.acted ? "was rebuilt" : "would be rebuilt") << tense << "\n"; + } else { + std::cout << " kept blocks " << rep.first_block << "-" << rep.last_block << ": " << rep.bytes_kept + << " bytes kept, " << rep.bytes_discarded << " bytes discarded" << tense << "\n"; + if(dst && rep.acted) + std::cout << " salvaged bundle written to " << dst->string() << ".log (original untouched)\n"; + } + return 0; +} + +int shiplog_actions::do_vacuum() { + const std::filesystem::path stem = resolve_stem(); + const log_utils::log_summary s = log_utils::summarize_log(stem); + EOS_ASSERT(s.valid_first_header && s.tail_ok, plugin_exception, + "${stem}.log is damaged; vacuum requires an intact pruned log", ("stem", stem.string())); + if(!s.pruned) { + std::cout << stem.string() << ".log is not pruned; nothing to do\n"; + return 0; + } + //opening a pruned log without a prune config vacuums it (and validates/regenerates the index) + eosio::state_history::state_history_log log(stem); + const auto [first, last] = log.block_range(); + std::cout << "vacuumed " << stem.string() << ".log; it now spans blocks " << first << "-" << last - 1 << "\n"; + return 0; +} + +int shiplog_actions::split() { + const std::filesystem::path stem = resolve_stem(); + const std::vector created = + log_utils::split_log(stem, opt->output_dir, opt->stride, report_progress); + for(const std::filesystem::path& c : created) + std::cout << "wrote " << c.string() << ".log\n"; + std::cout << "(the last bundle is the head log; the others are retained bundles)\n"; + return 0; +} + +int shiplog_actions::merge() { + EOS_ASSERT(!opt->log_name.empty() && !std::filesystem::path(opt->log_name).has_parent_path(), + plugin_exception, "merge requires --log with a plain log name, e.g. trace_history"); + const auto [first, last] = + log_utils::merge_logs(opt->state_history_dir, opt->log_name, opt->output_dir, report_progress); + std::cout << "wrote " << (std::filesystem::path(opt->output_dir) / opt->log_name).string() << ".log covering blocks " + << first << "-" << last << "\n"; + return 0; +} diff --git a/programs/spring-util/actions/shiplog.hpp b/programs/spring-util/actions/shiplog.hpp new file mode 100644 index 0000000000..993314f7c6 --- /dev/null +++ b/programs/spring-util/actions/shiplog.hpp @@ -0,0 +1,56 @@ +#include "subcommand.hpp" + +#include +#include +#include +#include +#include + +/// CLI options shared by the ship-log subcommands. +struct shiplog_options { + std::string state_history_dir = "state-history"; + std::string log_name; ///< --log: a well-known stem (trace_history, ...) or a path to a bundle + //these two double as "not supplied" sentinels for trim (see trim()); block 0 and UINT32_MAX are + // never valid ship block numbers, so a user can never collide with them + uint32_t first_block = 0; + uint32_t last_block = std::numeric_limits::max(); + uint32_t block_num = 0; ///< --block: the block a block-id lookup asks about + std::string output_dir; + uint32_t stride = 0; + + // flags + bool deep = false; + bool dry_run = false; + bool keep_tail = false; +}; + +/** + * spring-util `ship-log` subcommand family: offline inspection and repair of state history (SHiP) + * log bundles, built on eosio::state_history::log_utils. Mirrors the structure of the `block-log` + * subcommands. + */ +class shiplog_actions : public sub_command { +public: + shiplog_actions() : sub_command() {} + void setup(CLI::App& app); + +protected: + /// normalize option paths (relative -> absolute) before any subcommand runs + void initialize(); + + /// resolve --log (required) to a bundle stem; accepts a name in the state-history dir or a path + std::filesystem::path resolve_stem() const; + /// resolve --log to one stem, or, when --log was not given, every *.log bundle in the directory + std::vector resolve_stems() const; + + int info(); + int block_id(); + int smoke_test(); + int make_index(); + int trim(); + int extract(); + int repair(); + int do_vacuum(); ///< named to mirror blocklog_actions::do_vacuum (see class doc) + int split(); + int merge(); +}; diff --git a/programs/spring-util/main.cpp b/programs/spring-util/main.cpp index e02c39362d..37d52268a5 100644 --- a/programs/spring-util/main.cpp +++ b/programs/spring-util/main.cpp @@ -9,6 +9,7 @@ #include "actions/bls.hpp" #include "actions/chain.hpp" #include "actions/generic.hpp" +#include "actions/shiplog.hpp" #include "actions/snapshot.hpp" #include @@ -34,6 +35,10 @@ int main(int argc, char** argv) { auto blocklog_subcommand = std::make_shared(); blocklog_subcommand->setup(app); + // ship-log sc tree + auto shiplog_subcommand = std::make_shared(); + shiplog_subcommand->setup(app); + // bls sc tree auto bls_subcommand = std::make_shared(); bls_subcommand->setup(app); diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 60f58f0eb5..0f6d467dc0 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -59,6 +59,7 @@ configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_producer_watermark_test.py ${C configure_file(${CMAKE_CURRENT_SOURCE_DIR}/cli_test.py ${CMAKE_CURRENT_BINARY_DIR}/cli_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_reqs_across_svnn_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_reqs_across_svnn_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_restart_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_restart_test.py COPYONLY) +configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_log_util_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_log_util_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_streamer_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_streamer_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/ship_kill_client_test.py ${CMAKE_CURRENT_BINARY_DIR}/ship_kill_client_test.py COPYONLY) @@ -157,6 +158,7 @@ add_np_test(NAME production_restart COMMAND tests/production_restart.py -v ${UNS add_np_test(NAME ship_reqs_across_svnn_test COMMAND tests/ship_reqs_across_svnn_test.py -v ${UNSHARE}) add_np_test(NAME ship_restart_test COMMAND tests/ship_restart_test.py -v ${UNSHARE}) +add_np_test(NAME ship_log_util_test COMMAND tests/ship_log_util_test.py -v ${UNSHARE}) add_np_test(NAME ship_test COMMAND tests/ship_test.py -v --num-clients 10 --num-requests 5000 ${UNSHARE}) add_np_test(NAME ship_test_unix COMMAND tests/ship_test.py -v --num-clients 10 --num-requests 5000 ${UNSHARE} --unix-socket) add_np_test(NAME ship_if_test COMMAND tests/ship_test.py -v --activate-if --num-clients 10 --num-requests 5000 ${UNSHARE}) diff --git a/tests/ship_log_util_test.py b/tests/ship_log_util_test.py new file mode 100755 index 0000000000..0a249bdba2 --- /dev/null +++ b/tests/ship_log_util_test.py @@ -0,0 +1,325 @@ +#!/usr/bin/env python3 + +import os +import re +import shutil +import signal +import subprocess +import tempfile +import time + +from TestHarness import Cluster, TestHelper, Utils, WalletMgr + +############################################################################### +# ship_log_util_test +# +# Exercises the "spring-util ship-log" utilities against state history logs +# produced by a real nodeos: info, smoke-test (--deep), make-index, repair +# (truncate and --keep-tail), trim, extract-blocks, split, and merge. Also +# verifies nodeos's state-history-force-write option regenerates a lying +# index and moves an unusable log aside rather than refusing to run. +# +############################################################################### + +Print = Utils.Print + +args = TestHelper.parse_args({"--dump-error-details", "--keep-logs", "-v", "--leave-running", "--unshared"}) + +Utils.Debug = args.v +cluster = Cluster(unshared=args.unshared, keepRunning=args.leave_running, keepLogs=args.keep_logs) +dumpErrorDetails = args.dump_error_details +walletPort = TestHelper.DEFAULT_WALLET_PORT + +totalProducerNodes = 1 +totalNonProducerNodes = 1 # for SHiP node +totalNodes = totalProducerNodes + totalNonProducerNodes + +walletMgr = WalletMgr(True, port=walletPort) +testSuccessful = False + +prodNodeId = 0 +shipNodeId = 1 + +shipStride = 50 + +tmpDir = None + + +def shipLogUtil(subcommand, *extraArgs, expectSuccess=True): + """Run "spring-util ship-log " and return (returncode, stdout+stderr).""" + cmd = [Utils.SpringClientPath, "ship-log", subcommand] + [str(a) for a in extraArgs] + if Utils.Debug: + Utils.Print("cmd: %s" % (" ".join(cmd))) + result = subprocess.run(cmd, capture_output=True, text=True) + output = result.stdout + result.stderr + if expectSuccess: + assert result.returncode == 0, f"'{' '.join(cmd)}' failed ({result.returncode}):\n{output}" + else: + assert result.returncode != 0, f"'{' '.join(cmd)}' unexpectedly succeeded:\n{output}" + return result.returncode, output + + +def parseInfoBlocks(infoOutput, logPath): + """Extract the (first, last) block range the info subcommand reported for logPath.""" + stem = re.escape(os.path.splitext(logPath)[0]) + m = re.search(stem + r"\.log:.*?blocks:\s+(\d+)-(\d+)", infoOutput, re.DOTALL) + assert m, f"no block range for {logPath} in:\n{infoOutput}" + return int(m.group(1)), int(m.group(2)) + + +def logRange(stemDir, logName): + """Return the (first, last) block range of one bundle via the info subcommand.""" + _, out = shipLogUtil("info", "--state-history-dir", stemDir, "--log", logName) + return parseInfoBlocks(out, os.path.join(stemDir, logName + ".log")) + + +def readIndexSlot(indexPath, slot): + """Return the log position stored for the given zero-based slot of an index file.""" + with open(indexPath, "rb") as f: + f.seek(slot * 8) + return int.from_bytes(f.read(8), "little") + + +def copyBundle(srcStem, dstStem): + shutil.copyfile(srcStem + ".log", dstStem + ".log") + shutil.copyfile(srcStem + ".index", dstStem + ".index") + + +try: + TestHelper.printSystemInfo("BEGIN") + + cluster.setWalletMgr(walletMgr) + Print("Stand up cluster") + + specificExtraNodeosArgs = { + prodNodeId: "--plugin eosio::producer_api_plugin", + shipNodeId: "--plugin eosio::state_history_plugin --trace-history --chain-state-history " + f"--finality-data-history --state-history-stride {shipStride} " + "--plugin eosio::net_api_plugin --plugin eosio::producer_api_plugin", + } + + if cluster.launch(topo="mesh", pnodes=totalProducerNodes, totalNodes=totalNodes, + activateIF=True, specificExtraNodeosArgs=specificExtraNodeosArgs) is False: + Utils.cmdError("launcher") + Utils.errorExit("Failed to stand up cluster.") + + cluster.waitOnClusterSync(blockAdvancing=5) + Print("Cluster in Sync") + + Print("Shutdown unneeded bios node") + cluster.biosNode.kill(signal.SIGTERM) + + prodNode = cluster.getNode(prodNodeId) + shipNode = cluster.getNode(shipNodeId) + + # run past at least one stride boundary so a retained bundle exists + assert Utils.waitForBool(lambda: prodNode.getHeadBlockNum() > shipStride + 10, timeout=300), \ + f"chain did not reach block {shipStride + 10}" + + Print("Pause producer and stop both nodes") + prodNode.processUrllibRequest("producer", "pause", exitOnError=True) + # pause can return while one more block is mid-production; wait for the head to settle so the + # ids captured below cover every block the ship logs can end on + headBlock = prodNode.getHeadBlockNum() + for _ in range(60): + time.sleep(1) + newHead = prodNode.getHeadBlockNum() + if newHead == headBlock: + break + headBlock = newHead + else: + Utils.errorExit(f"producer head did not settle after pause (still advancing at {headBlock})") + shipNode.waitForBlock(headBlock) + + # capture chain block ids while the node is still up; the offline block-id checks below compare + # what the ship logs recorded against these + chainIds = {n: shipNode.getBlock(n)["id"] for n in range(max(2, headBlock - 3), headBlock + 1)} + retainedProbeBlock = shipStride // 2 + retainedProbeId = shipNode.getBlock(retainedProbeBlock)["id"] + + prodNode.kill(signal.SIGTERM) + shipNode.kill(signal.SIGTERM) + + shipDir = os.path.join(Utils.getNodeDataDir(shipNodeId), "state-history") + retainedDir = os.path.join(shipDir, "retained") + chainStateLog = os.path.join(shipDir, "chain_state_history.log") + chainStateIndex = os.path.join(shipDir, "chain_state_history.index") + traceIndex = os.path.join(shipDir, "trace_history.index") + + tmpDir = tempfile.mkdtemp() + origChainStateLog = os.path.join(tmpDir, "chain_state_history.log") + origChainStateIndex = os.path.join(tmpDir, "chain_state_history.index") + origTraceIndex = os.path.join(tmpDir, "trace_history.index") + + Print("Save pristine SHiP files") + shutil.copyfile(chainStateLog, origChainStateLog) + shutil.copyfile(chainStateIndex, origChainStateIndex) + shutil.copyfile(traceIndex, origTraceIndex) + + # -------- info + deep smoke-test on everything nodeos wrote + Print("info and deep smoke-test on pristine logs") + _, infoOut = shipLogUtil("info", "--state-history-dir", shipDir) + headFirst, headLast = parseInfoBlocks(infoOut, chainStateLog) + assert headLast >= headBlock - 1, f"chain_state log head {headLast} too far behind chain head {headBlock}" + shipLogUtil("smoke-test", "--state-history-dir", shipDir, "--deep") + + retained = sorted(f for f in os.listdir(retainedDir) if re.match(r"chain_state_history-\d+-\d+\.log$", f)) + assert retained, f"expected retained bundles in {retainedDir}" + shipLogUtil("smoke-test", "--log", os.path.join(retainedDir, retained[0]), "--deep") + + # -------- block-id reports the ids the logs actually recorded + Print("block-id matches the chain") + assert headLast in chainIds, \ + f"chain_state head log ends at {headLast}, outside the captured ids {sorted(chainIds)}" + _, bidOut = shipLogUtil("block-id", "--state-history-dir", shipDir, "--block", headLast) + assert bidOut.count(chainIds[headLast]) == 3, \ + f"expected all three head logs to record {chainIds[headLast]} for block {headLast}:\n{bidOut}" + _, bidOut = shipLogUtil("block-id", "--log", os.path.join(retainedDir, retained[0]), + "--block", retainedProbeBlock) + assert retainedProbeId in bidOut, \ + f"retained bundle did not record {retainedProbeId} for block {retainedProbeBlock}:\n{bidOut}" + # block 1 predates every ship log; the lookup reports not-present and exits non-zero + shipLogUtil("block-id", "--state-history-dir", shipDir, "--block", 1, expectSuccess=False) + + # -------- make-index reproduces the index nodeos wrote, byte for byte + Print("make-index byte-equality test") + os.remove(traceIndex) + shipLogUtil("make-index", "--state-history-dir", shipDir, "--log", "trace_history") + assert Utils.compareFiles(traceIndex, origTraceIndex, mode="rb"), "rebuilt trace index differs from nodeos's" + + # -------- repair a torn tail write (the classic crash case) + Print("repair truncated-tail test") + with open(chainStateLog, "ab") as f: + f.write(b"\x5a" * 137) # partial entry torn mid-write + shipLogUtil("smoke-test", "--state-history-dir", shipDir, "--log", "chain_state_history", expectSuccess=False) + # block-id must report the damage and exit non-zero, never crash, on a log the chain can no longer + # open cleanly: returncode > 0 is a normal "damaged" exit; a negative returncode would be a signal + # (segfault/abort), which is exactly the operator-facing failure this tooling exists to prevent + rc, bidOut = shipLogUtil("block-id", "--state-history-dir", shipDir, "--log", "chain_state_history", + "--block", headLast, expectSuccess=False) + assert rc > 0, f"block-id crashed (signal {-rc}) on a damaged log instead of reporting it:\n{bidOut}" + assert "damaged" in bidOut.lower(), f"block-id did not report the damage on a corrupt log:\n{bidOut}" + shipLogUtil("repair", "--state-history-dir", shipDir, "--log", "chain_state_history") + assert Utils.compareFiles(chainStateLog, origChainStateLog, mode="rb"), "repair did not restore the exact log" + assert Utils.compareFiles(chainStateIndex, origChainStateIndex, mode="rb"), "repair did not rebuild the index" + + Print("SHiP node relaunches on the repaired log") + assert shipNode.relaunch(), "Failed to relaunch shipNode after repair" + shipNode.kill(signal.SIGTERM) + + # -------- merge the retained bundles into one wide-range bundle for the remaining scenarios + Print("merge retained bundles") + mergeDir = os.path.join(tmpDir, "merged") + shipLogUtil("merge", "--state-history-dir", retainedDir, "--log", "chain_state_history", + "--output-dir", mergeDir) + mergedStem = os.path.join(mergeDir, "chain_state_history") + mergedFirst, mergedLast = logRange(mergeDir, "chain_state_history") + assert mergedLast - mergedFirst >= shipStride - 5, f"merged range {mergedFirst}-{mergedLast} suspiciously narrow" + shipLogUtil("smoke-test", "--state-history-dir", mergeDir, "--deep") + + # -------- trim a copy of the merged bundle down to a subrange + Print("trim test") + workDir = os.path.join(tmpDir, "work") + os.makedirs(workDir) + workStem = os.path.join(workDir, "chain_state_history") + copyBundle(mergedStem, workStem) + trimFirst, trimLast = mergedFirst + 10, mergedLast - 10 + shipLogUtil("trim", "--state-history-dir", workDir, "--log", "chain_state_history", + "--first", trimFirst, "--last", trimLast) + assert logRange(workDir, "chain_state_history") == (trimFirst, trimLast), "trim produced the wrong range" + shipLogUtil("smoke-test", "--state-history-dir", workDir) + + # -------- extract a slice without touching the source + Print("extract-blocks test") + extractDir = os.path.join(tmpDir, "extracted") + shipLogUtil("extract-blocks", "--state-history-dir", mergeDir, "--log", "chain_state_history", + "--first", mergedFirst + 5, "--last", mergedFirst + 15, "--output-dir", extractDir) + assert logRange(extractDir, "chain_state_history") == (mergedFirst + 5, mergedFirst + 15) + shipLogUtil("smoke-test", "--state-history-dir", extractDir, "--deep") + assert logRange(mergeDir, "chain_state_history") == (mergedFirst, mergedLast), "extract modified its source" + + # -------- keep-tail repair of mid-file damage + Print("repair --keep-tail mid-file damage test") + shutil.rmtree(workDir) + os.makedirs(workDir) + copyBundle(mergedStem, workStem) + midBlock = (mergedFirst + mergedLast) // 2 + midPos = readIndexSlot(workStem + ".index", midBlock - mergedFirst) + with open(workStem + ".log", "rb+") as f: + f.seek(midPos) + f.write(b"\x5a" * 16) # destroy the mid entry's header + # a dry run reports without touching anything + _, dryOut = shipLogUtil("repair", "--state-history-dir", workDir, "--log", "chain_state_history", + "--keep-tail", "--dry-run") + assert "DAMAGED" in dryOut, f"dry run did not report damage:\n{dryOut}" + shipLogUtil("smoke-test", "--state-history-dir", workDir, "--log", "chain_state_history", expectSuccess=False) + shipLogUtil("repair", "--state-history-dir", workDir, "--log", "chain_state_history", "--keep-tail") + assert logRange(workDir, "chain_state_history") == (midBlock + 1, mergedLast), "keep-tail kept the wrong range" + shipLogUtil("smoke-test", "--state-history-dir", workDir) + + # -------- split the merged bundle and merge it back + Print("split and merge round-trip test") + splitDir = os.path.join(tmpDir, "split") + shipLogUtil("split", "--state-history-dir", mergeDir, "--log", "chain_state_history", + "--stride", "20", "--output-dir", splitDir) + splitBundles = sorted(f for f in os.listdir(splitDir) if f.endswith(".log")) + assert len(splitBundles) >= 2, f"expected several split bundles, got {splitBundles}" + shipLogUtil("smoke-test", "--state-history-dir", splitDir) + + remergeDir = os.path.join(tmpDir, "remerged") + shipLogUtil("merge", "--state-history-dir", splitDir, "--log", "chain_state_history", + "--output-dir", remergeDir) + remergedFirst, remergedLast = logRange(remergeDir, "chain_state_history") + assert remergedFirst == mergedFirst, f"re-merged range starts at {remergedFirst}, expected {mergedFirst}" + shipLogUtil("smoke-test", "--state-history-dir", remergeDir, "--deep") + + # -------- state-history-force-write: an index that lies is regenerated instead of fatal + Print("state-history-force-write index-disagreement test") + with open(chainStateIndex, "rb+") as f: + f.seek(-8, 2) + f.write(b"\x00\x01\x02\x03\x04\x05\x06\x07") + + assert not shipNode.relaunch(), "SHiP node should refuse to start with a lying index" + assert shipNode.relaunch(chainArg="--state-history-force-write"), \ + "SHiP node should start with state-history-force-write" + shipNode.kill(signal.SIGTERM) + assert Utils.compareFiles(chainStateIndex, origChainStateIndex, mode="rb"), \ + "force-write should have regenerated the index" + assert not [f for f in os.listdir(shipDir) if "-corrupt-" in f], \ + "an index disagreement must not orphan the log" + + # -------- state-history-force-write: a log that cannot accept the next block is moved aside + Print("state-history-force-write head-gap test") + # replace the chain_state head log with one ending far behind the chain's head and clear its + # retained bundles; the next block nodeos writes is then a gap the log cannot represent + gapLast = mergedFirst + 20 + gapDir = os.path.join(tmpDir, "gap") + os.makedirs(gapDir) + copyBundle(mergedStem, os.path.join(gapDir, "chain_state_history")) + shipLogUtil("trim", "--state-history-dir", gapDir, "--log", "chain_state_history", "--last", gapLast) + copyBundle(os.path.join(gapDir, "chain_state_history"), os.path.join(shipDir, "chain_state_history")) + for f in os.listdir(retainedDir): + if f.startswith("chain_state_history-"): + os.remove(os.path.join(retainedDir, f)) + + assert prodNode.relaunch(chainArg="--enable-stale-production"), "Failed to relaunch prodNode" + # relaunch(chainArg=...) is sticky: the force-write flag from the previous relaunch is still on + # the command line, and passing it again would duplicate the switch + assert shipNode.relaunch(), "SHiP node should start with state-history-force-write" + assert shipNode.waitForHeadToAdvance(), "Head did not advance on shipNode" + + def orphanAppeared(): + return bool([f for f in os.listdir(shipDir) if re.match(r"chain_state_history-corrupt-\d+\.log$", f)]) + assert Utils.waitForBool(orphanAppeared, timeout=60), "force-write did not move the gapped log aside" + + orphanFirst, orphanLast = logRange(shipDir, "chain_state_history-corrupt-1") + assert orphanLast == gapLast, f"orphan should hold the gapped log ending at {gapLast}, ends at {orphanLast}" + + testSuccessful = True +finally: + TestHelper.shutdown(cluster, walletMgr, testSuccessful=testSuccessful, dumpErrorDetails=dumpErrorDetails) + if tmpDir is not None: + shutil.rmtree(tmpDir, ignore_errors=True) + +errorCode = 0 if testSuccessful else 1 +exit(errorCode) diff --git a/tests/ship_log_utils.cpp b/tests/ship_log_utils.cpp new file mode 100644 index 0000000000..7a5e1531b9 --- /dev/null +++ b/tests/ship_log_utils.cpp @@ -0,0 +1,1010 @@ +#include + +#include +#include + +#include +#include +#include + +#include +#include + +#include + +namespace bio = boost::iostreams; +using namespace eosio; +using namespace eosio::chain; +namespace log_utils = eosio::state_history::log_utils; + +namespace { + +/** + * Writes real ship logs through log_catalog (the same code path nodeos uses) while remembering + * every block's payload, then hands the closed files to the log_utils functions under test. + */ +struct utils_fixture { + explicit utils_fixture(std::optional prune_blocks = std::nullopt) { + if(prune_blocks) + conf = eosio::state_history::prune_config{.prune_blocks = *prune_blocks, .prune_threshold = 8}; + open(); + } + + static block_id_type id_for(uint32_t block_num, char fill) { + fc::sha256 id = fc::sha256::hash(std::to_string(block_num) + fill); + id._hash[0] = fc::endian_reverse_u32(block_num); + return id; + } + + /// append one block whose payload is `size` copies of `fill`; prev_fill names the parent's variant + void add(uint32_t block_num, char fill, char prev_fill, size_t size = 192) { + std::vector payload(size, fill); + log->pack_and_write_entry(id_for(block_num, fill), id_for(block_num - 1, prev_fill), + [&](auto& f) { bio::write(f, payload.data(), payload.size()); }); + if(written.size() < block_num + 1) + written.resize(block_num + 1); + written[block_num] = std::move(payload); + } + + /// append blocks [first, last] all with the same fill lineage + void add_range(uint32_t first, uint32_t last, char fill, char prev_fill, size_t size = 192) { + for(uint32_t b = first; b <= last; ++b) + add(b, fill, b == first ? prev_fill : fill, size); + } + + void close() { log.reset(); } + void open(bool force_write = false) { + log.emplace(dir.path(), conf, name, eosio::state_history::state_history_log::no_non_local_get_block_id_func, + force_write); + } + + std::filesystem::path stem() const { return dir.path() / name; } + std::filesystem::path log_path() const { return dir.path() / (name + ".log"); } + std::filesystem::path index_path() const { return dir.path() / (name + ".index"); } + + /// entry position of a block, read straight from the on-disk index (for surgical corruption) + uint64_t index_slot(uint32_t block_num, uint32_t index_first_block) const { + std::ifstream in(index_path(), std::ios::binary); + in.seekg((uint64_t(block_num) - index_first_block) * sizeof(uint64_t)); + uint64_t pos = 0; + in.read(reinterpret_cast(&pos), sizeof(pos)); + BOOST_REQUIRE(in.good()); + return pos; + } + + /// rewrite the block id recorded by the header at log offset `pos`, leaving the entry otherwise + /// structurally intact (magic, payload, and position trailer untouched) so it still passes every + /// check_entry test except the block-number range — used to forge an out-of-range block number + void set_block_id_at(uint64_t pos, const block_id_type& id) { + std::fstream f(log_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp(pos + sizeof(uint64_t)); //past the 8-byte magic, onto block_id + f.write(id.data(), id.data_size()); + BOOST_REQUIRE(f.good()); + } + + /// overwrite `len` bytes of the log at `pos` with bytes that can never look like a ship header + void clobber(uint64_t pos, size_t len) { + std::fstream f(log_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp(pos); + const std::vector junk(len, '\x5a'); + f.write(junk.data(), junk.size()); + BOOST_REQUIRE(f.good()); + } + + void append_garbage(size_t len) { + std::ofstream f(log_path(), std::ios::binary | std::ios::app); + const std::vector junk(len, '\x5a'); + f.write(junk.data(), junk.size()); + BOOST_REQUIRE(f.good()); + } + + /// verify (through the real library) that the bundle serves exactly [first, last] with the written payloads + void check_serves(uint32_t first, uint32_t last) { + eosio::state_history::log_catalog reopened(dir.path(), conf, name); + const auto [begin, end] = reopened.block_range(); + BOOST_REQUIRE_EQUAL(begin, first); + BOOST_REQUIRE_EQUAL(end, last + 1); + for(uint32_t b = first; b <= last; ++b) { + std::optional entry = reopened.get_entry(b); + BOOST_REQUIRE_MESSAGE(!!entry, "block " + std::to_string(b) + " missing"); + bio::filtering_istreambuf stream = entry->get_stream(); + std::vector got; + bio::copy(stream, bio::back_inserter(got)); + BOOST_REQUIRE_MESSAGE(got == written.at(b), "block " + std::to_string(b) + " content mismatch"); + } + } + + static std::vector slurp(const std::filesystem::path& p) { + std::ifstream in(p, std::ios::binary); + std::vector bytes((std::istreambuf_iterator(in)), std::istreambuf_iterator()); + return bytes; + } + + std::string name = "shipit"; + eosio::state_history::state_history_log_config conf; + fc::temp_directory dir; + std::optional log; + std::vector> written; +}; + +} // namespace + +BOOST_AUTO_TEST_SUITE(ship_log_utils_tests) + +BOOST_AUTO_TEST_CASE(scan_intact_and_summary) { try { + utils_fixture t; + t.add_range(2, 50, 'A', 'A'); + t.close(); + + const log_utils::scan_result scan = log_utils::scan_log(t.stem(), true); + BOOST_REQUIRE(scan.intact()); + BOOST_REQUIRE(!scan.pruned); + BOOST_REQUIRE_EQUAL(scan.valid_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].first_block, 2u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].last_block, 50u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].canonical_first_block, 2u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].entry_count, 49u); + BOOST_REQUIRE_EQUAL(scan.entries_scanned, 49u); + BOOST_REQUIRE_EQUAL(scan.payloads_validated, 49u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].end_pos, scan.file_size); + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.valid_first_header); + BOOST_REQUIRE(s.tail_ok); + BOOST_REQUIRE(!s.pruned); + BOOST_REQUIRE_EQUAL(s.first_block, 2u); + BOOST_REQUIRE_EQUAL(s.last_block, 50u); + BOOST_REQUIRE(s.index == log_utils::index_status::ok); + + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(empty_log) { try { + utils_fixture t; + t.close(); + + BOOST_REQUIRE(log_utils::scan_log(t.stem(), true).intact()); + BOOST_REQUIRE(log_utils::summarize_log(t.stem()).index == log_utils::index_status::ok); + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); + const auto [first, last] = log_utils::build_index(t.stem()); + BOOST_REQUIRE_EQUAL(first, 0u); + BOOST_REQUIRE_EQUAL(last, 0u); + + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, true); + BOOST_REQUIRE(!rep.acted); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(make_index_matches_library_including_forks) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + //fork: rewrite 8..10, then continue + t.add(8, 'B', 'A'); + t.add_range(9, 12, 'B', 'B'); + //fork again right at the end so stale entries trail the final head + t.add(11, 'C', 'B'); + t.close(); + + const std::vector library_index = utils_fixture::slurp(t.index_path()); + BOOST_REQUIRE(!library_index.empty()); + + std::filesystem::remove(t.index_path()); + const auto [first, last] = log_utils::build_index(t.stem()); + BOOST_REQUIRE_EQUAL(first, 2u); + BOOST_REQUIRE_EQUAL(last, 11u); + + const std::vector rebuilt_index = utils_fixture::slurp(t.index_path()); + BOOST_REQUIRE(library_index == rebuilt_index); + + t.check_serves(2, 11); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(index_status_detection) { try { + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + + BOOST_REQUIRE(log_utils::check_index(t.stem(), false) == log_utils::index_status::ok); + + //wrong size: lop 8 bytes off + const std::vector good = utils_fixture::slurp(t.index_path()); + std::filesystem::resize_file(t.index_path(), good.size() - sizeof(uint64_t)); + BOOST_REQUIRE(log_utils::check_index(t.stem(), false) == log_utils::index_status::wrong_size); + BOOST_REQUIRE(log_utils::summarize_log(t.stem()).index == log_utils::index_status::wrong_size); + + //missing + std::filesystem::remove(t.index_path()); + BOOST_REQUIRE(log_utils::check_index(t.stem(), false) == log_utils::index_status::missing); + + //right size but an interior slot lies: only the full check sees it + { + std::ofstream out(t.index_path(), std::ios::binary); + out.write(good.data(), good.size()); + } + { + std::fstream f(t.index_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp(5 * sizeof(uint64_t)); + const uint64_t lie = 1; + f.write(reinterpret_cast(&lie), sizeof(lie)); + } + BOOST_REQUIRE(log_utils::check_index(t.stem(), false) == log_utils::index_status::ok); + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::mismatched); + + //repair fixes it + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE(rep.index_rebuilt); + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); + t.check_serves(2, 30); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(find_block_id_and_endpoint_ids) { try { + utils_fixture t; + t.add_range(2, 40, 'A', 'A'); + //fork: rewrite 30..32 so those heights have canonical 'B' entries with stale 'A' entries lingering + t.add(30, 'B', 'A'); + t.add_range(31, 32, 'B', 'B'); + t.close(); + + //the summary reports the ids recorded at the endpoints + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.first_block_id && *s.first_block_id == utils_fixture::id_for(2, 'A')); + BOOST_REQUIRE(s.last_block_id && *s.last_block_id == utils_fixture::id_for(32, 'B')); + + //index fast path, including the canonical (latest-written) answer for fork-overwritten heights + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 2) == utils_fixture::id_for(2, 'A')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 29) == utils_fixture::id_for(29, 'A')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 30) == utils_fixture::id_for(30, 'B')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 32) == utils_fixture::id_for(32, 'B')); + + //out of range: before the first block, and past the head even though stale 'A' entries for + // 33..40 physically remain in the file + BOOST_REQUIRE(!log_utils::find_block_id(t.stem(), 1)); + BOOST_REQUIRE(!log_utils::find_block_id(t.stem(), 33)); + + //no index at all: the read-only walk gives the same answers + std::filesystem::remove(t.index_path()); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 2) == utils_fixture::id_for(2, 'A')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 30) == utils_fixture::id_for(30, 'B')); + BOOST_REQUIRE(!std::filesystem::exists(t.index_path())); //and it really was read-only +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(find_block_id_distrusts_bad_index) { try { + utils_fixture t; + t.add_range(2, 25, 'A', 'A'); + t.close(); + + //point block 10's slot at block 11's entry: the index keeps its expected size and its final + // slot, so the shallow open-time checks (and a naive lookup) would happily trust it + const uint64_t pos11 = t.index_slot(11, 2); + { + std::fstream f(t.index_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp((10 - 2) * sizeof(uint64_t)); + f.write(reinterpret_cast(&pos11), sizeof(pos11)); + BOOST_REQUIRE(f.good()); + } + //the poisoned slot is detected and the answer comes from walking the log instead + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 10) == utils_fixture::id_for(10, 'A')); + //unpoisoned slots still resolve (fast path) + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 11) == utils_fixture::id_for(11, 'A')); + + //a final slot that disagrees with the log fails the shallow check; everything walks + { + std::fstream f(t.index_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp((25 - 2) * sizeof(uint64_t)); + const uint64_t junk = 1; + f.write(reinterpret_cast(&junk), sizeof(junk)); + BOOST_REQUIRE(f.good()); + } + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 25) == utils_fixture::id_for(25, 'A')); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(find_block_id_pruned) { try { + utils_fixture t(4 /*prune_blocks*/); + const size_t entry_size = 4096 + 2048; //large enough that hole punching actually frees blocks + t.add_range(2, 20, 'A', 'A', entry_size); + t.close(); + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.pruned && s.tail_ok); + //a pruned log's first header is the stub for its pre-prune first block; the id is still real + BOOST_REQUIRE(s.first_block_id && *s.first_block_id == utils_fixture::id_for(2, 'A')); + BOOST_REQUIRE(s.last_block_id && *s.last_block_id == utils_fixture::id_for(20, 'A')); + + const uint32_t first_servable = s.last_block - *s.pruned_block_count + 1; + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 20) == utils_fixture::id_for(20, 'A')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), first_servable) == utils_fixture::id_for(first_servable, 'A')); + BOOST_REQUIRE(!log_utils::find_block_id(t.stem(), first_servable - 1)); //pruned away + BOOST_REQUIRE(!log_utils::find_block_id(t.stem(), 21)); + + //the backward trailer-chain walk handles pruned logs when the index is gone + std::filesystem::remove(t.index_path()); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 20) == utils_fixture::id_for(20, 'A')); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(fork_mismatch_messages_carry_ids) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + + //rewind path: the expected id, the recorded id, and the recorded id's own block number must all be + // reported, so a corrupt index (which resolves to some unrelated block's entry) is tellable from a + // genuine fork without further digging + BOOST_CHECK_EXCEPTION(t.add(8, 'X', 'Z'), plugin_exception, [](const plugin_exception& e) { + const std::string d = e.to_detail_string(); + return d.find("missed a fork change") != std::string::npos && + d.find(utils_fixture::id_for(7, 'Z').str()) != std::string::npos && //what the incoming block expected + d.find(utils_fixture::id_for(7, 'A').str()) != std::string::npos && //what the log recorded + d.find("an id for block 7") != std::string::npos; + }); + + //append path: same information, sourced from the in-memory last_block_id + BOOST_CHECK_EXCEPTION(t.add(11, 'X', 'Z'), plugin_exception, [](const plugin_exception& e) { + const std::string d = e.to_detail_string(); + return d.find("missed a fork change") != std::string::npos && + d.find(utils_fixture::id_for(10, 'Z').str()) != std::string::npos && + d.find(utils_fixture::id_for(10, 'A').str()) != std::string::npos && + d.find("block 10") != std::string::npos; + }); + + //neither failed write may disturb the log + t.close(); + t.check_serves(2, 10); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(find_block_id_empty_and_damaged) { try { + utils_fixture empty; + empty.close(); + BOOST_REQUIRE(!log_utils::find_block_id(empty.stem(), 1)); + BOOST_REQUIRE(!log_utils::summarize_log(empty.stem()).first_block_id); + BOOST_REQUIRE(!log_utils::summarize_log(empty.stem()).last_block_id); + + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + t.close(); + t.append_garbage(33); //torn tail + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.first_block_id && !s.last_block_id); + BOOST_CHECK_EXCEPTION(log_utils::find_block_id(t.stem(), 5), plugin_exception, [](const plugin_exception& e) { + return e.to_detail_string().find("damaged") != std::string::npos; + }); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(repair_truncated_tail) { try { + utils_fixture t; + t.add_range(2, 40, 'A', 'A'); + t.close(); + + const uint64_t good_size = std::filesystem::file_size(t.log_path()); + t.append_garbage(100); //simulates a torn write at shutdown + + log_utils::scan_result scan = log_utils::scan_log(t.stem(), false); + BOOST_REQUIRE(!scan.intact()); + BOOST_REQUIRE_EQUAL(scan.valid_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(scan.damaged_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(scan.damaged_ranges[0].begin_pos, good_size); + + //dry run changes nothing + const log_utils::repair_report dry = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, true, false); + BOOST_REQUIRE(!dry.acted); + BOOST_REQUIRE_EQUAL(std::filesystem::file_size(t.log_path()), good_size + 100); + + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 2u); + BOOST_REQUIRE_EQUAL(rep.last_block, 40u); + BOOST_REQUIRE_EQUAL(std::filesystem::file_size(t.log_path()), good_size); + t.check_serves(2, 40); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(repair_mid_file_damage_truncate_and_keep_tail) { try { + utils_fixture t; + t.add_range(2, 60, 'A', 'A'); + t.close(); + + //clobber the header of block 30's entry: everything from there is structurally unreachable + // until the scanner resynchronizes at block 31's entry + const uint64_t pos30 = t.index_slot(30, 2); + const uint64_t pos31 = t.index_slot(31, 2); + t.clobber(pos30, 16); + + const log_utils::scan_result scan = log_utils::scan_log(t.stem(), false); + BOOST_REQUIRE(!scan.intact()); + BOOST_REQUIRE_EQUAL(scan.valid_ranges.size(), 2u); + BOOST_REQUIRE_EQUAL(scan.damaged_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].first_block, 2u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].last_block, 29u); + BOOST_REQUIRE_EQUAL(scan.damaged_ranges[0].begin_pos, pos30); + BOOST_REQUIRE_EQUAL(scan.damaged_ranges[0].end_pos, pos31); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[1].first_block, 31u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[1].last_block, 60u); + + //keep-tail to a separate output leaves the original untouched + { + fc::temp_directory out_dir; + const std::filesystem::path out_stem = out_dir.path() / "salvaged"; + const log_utils::repair_report rep = + log_utils::repair_log(t.stem(), log_utils::repair_mode::keep_tail, false, false, out_stem); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 31u); + BOOST_REQUIRE_EQUAL(rep.last_block, 60u); + + utils_fixture::slurp(out_stem.string() + ".log"); //exists and is readable + eosio::state_history::state_history_log salvaged(out_stem); + const auto [begin, end] = salvaged.block_range(); + BOOST_REQUIRE_EQUAL(begin, 31u); + BOOST_REQUIRE_EQUAL(end, 61u); + } + + //truncate repair keeps the prefix + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 2u); + BOOST_REQUIRE_EQUAL(rep.last_block, 29u); + t.check_serves(2, 29); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(repair_keep_tail_in_place) { try { + utils_fixture t; + t.add_range(2, 50, 'A', 'A'); + t.close(); + + t.clobber(t.index_slot(10, 2), 16); + + const log_utils::repair_report rep = + log_utils::repair_log(t.stem(), log_utils::repair_mode::keep_tail, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 11u); + BOOST_REQUIRE_EQUAL(rep.last_block, 50u); + t.check_serves(11, 50); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(repair_damaged_from_start) { try { + utils_fixture t; + t.add_range(2, 20, 'A', 'A'); + t.close(); + + t.clobber(0, 16); //first header gone + + const log_utils::scan_result scan = log_utils::scan_log(t.stem(), false); + BOOST_REQUIRE(!scan.intact()); + BOOST_REQUIRE(!scan.valid_ranges.empty()); + BOOST_REQUIRE(scan.valid_ranges[0].begin_pos > 0); + + //nothing before the damage, so a truncate repair has nothing to keep + BOOST_REQUIRE_THROW(log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false), + plugin_exception); + + const log_utils::repair_report rep = + log_utils::repair_log(t.stem(), log_utils::repair_mode::keep_tail, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 3u); + BOOST_REQUIRE_EQUAL(rep.last_block, 20u); + t.check_serves(3, 20); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(deep_scan_catches_payload_bitflip) { try { + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + + //flip one byte inside block 15's compressed payload: structure stays perfectly valid + const uint64_t pos15 = t.index_slot(15, 2); + t.clobber(pos15 + 70, 1); //48-byte header + 12-byte preamble + a few bytes into the zlib stream + + BOOST_REQUIRE(log_utils::scan_log(t.stem(), false).intact()); + + const log_utils::scan_result deep = log_utils::scan_log(t.stem(), true); + BOOST_REQUIRE(!deep.intact()); + BOOST_REQUIRE_EQUAL(deep.damaged_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(deep.damaged_ranges[0].begin_pos, pos15); + BOOST_REQUIRE_EQUAL(deep.valid_ranges.size(), 2u); + BOOST_REQUIRE_EQUAL(deep.valid_ranges[0].last_block, 14u); + BOOST_REQUIRE_EQUAL(deep.valid_ranges[1].first_block, 16u); + + //a plain repair sees nothing wrong; a deep repair truncates at the rotten entry + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, true); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.last_block, 14u); + t.check_serves(2, 14); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(keep_tail_canonical_start_with_forks) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + //fork: rewrite 8..10 with different content + t.add(8, 'B', 'A'); + t.add(9, 'B', 'B'); + t.add(10, 'B', 'B'); + t.close(); + + //destroy block 7's entry; the tail range then starts at the STALE block-8 entry, and a salvaged + // bundle must instead begin at the fork's rewritten block 8 + const uint64_t stale8 = [&]() { + //the stale entry for 8 sits right after block 7's entry; find 7's start from the index and + // walk one entry forward using its header + const uint64_t pos7 = t.index_slot(7, 2); + std::ifstream in(t.log_path(), std::ios::binary); + in.seekg(pos7 + 40); //past magic + block_id to payload_size + uint64_t psz = 0; + in.read(reinterpret_cast(&psz), sizeof(psz)); + return pos7 + 48 + psz + 8; + }(); + t.clobber(t.index_slot(7, 2), 16); + + const log_utils::scan_result scan = log_utils::scan_log(t.stem(), false); + BOOST_REQUIRE(!scan.intact()); + const log_utils::entry_range& tail = scan.valid_ranges.back(); + BOOST_REQUIRE_EQUAL(tail.begin_pos, stale8); //resynchronized at the stale fork entry + BOOST_REQUIRE_EQUAL(tail.first_block, 8u); + BOOST_REQUIRE_EQUAL(tail.canonical_first_block, 8u); + BOOST_REQUIRE_GT(tail.canonical_begin_pos, stale8); //canonical start is the rewritten 8, later in the file + + const log_utils::repair_report rep = + log_utils::repair_log(t.stem(), log_utils::repair_mode::keep_tail, false, false); + BOOST_REQUIRE(rep.acted); + BOOST_REQUIRE_EQUAL(rep.first_block, 8u); + BOOST_REQUIRE_EQUAL(rep.last_block, 10u); + t.check_serves(8, 10); //written[] holds the fork's 'B' payloads, so this proves the new content survived +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(trim_end_and_front) { try { + utils_fixture t; + t.add_range(2, 60, 'A', 'A'); + t.close(); + + const uint64_t end_removed = log_utils::truncate_log(t.stem(), 50); + BOOST_REQUIRE_GT(end_removed, 0u); + BOOST_REQUIRE_EQUAL(log_utils::truncate_log(t.stem(), 50), 0u); //no-op at the boundary + + const uint64_t front_removed = log_utils::trim_front(t.stem(), 10); + BOOST_REQUIRE_GT(front_removed, 0u); + BOOST_REQUIRE_EQUAL(log_utils::trim_front(t.stem(), 10), 0u); + + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); + t.check_serves(10, 50); + + BOOST_REQUIRE_THROW(log_utils::truncate_log(t.stem(), 9), plugin_exception); //outside range + BOOST_REQUIRE_THROW(log_utils::trim_front(t.stem(), 51), plugin_exception); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(trim_front_without_index) { try { + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + + std::filesystem::remove(t.index_path()); //forces the in-memory forward-walk fallback + const uint64_t removed = log_utils::trim_front(t.stem(), 12); + BOOST_REQUIRE_GT(removed, 0u); + t.check_serves(12, 30); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(extract_blocks_basic) { try { + utils_fixture t; + t.add_range(2, 40, 'A', 'A'); + t.close(); + + fc::temp_directory out_dir; + const std::filesystem::path out_stem = out_dir.path() / "slice"; + const uint64_t bytes = log_utils::extract_blocks(t.stem(), out_stem, 10, 20); + BOOST_REQUIRE_GT(bytes, 0u); + + eosio::state_history::state_history_log slice(out_stem); + const auto [begin, end] = slice.block_range(); + BOOST_REQUIRE_EQUAL(begin, 10u); + BOOST_REQUIRE_EQUAL(end, 21u); + + //source untouched + t.check_serves(2, 40); + + //destination collision refused + BOOST_REQUIRE_THROW(log_utils::extract_blocks(t.stem(), out_stem, 10, 20), plugin_exception); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(split_then_serve_through_catalog_then_merge) { try { + utils_fixture t; + t.add_range(2, 25, 'A', 'A'); + t.close(); + + fc::temp_directory split_dir; + const std::vector created = log_utils::split_log(t.stem(), split_dir.path(), 10); + //blocks 2-25 with stride 10 -> retained 2-10, 11-20, and head 21-25 + BOOST_REQUIRE_EQUAL(created.size(), 3u); + BOOST_REQUIRE_EQUAL(created[0].filename().string(), "shipit-2-10"); + BOOST_REQUIRE_EQUAL(created[1].filename().string(), "shipit-11-20"); + BOOST_REQUIRE_EQUAL(created[2].filename().string(), "shipit"); + + //the real consumer check: a log_catalog with a partition config must serve every block from the split set + { + eosio::state_history::state_history_log_config split_conf = + eosio::state_history::partition_config{.retained_dir = split_dir.path(), .archive_dir = "", .stride = 10}; + eosio::state_history::log_catalog catalog(split_dir.path(), split_conf, t.name); + const auto [begin, end] = catalog.block_range(); + BOOST_REQUIRE_EQUAL(begin, 2u); + BOOST_REQUIRE_EQUAL(end, 26u); + for(uint32_t b = 2; b <= 25; ++b) { + std::optional entry = catalog.get_entry(b); + BOOST_REQUIRE(!!entry); + bio::filtering_istreambuf stream = entry->get_stream(); + std::vector got; + bio::copy(stream, bio::back_inserter(got)); + BOOST_REQUIRE(got == t.written.at(b)); + } + } + + //merge the retained bundles back into one log + fc::temp_directory merge_dir; + const auto [first, last] = log_utils::merge_logs(split_dir.path(), t.name, merge_dir.path()); + BOOST_REQUIRE_EQUAL(first, 2u); + BOOST_REQUIRE_EQUAL(last, 20u); + eosio::state_history::state_history_log merged(merge_dir.path() / t.name); + const auto [mbegin, mend] = merged.block_range(); + BOOST_REQUIRE_EQUAL(mbegin, 2u); + BOOST_REQUIRE_EQUAL(mend, 21u); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(split_exact_boundary_leaves_empty_head) { try { + utils_fixture t; + t.add_range(2, 20, 'A', 'A'); + t.close(); + + fc::temp_directory split_dir; + const std::vector created = log_utils::split_log(t.stem(), split_dir.path(), 10); + BOOST_REQUIRE_EQUAL(created.size(), 3u); + BOOST_REQUIRE_EQUAL(created.back().filename().string(), "shipit"); + BOOST_REQUIRE_EQUAL(std::filesystem::file_size(created.back().string() + ".log"), 0u); + + //merge refuses nothing here: both retained bundles are contiguous + fc::temp_directory merge_dir; + const auto [first, last] = log_utils::merge_logs(split_dir.path(), t.name, merge_dir.path()); + BOOST_REQUIRE_EQUAL(first, 2u); + BOOST_REQUIRE_EQUAL(last, 20u); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(merge_refuses_gaps) { try { + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + + fc::temp_directory split_dir; + log_utils::split_log(t.stem(), split_dir.path(), 10); + //remove the middle bundle to create a hole + std::filesystem::remove(split_dir.path() / "shipit-11-20.log"); + std::filesystem::remove(split_dir.path() / "shipit-11-20.index"); + + fc::temp_directory merge_dir; + BOOST_REQUIRE_THROW(log_utils::merge_logs(split_dir.path(), t.name, merge_dir.path()), plugin_exception); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(pruned_log_scan_index_and_refusals) { try { + utils_fixture t(4 /*prune_blocks*/); + const size_t entry_size = 4096 + 2048; //large enough that hole punching actually frees blocks + t.add_range(2, 20, 'A', 'A', entry_size); + t.close(); + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.pruned); + BOOST_REQUIRE(s.tail_ok); + + const log_utils::scan_result scan = log_utils::scan_log(t.stem(), true); + BOOST_REQUIRE(scan.pruned); + BOOST_REQUIRE(scan.intact()); + BOOST_REQUIRE_EQUAL(scan.valid_ranges.size(), 1u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].last_block, 20u); + BOOST_REQUIRE_EQUAL(scan.valid_ranges[0].first_block, 20u - *scan.pruned_block_count + 1); + + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); + + //the library's regenerated index and ours must agree byte for byte + { + t.open(); //library reopen (still pruned) + t.close(); + std::filesystem::remove(t.index_path()); + t.open(); //library regenerates the index + t.close(); + const std::vector library_index = utils_fixture::slurp(t.index_path()); + std::filesystem::remove(t.index_path()); + log_utils::build_index(t.stem()); + const std::vector ours = utils_fixture::slurp(t.index_path()); + BOOST_REQUIRE(library_index == ours); + } + + //mutating operations refuse pruned logs + BOOST_REQUIRE_THROW(log_utils::truncate_log(t.stem(), 19), plugin_exception); + BOOST_REQUIRE_THROW(log_utils::trim_front(t.stem(), 19), plugin_exception); + BOOST_REQUIRE_THROW(log_utils::split_log(t.stem(), t.dir.path() / "split", 5), plugin_exception); + fc::temp_directory out_dir; + BOOST_REQUIRE_THROW(log_utils::extract_blocks(t.stem(), out_dir.path() / "x", 19, 20), plugin_exception); + + //a damaged pruned log is beyond repair, matching the library + t.clobber(t.index_slot(19, 2), 16); + BOOST_REQUIRE(!log_utils::scan_log(t.stem(), false).intact()); + BOOST_REQUIRE_THROW(log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false), + plugin_exception); +} FC_LOG_AND_RETHROW() } + +// A deep fork switch in a pruned log's retained tail leaves superseded entries whose block number is +// ABOVE the final head (the library's "we see block 7 and 6 when reading" case). The library skips +// them when regenerating the index rather than treating them as damage; make-index, full check-index +// and block-id must do the same and never index past the slot vector. Without the high-side skip in +// compute_index_pruned this backward walk writes out of bounds even though the log is perfectly valid. +BOOST_AUTO_TEST_CASE(pruned_index_skips_superseded_above_head) { try { + utils_fixture t(6 /*prune_blocks*/); + const size_t entry_size = 4096 + 2048; //large enough that hole punching actually frees blocks + t.add_range(2, 20, 'A', 'A', entry_size); //head climbs to 20 + //fork: rewrite block 19 on a 'B' lineage; the head retreats to 19 while the now-stale 'A' entry + // for block 20 stays in the retained tail with a block number above the head + t.add(19, 'B', 'A', entry_size); + t.close(); + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.pruned && s.tail_ok); + BOOST_REQUIRE_EQUAL(s.last_block, 19u); + const uint32_t first_servable = s.last_block - *s.pruned_block_count + 1; + + //the library's regenerated index is the reference: it skips the above-head block-20 entry + t.open(); //library reopen (still pruned) confirms the forked log is accepted + t.close(); + std::filesystem::remove(t.index_path()); + t.open(); //library regenerates the index + t.close(); + const std::vector library_index = utils_fixture::slurp(t.index_path()); + + //ours must match it byte for byte rather than crash or diverge + std::filesystem::remove(t.index_path()); + const auto [first, last] = log_utils::build_index(t.stem()); + BOOST_REQUIRE_EQUAL(first, first_servable); + BOOST_REQUIRE_EQUAL(last, 19u); + BOOST_REQUIRE(utils_fixture::slurp(t.index_path()) == library_index); + + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::ok); + BOOST_REQUIRE(log_utils::scan_log(t.stem(), true).intact()); + + //id lookups return the canonical (latest-written) content and refuse the above-head block + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 19) == utils_fixture::id_for(19, 'B')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), first_servable) == utils_fixture::id_for(first_servable, 'A')); + BOOST_REQUIRE(!log_utils::find_block_id(t.stem(), 20)); //above the head: not served + + //the backward walk (index removed) reaches the same answer without indexing out of range + std::filesystem::remove(t.index_path()); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), 19) == utils_fixture::id_for(19, 'B')); + + t.check_serves(first_servable, 19); +} FC_LOG_AND_RETHROW() } + +// A structurally valid entry whose recorded block number is BELOW the log's first block cannot occur +// in a healthy log (nothing is ever written before the first block), so the inspection tooling must +// report it as damage and fail cleanly instead of indexing below slot 0. This is the underflow half +// of the ci.slots[c.block_num - ci.index_first] concern: build_index, full check-index, the scanner, +// and find_block_id must all reject it rather than read out of bounds. +BOOST_AUTO_TEST_CASE(pruned_out_of_range_block_num_is_damage) { try { + utils_fixture t(4 /*prune_blocks*/); + const size_t entry_size = 4096 + 2048; + t.add_range(2, 20, 'A', 'A', entry_size); + t.close(); + + //forge a retained entry so it decodes to block 1, before the log's first block (2); the magic, + // payload, and position trailer stay valid, so only the range check stands between this entry and + // an out-of-bounds slot index + t.set_block_id_at(t.index_slot(19, 2), utils_fixture::id_for(1, 'A')); + + BOOST_REQUIRE_THROW(log_utils::build_index(t.stem()), plugin_exception); + BOOST_REQUIRE(log_utils::check_index(t.stem(), true) == log_utils::index_status::log_damaged); + BOOST_REQUIRE(!log_utils::scan_log(t.stem(), false).intact()); + + std::filesystem::remove(t.index_path()); + BOOST_REQUIRE_THROW(log_utils::find_block_id(t.stem(), 20), plugin_exception); +} FC_LOG_AND_RETHROW() } + +// find_block_id's fallback — taken when the on-disk index is missing or untrusted — recomputes the +// index by walking the log. The pruned backward walk does not require contiguous block numbers, so a +// damaged retained chain can leave a block inside the servable range with no entry of its own: a zero +// slot. Reading that slot blindly unpacks the header at offset 0 (the pruned stub, whose id is a real +// but unrelated block) and returns the wrong id. The fallback must validate the slot the same way the +// fast path does and report the log as damaged instead. Verified to return block 2's stub id, not +// throw, without the slot_holds_block check in the fallback. +BOOST_AUTO_TEST_CASE(find_block_id_fallback_rejects_orphaned_servable_block) { try { + utils_fixture t(6 /*prune_blocks*/); + const size_t entry_size = 4096 + 2048; //large enough that hole punching actually frees blocks + t.add_range(2, 20, 'A', 'A', entry_size); + t.close(); + + const log_utils::log_summary s = log_utils::summarize_log(t.stem()); + BOOST_REQUIRE(s.pruned && s.tail_ok); + const uint32_t first_servable = s.last_block - *s.pruned_block_count + 1; + const uint32_t orphan = first_servable + 1; //comfortably inside (first_servable, last_block) + BOOST_REQUIRE(orphan > first_servable && orphan < s.last_block); + + //forge the orphan's retained entry so it decodes as its successor — a block already covered by its + // own real entry. Nothing now decodes to `orphan`, so the recomputed index leaves its slot at zero, + // while positions are untouched so the trailer chain still walks cleanly (no damage detected there). + t.set_block_id_at(t.index_slot(orphan, 2), utils_fixture::id_for(orphan + 1, 'A')); + + //force the fallback: with no on-disk index find_block_id must recompute by walking the log + std::filesystem::remove(t.index_path()); + + //the orphaned block is inside the servable range but absent from the log: report damage, never the + // stub's (block 2's) id that unpacking offset 0 would otherwise yield + BOOST_REQUIRE_THROW(log_utils::find_block_id(t.stem(), orphan), plugin_exception); + + //blocks that are present still resolve to their real ids through the same fallback + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), s.last_block) == utils_fixture::id_for(s.last_block, 'A')); + BOOST_REQUIRE(log_utils::find_block_id(t.stem(), first_servable) == utils_fixture::id_for(first_servable, 'A')); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_head_gap) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + t.close(); + + //without force-write, a gap (e.g. after restoring a snapshot beyond the log's head) is fatal + t.open(); + BOOST_REQUIRE_EXCEPTION(t.add(50, 'A', 'A'), plugin_exception, [](const plugin_exception& e) { + return e.to_detail_string().find("skips over") != std::string::npos; + }); + t.close(); + + //with force-write the old bundle is moved aside and writing continues in a fresh log + t.open(true); + t.add(50, 'A', 'A'); + t.add(51, 'A', 'A'); + t.close(); + t.check_serves(50, 51); + + const std::filesystem::path orphan = t.dir.path() / (t.name + "-corrupt-1.log"); + BOOST_REQUIRE(std::filesystem::exists(orphan)); + BOOST_REQUIRE_GT(std::filesystem::file_size(orphan), 0u); + //the orphan is itself a healthy bundle holding the old blocks + const log_utils::scan_result orphan_scan = log_utils::scan_log(t.dir.path() / (t.name + "-corrupt-1"), true); + BOOST_REQUIRE(orphan_scan.intact()); + BOOST_REQUIRE_EQUAL(orphan_scan.valid_ranges[0].first_block, 2u); + BOOST_REQUIRE_EQUAL(orphan_scan.valid_ranges[0].last_block, 10u); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_fork_mismatch) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + t.close(); + + t.open(); + BOOST_REQUIRE_EXCEPTION(t.add(10, 'X', 'Z'), plugin_exception, [](const plugin_exception& e) { + return e.to_detail_string().find("missed a fork change") != std::string::npos; + }); + t.close(); + + t.open(true); + t.add(10, 'X', 'Z'); //a different chain's history: old bundle orphaned, fresh log starts at 10 + t.close(); + t.check_serves(10, 10); + BOOST_REQUIRE(std::filesystem::exists(t.dir.path() / (t.name + "-corrupt-1.log"))); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_index_disagreement_self_heals) { try { + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + t.close(); + + //right-size index whose final position lies: only check_log_and_index_on_init notices + const uint64_t index_size = std::filesystem::file_size(t.index_path()); + { + std::fstream f(t.index_path(), std::ios::binary | std::ios::in | std::ios::out); + f.seekp(index_size - sizeof(uint64_t)); + const uint64_t lie = 1; + f.write(reinterpret_cast(&lie), sizeof(lie)); + } + + BOOST_REQUIRE_THROW(t.open(), plugin_exception); + t.close(); + + t.open(true); //regenerates the index instead of failing, and must not orphan anything + t.close(); + BOOST_REQUIRE(!std::filesystem::exists(t.dir.path() / (t.name + "-corrupt-1.log"))); + t.check_serves(2, 10); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_retained_gap_tolerated) { try { + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + + fc::temp_directory split_dir; + log_utils::split_log(t.stem(), split_dir.path(), 10); + std::filesystem::remove(split_dir.path() / "shipit-11-20.log"); + std::filesystem::remove(split_dir.path() / "shipit-11-20.index"); + + const eosio::state_history::state_history_log_config split_conf = + eosio::state_history::partition_config{.retained_dir = split_dir.path(), .archive_dir = "", .stride = 10}; + + //the hole is fatal without force-write + BOOST_REQUIRE_THROW(eosio::state_history::log_catalog(split_dir.path(), split_conf, t.name), plugin_exception); + + //with force-write the catalog opens; blocks in the hole are simply not served + eosio::state_history::log_catalog catalog(split_dir.path(), split_conf, t.name, + eosio::state_history::state_history_log::no_non_local_get_block_id_func, + true); + BOOST_REQUIRE(!!catalog.get_entry(5)); + BOOST_REQUIRE(!catalog.get_entry(15)); + BOOST_REQUIRE(!!catalog.get_entry(25)); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_below_retained_history) { try { + //a write below the first retained block (a chain wiped and resynced from scratch) cannot be + // absorbed by orphaning just the head log; force-write must move the whole catalog aside + utils_fixture t; + t.add_range(2, 25, 'A', 'A'); + t.close(); + + fc::temp_directory catalog_dir; + const std::filesystem::path retained = catalog_dir.path() / "retained"; + log_utils::split_log(t.stem(), retained, 10); //retained 2-10, 11-20, head 21-25 + std::filesystem::rename(log_utils::normalize_stem(retained / t.name).string() + ".log", + (catalog_dir.path() / (t.name + ".log")).string()); + std::filesystem::rename(log_utils::normalize_stem(retained / t.name).string() + ".index", + (catalog_dir.path() / (t.name + ".index")).string()); + + const eosio::state_history::state_history_log_config conf = + eosio::state_history::partition_config{.retained_dir = retained, .archive_dir = "", .stride = 10}; + + eosio::state_history::log_catalog catalog(catalog_dir.path(), conf, t.name, + eosio::state_history::state_history_log::no_non_local_get_block_id_func, + true); + std::vector payload(64, 'Z'); + catalog.pack_and_write_entry(utils_fixture::id_for(1, 'Z'), utils_fixture::id_for(0, 'Z'), + [&](auto& f) { bio::write(f, payload.data(), payload.size()); }); + + const auto [begin, end] = catalog.block_range(); + BOOST_REQUIRE_EQUAL(begin, 1u); + BOOST_REQUIRE_EQUAL(end, 2u); + //every pre-existing bundle was moved aside, none deleted + unsigned orphans = 0; + for(const auto& de : std::filesystem::recursive_directory_iterator(catalog_dir.path())) + if(de.is_regular_file() && de.path().filename().string().find("-corrupt-") != std::string::npos && + de.path().extension() == ".log") + ++orphans; + BOOST_REQUIRE_EQUAL(orphans, 3u); //two retained bundles + the old head +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(force_write_skips_block_the_chain_rejects) { try { + //the cascade's last resort -- writing into a fresh empty log -- can still be rejected when the + // disagreement is with the chain itself (the non-local block-id lookup), not with any log the + // catalog holds. force-write must skip such a block and keep running rather than throw. + utils_fixture t; + t.add_range(2, 10, 'A', 'A'); + t.close(); + + //a non-local lookup that always disagrees stands in for a block whose parent id no log can ever + // satisfy, so every write tier -- existing head, fresh head, fresh head after orphaning all -- is + // rejected, exercising the final guarded attempt + auto always_disagrees = [](block_num_type) -> std::optional { + return utils_fixture::id_for(1, 'Z'); + }; + eosio::state_history::log_catalog catalog(t.dir.path(), t.conf, t.name, always_disagrees, true /*force_write*/); + + //block 50 skips over the head's next block (11) so the existing head rejects it outright, and the + // disagreeing lookup makes every fresh-log retry reject it too; the call must return, not throw + const std::vector payload(64, 'A'); + BOOST_REQUIRE_NO_THROW(catalog.pack_and_write_entry( + utils_fixture::id_for(50, 'A'), utils_fixture::id_for(49, 'A'), + [&](auto& f) { bio::write(f, payload.data(), payload.size()); })); + + //the conflicting block was skipped (nothing serves it) while the original blocks were set aside + BOOST_REQUIRE(!catalog.get_entry(50)); + BOOST_REQUIRE(std::filesystem::exists(t.dir.path() / (t.name + "-corrupt-1.log"))); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_CASE(repaired_logs_reopen_and_continue) { try { + //after a truncate repair, nodeos must be able to append right where the log now ends + utils_fixture t; + t.add_range(2, 30, 'A', 'A'); + t.close(); + t.append_garbage(33); + + const log_utils::repair_report rep = log_utils::repair_log(t.stem(), log_utils::repair_mode::truncate, false, false); + BOOST_REQUIRE(rep.acted); + + t.open(); + t.add(31, 'A', 'A'); //would throw if the repaired log were inconsistent + t.close(); + t.check_serves(2, 31); +} FC_LOG_AND_RETHROW() } + +BOOST_AUTO_TEST_SUITE_END()