diff --git a/src/borg/archive.py b/src/borg/archive.py index 541e69e2d2..2a08330be3 100644 --- a/src/borg/archive.py +++ b/src/borg/archive.py @@ -2249,6 +2249,9 @@ def __init__(self): self.chunks_modified = False # ids of the packs repair wrote: stored by put() and flush(), or written by delete() rewriting a pack. self.written_packs = set() + # ids of the objects with ro_type ROBJ_ARCHIVE_META that verify_data found. + # None if verify_data did not run or was interrupted. + self.archive_meta_ids = None def record_stored(self, results): """Add the pack ids in results to written_packs. @@ -2397,6 +2400,7 @@ def verify_data(self): errors = 0 verified = 0 # chunks actually verified defect_chunks = [] + archive_meta_ids = set() pi = ProgressIndicatorPercent( total=chunks_count, msg="Verifying data %6.2f%%", step=0.01, msgid="check.verify_data" ) @@ -2413,13 +2417,15 @@ def verify_data(self): # we must decompress, so it'll call assert_id() in there. # this is the audit that re-certifies the id/content invariant, so it reads at its # own place, which always verifies and can not be switched off, see BORG_ASSERT_ID. - self.repo_objs.parse( + meta, _ = self.repo_objs.parse( chunk_id, encrypted_data, decompress=True, ro_type=ROBJ_DONTCARE, assert_id_place="verify_data", ) + if meta["type"] == ROBJ_ARCHIVE_META: + archive_meta_ids.add(chunk_id) except IntegrityErrorBase as integrity_error: self.error_found = True errors += 1 @@ -2456,7 +2462,7 @@ def verify_data(self): try: encrypted_data = self.repository.get(defect_chunk) # we must decompress, so it'll call assert_id() in there (see above): - self.repo_objs.parse( + meta, _ = self.repo_objs.parse( defect_chunk, encrypted_data, decompress=True, @@ -2477,10 +2483,15 @@ def verify_data(self): self.written_packs.add(new_pack_id) else: logger.warning("chunk %s not deleted, did not consistently fail.", bin_to_hex(defect_chunk)) + if meta["type"] == ROBJ_ARCHIVE_META: + archive_meta_ids.add(defect_chunk) else: 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 not sig_int: + # the ids of an interrupted pass are incomplete. + self.archive_meta_ids = archive_meta_ids log = logger.error if errors else logger.info if sig_int: log( @@ -2500,11 +2511,13 @@ def verify_data(self): def rebuild_archives_directory(self): """Rebuild the archives directory, undeleting archives. - Iterates through all objects in the repository looking for archive metadata blocks. - When finding some that do not have a corresponding archives directory entry (either - a normal entry for an "existing" archive, or a soft-deleted entry for a "deleted" - archive), it will create that entry (making the archives directory consistent with - the repository). + Reads the archive metadata objects (ro_type ROBJ_ARCHIVE_META) in the repository. When + finding some that do not have a corresponding archives directory entry (either a normal + entry for an "existing" archive, or a soft-deleted entry for a "deleted" archive), it will + create that entry (making the archives directory consistent with the repository). + + If self.archive_meta_ids is not None, it reads only these objects. Otherwise, it reads the + meta dict (ro_type and other object metadata, without the data) of every object to find them. """ def valid_archive(obj): @@ -2512,41 +2525,24 @@ def valid_archive(obj): return False return REQUIRED_ARCHIVE_KEYS.issubset(obj) - logger.info("Rebuilding missing archives directory entries, this might take some time...") - pi = ProgressIndicatorPercent( - total=len(self.chunks), - msg="Rebuilding missing archives directory entries %6.2f%%", - step=0.01, - msgid="check.rebuild_archives_directory", - ) - for chunk_id, _ in self.chunks.iteritems(): - if sig_int: - break - pi.show() - 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 - if meta["type"] != ROBJ_ARCHIVE_META: - continue - # now we know it is an archive metadata chunk, load the full object from the repo: + def check_archive_meta(chunk_id): + """Load the archive metadata object chunk_id. If it has no archives directory entry, create one + (with --repair) or log that it would create one. + """ cdata = self.repository.get(chunk_id) try: 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 + return if meta["type"] != ROBJ_ARCHIVE_META: - continue # should never happen + return # should never happen try: archive = msgpack.unpackb(data) # Ignore exceptions that might be raised when feeding msgpack with invalid data except msgpack.UnpackException: - continue + return if valid_archive(archive): archive = self.key.unpack_archive(data) archive = ArchiveItem(internal_dict=archive) @@ -2566,6 +2562,38 @@ def valid_archive(obj): else: logger.warning(f"Would create archives directory entry for {name} {archive_id_hex}.") + if self.archive_meta_ids is not None: + logger.info("Rebuilding missing archives directory entries...") + logger.debug("Using the %d archive metadata objects found by verify_data.", len(self.archive_meta_ids)) + # sorted, so the entries are logged in the same order on every run. + chunk_ids = sorted(self.archive_meta_ids) + total = len(chunk_ids) + else: + logger.info("Rebuilding missing archives directory entries, this might take some time...") + chunk_ids = (chunk_id for chunk_id, _ in self.chunks.iteritems()) + total = len(self.chunks) + pi = ProgressIndicatorPercent( + total=total, + msg="Rebuilding missing archives directory entries %6.2f%%", + step=0.01, + msgid="check.rebuild_archives_directory", + ) + for chunk_id in chunk_ids: + if sig_int: + break + pi.show() + if self.archive_meta_ids is None: + 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 + if meta["type"] != ROBJ_ARCHIVE_META: + continue + check_archive_meta(chunk_id) + pi.finish() if sig_int: logger.info("Rebuilding missing archives directory entries interrupted.") diff --git a/src/borg/archiver/check_cmd.py b/src/borg/archiver/check_cmd.py index 50364adf45..3cccb3c172 100644 --- a/src/borg/archiver/check_cmd.py +++ b/src/borg/archiver/check_cmd.py @@ -238,13 +238,14 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser): which normal reads do not do by default (see ``BORG_ASSERT_ID``). Running it periodically is therefore recommended. - The ``--find-lost-archives`` option will also scan the whole repository, but - tells Borg to search for lost archive metadata. If Borg encounters any archive - metadata that does not match an archive directory entry (including - soft-deleted archives), it means that an entry was lost. - Unless ``borg compact`` is called, these archives can be fully restored with - ``--repair``. Please note that ``--find-lost-archives`` must look at every - object in the repository and is thus very time-consuming. You cannot use + The ``--find-lost-archives`` option tells Borg to search for lost archive + metadata. If Borg encounters any archive metadata that does not match an + archive directory entry (including soft-deleted archives), it means that an + entry was lost. Unless ``borg compact`` is called, these archives can be fully + restored with ``--repair``. Without ``--verify-data``, ``--find-lost-archives`` + reads the metadata of every object in the repository and is thus very + time-consuming. With ``--verify-data``, it reads only the archive metadata + objects that the data verification found. You cannot use ``--find-lost-archives`` with ``--repository-only``. You can influence how the archive part of the ``Analyzing archive ...`` output is diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index 90a03f873f..eb58d3cf78 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -23,7 +23,7 @@ ) from ...crypto.key import RepositoryKeyInfoMissing from ...constants import * # NOQA -from ...helpers import bin_to_hex, CommandError, CorruptPack, Error, sig_int +from ...helpers import bin_to_hex, CommandError, CorruptPack, Error, IntegrityError, sig_int from ...helpers import BackupDamagedChunksError from ...helpers.passphrase import PassphraseWrong from ...hashindex import ChunkIndex @@ -993,7 +993,8 @@ def test_check_repository_only_repair_aborts_on_wrong_passphrase(archivers, requ cmd(archiver, "check", "-v", "--repository-only", "--repair") -def test_check_undelete_archives(archivers, request): +@pytest.mark.parametrize("verify_data_args", [[], ["--verify-data"]]) +def test_check_undelete_archives(archivers, request, verify_data_args): archiver = request.getfixturevalue(archivers) check_cmd_setup(archiver) # creates archive1 and archive2 existing_archive_ids = set(cmd(archiver, "repo-list", "--short").splitlines()) @@ -1006,14 +1007,19 @@ def test_check_undelete_archives(archivers, request): assert "archive2" in output assert "archive3" not in output # borg check will re-discover archive3 and create a new archives directory entry. - cmd(archiver, "check", "--repair", "--find-lost-archives", exit_code=0) + output = cmd(archiver, "check", "--repair", "--find-lost-archives", *verify_data_args, "--debug", exit_code=0) + # with --verify-data, the search uses the 3 archive metadata objects verify_data found. + reused = "Using the 3 archive metadata objects found by verify_data." in output + assert reused == bool(verify_data_args) + assert f"Creating archives directory entry for archive3 {new_archive_id_hex}." in output output = cmd(archiver, "repo-list") assert "archive1" in output assert "archive2" in output assert "archive3" in output -def test_spoofed_archive(archivers, request): +@pytest.mark.parametrize("verify_data_args", [[], ["--verify-data"]]) +def test_spoofed_archive(archivers, request, verify_data_args): archiver = request.getfixturevalue(archivers) check_cmd_setup(archiver) archive, repository = open_archive(archiver.repository_path, "archive1") @@ -1044,7 +1050,7 @@ def test_spoofed_archive(archivers, request): repository.flush() # make the put durable before close()/the check below # the attacker would hope that the search for lost archives picks the fake archive up, but # borg notices that the object has the wrong ro_type. - cmd(archiver, "check", "--repair", "--find-lost-archives", "--debug", exit_code=0) + cmd(archiver, "check", "--repair", "--find-lost-archives", *verify_data_args, "--debug", exit_code=0) output = cmd(archiver, "repo-list") assert "archive1" in output assert "archive2" in output @@ -1713,6 +1719,157 @@ def test_verify_data_reports_a_missing_pack(archivers, request, monkeypatch): assert sorted(loaded) == sorted("packs/" + bin_to_hex(pack_id) for pack_id in packs) +def test_verify_data_collects_archive_meta_ids(archivers, request, monkeypatch): + """verify_data() collects the archive metadata object ids, rebuild_archives_directory() then reads only these.""" + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + cmd(archiver, "delete", "-a", "archive2") # a soft-deleted archive is found, too + archive_ids = {bytes.fromhex(line) for line in cmd(archiver, "repo-list", "--short", "--deleted").splitlines()} + archive_ids |= {bytes.fromhex(line) for line in cmd(archiver, "repo-list", "--short").splitlines()} + assert len(archive_ids) == 2 + with open_repository(archiver) as repository: + checker = _archive_checker(repository) + + checker.verify_data() + + assert checker.archive_meta_ids == archive_ids + checker.manifest = Manifest.load(repository, key=checker.key) + orig_get = repository.get + read_data_args = [] + + def get(id, read_data=True, **kwargs): + read_data_args.append(read_data) + return orig_get(id, read_data=read_data, **kwargs) + + monkeypatch.setattr(repository, "get", get) + + checker.rebuild_archives_directory() + + assert not checker.error_found # both archives have their archives directory entry + assert read_data_args == [True, True] # one full read per archive metadata object + + +def test_verify_data_interrupted_collects_no_archive_meta_ids(archivers, request, monkeypatch): + """An interrupted verify_data() leaves archive_meta_ids at None.""" + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + with open_repository(archiver) as repository: + checker = _archive_checker(repository) + orig_get_many = repository.get_many + + def get_many_then_interrupt(ids, **kwargs): + # Ctrl-C before the first object is verified. + sig_int._sig_int_triggered = True + yield from orig_get_many(ids, **kwargs) + + monkeypatch.setattr(repository, "get_many", get_many_then_interrupt) + try: + checker.verify_data() + finally: + sig_int._sig_int_triggered = False # reset the global flag for the following tests + + assert checker.archive_meta_ids is None + + +def test_verify_data_repair_collects_archive_meta_ids_of_retried_chunks(archivers, request, monkeypatch): + """Objects that fail once, but not on the --repair retry, are kept. Only archive metadata ids are collected.""" + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + archive_ids = {bytes.fromhex(line) for line in cmd(archiver, "repo-list", "--short").splitlines()} + with open_repository(archiver) as repository: + checker = _archive_checker(repository) + checker.repair = True + other_id = next(id for id, _ in checker.chunks.iteritems() if id not in archive_ids) + flaky_ids = {min(archive_ids), other_id} + orig_parse = checker.repo_objs.parse + failed = set() + + def parse_failing_once(id, *args, **kwargs): + if id in flaky_ids and id not in failed: + failed.add(id) + raise IntegrityError("simulated transient read error") + return orig_parse(id, *args, **kwargs) + + monkeypatch.setattr(checker.repo_objs, "parse", parse_failing_once) + + checker.verify_data() + + assert failed == flaky_ids + assert all(id in repository.chunks for id in flaky_ids) # not deleted, the retry succeeded + assert checker.archive_meta_ids == archive_ids + + +@pytest.mark.parametrize("verify_data_args", [[], ["--verify-data"]]) +def test_check_find_lost_archives_corrupt_archive_meta(archivers, request, verify_data_args): + """A corrupt archive metadata object is reported by --verify-data or else by the search for lost archives.""" + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + archive_ids = [bytes.fromhex(line) for line in cmd(archiver, "repo-list", "--short").splitlines()] + with open_repository(archiver) as repository: + corrupt_chunk_on_disk(repository, min(archive_ids)) + output = cmd(archiver, "check", "--find-lost-archives", *verify_data_args, exit_code=1) + assert (f"chunk {bin_to_hex(min(archive_ids))}, integrity error" in output) == bool(verify_data_args) + assert ("Skipping corrupted chunk" in output) == (not verify_data_args) + + +@pytest.mark.parametrize("verify_data", [False, True]) +def test_rebuild_archives_directory_interrupted(archivers, request, monkeypatch, verify_data): + """With sig_int set, rebuild_archives_directory() reads no object.""" + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + with open_repository(archiver) as repository: + checker = _archive_checker(repository) + if verify_data: + checker.verify_data() + assert checker.archive_meta_ids is not None + checker.manifest = Manifest.load(repository, key=checker.key) + read_ids = [] + + def get(id, **kwargs): + read_ids.append(id) + + monkeypatch.setattr(repository, "get", get) + sig_int._sig_int_triggered = True + try: + checker.rebuild_archives_directory() + finally: + sig_int._sig_int_triggered = False # reset the global flag for the following tests + + assert read_ids == [] + + +@pytest.mark.parametrize( + "damage, error_found", [("corrupt", True), ("not_archive_meta", False), ("invalid_msgpack", False)] +) +def test_rebuild_archives_directory_skips_unusable_archive_meta_ids(archivers, request, damage, error_found): + """rebuild_archives_directory() skips an archive_meta_ids object it can not use as archive metadata. + + Only a corrupt object sets error_found. + """ + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + archive_ids = {bytes.fromhex(line) for line in cmd(archiver, "repo-list", "--short").splitlines()} + with open_repository(archiver) as repository: + checker = _archive_checker(repository) + checker.verify_data() + assert checker.archive_meta_ids == archive_ids + checker.manifest = Manifest.load(repository, key=checker.key) + if damage == "corrupt": + corrupt_chunk_on_disk(repository, min(archive_ids)) + elif damage == "not_archive_meta": + checker.archive_meta_ids.add(next(id for id, _ in checker.chunks.iteritems() if id not in archive_ids)) + else: + data = b"\xc1" # a byte msgpack never uses + id = checker.repo_objs.id_hash(data) + repository.put(id, checker.repo_objs.format(id, {}, data, ro_type=ROBJ_ARCHIVE_META)) + repository.flush() + checker.archive_meta_ids.add(id) + + checker.rebuild_archives_directory() + + assert checker.error_found == error_found + + def test_verify_data_wrong_chunk_content(archivers, request, monkeypatch): # a chunk whose content does not match its id (only an evil borg client that had the repo key could # have written it): the AEAD layer authenticates it just fine, only the id check notices, see #9994.