From d67182dec527373ada4418212b7ded3b408fb550 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Mon, 24 Aug 2026 18:19:58 +0200 Subject: [PATCH 1/4] check: survive I/O errors while reading repository objects, fixes #3509 An OSError from the store (failing disk, flaky network filesystem, ...) escaped up to the top-level handler, so borg check died with a "Local Exception" traceback and the results collected so far were lost. Reads of repository objects now raise Repository.StoreReadError, keeping the original OSError as __cause__. It is deliberately distinct from ObjectNotFound and IntegrityError: borg never saw the content, so it can tell neither that the object is missing nor that it is corrupt. The repository check reports such an object, goes on and fails at the end, so one run lists everything that is affected. No result is recorded for it, so a later check verifies it again rather than remembering it as corrupt. The archives check reports the affected archive and continues with the next one. Because the data may well be readable again once the underlying problem is fixed, nothing acts on an unreadable object: --repair refuses to repair, the index is not rebuilt from packs that could not be read, and --verify-data leaves those chunks in place instead of deleting them. --- docs/changes.rst | 6 + docs/internals/frontends.rst | 4 + docs/usage/check.rst.inc | 18 ++- src/borg/archive.py | 129 +++++++++++------- src/borg/archiver/check_cmd.py | 14 ++ src/borg/cache.py | 15 +- src/borg/repository.py | 91 ++++++++++-- src/borg/testsuite/archiver/check_cmd_test.py | 116 +++++++++++++++- 8 files changed, 323 insertions(+), 70 deletions(-) diff --git a/docs/changes.rst b/docs/changes.rst index f92ba1db21..599fcdfda0 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -187,6 +187,12 @@ Fixes: - do not report a merely touched file as modified when the chunker params differ, #10351 - report a file as modified when chunks were reordered or duplicated +- check: do not crash with a traceback when a repository object can not be read + (I/O error, e.g. failing disk or flaky network filesystem). The affected object + is reported, the check continues and fails at the end. Such an object is not + recorded as corrupt (a later check verifies it again), ``--repair`` refuses to + repair around it and ``--verify-data`` no longer deletes chunks it could not + read, #3509 Other changes: diff --git a/docs/internals/frontends.rst b/docs/internals/frontends.rst index 0c598dfa82..e7bc36af9d 100644 --- a/docs/internals/frontends.rst +++ b/docs/internals/frontends.rst @@ -855,6 +855,10 @@ Errors Object with key {} is indexed to pack {}, but that whole pack is missing from repository {}. Repository.PermissionDenied rc: 24 traceback: no Repository permission denied: {} + Repository.RepairUnsafe rc: 29 traceback: no + Not repairing: {} repository object(s) could not be read. Fix the underlying problem, then check again. + Repository.StoreReadError rc: 28 traceback: no + Error reading {} from the repository: {}. Check the storage hardware / filesystem. MandatoryFeatureUnsupported rc: 25 traceback: no Unsupported repository feature(s) {}. A newer version of Borg is required to access this repository. diff --git a/docs/usage/check.rst.inc b/docs/usage/check.rst.inc index 5a59c9eb5d..e53772b548 100644 --- a/docs/usage/check.rst.inc +++ b/docs/usage/check.rst.inc @@ -98,12 +98,12 @@ The check command verifies the consistency of a repository and its archives. It consists of two major steps: 1. Checking the consistency of the repository itself. The objects in the ``index/`` - and ``packs/`` namespaces are named by the sha256 hash of their content, so such + and ``packs/`` namespaces are named by the store hash of their content, so such an object is intact if and only if the hash of its content still equals its name. The check verifies the (small) index objects first and, only if they are intact, all packs. It also cross-checks the chunk index against the packs present in the repository to detect referenced but missing packs. Bit rot and other types of - accidental damage can be detected this way, but as sha256 content-addressing is + accidental damage can be detected this way, but as content-addressing is not a MAC, this step does not detect tampering. Running the repository check can be split into multiple partial checks using ``--max-duration``. For rest:// repositories, the server computes the hashes, so the pack contents do @@ -199,6 +199,20 @@ packs, and, if the key must be recovered, scans chunks for it. These phases do n respond to SIGINT, so on a large repository a Ctrl-C during them may appear to have no effect until they finish. +Unreadable repository objects ++++++++++++++++++++++++++++++ + +A repository object that cannot be read at all (an I/O error from a failing disk, a +flaky network filesystem, ...) is different from a corrupt one: Borg never saw its +content, so it cannot tell whether the object is fine. Such an object is reported and +the check continues, so one run lists everything that is affected; the check then +fails. The object is not remembered as corrupt, so a later check verifies it again. + +Because the data may well be readable again once the underlying problem is fixed, +``--repair`` refuses to repair while there are unreadable objects, and +``--verify-data`` leaves chunks it could not read in place instead of deleting them. +Fix the storage hardware, filesystem or network first, then run the check again. + About repair mode +++++++++++++++++ diff --git a/src/borg/archive.py b/src/borg/archive.py index f8769f526d..ec93078a13 100644 --- a/src/borg/archive.py +++ b/src/borg/archive.py @@ -2375,6 +2375,7 @@ def verify_data(self): errors = 0 verified = 0 # chunks actually verified defect_chunks = [] + unreadable_chunks = 0 # chunks we could not even read, refs #3509 pi = ProgressIndicatorPercent( total=chunks_count, msg="Verifying data %6.2f%%", step=0.01, msgid="check.verify_data" ) @@ -2385,6 +2386,13 @@ def verify_data(self): verified += 1 try: encrypted_data = self.repository.get(chunk_id) + except Repository.StoreReadError as err: + # unreadable, not defect: we did not see the content, so we must not conclude it is + # bad and delete it - it may read fine once the hardware/fs problem is fixed, refs #3509. + self.error_found = True + errors += 1 + unreadable_chunks += 1 + logger.error("chunk %s: %s", bin_to_hex(chunk_id), err) except (Repository.ObjectNotFound, IntegrityErrorBase) as err: self.error_found = True errors += 1 @@ -2425,6 +2433,11 @@ def verify_data(self): ro_type=ROBJ_DONTCARE, assert_id_place="verify_data", ) + except Repository.StoreReadError as err: + # the retry did not fail on the content, it failed to read at all: keep the + # chunk, the read may well succeed again later, refs #3509. + unreadable_chunks += 1 + logger.error("chunk %s not deleted, could not be re-read: %s", bin_to_hex(defect_chunk), err) except IntegrityErrorBase: # failed twice -> remove this defect chunk. delete rewrites its pack without it, # keeping the other chunks. update_index=False: finish() rebuilds the index from @@ -2439,18 +2452,23 @@ def verify_data(self): logger.warning("Found defect chunks. Run with --repair to remove them.") for defect_chunk in defect_chunks: logger.debug("chunk %s is defect.", bin_to_hex(defect_chunk)) + if unreadable_chunks: + logger.error( + "%d chunk(s) could not be read and were left untouched. This usually means a hardware, " + "filesystem or network problem - fix that first, then run the check again.", + unreadable_chunks, + ) log = logger.error if errors else logger.info if sig_int: log( - "Interrupted cryptographic data integrity verification, " - "verified %d of %d chunks with %d integrity errors.", + "Interrupted cryptographic data integrity verification, verified %d of %d chunks with %d error(s).", verified, chunks_count, errors, ) else: log( - "Finished cryptographic data integrity verification, verified %d chunks with %d integrity errors.", + "Finished cryptographic data integrity verification, verified %d chunks with %d error(s).", verified, errors, ) @@ -2743,57 +2761,66 @@ def valid_item(obj): pi.show(i) archive_id, archive_id_hex = info.id, bin_to_hex(info.id) try: - formatted = formatter.format_item(info, jsonline=False) - except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase): - # keys like {comment} need the archive metadata, which is damaged or missing here. - # use the values from the archive directory entry, they are always available. - formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}" - logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})") - if archive_id not in self.chunks: - logger.error(f"Archive metadata block {archive_id_hex} is missing!") - self.error_found = True + try: + formatted = formatter.format_item(info, jsonline=False) + except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase): + # keys like {comment} need the archive metadata, which is damaged or missing here. + # use the values from the archive directory entry, they are always available. + formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}" + logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})") + if archive_id not in self.chunks: + logger.error(f"Archive metadata block {archive_id_hex} is missing!") + self.error_found = True + if self.repair: + logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") + self.manifest.archives.delete_by_id(archive_id) + else: + logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") + continue + cdata = self.repository.get(archive_id) + try: + _, data = self.repo_objs.parse(archive_id, cdata, ro_type=ROBJ_ARCHIVE_META) + except IntegrityErrorBase as integrity_error: + logger.error(f"Archive metadata block {archive_id_hex} is corrupted: {integrity_error}") + self.error_found = True + if self.repair: + logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") + self.manifest.archives.delete_by_id(archive_id) + else: + logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") + continue + archive = self.key.unpack_archive(data) + archive = ArchiveItem(internal_dict=archive) + if archive.version != 2: + raise Exception("Unknown archive metadata version") + items_buffer = ChunkBuffer(self.key) + items_buffer.write_chunk = add_callback + for item in robust_iterator(archive): + if "chunks" in item: + verify_file_chunks(info.name, item) + items_buffer.add(item) + items_buffer.flush(flush=True) if self.repair: - logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") - self.manifest.archives.delete_by_id(archive_id) - else: - logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") - continue - cdata = self.repository.get(archive_id) - try: - _, data = self.repo_objs.parse(archive_id, cdata, ro_type=ROBJ_ARCHIVE_META) - except IntegrityErrorBase as integrity_error: - logger.error(f"Archive metadata block {archive_id_hex} is corrupted: {integrity_error}") + archive.item_ptrs = archive_put_items( + items_buffer.chunks, repo_objs=self.repo_objs, add_reference=add_reference + ) + data = self.key.pack_metadata(archive.as_dict()) + new_archive_id = self.key.id_hash(data) + logger.debug(f"archive id old: {bin_to_hex(archive_id)}") + logger.debug(f"archive id new: {bin_to_hex(new_archive_id)}") + cdata = self.repo_objs.format(new_archive_id, {}, data, ro_type=ROBJ_ARCHIVE_META) + add_reference(new_archive_id, len(data), cdata) + self.manifest.archives.create(info.name, new_archive_id, info.ts) + if archive_id != new_archive_id: + self.manifest.archives.delete_by_id(archive_id) + except Repository.StoreReadError as err: + # some object of this archive could not be read at all (I/O error, refs #3509). + # we do not know what is in it, so we can not tell whether the archive is fine. + logger.error(f"Archive {info.name} {archive_id_hex} could not be checked: {err}") self.error_found = True if self.repair: - logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") - self.manifest.archives.delete_by_id(archive_id) - else: - logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") - continue - archive = self.key.unpack_archive(data) - archive = ArchiveItem(internal_dict=archive) - if archive.version != 2: - raise Exception("Unknown archive metadata version") - items_buffer = ChunkBuffer(self.key) - items_buffer.write_chunk = add_callback - for item in robust_iterator(archive): - if "chunks" in item: - verify_file_chunks(info.name, item) - items_buffer.add(item) - items_buffer.flush(flush=True) - if self.repair: - archive.item_ptrs = archive_put_items( - items_buffer.chunks, repo_objs=self.repo_objs, add_reference=add_reference - ) - data = self.key.pack_metadata(archive.as_dict()) - new_archive_id = self.key.id_hash(data) - logger.debug(f"archive id old: {bin_to_hex(archive_id)}") - logger.debug(f"archive id new: {bin_to_hex(new_archive_id)}") - cdata = self.repo_objs.format(new_archive_id, {}, data, ro_type=ROBJ_ARCHIVE_META) - add_reference(new_archive_id, len(data), cdata) - self.manifest.archives.create(info.name, new_archive_id, info.ts) - if archive_id != new_archive_id: - self.manifest.archives.delete_by_id(archive_id) + # rewriting the archive now would drop whatever we could not read from it. + raise finally: pi.finish() report_missing_chunks() diff --git a/src/borg/archiver/check_cmd.py b/src/borg/archiver/check_cmd.py index fd3a18beed..80c12f2f29 100644 --- a/src/borg/archiver/check_cmd.py +++ b/src/borg/archiver/check_cmd.py @@ -213,6 +213,20 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser): respond to SIGINT, so on a large repository a Ctrl-C during them may appear to have no effect until they finish. + Unreadable repository objects + +++++++++++++++++++++++++++++ + + A repository object that cannot be read at all (an I/O error from a failing disk, a + flaky network filesystem, ...) is different from a corrupt one: Borg never saw its + content, so it cannot tell whether the object is fine. Such an object is reported and + the check continues, so one run lists everything that is affected; the check then + fails. The object is not remembered as corrupt, so a later check verifies it again. + + Because the data may well be readable again once the underlying problem is fixed, + ``--repair`` refuses to repair while there are unreadable objects, and + ``--verify-data`` leaves chunks it could not read in place instead of deleting them. + Fix the storage hardware, filesystem or network first, then run the check again. + About repair mode +++++++++++++++++ diff --git a/src/borg/cache.py b/src/borg/cache.py index 50807d075a..ceae6d8ac5 100644 --- a/src/borg/cache.py +++ b/src/borg/cache.py @@ -936,12 +936,17 @@ def build_chunkindex_from_repo( break chunks = ChunkIndex() # we'll merge all fragments into this complete = True - corrupt_fragment = None + unusable_fragment = None # message about a fragment that is corrupt or could not be read for hash in hashes: try: chunks_to_merge = read_chunkindex_from_repo(repository, hash) except CorruptChunkIndexFragment as err: - corrupt_fragment = err + unusable_fragment = f"{err} is corrupt" + break + except Repository.StoreReadError as err: + # the fragment could not be read (I/O error, refs #3509). retrying would just hit + # the same error, so give up on the fragments and rebuild from the packs instead. + unusable_fragment = f"chunk index fragment {hash} could not be read: {err}" break if chunks_to_merge is None: logger.debug(f"chunk index fragment {hash} vanished, restarting the merge...") @@ -951,13 +956,13 @@ def build_chunkindex_from_repo( for k, v in chunks_to_merge.items(): chunks[k] = v chunks_to_merge.clear() - if corrupt_fragment is not None: - # retrying would re-read the same corrupt fragment; rebuild the whole index from + if unusable_fragment is not None: + # retrying would re-read the same unusable fragment; rebuild the whole index from # the packs instead (or return None in fragments_only mode). chunks.clear() if fragments_only: return None - logger.warning(f"{corrupt_fragment} is corrupt, rebuilding the chunk index from the packs.") + logger.warning(f"{unusable_fragment}, rebuilding the chunk index from the packs.") break if complete: if len(hashes) > 1 and write_immediately: diff --git a/src/borg/repository.py b/src/borg/repository.py index 58e1cba5b4..f097941e3c 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -371,13 +371,22 @@ def read(self, offset, size): # in-memory pack: return a memoryview into pack_contents. store: range-read bytes. if self.pack_contents is not None: return memoryview(self.pack_contents)[offset : offset + size] - return self.store.load(self.key, offset=offset, size=size) + try: + return self.store.load(self.key, offset=offset, size=size) + except OSError as exc: + # the pack exists, but reading it failed (bad disk, flaky network fs, ...). that is + # neither "object missing" nor "content corrupt", so it gets its own error class: + # callers must not react to it by dropping data, refs #3509. + raise Repository.StoreReadError(f"pack {bin_to_hex(self.pack_id)}", exc) from exc def size(self): """Return the pack size in bytes (a store metadata lookup, unless the pack is in memory).""" if self.pack_contents is not None: return len(self.pack_contents) - return self.store.info(self.key).size + try: + return self.store.info(self.key).size + except OSError as exc: + raise Repository.StoreReadError(f"pack {bin_to_hex(self.pack_id)}", exc) from exc @staticmethod def _parse_header(hdr_data, offset, pack_size): @@ -809,6 +818,18 @@ class PermissionDenied(Error): exit_mcode = 24 + class RepairUnsafe(Error): + """Not repairing: {} repository object(s) could not be read. Fix the underlying problem, then check again.""" + + exit_mcode = 29 + + class StoreReadError(Error): + """Error reading {} from the repository: {}. Check the storage hardware / filesystem.""" + + exit_mcode = 28 + + # the underlying I/O error (bad disk, flaky network fs, ...) is kept as __cause__, refs #3509. + # Whole packs kept in memory for reads; the least recently used is evicted first. # Memory use is this count times the pack size. PACK_READER_CACHE_SIZE = 3 @@ -1201,12 +1222,19 @@ def check(self, repair=False, max_duration=0, max_age=0, repo_only=False): """ def verify(namespace, name): + """Return True if the object is intact, False if it is corrupt, None if it could not be read.""" # name is the store hash of the object's content, so it is intact iff store.hash() matches. key = f"{namespace}/{name}" try: ok = self.store.hash(key, algorithm=STORE_HASH_NAME) == name except StoreObjectNotFound: return True # vanished since store.list(); not an error + except OSError as exc: + # reading failed (bad disk, flaky network fs, ...), so we do not know whether the + # object is intact. report it and go on: one unreadable object must not abort the + # whole check, and the result must not be recorded as "corrupt", refs #3509. + logger.error(f"Store object {key} could not be read: {exc}") + return None if not ok: logger.error(f"Store object {key} is corrupted: content does not match its name (store hash).") return ok @@ -1216,6 +1244,10 @@ def store_list(namespace): return list(self.store.list(namespace)) except StoreObjectNotFound: return [] # namespace does not exist + except OSError as exc: + # without a listing we do not know what to check, so this one is fatal - but it + # ends the check with a clear message instead of a traceback, refs #3509. + raise self.StoreReadError(f"the {namespace}/ listing", exc) from exc partial = bool(max_duration) assert not (repair and partial) @@ -1236,6 +1268,9 @@ def store_list(namespace): t_last_checkpoint = t_start index_files = index_errors = 0 pack_files = pack_errors = pack_skipped = 0 + # objects that could not be read at all (I/O errors, refs #3509) - counted apart from + # corruption: "unreadable" is a different diagnosis and is often transient/fixable. + read_errors = 0 missing_pack_ids = [] # packs referenced by the index but absent from packs/ (refs #9898) index_repaired = False packs_scanned = False @@ -1255,7 +1290,10 @@ def store_list(namespace): self._lock_refresh() index_pi.show(increase=1) index_files += 1 - if not verify("index", info.name): + result = verify("index", info.name) + if result is None: + read_errors += 1 + elif not result: index_errors += 1 if index_infos: index_pi.show(current=len(index_infos)) # finish at 100% @@ -1341,9 +1379,14 @@ def recorded_ts(info): continue pack_files += 1 ok = verify("packs", info.name) - if not ok: - pack_errors += 1 - tracker.record(pack_id, ok) + if ok is None: + # unreadable: we did not learn anything about this pack, so do not record a + # result for it - a later check re-verifies it (unrecorded packs come first). + read_errors += 1 + else: + if not ok: + pack_errors += 1 + tracker.record(pack_id, ok) now = time.monotonic() # a checkpoint rewrites the whole table (41 bytes per pack), so keep the interval long. if now > t_last_checkpoint + 30 * 60: @@ -1362,7 +1405,9 @@ def recorded_ts(info): # rebuild only if the index was the sole problem and every pack was verified intact this # run: sig_int breaks the loop early, so "no pack errors" must be paired with "all packs # scanned" (pack_files == len(pack_infos)) to not rebuild from unverified packs. - if index_errors and pack_errors == 0 and not sig_int and pack_files == len(pack_infos): + # read_errors == 0 for the same reason: an unreadable pack was not verified either, and + # rebuilding the index from packs we could not read would drop their chunks, refs #3509. + if index_errors and pack_errors == 0 and read_errors == 0 and not sig_int and pack_files == len(pack_infos): # the exclusive check lock keeps the pack set fixed, so re-listing packs/ inside # build_chunkindex_from_repo matches this verification. write_immediately persists the # index and drops the corrupt fragments. @@ -1383,6 +1428,13 @@ def recorded_ts(info): if pack_skipped: summary += f" Reused {pack_skipped} recent pack check result(s)." logger.info(summary) + if read_errors: + logger.error( + f"{read_errors} store object(s) could not be read, so they could not be checked. " + "This usually means a hardware, filesystem or network problem - see the " + '"Data integrity" section of the docs. The repository was not modified; fix the ' + "underlying problem, then run the check again." + ) if missing_pack_ids: # one id per line (the list can be long). logger.error(f"{len(missing_pack_ids)} pack(s) referenced by the index are missing:") @@ -1402,14 +1454,17 @@ def recorded_ts(info): logger.error(f"Found {len(corrupt_ids)} corrupt pack(s):") for pack_id in corrupt_ids: logger.error(f"Corrupt pack: {bin_to_hex(pack_id)}") - # fail if this run found errors, or any pack is recorded corrupt. - problems = objs_errors != 0 or bool(corrupt_ids) + # fail if this run found errors or could not read some objects, or any pack is recorded corrupt. + problems = objs_errors != 0 or read_errors != 0 or bool(corrupt_ids) # On Ctrl-C the check stopped early, so the summary only covers the packs seen so far. done, so_far = ("Interrupted", " so far") if sig_int else ("Finished", "") if not problems: logger.info(f"{done} {mode} repository check, no problems found{so_far}.") elif not repair: logger.error(f"{done} {mode} repository check, errors found{so_far}.") + elif read_errors: + # repair mode, but unreadable objects stop us below - so report like a read-only check. + logger.error(f"{done} {mode} repository check, errors found{so_far}.") elif index_repaired and not (pack_errors or corrupt_ids or missing_pack_ids): # the index was the only problem and it has been rebuilt from the packs. logger.info(f"{done} {mode} repository check, repaired{so_far}.") @@ -1435,6 +1490,10 @@ def recorded_ts(info): if repair: if index_errors and not index_repaired: return False + if read_errors: + # we do not know what is in those objects, so repairing around them could throw away + # data that reads fine again once the underlying problem is fixed, refs #3509. + raise self.RepairUnsafe(read_errors) return not (repo_only and (pack_errors or corrupt_ids or missing_pack_ids)) return not problems @@ -1527,7 +1586,11 @@ def _cached_pack_reader(self, pack_id): reader = self._pack_cache.get(pack_id) if reader is None: key = "packs/" + bin_to_hex(pack_id) - reader = PackReader(pack_id=pack_id, pack_contents=self.store.load(key)) + try: + pack_contents = self.store.load(key) + except OSError as exc: + raise self.StoreReadError(f"pack {bin_to_hex(pack_id)}", exc) from exc + reader = PackReader(pack_id=pack_id, pack_contents=pack_contents) self._pack_cache[pack_id] = reader return reader @@ -1552,6 +1615,7 @@ def get_many(self, ids, read_data=True, raise_missing=True): raise self.PackNotFound(id_, entry.pack_id, str(self._location)) from None yield None else: + # the pack is in memory here, so read() only slices it and can not raise OSError. yield reader.read(entry.obj_offset, entry.obj_size) def put(self, id, data): @@ -1930,10 +1994,15 @@ def store_list(self, name, *, deleted=False): return list(self.store.list(name, deleted=deleted)) except StoreObjectNotFound: return [] + except OSError as exc: + raise self.StoreReadError(f"the {name}/ listing", exc) from exc def store_load(self, name, *, size=None, offset=0): self._lock_refresh() - return self.store.load(name, size=size, offset=offset) + try: + return self.store.load(name, size=size, offset=offset) + except OSError as exc: + raise self.StoreReadError(name, exc) from exc def store_store(self, name, value): self._lock_refresh() diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index bf9f90874b..7b8e5a94ae 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -1,3 +1,4 @@ +import errno from pathlib import Path import re import shutil @@ -11,7 +12,7 @@ from ...archive import Archive, ArchiveChecker, ChunkBuffer from ...cache import Cache, delete_chunkindex_from_repo from ...constants import * # NOQA -from ...helpers import bin_to_hex, msgpack, CommandError, CorruptPack, Error, IntegrityError, sig_int +from ...helpers import bin_to_hex, hex_to_bin, msgpack, CommandError, CorruptPack, Error, IntegrityError, sig_int from ...helpers import BackupDamagedChunksError from ...item import Item from ...manifest import Archives, Manifest @@ -1176,3 +1177,116 @@ def test_items_with_unknown_keys_are_kept(archivers, request): assert items[0].as_dict()["newkey"] == "future" output = cmd(archiver, "check", "--archives-only", exit_code=0) assert "keys unknown to this borg version" in output # still just the warning + + +def make_pack_unreadable(monkeypatch, pack_name): + """Make reading the pack packs/ fail with an OSError, like failing storage does. + + Patches the posixfs backend rather than using file permissions, so it also works when the tests + run as root and does not depend on the platform's permission semantics. Returns a dict whose + "failing" entry switches the failures off again (monkeypatch.undo() must not be used here, it + would also revert the autouse clean_env fixture). + """ + from borgstore.backends.posixfs import PosixFS + + state = {"failing": True} + orig_hash, orig_load = PosixFS.hash, PosixFS.load + + def hits_pack(name): + # the backend gets the name including borgstore's nesting levels, e.g. packs/d0/d0a6... + return state["failing"] and name.rsplit("/", 1)[-1] == pack_name + + def failing_hash(self, name, algorithm="sha256"): + if hits_pack(name): + raise OSError(errno.EIO, "Input/output error", name) + return orig_hash(self, name, algorithm=algorithm) + + def failing_load(self, name, *, size=None, offset=0): + if hits_pack(name): + raise OSError(errno.EIO, "Input/output error", name) + return orig_load(self, name, size=size, offset=offset) + + monkeypatch.setattr(PosixFS, "hash", failing_hash) + monkeypatch.setattr(PosixFS, "load", failing_load) + return state + + +def some_pack_name(archiver): + """Return the name of one of the repository's pack files.""" + with Repository(archiver.repository_location, exclusive=True) as repository: + return sorted(info.name for info in repository.store_list("packs"))[0] + + +def test_check_unreadable_pack(archivers, request, monkeypatch): + # an I/O error while reading a pack must not crash the check with a traceback: it is reported, + # the check goes on and fails at the end, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + cmd(archiver, "check", exit_code=0) + pack_name = some_pack_name(archiver) + make_pack_unreadable(monkeypatch, pack_name) + + output = cmd(archiver, "check", "-v", "--repository-only", exit_code=1) + assert f"Store object packs/{pack_name} could not be read" in output + assert "Input/output error" in output + # the check did not stop at the unreadable pack ... + assert "Finished checking packs." in output + assert "store object(s) could not be read" in output + # ... and it did not claim the pack is corrupt (we never saw its content). + assert "is corrupted" not in output + assert "Corrupt pack" not in output + + +def test_check_unreadable_pack_not_recorded(archivers, request, monkeypatch): + # a pack we could not read gets no result recorded, so a later check verifies it again instead + # of remembering it as corrupt, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + pack_name = some_pack_name(archiver) + state = make_pack_unreadable(monkeypatch, pack_name) + cmd(archiver, "check", "--repository-only", exit_code=1) + with Repository(archiver.repository_location, exclusive=True) as repository: + tracker = PackTracker.load(repository.store) + assert tracker.get(hex_to_bin(pack_name)) is None + assert tracker.corrupt_ids() == [] + # once the pack reads fine again, the check passes without any manual cleanup. + state["failing"] = False + cmd(archiver, "check", exit_code=0) + + +def test_check_repair_refuses_unreadable_pack(archivers, request, monkeypatch): + # --repair must not repair around an unreadable pack: its chunks may well be readable again + # once the underlying problem is fixed, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + pack_name = some_pack_name(archiver) + make_pack_unreadable(monkeypatch, pack_name) + with pytest.raises(Repository.RepairUnsafe): # local (not forked): the Error propagates + cmd(archiver, "check", "--repair") + + +def test_check_verify_data_unreadable_pack_keeps_chunks(archivers, request, monkeypatch): + # --verify-data deletes chunks whose content is defect, but must keep chunks it could not read + # at all, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + pack_name = some_pack_name(archiver) + with Repository(archiver.repository_location, exclusive=True) as repository: + chunks_before = sorted(chunk_id for chunk_id, _ in repository.chunks.iteritems()) + state = make_pack_unreadable(monkeypatch, pack_name) + + output = cmd(archiver, "check", "--archives-only", "--verify-data", exit_code=1) + assert "could not be read and were left untouched" in output + + state["failing"] = False + with Repository(archiver.repository_location, exclusive=True) as repository: + chunks_after = sorted(chunk_id for chunk_id, _ in repository.chunks.iteritems()) + assert chunks_after == chunks_before # nothing was thrown away From db4ed78e6244928cd593da8620a9578bb34d5bcc Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Mon, 24 Aug 2026 19:07:35 +0200 Subject: [PATCH 2/4] check: survive an unreadable archive metadata pack, refs #3509 Listing the archives reads each archive's metadata chunk, so an unreadable pack holding one made the archives check die before its per-archive loop even started. The FreeBSD CI job hit this because the pack it picked happened to hold archive metadata. Archives.list() gets an opt-in tolerate_read_errors: with it, an archive whose metadata could not be read becomes a placeholder entry, so the check can report it and go on with the other archives. Only the archives check opts in. Everywhere else the read error propagates, because acting on a partially readable repository is how a transient I/O error turns into data loss: prune would see the placeholder's 1970 timestamp and treat the archive as the oldest one. The --find-lost-archives scan now also skips an unreadable chunk instead of aborting; it only looks for archive metadata there, so skipping one can at worst miss a lost archive. The verify-data test now targets the pack holding file content, so it tests what it means to test regardless of how chunks land in packs. --- docs/changes.rst | 3 +- docs/usage/check.rst.inc | 4 ++ src/borg/archive.py | 31 ++++++++--- src/borg/archiver/check_cmd.py | 4 ++ src/borg/manifest.py | 35 +++++++++--- src/borg/testsuite/archiver/check_cmd_test.py | 54 ++++++++++++++++++- src/borg/testsuite/archives_test.py | 15 +++--- 7 files changed, 124 insertions(+), 22 deletions(-) diff --git a/docs/changes.rst b/docs/changes.rst index 599fcdfda0..b9da40ed1d 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -192,7 +192,8 @@ Fixes: is reported, the check continues and fails at the end. Such an object is not recorded as corrupt (a later check verifies it again), ``--repair`` refuses to repair around it and ``--verify-data`` no longer deletes chunks it could not - read, #3509 + read. Other commands stop with the read error instead of working with a + partially readable repository, #3509 Other changes: diff --git a/docs/usage/check.rst.inc b/docs/usage/check.rst.inc index e53772b548..fb93872c3a 100644 --- a/docs/usage/check.rst.inc +++ b/docs/usage/check.rst.inc @@ -213,6 +213,10 @@ Because the data may well be readable again once the underlying problem is fixed ``--verify-data`` leaves chunks it could not read in place instead of deleting them. Fix the storage hardware, filesystem or network first, then run the check again. +Only ``borg check`` goes on like this. Other commands stop with the read error rather +than work with a partially readable repository - e.g. ``borg prune`` would otherwise +see an archive whose metadata it could not read as undated and thus as the oldest one. + About repair mode +++++++++++++++++ diff --git a/src/borg/archive.py b/src/borg/archive.py index ec93078a13..e0635406d7 100644 --- a/src/borg/archive.py +++ b/src/borg/archive.py @@ -2505,23 +2505,33 @@ def valid_archive(obj): if sig_int: break pi.show() - cdata = self.repository.get(chunk_id, read_data=False) # only get metadata try: + cdata = self.repository.get(chunk_id, read_data=False) # only get metadata meta = self.repo_objs.parse_meta(chunk_id, cdata, ro_type=ROBJ_DONTCARE) except IntegrityErrorBase as exc: logger.error("Skipping corrupted chunk: %s", exc) self.error_found = True continue + except Repository.StoreReadError as exc: + # unreadable, not corrupt: this scan only looks for archive metadata, so skipping + # such a chunk can at worst miss a lost archive - it never drops data, refs #3509. + logger.error("Skipping unreadable chunk: %s", exc) + self.error_found = True + continue if meta["type"] != ROBJ_ARCHIVE_META: continue # now we know it is an archive metadata chunk, load the full object from the repo: - cdata = self.repository.get(chunk_id) try: + cdata = self.repository.get(chunk_id) meta, data = self.repo_objs.parse(chunk_id, cdata, ro_type=ROBJ_DONTCARE) except IntegrityErrorBase as exc: logger.error("Skipping corrupted chunk: %s", exc) self.error_found = True continue + except Repository.StoreReadError as exc: + logger.error("Skipping unreadable chunk: %s", exc) + self.error_found = True + continue if meta["type"] != ROBJ_ARCHIVE_META: continue # should never happen try: @@ -2735,6 +2745,9 @@ def valid_item(obj): newest=newest, older=older, newer=newer, + # an archive whose metadata we can not read gets a placeholder entry here, so the + # other archives still get checked; the loop below reports it, refs #3509. + tolerate_read_errors=True, ) if match and not archive_infos: logger.warning("--match-archives %s does not match any archives", match) @@ -2743,7 +2756,7 @@ def valid_item(obj): if last and len(archive_infos) < last: logger.warning("--last %d archives: only found %d archives", last, len(archive_infos)) else: - archive_infos = self.manifest.archives.list(sort_by=sort_by) + archive_infos = self.manifest.archives.list(sort_by=sort_by, tolerate_read_errors=True) num_archives = len(archive_infos) formatter = ArchiveFormatter(self.format, self.repository, self.manifest, self.key) @@ -2763,9 +2776,15 @@ def valid_item(obj): try: try: formatted = formatter.format_item(info, jsonline=False) - except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase): - # keys like {comment} need the archive metadata, which is damaged or missing here. - # use the values from the archive directory entry, they are always available. + except ( + Archive.DoesNotExist, + Repository.ObjectNotFound, + IntegrityErrorBase, + Repository.StoreReadError, + ): + # keys like {comment} need the archive metadata, which is damaged, missing or + # unreadable here. use the values from the archive directory entry, they are + # always available. formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}" logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})") if archive_id not in self.chunks: diff --git a/src/borg/archiver/check_cmd.py b/src/borg/archiver/check_cmd.py index 80c12f2f29..4796933455 100644 --- a/src/borg/archiver/check_cmd.py +++ b/src/borg/archiver/check_cmd.py @@ -227,6 +227,10 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser): ``--verify-data`` leaves chunks it could not read in place instead of deleting them. Fix the storage hardware, filesystem or network first, then run the check again. + Only ``borg check`` goes on like this. Other commands stop with the read error rather + than work with a partially readable repository - e.g. ``borg prune`` would otherwise + see an archive whose metadata it could not read as undated and thus as the oldest one. + About repair mode +++++++++++++++++ diff --git a/src/borg/manifest.py b/src/borg/manifest.py index de5c6606fb..6e12c3c512 100644 --- a/src/borg/manifest.py +++ b/src/borg/manifest.py @@ -189,12 +189,28 @@ def ids(self, *, deleted=False): info = ItemInfo(*info) # RPC does not give us a NamedTuple yield hex_to_bin(info.name) - def _get_archive_meta(self, id: bytes) -> dict: + def _get_archive_meta(self, id: bytes, *, tolerate_read_errors: bool = False) -> dict: # get all metadata directly from the ArchiveItem in the repo. from .repository import Repository try: cdata = self.repository.get(id) + except Repository.StoreReadError: + # the archive metadata could not be read at all (I/O error, refs #3509). only borg check + # opts into a placeholder here, so it can go on and check the other archives. everybody + # else must not act on a repository it can not fully read: the placeholder's 1970 + # timestamp would e.g. make prune treat the archive as the oldest one. + if not tolerate_read_errors: + raise + metadata = dict( + id=id, + name="archive-metadata-could-not-be-read", + time="1970-01-01T00:00:00.000000", + exists=False, # we have the pointer, but we could not read the archive item + username="", + hostname="", + tags=(), + ) except Repository.ObjectNotFound: metadata = dict( id=id, @@ -239,13 +255,13 @@ def _get_archive_meta(self, id: bytes) -> dict: ) return metadata - def _infos(self, *, deleted=False): + def _infos(self, *, deleted=False, tolerate_read_errors=False): # yield the infos of all archives for id in self.ids(deleted=deleted): - yield self._get_archive_meta(id) + yield self._get_archive_meta(id, tolerate_read_errors=tolerate_read_errors) - def _info_tuples(self, *, deleted=False): - for info in self._infos(deleted=deleted): + def _info_tuples(self, *, deleted=False, tolerate_read_errors=False): + for info in self._infos(deleted=deleted, tolerate_read_errors=tolerate_read_errors): yield ArchiveInfo( name=info["name"], id=info["id"], @@ -255,8 +271,8 @@ def _info_tuples(self, *, deleted=False): host=info["hostname"], ) - def _matching_info_tuples(self, match_patterns, match_end, *, deleted=False): - archive_infos = list(self._info_tuples(deleted=deleted)) + def _matching_info_tuples(self, match_patterns, match_end, *, deleted=False, tolerate_read_errors=False): + archive_infos = list(self._info_tuples(deleted=deleted, tolerate_read_errors=tolerate_read_errors)) if match_patterns: assert isinstance(match_patterns, list), f"match_pattern is a {type(match_patterns)}" for match in match_patterns: @@ -414,6 +430,7 @@ def list( oldest=None, newest=None, deleted=False, + tolerate_read_errors=False, ): """ Return list of ArchiveInfo instances according to the parameters. @@ -435,7 +452,9 @@ def list( if isinstance(sort_by, (str, bytes)): raise TypeError("sort_by must be a sequence of str") - archive_infos = self._matching_info_tuples(match, match_end, deleted=deleted) + archive_infos = self._matching_info_tuples( + match, match_end, deleted=deleted, tolerate_read_errors=tolerate_read_errors + ) if any([oldest, newest, older, newer]): archive_infos = filter_archives_by_date( diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index 7b8e5a94ae..455ec7d372 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -1217,6 +1217,22 @@ def some_pack_name(archiver): return sorted(info.name for info in repository.store_list("packs"))[0] +def pack_name_of(archiver, chunk_id): + """Return the name of the pack file holding chunk_id.""" + with Repository(archiver.repository_location, exclusive=True) as repository: + return bin_to_hex(repository.chunks[chunk_id].pack_id) + + +def file_content_chunk_id(archiver, archive_name="archive1"): + """Return the id of a file content chunk of the given archive.""" + archive, repository = open_archive(archiver.repository_path, archive_name) + with repository: + for item in archive.iter_items(): + if item.path.endswith(src_file): + return item.chunks[-1].id + raise AssertionError(f"{src_file} not found in {archive_name}") + + def test_check_unreadable_pack(archivers, request, monkeypatch): # an I/O error while reading a pack must not crash the check with a traceback: it is reported, # the check goes on and fails at the end, refs #3509. @@ -1278,7 +1294,8 @@ def test_check_verify_data_unreadable_pack_keeps_chunks(archivers, request, monk if archiver.get_kind() != "local": pytest.skip("only works locally, patches objects") check_cmd_setup(archiver) - pack_name = some_pack_name(archiver) + # target the pack holding file content, so --verify-data is what reads it. + pack_name = pack_name_of(archiver, file_content_chunk_id(archiver)) with Repository(archiver.repository_location, exclusive=True) as repository: chunks_before = sorted(chunk_id for chunk_id, _ in repository.chunks.iteritems()) state = make_pack_unreadable(monkeypatch, pack_name) @@ -1290,3 +1307,38 @@ def test_check_verify_data_unreadable_pack_keeps_chunks(archivers, request, monk with Repository(archiver.repository_location, exclusive=True) as repository: chunks_after = sorted(chunk_id for chunk_id, _ in repository.chunks.iteritems()) assert chunks_after == chunks_before # nothing was thrown away + + +def test_check_unreadable_archive_metadata_pack(archivers, request, monkeypatch): + # the pack holding an archive's metadata is unreadable: listing the archives must not die, the + # affected archive is reported and the other archives still get checked, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + archive, repository = open_archive(archiver.repository_path, "archive1") + with repository: + archive_id = archive.id + pack_name = pack_name_of(archiver, archive_id) + make_pack_unreadable(monkeypatch, pack_name) + + output = cmd(archiver, "check", "--archives-only", exit_code=1) + assert "could not be checked" in output + assert "Input/output error" in output + assert "Archive consistency check complete, problems found." in output + + +def test_unreadable_archive_metadata_pack_does_not_fake_an_archive(archivers, request, monkeypatch): + # outside of borg check, an unreadable archive metadata object must not turn into a placeholder + # entry: acting on a repository we can not fully read (e.g. prune, which would see the + # placeholder's 1970 timestamp) is how transient I/O errors become data loss, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + archive, repository = open_archive(archiver.repository_path, "archive1") + with repository: + archive_id = archive.id + make_pack_unreadable(monkeypatch, pack_name_of(archiver, archive_id)) + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "repo-list") diff --git a/src/borg/testsuite/archives_test.py b/src/borg/testsuite/archives_test.py index 59c4d33896..8c4ec2920e 100644 --- a/src/borg/testsuite/archives_test.py +++ b/src/borg/testsuite/archives_test.py @@ -53,13 +53,15 @@ def _archiveinfo(name, id_, ts=TS, *, username="", hostname="", tags=()): def _stub_matching_info_tuples(infos): ar, _, _ = _archives() - ar._matching_info_tuples = Mock(side_effect=lambda match_patterns, match_end, deleted=False: list(infos)) + ar._matching_info_tuples = Mock( + side_effect=lambda match_patterns, match_end, deleted=False, tolerate_read_errors=False: list(infos) + ) return ar def _stub_info_tuples(infos): ar, _, _ = _archives() - ar._info_tuples = Mock(side_effect=lambda deleted=False: iter(infos)) + ar._info_tuples = Mock(side_effect=lambda deleted=False, tolerate_read_errors=False: iter(infos)) return ar @@ -438,9 +440,9 @@ def test_list_date_filter(): def test_list_deleted_passes_flag(): ar, _, _ = _archives() - ar._info_tuples = Mock(side_effect=lambda deleted=False: iter([])) + ar._info_tuples = Mock(side_effect=lambda deleted=False, tolerate_read_errors=False: iter([])) ar.list(deleted=True) - ar._info_tuples.assert_called_once_with(deleted=True) + ar._info_tuples.assert_called_once_with(deleted=True, tolerate_read_errors=False) def test_list_match_name(): @@ -537,9 +539,10 @@ def test_get_one_multiple_matches_raises(): def test_get_one_deleted_passes_flag(): i1 = _archiveinfo("a", _id(1)) ar, _, _ = _archives() - ar._info_tuples = Mock(side_effect=lambda deleted=False: iter([i1])) + ar._info_tuples = Mock(side_effect=lambda deleted=False, tolerate_read_errors=False: iter([i1])) ar.get_one(["a"], deleted=True) - ar._info_tuples.assert_called_once_with(deleted=True) + # get_one never opts into tolerance: it must not return a placeholder for an unreadable archive. + ar._info_tuples.assert_called_once_with(deleted=True, tolerate_read_errors=False) def test_list_considering_raises_if_name_set(): From 61002074cf3c3bb5f2113ade585539778eacfac2 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Mon, 24 Aug 2026 19:59:15 +0200 Subject: [PATCH 3/4] check: narrow the archive read-error handling, and test it, refs #3509 Instead of one try around the whole per-archive body, catch the read error at the two places that can raise it: reading the archive metadata block, and reading the item metadata stream. Both are precise about what failed, neither can swallow a read error from somewhere unexpected, and the body stays where it was, so the diff is readable. Also add tests for the branches the first two commits left untested: an unreadable namespace listing, an unreadable index object, --repair stopping at an unreadable pack while rebuilding the index, --repair stopping at unreadable archive metadata (with the archive left intact), --find-lost-archives skipping an unreadable chunk, and the one that matters most - a defect chunk whose re-read fails is kept rather than deleted, which is how a flaky disk would otherwise talk borg into throwing data away. The failure injection is now one helper taking a per-read predicate and an "after N reads" counter, so a test can fail one object, one range, one namespace, or only the second read of something. --- src/borg/archive.py | 117 +++++------ src/borg/testsuite/archiver/check_cmd_test.py | 193 ++++++++++++++++-- 2 files changed, 237 insertions(+), 73 deletions(-) diff --git a/src/borg/archive.py b/src/borg/archive.py index e0635406d7..5f749db3eb 100644 --- a/src/borg/archive.py +++ b/src/borg/archive.py @@ -2774,72 +2774,75 @@ def valid_item(obj): pi.show(i) archive_id, archive_id_hex = info.id, bin_to_hex(info.id) try: - try: - formatted = formatter.format_item(info, jsonline=False) - except ( - Archive.DoesNotExist, - Repository.ObjectNotFound, - IntegrityErrorBase, - Repository.StoreReadError, - ): - # keys like {comment} need the archive metadata, which is damaged, missing or - # unreadable here. use the values from the archive directory entry, they are - # always available. - formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}" - logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})") - if archive_id not in self.chunks: - logger.error(f"Archive metadata block {archive_id_hex} is missing!") - self.error_found = True - if self.repair: - logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") - self.manifest.archives.delete_by_id(archive_id) - else: - logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") - continue + formatted = formatter.format_item(info, jsonline=False) + except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase, Repository.StoreReadError): + # keys like {comment} need the archive metadata, which is damaged, missing or + # unreadable here. use the values from the archive directory entry, they are + # always available. + formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}" + logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})") + if archive_id not in self.chunks: + logger.error(f"Archive metadata block {archive_id_hex} is missing!") + self.error_found = True + if self.repair: + logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") + self.manifest.archives.delete_by_id(archive_id) + else: + logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") + continue + try: cdata = self.repository.get(archive_id) - try: - _, data = self.repo_objs.parse(archive_id, cdata, ro_type=ROBJ_ARCHIVE_META) - except IntegrityErrorBase as integrity_error: - logger.error(f"Archive metadata block {archive_id_hex} is corrupted: {integrity_error}") - self.error_found = True - if self.repair: - logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") - self.manifest.archives.delete_by_id(archive_id) - else: - logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") - continue - archive = self.key.unpack_archive(data) - archive = ArchiveItem(internal_dict=archive) - if archive.version != 2: - raise Exception("Unknown archive metadata version") - items_buffer = ChunkBuffer(self.key) - items_buffer.write_chunk = add_callback + _, data = self.repo_objs.parse(archive_id, cdata, ro_type=ROBJ_ARCHIVE_META) + except Repository.StoreReadError as err: + # unreadable, not corrupt: we did not see the metadata, so we can not tell + # whether this archive is fine - and must not "repair" it away, refs #3509. + logger.error(f"Archive metadata block {archive_id_hex} could not be read: {err}") + self.error_found = True + if self.repair: + raise + continue + except IntegrityErrorBase as integrity_error: + logger.error(f"Archive metadata block {archive_id_hex} is corrupted: {integrity_error}") + self.error_found = True + if self.repair: + logger.error(f"Deleting broken archive {info.name} {archive_id_hex}.") + self.manifest.archives.delete_by_id(archive_id) + else: + logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.") + continue + archive = self.key.unpack_archive(data) + archive = ArchiveItem(internal_dict=archive) + if archive.version != 2: + raise Exception("Unknown archive metadata version") + items_buffer = ChunkBuffer(self.key) + items_buffer.write_chunk = add_callback + try: for item in robust_iterator(archive): if "chunks" in item: verify_file_chunks(info.name, item) items_buffer.add(item) - items_buffer.flush(flush=True) - if self.repair: - archive.item_ptrs = archive_put_items( - items_buffer.chunks, repo_objs=self.repo_objs, add_reference=add_reference - ) - data = self.key.pack_metadata(archive.as_dict()) - new_archive_id = self.key.id_hash(data) - logger.debug(f"archive id old: {bin_to_hex(archive_id)}") - logger.debug(f"archive id new: {bin_to_hex(new_archive_id)}") - cdata = self.repo_objs.format(new_archive_id, {}, data, ro_type=ROBJ_ARCHIVE_META) - add_reference(new_archive_id, len(data), cdata) - self.manifest.archives.create(info.name, new_archive_id, info.ts) - if archive_id != new_archive_id: - self.manifest.archives.delete_by_id(archive_id) except Repository.StoreReadError as err: - # some object of this archive could not be read at all (I/O error, refs #3509). - # we do not know what is in it, so we can not tell whether the archive is fine. - logger.error(f"Archive {info.name} {archive_id_hex} could not be checked: {err}") + # part of the item metadata stream could not be read (see above): rewriting the + # archive from what we did read would drop the rest of it, refs #3509. + logger.error(f"Archive {info.name} {archive_id_hex} could not be read fully: {err}") self.error_found = True if self.repair: - # rewriting the archive now would drop whatever we could not read from it. raise + continue + items_buffer.flush(flush=True) + if self.repair: + archive.item_ptrs = archive_put_items( + items_buffer.chunks, repo_objs=self.repo_objs, add_reference=add_reference + ) + data = self.key.pack_metadata(archive.as_dict()) + new_archive_id = self.key.id_hash(data) + logger.debug(f"archive id old: {bin_to_hex(archive_id)}") + logger.debug(f"archive id new: {bin_to_hex(new_archive_id)}") + cdata = self.repo_objs.format(new_archive_id, {}, data, ro_type=ROBJ_ARCHIVE_META) + add_reference(new_archive_id, len(data), cdata) + self.manifest.archives.create(info.name, new_archive_id, info.ts) + if archive_id != new_archive_id: + self.manifest.archives.delete_by_id(archive_id) finally: pi.finish() report_missing_chunks() diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index 455ec7d372..ff49d818a9 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -1179,38 +1179,70 @@ def test_items_with_unknown_keys_are_kept(archivers, request): assert "keys unknown to this borg version" in output # still just the warning -def make_pack_unreadable(monkeypatch, pack_name): - """Make reading the pack packs/ fail with an OSError, like failing storage does. +def make_store_reads_fail(monkeypatch, should_fail, *, after=0): + """Make matching posixfs reads fail with an OSError, like failing storage does. + + should_fail(name, offset, size) decides per read; offset/size are None for the operations that + do not take a range (hash, info, list). The first matching reads still succeed, which + models storage that starts failing (or fails only sometimes) rather than being dead from the + start. - Patches the posixfs backend rather than using file permissions, so it also works when the tests - run as root and does not depend on the platform's permission semantics. Returns a dict whose + Patches the backend rather than using file permissions, so this also works when the tests run + as root and does not depend on the platform's permission semantics. Returns a dict whose "failing" entry switches the failures off again (monkeypatch.undo() must not be used here, it would also revert the autouse clean_env fixture). """ from borgstore.backends.posixfs import PosixFS - state = {"failing": True} - orig_hash, orig_load = PosixFS.hash, PosixFS.load + state = {"failing": True, "hits": 0} + orig = {name: getattr(PosixFS, name) for name in ("hash", "load", "info", "list")} - def hits_pack(name): - # the backend gets the name including borgstore's nesting levels, e.g. packs/d0/d0a6... - return state["failing"] and name.rsplit("/", 1)[-1] == pack_name + def check(name, offset=None, size=None): + if not (state["failing"] and should_fail(name, offset, size)): + return + state["hits"] += 1 + if state["hits"] > after: + raise OSError(errno.EIO, "Input/output error", name) def failing_hash(self, name, algorithm="sha256"): - if hits_pack(name): - raise OSError(errno.EIO, "Input/output error", name) - return orig_hash(self, name, algorithm=algorithm) + check(name) + return orig["hash"](self, name, algorithm=algorithm) def failing_load(self, name, *, size=None, offset=0): - if hits_pack(name): - raise OSError(errno.EIO, "Input/output error", name) - return orig_load(self, name, size=size, offset=offset) + check(name, offset, size) + return orig["load"](self, name, size=size, offset=offset) + + def failing_info(self, name): + check(name) + return orig["info"](self, name) + + def failing_list(self, name): + check(name) + return orig["list"](self, name) monkeypatch.setattr(PosixFS, "hash", failing_hash) monkeypatch.setattr(PosixFS, "load", failing_load) + monkeypatch.setattr(PosixFS, "info", failing_info) + monkeypatch.setattr(PosixFS, "list", failing_list) return state +def object_name(name): + """Return the object's own name, without the nesting levels borgstore puts in front of it.""" + # the backend gets the name including those levels, e.g. packs/d0/d0a6... for packs/d0a6... + return name.rsplit("/", 1)[-1] + + +def make_pack_unreadable(monkeypatch, pack_name): + """Make every read of the pack packs/ fail.""" + return make_store_reads_fail(monkeypatch, lambda name, offset, size: object_name(name) == pack_name) + + +def make_namespace_listing_fail(monkeypatch, namespace): + """Make listing the given store namespace fail.""" + return make_store_reads_fail(monkeypatch, lambda name, offset, size: name.split("/")[0] == namespace) + + def some_pack_name(archiver): """Return the name of one of the repository's pack files.""" with Repository(archiver.repository_location, exclusive=True) as repository: @@ -1323,7 +1355,7 @@ def test_check_unreadable_archive_metadata_pack(archivers, request, monkeypatch) make_pack_unreadable(monkeypatch, pack_name) output = cmd(archiver, "check", "--archives-only", exit_code=1) - assert "could not be checked" in output + assert f"Archive metadata block {bin_to_hex(archive_id)} could not be read" in output assert "Input/output error" in output assert "Archive consistency check complete, problems found." in output @@ -1342,3 +1374,132 @@ def test_unreadable_archive_metadata_pack_does_not_fake_an_archive(archivers, re make_pack_unreadable(monkeypatch, pack_name_of(archiver, archive_id)) with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates cmd(archiver, "repo-list") + + +def test_check_unreadable_packs_listing(archivers, request, monkeypatch): + # without a listing we do not know what to check, so this one is fatal - but it must end the + # check with a clear message instead of a traceback, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + make_namespace_listing_fail(monkeypatch, "packs") + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "check", "--repository-only") + + +def test_check_unreadable_index_object(archivers, request, monkeypatch): + # an unreadable index object is reported and the check goes on to the packs. the missing-pack + # cross-check needs the index too, so it is skipped rather than reporting bogus results, #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + with Repository(archiver.repository_location, exclusive=True) as repository: + index_name = sorted(info.name for info in repository.store_list("index"))[0] + make_store_reads_fail(monkeypatch, lambda name, offset, size: object_name(name) == index_name) + + output = cmd(archiver, "check", "-v", "--repository-only", exit_code=1) + assert f"Store object index/{index_name} could not be read" in output + assert "skipping missing-pack detection" in output + assert "Finished checking packs." in output # the packs were checked anyway + assert "store object(s) could not be read" in output + + +def test_check_repair_unreadable_pack_aborts_index_rebuild(archivers, request, monkeypatch): + # --repair rebuilds the chunk index from the packs' object headers. an unreadable pack stops + # that with a clear error: an index rebuilt without its objects would drop them, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + make_pack_unreadable(monkeypatch, some_pack_name(archiver)) + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "check", "--archives-only", "--repair") + + +def test_verify_data_repair_keeps_a_chunk_that_fails_to_re_read(archivers, request, monkeypatch): + # --verify-data --repair deletes a chunk only after its content failed to verify twice. if the + # second read fails outright, we did not see the content again, so the chunk must stay: this is + # exactly how a flaky disk would otherwise talk borg into throwing data away, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + chunk_id = file_content_chunk_id(archiver) + with Repository(archiver.repository_location, exclusive=True) as repository: + entry = repository.chunks[chunk_id] + corrupt_chunk_on_disk(repository, chunk_id) + pack_name = bin_to_hex(entry.pack_id) + # fail reads of exactly this object, and only from the second one on (a bad spot in the pack + # that the first read still got through): the first read returns the corrupted content, so the + # chunk lands in the defect list, and the re-read that would confirm it fails. matching on the + # object's full range leaves the pack's header scan (a short read at the same offset) working, + # so rebuilding the chunk index from the packs still succeeds. + make_store_reads_fail( + monkeypatch, + lambda name, offset, size: ( + object_name(name) == pack_name and offset == entry.obj_offset and size == entry.obj_size + ), + after=1, + ) + + output = cmd(archiver, "check", "--repair", "--verify-data", "--archives-only", exit_code=0) + assert "not deleted, could not be re-read" in output + with Repository(archiver.repository_location, exclusive=True) as repository: + assert chunk_id in repository.chunks # the chunk is still there + + +def test_find_lost_archives_skips_unreadable_chunk(archivers, request, monkeypatch): + # the --find-lost-archives scan only looks for archive metadata, so skipping an unreadable + # chunk can at worst miss a lost archive - it never drops data, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + make_pack_unreadable(monkeypatch, pack_name_of(archiver, file_content_chunk_id(archiver))) + + output = cmd(archiver, "check", "--archives-only", "--find-lost-archives", exit_code=1) + assert "Skipping unreadable chunk" in output + + +def test_unreadable_archives_listing_is_not_an_empty_repository(archivers, request, monkeypatch): + # a namespace listing that fails must not look like "the namespace is empty" - that would make + # e.g. repo-list report a repository with no archives at all, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + make_namespace_listing_fail(monkeypatch, "archives") + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "repo-list") + + +def test_check_repair_stops_at_unreadable_archive_metadata(archivers, request, monkeypatch): + # a bad spot inside an otherwise readable pack: the chunk index still rebuilds from the pack's + # headers, so --repair gets as far as the archive itself - and must stop there rather than + # rewrite the archive around metadata it never read, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + archive, repository = open_archive(archiver.repository_path, "archive1") + with repository: + archive_id = archive.id + entry = repository.chunks[archive_id] + pack_name = bin_to_hex(entry.pack_id) + # fail reads of the archive metadata object only; the short header reads at the same offset + # (and every other object in the pack) keep working. + state = make_store_reads_fail( + monkeypatch, + lambda name, offset, size: ( + object_name(name) == pack_name and offset == entry.obj_offset and size == entry.obj_size + ), + ) + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "check", "--archives-only", "--repair") + + # the archive is untouched: once it reads again, it is still there and still checks out. + state["failing"] = False + assert "archive1" in cmd(archiver, "repo-list") + cmd(archiver, "check", exit_code=0) From 7e7c01ab29c61febd1c7a27f63340909db9e0047 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Tue, 15 Sep 2026 23:00:36 +0200 Subject: [PATCH 4/4] check: do not rebuild a manifest that could not be read, refs #3509 Repository.get_manifest() only turned a missing manifest into NoManifestError; any other read failure escaped as a raw OSError, so borg check died with a traceback on it. It now raises StoreReadError. It must not become NoManifestError: check --repair rebuilds a missing manifest, and replacing one we merely could not read is the kind of repair around unreadable data this PR prevents. Co-Authored-By: Claude Opus 5 --- src/borg/repository.py | 3 +++ src/borg/testsuite/archiver/check_cmd_test.py | 16 ++++++++++++++++ 2 files changed, 19 insertions(+) diff --git a/src/borg/repository.py b/src/borg/repository.py index f097941e3c..22578d9d6d 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -1983,6 +1983,9 @@ def get_manifest(self): return self.store.load("config/manifest") except StoreObjectNotFound: raise NoManifestError + except OSError as exc: + # not "no manifest": check --repair must not rebuild a manifest it merely could not read, #3509. + raise self.StoreReadError("config/manifest", exc) from exc def put_manifest(self, data): self._lock_refresh() diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index ff49d818a9..b4781e37bc 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -1503,3 +1503,19 @@ def test_check_repair_stops_at_unreadable_archive_metadata(archivers, request, m state["failing"] = False assert "archive1" in cmd(archiver, "repo-list") cmd(archiver, "check", exit_code=0) + + +def test_check_repair_unreadable_manifest_is_not_rebuilt(archivers, request, monkeypatch): + # an unreadable manifest is not a missing one: --repair must stop instead of replacing it with + # a rebuilt one, refs #3509. + archiver = request.getfixturevalue(archivers) + if archiver.get_kind() != "local": + pytest.skip("only works locally, patches objects") + check_cmd_setup(archiver) + state = make_store_reads_fail(monkeypatch, lambda name, offset, size: name == "config/manifest") + with pytest.raises(Repository.StoreReadError): # local (not forked): the Error propagates + cmd(archiver, "check", "--repair", "--archives-only") + + state["failing"] = False + assert "archive1" in cmd(archiver, "repo-list") # the manifest was left alone + cmd(archiver, "check", exit_code=0)