diff --git a/docs/internals/data-structures.rst b/docs/internals/data-structures.rst index 53bb619efd..63d0e1aa6b 100644 --- a/docs/internals/data-structures.rst +++ b/docs/internals/data-structures.rst @@ -36,9 +36,13 @@ config/ cache/ checked-packs - repository check progress (partial checks, full checks' checkpointing), - the set of packs checked so far this cycle (pack id -> timestamp, result), - as a hashtable with an appended integrity hash + repository check results (pack id -> timestamp, result), as a hashtable with an + appended integrity hash. Records are kept across checks: ``check --max-age`` + skips packs whose intact record is younger than the given age, and partial checks + (``--max-duration``) verify the least-recently-checked packs first so repeated + runs cover the whole repository. Records of corrupt packs are kept for repair and + always re-verified. Records of packs no longer listed in packs/ are pruned when a + check finishes. There is a list of pointers to archive objects in this directory: diff --git a/src/borg/archiver/check_cmd.py b/src/borg/archiver/check_cmd.py index 682f3a9279..36e3ceda1b 100644 --- a/src/borg/archiver/check_cmd.py +++ b/src/borg/archiver/check_cmd.py @@ -4,8 +4,9 @@ from ..archive import ArchiveChecker from ..constants import * # NOQA from ..helpers import set_ec, EXIT_WARNING, CancelledByUser, CommandError, IntegrityError -from ..helpers import yes, ArchiveFormatter +from ..helpers import relative_time_marker_validator, yes, ArchiveFormatter from ..helpers.argparsing import ArgumentParser +from ..helpers.time import archive_ts_now, calculate_relative_offset from ..logger import create_logger @@ -42,12 +43,25 @@ def do_check(self, args, repository): ) if args.repo_only and args.find_lost_archives: raise CommandError("--repository-only contradicts the --find-lost-archives option.") + # resolve the marker (e.g. 4w, 12m) to seconds; calendar units (m, y) count from now, as for + # --older/--newer. max_age stays 0 when --max-age is not given, which disables reuse. + if args.max_age is not None: + now = archive_ts_now() + max_age = int((now - calculate_relative_offset(args.max_age, now, earlier=True)).total_seconds()) + else: + max_age = 0 if args.repair and args.max_duration: raise CommandError("--repair does not allow --max-duration argument.") + if args.repair and args.max_age is not None: + # repair verifies every pack; reusing recorded results during repair needs repository + # repair (refs #8572). + raise CommandError("--repair does not allow the --max-age option.") + if args.archives_only and args.max_age is not None: + # --max-age only affects the repository check; --archives-only skips it. + raise CommandError("--archives-only does not allow the --max-age option.") if args.max_duration and not args.repo_only: - # when doing a partial repo check, we can only do a low-level check of the repository files. - # archives check requires that a full repo check was done before and has built/cached a ChunkIndex. - # also, there is no max_duration support in the archives check code anyway. + # --max-duration limits only the repository check; the archives check has no max_duration + # support. raise CommandError("--repository-only is required for --max-duration support.") if not args.repo_only: # if we need the key later for the archives check, ask NOW for the passphrase! #1931 @@ -64,7 +78,7 @@ def do_check(self, args, repository): # the repository check has finished, which can take hours. ArchiveFormatter.validate_format(format) if not args.archives_only: - if not repository.check(repair=args.repair, max_duration=args.max_duration): + if not repository.check(repair=args.repair, max_duration=args.max_duration, max_age=max_age): set_ec(EXIT_WARNING) if not args.repo_only and not archive_checker.check( repository, @@ -118,17 +132,28 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser): repository checks only, or pass ``--archives-only`` to run the archive checks only. - The ``--max-duration`` option can be used to split a long-running repository - check into multiple partial checks. After the given number of seconds, the check - is interrupted. The next partial check will continue where the previous one - stopped, until the full repository has been checked. Assuming a complete check - would take 7 hours, then running a daily check with ``--max-duration=3600`` - (1 hour) would result in one full repository check per week. Doing a full - repository check aborts any previous partial check; the next partial check will - restart from the beginning. With partial repository checks you can run neither - archive checks, nor enable repair mode. Consequently, if you want to use - ``--max-duration`` you must also pass ``--repository-only``, and must not pass - ``--archives-only``, nor ``--repair``. + The ``--max-age`` option makes the check reuse the results of previous + repository checks: packs whose intact result is younger than the given + timespan (e.g. ``--max-age=4w`` or ``--max-age=12m``) are skipped, spreading + the verification cost over repeated checks. The timespan uses the same markers + as ``--older``/``--newer``: ``d``, ``w``, ``H``, ``M``, ``S`` are exact spans, + while ``m`` and ``y`` are calendar units counted from now (so ``12m`` equals + ``1y``). Check results are recorded in any case; ``--max-age`` only controls + their reuse. Packs recorded corrupt are always re-verified. ``--max-age`` + affects only the repository check and cannot be combined with + ``--archives-only`` or ``--repair``. + + The ``--max-duration`` option splits a long-running repository check into + several partial checks. After the given number of seconds, the check is + interrupted. A partial check verifies the least-recently-checked packs first, + so repeated runs cover the whole repository. Add ``--max-age`` to also skip + packs whose result is still younger than the given age: once every pack has a + recent result, further runs re-check each pack about once per ``--max-age``. + Assuming a complete check would take 7 hours, running a daily check with + ``--max-duration=3600 --max-age=1w`` (1 hour) results in one full repository + verification per week. Partial repository checks run neither archive checks + nor repair mode, so ``--max-duration`` requires ``--repository-only`` and + cannot be combined with ``--archives-only`` or ``--repair``. **Warning:** Please note that partial repository checks (i.e., running with ``--max-duration``) can only perform non-cryptographic checksum checks on the @@ -222,6 +247,15 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser): subparser.add_argument( "--find-lost-archives", dest="find_lost_archives", action="store_true", help="attempt to find lost archives" ) + subparser.add_argument( + "--max-age", + metavar="TIMESPAN", + dest="max_age", + type=relative_time_marker_validator, + default=None, + action=Highlander, + help="reuse intact-pack check results younger than TIMESPAN, e.g. 4w or 12m", + ) subparser.add_argument( "--max-duration", metavar="SECONDS", diff --git a/src/borg/constants.py b/src/borg/constants.py index 42b8ea07ce..7d3874a9c6 100644 --- a/src/borg/constants.py +++ b/src/borg/constants.py @@ -71,6 +71,11 @@ # MAX_OBJECT_SIZE = MAX_DATA_SIZE + len(PUT header) MAX_OBJECT_SIZE = MAX_DATA_SIZE + 41 # see assertion at end of repository module +# Clock skew is the difference between the clocks of the machines writing to a repository (seconds). +# A check result timestamp up to this far in the future still counts as recent; further ahead than +# this, the pack is re-verified. +MAX_CLOCK_SKEW = 7200 # [s] + # How many segment files Borg puts into a single directory by default. DEFAULT_SEGMENTS_PER_DIR = 1000 diff --git a/src/borg/repository.py b/src/borg/repository.py index 254c094589..6c3683b640 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -313,11 +313,13 @@ def superseded_gap_ranges(reader, chunks, pack_id, obj_ranges, pack_size): class PackTracker: - """Packs verified in the current check cycle, mapping pack_id -> (timestamp, result). + """Pack verification results, mapping pack_id -> (timestamp, result). - A cycle is one full pass over packs/; --max-duration may spread it over several partial checks. + Records are kept across checks: intact records (result=1) are reused by checks run with + max_age, corrupt records (result=0) are kept for repair and always re-verified. Records of + packs no longer listed in packs/ are pruned when a check finishes scanning packs/. Stored at cache/checked-packs as the serialized table with a sha256 over it appended. - new() starts a cycle, load() resumes the stored one. + new() starts an empty tracker, load() reads the stored one. """ NAME = "cache/checked-packs" @@ -377,6 +379,22 @@ def get(self, pack_id): def record(self, pack_id, ok): self.table[pack_id] = self.Entry(timestamp=int(time.time()), result=int(ok)) + def corrupt_ids(self): + """Return the ids of the packs recorded corrupt, sorted.""" + return sorted(pack_id for pack_id, entry in self.table.items() if not entry.result) + + def prune(self, pack_ids): + """Drop the records whose pack id is not in pack_ids (the set of pack ids listed in packs/), + then store the remaining records (or delete the stored object if none remain). + """ + # the keys are collected first because the table must not be mutated while iterating it. + for pack_id in [pack_id for pack_id, _ in self.table.items() if pack_id not in pack_ids]: + del self.table[pack_id] + if len(self.table): + self.save() + else: + self.clear() + def save(self): with io.BytesIO() as f: self.table.write(f) @@ -803,7 +821,7 @@ def info(self): info = dict(id=self.id, version=self.version) return info - def check(self, repair=False, max_duration=0): + def check(self, repair=False, max_duration=0, max_age=0): """Check repository consistency. packs/ and index/ objects are named by the sha256 of their content, so a pack or index file @@ -815,7 +833,16 @@ def check(self, repair=False, max_duration=0): rebuild re-reads every pack anyway - so a read-only check just stops and reports it instead of continuing. The index is never rebuilt here in any case: reading every pack to do so would be far too slow and expensive for a routine (e.g. cron) check. Salvaging good objects out of - corrupt packs and dropping those packs is left to repair, refs #8572. + corrupt packs and dropping those packs is left to repair, refs #8572. The ids of the packs + found corrupt are kept in cache/checked-packs for repair, refs #9696. + + A pack recorded corrupt fails the check, also on a partial run that stops before re-reaching + it. The record clears at the check that finds the pack intact again or gone (removed by + compact, or salvaged and dropped by repair; refs #8572); prune() does this from packs/. + + max_age (seconds, 0 = verify every pack): skip packs whose intact record is younger than + max_age, accepting a future timestamp up to MAX_CLOCK_SKEW (clock skew). Results are recorded + regardless of max_age. """ def verify(namespace, name): @@ -839,19 +866,17 @@ def store_list(namespace): assert not (repair and partial) mode = "partial" if partial else "full" logger.info(f"Starting {mode} repository check") - if partial: - tracker = PackTracker.load(self.store) - else: - tracker = PackTracker.new(self.store) - tracker.clear() # a full check verifies every pack, so discard the stored cycle - if len(tracker): - logger.info(f"Continuing check cycle, {len(tracker)} packs already checked.") - else: + tracker = PackTracker.load(self.store) + if not len(tracker): logger.info("Starting from beginning.") + elif max_age: + logger.info(f"{len(tracker)} pack check results on record, reusing those younger than --max-age.") + else: + logger.info(f"{len(tracker)} pack check results on record, verifying every pack.") t_start = time.monotonic() t_last_checkpoint = t_start index_files = index_errors = 0 - pack_files = pack_errors = 0 + pack_files = pack_errors = pack_skipped = 0 # index and packs get separate progress indicators, each running from 0% to 100%. # the index is checked first and in full, on partial checks too: it is small, and index errors # stop the pack check below. @@ -875,14 +900,29 @@ def store_list(namespace): if index_errors == 0: # packs are the bulk of the work and the part --max-duration spreads over several checks. pack_infos = store_list("packs") + if partial: + # a partial check stops after max_duration; verify the least-recently-checked packs + # first so repeated runs cover every pack. sort by recorded check time, unrecorded + # (time 0) first. + def recorded_ts(info): + entry = tracker.get(hex_to_bin(info.name)) + return entry.timestamp if entry is not None else 0 + + pack_infos.sort(key=recorded_ts) pack_pi = ProgressIndicatorPercent(total=len(pack_infos), msg="Checking packs %3.0f%%", msgid="check.packs") for info in pack_infos: self._lock_refresh() pack_pi.show(increase=1) # advance for skipped packs too, so the bar tracks packs/, not work done pack_id = hex_to_bin(info.name) entry = tracker.get(pack_id) - if entry is not None and entry.result: # intact in this cycle; a corrupt one is verified again - continue + # skip a pack recorded intact within the last max_age seconds. the timestamp is set + # by the client that ran the earlier check; accept a future one (negative age) up to + # MAX_CLOCK_SKEW, and re-verify anything at or past max_age. + if entry is not None and entry.result and max_age: + age = time.time() - entry.timestamp + if -min(MAX_CLOCK_SKEW, max_age) <= age < max_age: + pack_skipped += 1 + continue pack_files += 1 ok = verify("packs", info.name) if not ok: @@ -895,30 +935,42 @@ def store_list(namespace): logger.info(f"Checkpointing at pack {info.name}.") tracker.save() if partial and now > t_start + max_duration: - logger.info(f"Finished partial repository check, {len(tracker)} packs checked so far.") - tracker.save() + logger.info(f"Finished partial repository check, {len(tracker)} pack check results on record.") break else: - # scanned all packs without hitting the time limit: the cycle is done, drop the set. if pack_infos: pack_pi.show(current=len(pack_infos)) # finish at 100% logger.info("Finished checking packs.") - tracker.clear() + tracker.prune({hex_to_bin(info.name) for info in pack_infos}) pack_pi.finish() else: # TODO: --repair will rebuild the index from the packs here instead of stopping (refs #8572). logger.error("Repository index is corrupted and must be repaired; skipping the pack check.") objs_errors = index_errors + pack_errors - logger.info( - f"Checked {index_files} index files ({index_errors} errors) and {pack_files} packs ({pack_errors} errors)." + summary = ( + f"Checked {index_files} index files ({index_errors} errors) " + f"and {pack_files} packs ({pack_errors} errors)." ) - if objs_errors == 0: + if pack_skipped: + summary += f" Reused {pack_skipped} recent pack check result(s)." + logger.info(summary) + # corrupt_ids() is every pack recorded corrupt, including from earlier runs. with a corrupt + # index the packs were not scanned, so report nothing. + corrupt_ids = tracker.corrupt_ids() if index_errors == 0 else [] + if corrupt_ids: + # one id per line (the list can be long). + 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) + if not problems: logger.info(f"Finished {mode} repository check, no problems found.") elif repair: logger.error(f"Finished {mode} repository check, errors found (repository repair not implemented).") else: logger.error(f"Finished {mode} repository check, errors found.") - return objs_errors == 0 or repair + return not problems or repair def list(self, limit=None, marker=None): """ diff --git a/src/borg/testsuite/archiver/check_cmd_test.py b/src/borg/testsuite/archiver/check_cmd_test.py index ef42ad776b..124235c135 100644 --- a/src/borg/testsuite/archiver/check_cmd_test.py +++ b/src/borg/testsuite/archiver/check_cmd_test.py @@ -74,6 +74,38 @@ def test_check_usage(archivers, request): assert "archive2" in output +def test_check_max_age(archivers, request): + archiver = request.getfixturevalue(archivers) + check_cmd_setup(archiver) + + # --repair and --archives-only do not allow --max-age; 0d is a valid value (resolves to no reuse). + # --max-duration needs --repository-only, but not --max-age: a partial check advances on its own. + if archiver.FORK_DEFAULT: + cmd(archiver, "check", "--repair", "--max-age=1d", exit_code=CommandError().exit_code) + cmd(archiver, "check", "--repair", "--max-age=0d", exit_code=CommandError().exit_code) + cmd(archiver, "check", "--archives-only", "--max-age=1d", exit_code=CommandError().exit_code) + cmd(archiver, "check", "--max-duration=3600", exit_code=CommandError().exit_code) + else: + with pytest.raises(CommandError): + cmd(archiver, "check", "--repair", "--max-age=1d") + with pytest.raises(CommandError): + cmd(archiver, "check", "--repair", "--max-age=0d") + with pytest.raises(CommandError): + cmd(archiver, "check", "--archives-only", "--max-age=1d") + with pytest.raises(CommandError): + cmd(archiver, "check", "--max-duration=3600") + + # a partial check runs without --max-age. + cmd(archiver, "check", "--repository-only", "--max-duration=3600", exit_code=0) + + # a check records its results, a later one with --max-age reuses them. + output = cmd(archiver, "check", "-v", "--repository-only", exit_code=0) + assert "Starting full repository check" in output + output = cmd(archiver, "check", "-v", "--repository-only", "--max-age=4w", exit_code=0) + assert "reusing those younger than --max-age" in output + assert "no problems found" in output + + def test_date_matching(archivers, request): archiver = request.getfixturevalue(archivers) check_cmd_setup(archiver) diff --git a/src/borg/testsuite/repository_test.py b/src/borg/testsuite/repository_test.py index 1e6d7cfd1e..6f26f6935e 100644 --- a/src/borg/testsuite/repository_test.py +++ b/src/borg/testsuite/repository_test.py @@ -1,12 +1,15 @@ import io +import logging import os import sys +import time from collections import namedtuple from hashlib import sha256 import pytest from borghash import HashTableNT +from ..constants import MAX_CLOCK_SKEW from ..helpers import IntegrityError, Location, bin_to_hex from ..hashindex import ChunkIndex from ..repository import Repository, MAX_DATA_SIZE, propagate_rsh, rest_serve_command, PackWriter, PackReader @@ -1041,7 +1044,7 @@ def test_check_partial_rechecks_pack_sorting_before_checked_one(tmp_path): with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: repository.store_store("packs/" + bin_to_hex(intact_id), intact) - # mark the intact pack as already checked in this cycle. + # mark the intact pack as recently checked. tracker = PackTracker.new(repository.store) tracker.record(intact_id, ok=True) tracker.save() @@ -1051,11 +1054,11 @@ def test_check_partial_rechecks_pack_sorting_before_checked_one(tmp_path): assert bin_to_hex(early_id) < bin_to_hex(intact_id) repository.store_store("packs/" + bin_to_hex(early_id), b"CORRUPT-does-not-match-name") - assert repository.check(repair=False, max_duration=3600) is False + assert repository.check(repair=False, max_duration=3600, max_age=3600) is False def test_check_partial_rechecks_pack_recorded_corrupt(tmp_path): - # a pack recorded corrupt earlier in the cycle is re-verified, so the corruption keeps being reported. + # a pack recorded corrupt earlier is re-verified and reported again. with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: corrupt_id = H(1) # stored content does not hash to this name repository.store_store("packs/" + bin_to_hex(corrupt_id), b"CORRUPT-does-not-match-name") @@ -1064,7 +1067,7 @@ def test_check_partial_rechecks_pack_recorded_corrupt(tmp_path): tracker.record(corrupt_id, ok=False) tracker.save() - assert repository.check(repair=False, max_duration=3600) is False + assert repository.check(repair=False, max_duration=3600, max_age=3600) is False def _spy_hash(repository, monkeypatch): @@ -1080,8 +1083,9 @@ def spy_hash(key): return hashed_keys -def _store_intact_pack(repository): - intact = fchunk(b"INTACT", chunk_id=H(1)) +def _store_intact_pack(repository, chunk_id=H(1)): + # a distinct chunk_id yields distinct bytes and thus a distinct sha256 pack id. + intact = fchunk(b"INTACT", chunk_id=chunk_id) intact_id = sha256(intact).digest() pack_key = "packs/" + bin_to_hex(intact_id) repository.store_store(pack_key, intact) @@ -1099,12 +1103,12 @@ def test_check_partial_clears_recorded_corruption_when_intact(tmp_path, monkeypa hashed_keys = _spy_hash(repository, monkeypatch) - assert repository.check(repair=False, max_duration=3600) is True + assert repository.check(repair=False, max_duration=3600, max_age=3600) is True assert pack_key in hashed_keys # re-verified def test_check_partial_skips_pack_recorded_intact(tmp_path, monkeypatch): - # a pack recorded intact in this cycle is skipped when a partial check resumes. + # a pack recorded intact recently is skipped when a partial check resumes. with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: intact_id, pack_key = _store_intact_pack(repository) @@ -1114,12 +1118,12 @@ def test_check_partial_skips_pack_recorded_intact(tmp_path, monkeypatch): hashed_keys = _spy_hash(repository, monkeypatch) - assert repository.check(repair=False, max_duration=3600) is True + assert repository.check(repair=False, max_duration=3600, max_age=3600) is True assert pack_key not in hashed_keys # skipped, not re-verified -def test_check_full_ignores_recorded_set(tmp_path, monkeypatch): - # a full check verifies every pack regardless of the recorded set, then drops the set. +def test_check_without_max_age_verifies_all_but_keeps_records(tmp_path, monkeypatch): + # without max_age, a check verifies every pack regardless of the recorded set, but keeps the records. with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: intact_id, pack_key = _store_intact_pack(repository) @@ -1130,10 +1134,328 @@ def test_check_full_ignores_recorded_set(tmp_path, monkeypatch): hashed_keys = _spy_hash(repository, monkeypatch) assert repository.check(repair=False) is True - assert pack_key in hashed_keys # verified + assert pack_key in hashed_keys # verified despite the fresh intact record + + after = PackTracker.load(repository.store) + assert after.table[intact_id].result == 1 # record kept + + +def _store_corrupt_pack(repository, pack_id): + # the stored content does not hash to pack_id, so verifying it fails. + repository.store_store("packs/" + bin_to_hex(pack_id), b"CORRUPT-does-not-match-name") + return pack_id + + +def test_check_full_keeps_records_after_check(tmp_path): + # a completed check keeps the records of both corrupt and intact packs. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, _ = _store_intact_pack(repository) + corrupt_id = _store_corrupt_pack(repository, H(2)) + + assert repository.check(repair=False) is False + + after = PackTracker.load(repository.store) + assert after.corrupt_ids() == [corrupt_id] + assert after.table[intact_id].result == 1 + + +def test_check_full_reports_corrupt_pack_ids(tmp_path, caplog): + # the summary names the corrupt packs. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + corrupt_id = _store_corrupt_pack(repository, H(1)) + + with caplog.at_level(logging.ERROR, logger="borg.repository"): + assert repository.check(repair=False) is False + + assert f"Corrupt pack: {bin_to_hex(corrupt_id)}" in caplog.text + + +def test_check_full_reverifies_carried_over_corrupt_record(tmp_path, monkeypatch): + # a corrupt record from an earlier check is re-verified; an intact result replaces it. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + tracker.record(intact_id, ok=False) # recorded corrupt in an earlier check + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False) is True + assert pack_key in hashed_keys # re-verified + + after = PackTracker.load(repository.store) + assert after.table[intact_id].result == 1 # verified intact, corrupt record replaced + + +def test_check_full_prunes_corrupt_record_of_vanished_pack(tmp_path): + # a corrupt record for a pack that is no longer listed is dropped when the check finishes. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, _ = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + tracker.record(H(9), ok=False) # no such pack in packs/ + tracker.save() + + assert repository.check(repair=False) is True + + after = PackTracker.load(repository.store) + assert H(9) not in after.table + assert intact_id in after.table + + +def test_check_partial_keeps_corrupt_record_across_runs(tmp_path): + # corrupt records survive completed partial checks, too. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + corrupt_id = _store_corrupt_pack(repository, H(1)) + + assert repository.check(repair=False, max_duration=3600, max_age=3600) is False + assert PackTracker.load(repository.store).corrupt_ids() == [corrupt_id] + + # a second run re-verifies it and keeps reporting it. + assert repository.check(repair=False, max_duration=3600, max_age=3600) is False + assert PackTracker.load(repository.store).corrupt_ids() == [corrupt_id] + + +def test_check_partial_break_reports_unreached_corrupt_record(tmp_path, monkeypatch, caplog): + # a partial check that breaks before re-reaching a corrupt record from an earlier check still + # fails and reports that pack. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, intact_key = _store_intact_pack(repository) + # a corrupt pack whose id sorts after the intact one, so the scan reaches the intact pack first. + corrupt_id = b"\xff" * 32 + assert bin_to_hex(intact_id) < bin_to_hex(corrupt_id) + corrupt_key = "packs/" + bin_to_hex(corrupt_id) + repository.store_store(corrupt_key, b"CORRUPT-does-not-match-name") + + tracker = PackTracker.new(repository.store) + tracker.record(corrupt_id, ok=False) # recorded corrupt by an earlier check + tracker.save() + + # freeze the clock, then jump it past max_duration right after the intact pack is hashed, so the + # pack loop breaks before it reaches the corrupt pack. + clock = {"t": 0.0} + monkeypatch.setattr(time, "monotonic", lambda: clock["t"]) + hashed_keys = [] + orig_hash = repository.store.hash + + def hash_and_advance(key): + hashed_keys.append(key) + result = orig_hash(key) + if key == intact_key: + clock["t"] = 10**9 + return result + + monkeypatch.setattr(repository.store, "hash", hash_and_advance) + + with caplog.at_level(logging.ERROR, logger="borg.repository"): + assert repository.check(repair=False, max_duration=1, max_age=3600) is False + assert corrupt_key not in hashed_keys # the scan broke before reaching the corrupt pack + assert f"Corrupt pack: {bin_to_hex(corrupt_id)}" in caplog.text + + +def test_check_max_age_skips_fresh_ok(tmp_path, monkeypatch): + # with max_age, a pack recorded intact recently is not re-verified, and its record is kept. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + tracker.record(intact_id, ok=True) # fresh timestamp + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=3600) is True + assert pack_key not in hashed_keys # skipped, its record is fresh + + after = PackTracker.load(repository.store) + assert after.table[intact_id].result == 1 # record kept + + +def test_check_max_age_reverifies_stale_ok(tmp_path, monkeypatch): + # with max_age, a pack whose intact record is older than max_age is re-verified. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + max_age = 50 + tracker = PackTracker.new(repository.store) + old_ts = int(time.time()) - (max_age + 100) # clearly beyond max_age + tracker.table[intact_id] = PackTracker.Entry(timestamp=old_ts, result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=max_age) is True + assert pack_key in hashed_keys # stale, re-verified + + after = PackTracker.load(repository.store) + assert after.table[intact_id].timestamp > old_ts # record refreshed + + +def test_check_max_age_reverifies_stale_within_skew(tmp_path, monkeypatch): + # a record past max_age gets no skew tolerance: it is re-verified even within MAX_CLOCK_SKEW of it. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + max_age = MAX_CLOCK_SKEW * 2 # window wider than MAX_CLOCK_SKEW + tracker = PackTracker.new(repository.store) + past_ts = int(time.time()) - (max_age + MAX_CLOCK_SKEW // 2) # just past the window + tracker.table[intact_id] = PackTracker.Entry(timestamp=past_ts, result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=max_age) is True + assert pack_key in hashed_keys # past max_age, re-verified + + +def test_check_max_age_skips_near_future_ok(tmp_path, monkeypatch): + # a future timestamp (writer clock ahead of ours) up to MAX_CLOCK_SKEW is tolerated and skipped. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + future_ts = int(time.time()) + MAX_CLOCK_SKEW // 2 + tracker.table[intact_id] = PackTracker.Entry(timestamp=future_ts, result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=MAX_CLOCK_SKEW * 2) is True + assert pack_key not in hashed_keys # within MAX_CLOCK_SKEW ahead, skipped + + +def test_check_max_age_reverifies_far_future_ok(tmp_path, monkeypatch): + # a future timestamp more than MAX_CLOCK_SKEW ahead exceeds the skew tolerance and is re-verified. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + far_future_ts = int(time.time()) + MAX_CLOCK_SKEW + 3600 + tracker.table[intact_id] = PackTracker.Entry(timestamp=far_future_ts, result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=MAX_CLOCK_SKEW * 2) is True + assert pack_key in hashed_keys # more than MAX_CLOCK_SKEW ahead, re-verified + + +def test_check_max_age_reverifies_future_beyond_small_window(tmp_path, monkeypatch): + # the future tolerance is capped at max_age: with a window smaller than MAX_CLOCK_SKEW, a record + # further ahead than max_age is re-verified even though it is within MAX_CLOCK_SKEW. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + small_window = MAX_CLOCK_SKEW // 4 + tracker = PackTracker.new(repository.store) + future_ts = int(time.time()) + MAX_CLOCK_SKEW // 2 # ahead of us, but < MAX_CLOCK_SKEW + tracker.table[intact_id] = PackTracker.Entry(timestamp=future_ts, result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=small_window) is True + assert pack_key in hashed_keys # further ahead than max_age, re-verified + + +def test_check_max_age_reverifies_corrupt_even_when_fresh(tmp_path, monkeypatch): + # the age window only applies to intact records: a fresh corrupt record is still re-verified. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + tracker.record(intact_id, ok=False) # fresh, but corrupt + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=3600) is True + assert pack_key in hashed_keys # re-verified despite the fresh record + + +def test_check_max_age_prunes_vanished_ok_record(tmp_path): + # an intact record for a pack no longer listed is pruned when the check finishes. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, _ = _store_intact_pack(repository) + + tracker = PackTracker.new(repository.store) + tracker.record(intact_id, ok=True) + tracker.record(H(9), ok=True) # no such pack in packs/ + tracker.save() + + assert repository.check(repair=False, max_age=3600) is True after = PackTracker.load(repository.store) - assert len(after) == 0 # cycle complete, set dropped + assert intact_id in after.table + assert H(9) not in after.table + + +def test_check_max_age_partial_progress(tmp_path, monkeypatch): + # a partial check with max_age skips packs with a fresh intact record and verifies the rest. + pack_a = fchunk(b"A", chunk_id=H(1)) + pack_a_id = sha256(pack_a).digest() + pack_b = fchunk(b"BB", chunk_id=H(2)) + pack_b_id = sha256(pack_b).digest() + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + repository.store_store("packs/" + bin_to_hex(pack_a_id), pack_a) + repository.store_store("packs/" + bin_to_hex(pack_b_id), pack_b) + + tracker = PackTracker.new(repository.store) + tracker.record(pack_a_id, ok=True) # fresh + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_duration=3600, max_age=3600) is True + assert "packs/" + bin_to_hex(pack_a_id) not in hashed_keys + assert "packs/" + bin_to_hex(pack_b_id) in hashed_keys + + after = PackTracker.load(repository.store) + assert pack_a_id in after.table and pack_b_id in after.table + + +def test_check_partial_orders_stale_oldest_first_and_skips_fresh(tmp_path, monkeypatch): + # a partial check skips packs whose intact record is younger than max_age and verifies the rest + # least-recently-checked first. the sort orders by recorded time, not pack id: the older record is + # on the pack whose id sorts later, so an id-ordered scan would verify the two stale packs in the + # other order. + max_age = 3600 + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + fresh_id, fresh_key = _store_intact_pack(repository, chunk_id=H(1)) + id2, _ = _store_intact_pack(repository, chunk_id=H(2)) + id3, _ = _store_intact_pack(repository, chunk_id=H(3)) + older_id, newer_id = (id2, id3) if id2 > id3 else (id3, id2) + older_key = "packs/" + bin_to_hex(older_id) + newer_key = "packs/" + bin_to_hex(newer_id) + + now = int(time.time()) + tracker = PackTracker.new(repository.store) + tracker.table[fresh_id] = PackTracker.Entry(timestamp=now - 10, result=1) # within max_age + tracker.table[older_id] = PackTracker.Entry(timestamp=now - (max_age + 1000), result=1) + tracker.table[newer_id] = PackTracker.Entry(timestamp=now - (max_age + 100), result=1) + tracker.save() + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_duration=3600, max_age=max_age) is True + + pack_hashes = [key for key in hashed_keys if key.startswith("packs/")] + assert fresh_key not in pack_hashes # skipped, record younger than max_age + assert pack_hashes == [older_key, newer_key] # oldest record first, ignoring id order + + +def test_check_max_age_reuses_records_of_plain_check(tmp_path, monkeypatch): + # a check without max_age records its results, a later check with max_age reuses them. + with Repository(str(tmp_path / "repo"), exclusive=True, create=True) as repository: + intact_id, pack_key = _store_intact_pack(repository) + + assert repository.check(repair=False) is True + + hashed_keys = _spy_hash(repository, monkeypatch) + + assert repository.check(repair=False, max_age=3600) is True + assert pack_key not in hashed_keys # skipped, reusing the plain check's record def test_check_checked_packs_ignores_foreign_entry_layout(tmp_path):