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()