diff --git a/CHANGELOG.md b/CHANGELOG.md index 417903f..befe9c9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -54,6 +54,46 @@ worse than no alert, because one day it carries a security fix. `zfs.dataset.query`, which returns all 270 datasets. The bug existed only in the unreleased TrueNAS 26 port. +- **The patch now owns the snapshot sweep even when it does not stage anything.** + Stock decides whether to take a *recursive* snapshot by its own rule, and on + TrueNAS 26 that rule stopped being ours. + + Up to 25.10, stock's `create_snapshot` called `get_dataset_recursive()` — the same + function this module vendors — so "stock went recursive" and "we have something to + stage" were the *same question*, and stock's non-recursive delete was correct for + everything the patch declined to stage. TrueNAS 26 uses `filesystem.statfs`: + `recursive = (path == the dataset's mountpoint)`. The two rules now disagree for a + dataset whose only descendants are **ZVOLs** or **legacy/none-mountpoint** datasets + — stock snapshots it recursively, while the patch sees nothing to stage. + + The patch then handed the snapshot back to stock, which destroys the parent only. + With no staging tree there was no sidecar, and the garbage collector only ever ran + from the staging path — so nothing on the box would ever have found the children. + Reproduced on the test VM: one orphaned snapshot per zvol, on every run, forever, + with the backup reporting success. Ownership of the sweep is no longer conditional + on staging. + +- **The runtime resolved a *namespace*; the checker verified a *method*.** Those are + different questions, and the gap is a false "ok". `get_service()` only proves a + namespace is registered — it says nothing about whether `delete` still exists on it. + So if iX guts the method while keeping the service (they have already done exactly + that to `pool.snapshot.do_update` on master), `tools/compat.py` would fall through + to `zfs.snapshot`, report the box healthy, and let the patch apply — while the + runtime picked `pool.snapshot` and failed *every* delete, orphaning the whole tree. + Both sides now ask the same question, and a test binds the two lists together. + +- `query_filesystems()` **dropped malformed `zfs list` rows silently** — the last + remaining silent-omission path, and a direct contradiction of this module's cardinal + rule. It raises now. A missing `zfs` binary raised `FileNotFoundError` rather than + `ZfsError`; also fixed. + +- The snapshot retry loop **discarded the delete error** and reported every survivor + as "(still busy?)" — naming the one cause that is benign and self-healing, and + hiding the ones that are permanent. It keeps and reports the real error. + +- The staging-failure handler could **lose the original exception** if its own cleanup + sweep raised. An error handler must not be able to lose the error. + ## v0.6.1 — 2026-07-13 ### Fixed diff --git a/patch/truecloud_nested.py b/patch/truecloud_nested.py index 652b444..ab8e6b3 100644 --- a/patch/truecloud_nested.py +++ b/patch/truecloud_nested.py @@ -162,8 +162,43 @@ def pick_snapshot_service(can_delete): return None +#: Where middlewared's own service framework lives. Classes from this package are +#: PLUMBING, not implementations -- see `_defines_delete`. +FRAMEWORK_PACKAGE = "middlewared.service" + + +def _defines_delete(service): + """Does this service ITSELF implement a delete -- or merely inherit the framework's? + + The distinction is the whole fix, and getting it wrong is silent. + + `CRUDService` defines `delete` on the BASE class and dispatches to `self.do_delete` + at call time. So `getattr(service, "delete")` is a bound method on EVERY + CRUDService subclass, whether or not that subclass still implements one: + + middlewared.plugins.pool_.snapshot.PoolSnapshotService defines ['do_delete'] + middlewared.service.crud_service.CRUDService defines ['delete'] + + An earlier version of this check asked `callable(getattr(service, "delete"))` and + was therefore answering "is this a CRUDService?" -- exactly the weaker "is the + namespace registered?" question that `pick_snapshot_service` exists to avoid. It + would have picked a gutted `pool.snapshot` and failed every delete. + + So walk the MRO and ignore the framework's generic plumbing: a delete is real only + where a PLUGIN class defines it. That mirrors `tools/compat.py`, which looks for + the `def` in the plugin file declaring the namespace. + """ + for klass in type(service).__mro__: + module = getattr(klass, "__module__", "") or "" + if module == FRAMEWORK_PACKAGE or module.startswith(FRAMEWORK_PACKAGE + "."): + continue # the framework's generic CRUD dispatcher + if any(m in vars(klass) for m in DELETE_METHODS): + return True + return False + + def _can_delete(middleware, namespace): - """Is `.delete` actually callable on this middleware?""" + """Is `.delete` actually implemented on this middleware?""" try: service = middleware.get_service(namespace) except Exception: @@ -172,7 +207,7 @@ def _can_delete(middleware, namespace): # service that is not really there fails later, mid-backup, holding a # snapshot -- the worst possible moment to find out. return False - return any(callable(getattr(service, m, None)) for m in DELETE_METHODS) + return _defines_delete(service) def snapshot_service(middleware): @@ -342,6 +377,12 @@ def list_snapshot_names(dataset, runner=None): #: Where staging trees are assembled. tmpfs; bind mounts consume no space. STAGING_BASE = "/run/truecloud-nested" +#: The kernel's mount table. Late-bound (never a default argument) so a +#: test can point it somewhere harmless -- a default is frozen at def time, +#: which is how 19 tests ended up reading the REAL table, one matching name +#: away from running a real `umount` on the NAS. +MOUNTS_FILE = "/proc/self/mounts" + # Which snapshot a staging tree pins is recorded ONLY in the sidecar file, never # also in memory. An in-process dict would be a second source of truth that a # middlewared restart silently empties -- and it is exactly the restart case that @@ -376,7 +417,7 @@ def sidecar_for(staging_root: str) -> str: return staging_root + ".snapshot" -def _write_sidecar(staging_root: str, snapshots) -> None: +def _write_sidecar(staging_root: str, snapshots, logger=None) -> None: """Record every snapshot tree this task still owns. One per line. A LIST, not a single name -- and that is not over-engineering, it is a bug fix. @@ -393,10 +434,22 @@ def _write_sidecar(staging_root: str, snapshots) -> None: """ if isinstance(snapshots, str): snapshots = [snapshots] - with contextlib.suppress(OSError): + try: os.makedirs(os.path.dirname(staging_root), exist_ok=True) with open(sidecar_for(staging_root), "w", encoding="utf-8") as fh: fh.write("\n".join(dict.fromkeys(snapshots))) # de-duped, order kept + except OSError as e: + # This used to be suppressed silently, and it is the LAST thing that should be. + # The sidecar is the only record that these snapshots exist; if the write fails + # (a full /run, say) cleanup_task finds nothing to sweep, and only the by-name + # collector -- an hour later -- has any chance of finding them. Failing to + # write it is not fatal, but it must never be invisible. + if logger: + logger.error( + "truecloud-patch: COULD NOT RECORD the snapshot(s) %s (%r). If this " + "run does not clean them up itself, only the by-name collector will " + "ever find them.", ", ".join(snapshots), e, + ) def _read_sidecar(staging_root: str): @@ -608,8 +661,9 @@ def plan_staging(base_dataset, base_mountpoint, path, snapshot_name, datasets, return mounts, skipped -def current_mounts_under(root, mounts_file="/proc/self/mounts"): +def current_mounts_under(root, mounts_file=None): """Mountpoints at or under ``root``, deepest first. Used for teardown.""" + mounts_file = mounts_file or MOUNTS_FILE found = [] try: with open(mounts_file, encoding="utf-8") as fh: @@ -637,12 +691,13 @@ def _run(cmd): ) -def apply_plan(mounts, runner=_run, isdir=os.path.isdir): +def apply_plan(mounts, runner=None, isdir=os.path.isdir): """Execute the bind-mount plan. Blocking; call via ``run_in_thread``. Raises StagingError on the first failure, after rolling back what was mounted -- a half-built tree must never be handed to the backup tool. """ + runner = runner or _run if not mounts: raise StagingError("empty staging plan") @@ -695,12 +750,14 @@ def verify_staged(mounts, ismount=os.path.ismount, listdir=os.listdir): return True -def teardown(staging_root, runner=_run, mounts_file="/proc/self/mounts"): +def teardown(staging_root, runner=None, mounts_file=None): """Unmount the staging tree (deepest first) and remove the root. Idempotent, and does not depend on an in-memory plan -- so it also cleans up leftovers from a crashed run. """ + mounts_file = mounts_file or MOUNTS_FILE + runner = runner or _run errors = [] for mp in current_mounts_under(staging_root, mounts_file=mounts_file): res = runner(["umount", mp]) @@ -713,8 +770,9 @@ def teardown(staging_root, runner=_run, mounts_file="/proc/self/mounts"): return errors -def snapdir_automounts(snapshot_name, mounts_file="/proc/self/mounts"): +def snapdir_automounts(snapshot_name, mounts_file=None): """Every ``/.zfs/snapshot/`` ZFS automount for this snapshot.""" + mounts_file = mounts_file or MOUNTS_FILE suffix = "/.zfs/snapshot/" + snapshot_name found = [] try: @@ -730,7 +788,7 @@ def snapdir_automounts(snapshot_name, mounts_file="/proc/self/mounts"): return sorted(found, key=_depth, reverse=True) # deepest first -def release_snapdirs(snapshot_name, runner=_run, mounts_file="/proc/self/mounts"): +def release_snapdirs(snapshot_name, runner=None, mounts_file=None): """Unmount ZFS's OWN snapshot automounts, so the snapshots can be destroyed. Reading anything under ``/.zfs/snapshot//`` makes ZFS **automount** @@ -747,6 +805,8 @@ def release_snapdirs(snapshot_name, runner=_run, mounts_file="/proc/self/mounts" Deepest first, so a child's automount is released before its parent's. """ + mounts_file = mounts_file or MOUNTS_FILE + runner = runner or _run errors = [] for mp in snapdir_automounts(snapshot_name, mounts_file=mounts_file): res = runner(["umount", mp]) @@ -818,7 +878,7 @@ def get_dataset_recursive(datasets, directory): def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, - sleep=time.sleep, list_snapshots=None): + sleep=None, list_snapshots=None): """Delete the parent snapshot AND every child created by ``zfs snapshot -r``. Returns the snapshots it could NOT delete -- callers must not throw that away. @@ -837,6 +897,7 @@ def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, """ dataset, _, snapname = snapshot.partition("@") snaps = _Snapshots(middleware, list_snapshots) + sleep = sleep or time.sleep # Release ZFS's own automounts first, or `zfs destroy` refuses with EBUSY on # everything restic read in the last few minutes. @@ -851,7 +912,44 @@ def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, # exists to prevent. try: snaps.delete(snapshot, recursive=True) - return [] + + # CONFIRM it. A delete that returns without raising is not proof that anything + # was destroyed, and this is the one place where believing it is catastrophic: + # `cleanup_task` reads an empty survivor list as "clean sweep" and REMOVES THE + # SIDECAR -- the only record the tree ever existed. ~250 snapshots would be + # orphaned per run, with nothing left to find them, and the backup green. + # + # Not paranoia about a hypothetical: iX has already gutted + # `pool.snapshot.do_update` on master into a no-op whose body is commented out + # and which returns None. An AST check still sees the `def`, and a callable + # check still sees the method. Only asking ZFS can tell. + # + # It costs one `zfs list` (~350ms against 2148 snapshots) on an 18-minute + # backup, and only on the path that would otherwise skip verification entirely. + try: + left = snapshot_tree_names(snapshot, snaps.names(dataset)) + except Exception as e: # noqa: BLE001 - cannot confirm; do not claim success + if logger: + logger.warning( + "truecloud-patch: deleted %s but could not confirm it is gone " + "(%r); keeping it recorded so the next run re-checks", snapshot, e, + ) + # Keep OWNING it. Reporting a clean sweep here makes cleanup_task drop the + # sidecar; if the delete had in fact done nothing, the tree is orphaned + # with no record. A survivor we later find already gone costs one + # idempotent retry; a lost record costs the snapshots, permanently. + return [snapshot] + + if not left: + return [] + + if logger: + logger.warning( + "truecloud-patch: the recursive delete of %s reported success but " + "%d snapshot(s) are still there; sweeping them by name", + snapshot, len(left), + ) + # Fall through to the by-name sweep, which retries and reports survivors. except Exception as e: # noqa: BLE001 - fall through to the explicit sweep # "Parent already gone" is the EXPECTED race (stock's finally won, once our # mounts were released) and happens on every clean run, so it is debug. @@ -886,22 +984,34 @@ def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, ) names = [snapshot] - def confirm_gone(failed): - """Drop any name ZFS no longer has, even though its delete raised. + def still_there(tried, failed): + """Which of `tried` does ZFS STILL have? The delete's verdict is not evidence. - A delete that raised "does not exist" SUCCEEDED as far as we care, and must - not be retried or reported. The query is only a refinement: if it cannot be - answered we keep the delete's own verdict, rather than inventing survivors -- - a false survivor keeps the sidecar forever and is reported as a leak that - isn't there. + ZFS is the authority, not the API's return value, and the difference is not + academic in either direction: + + * A delete that RAISED "does not exist" succeeded as far as we care, and must + not be retried or reported as a leak. + * A delete that RETURNED CLEANLY may have done nothing at all. iX has already + gutted `pool.snapshot.do_update` on master into a no-op whose body is + commented out and which returns None. Trusting that verdict makes + `cleanup_task` see "no survivors", drop the sidecar -- the only record -- and + orphan the whole tree, forever, silently. + + If ZFS cannot be read we cannot check either way -- so keep owning ALL of them. + The two mistakes are not symmetric: + + * a false survivor SELF-HEALS. The sidecar is kept, the next run reclaims it, + the delete raises "does not exist", and the record clears. + * a lost record does NOT. The snapshots are orphaned with nothing pointing at + them, and only the by-name collector -- an hour later, and only if ZFS is + readable by then -- has any chance of finding them. """ - if not failed: - return [] try: live = set(snaps.names(dataset)) - except Exception: # noqa: BLE001 - cannot refine; trust the delete's verdict - return list(failed) - return [n for n in failed if n in live] + except Exception: # noqa: BLE001 - cannot check; keep owning them + return list(tried) + return [n for n in tried if n in live] remaining = list(names) last_error = {} @@ -919,7 +1029,7 @@ def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, last_error[name] = e failed.append(name) - remaining = confirm_gone(failed) + remaining = still_there(remaining, failed) if not remaining: return [] @@ -939,7 +1049,7 @@ def delete_snapshot_tree(middleware, snapshot, logger=None, attempts=4, return remaining -def mounted_snapshots(mounts_file="/proc/self/mounts"): +def mounted_snapshots(mounts_file=None): """Every ZFS snapshot something is currently mounted from. The device field of a snapshot mount IS the snapshot name (`Tap/apps/x@snap`), for @@ -948,6 +1058,7 @@ def mounted_snapshots(mounts_file="/proc/self/mounts"): protects a concurrently-running backup from the garbage collector, rather than trusting an age heuristic to be generous enough. """ + mounts_file = mounts_file or MOUNTS_FILE live = set() try: with open(mounts_file, encoding="utf-8") as fh: @@ -961,7 +1072,7 @@ def mounted_snapshots(mounts_file="/proc/self/mounts"): def gc_stale_snapshots(middleware, task_name, current_snapshot, logger=None, - now=None, mounts_file="/proc/self/mounts", list_snapshots=None): + now=None, mounts_file=None, list_snapshots=None): """Delete snapshots this task left behind in an earlier run. Returns what remains. The backstop for when the RECORD is gone, not just the snapshots: the sidecar lives @@ -972,6 +1083,7 @@ def gc_stale_snapshots(middleware, task_name, current_snapshot, logger=None, Selection is `stale_snapshot_names()`, which is pure and heavily tested, because a name match is a weaker claim than a recorded fact and this deletes data on one. """ + mounts_file = mounts_file or MOUNTS_FILE dataset = current_snapshot.partition("@")[0] now = now or datetime.datetime.now(datetime.UTC) snaps = _Snapshots(middleware, list_snapshots) @@ -1101,7 +1213,7 @@ def own_snapshot(middleware, task_name, snapshot, logger=None, list_snapshots=No # sidecar is the only thing that survives it -- an in-process dict would take # the sole record of a 160-snapshot tree with it. Writing it after apply_plan # would leave exactly the crash window the sidecar exists to close. - _write_sidecar(staging_root, [*pending, snapshot]) + _write_sidecar(staging_root, [*pending, snapshot], logger=logger) return staging_root @@ -1126,6 +1238,15 @@ def stage_nested(middleware, path, snapshot, base_dataset, base_mountpoint, (see SNAPSHOT_BLOCK in apply.sh). """ snapshot_name = snapshot.split("@", 1)[1] + + # Refuse BEFORE staging, not after restic has run. We are about to pin a recursive + # snapshot with bind mounts; if this middleware has no usable snapshot delete we + # could never sweep it, and the honest move is to fail now rather than take a + # snapshot we cannot clean up. (`_Snapshots` resolves lazily on purpose -- the + # read-only paths must not raise over a mutation they never make -- so the staging + # path asks explicitly.) + snapshot_service(middleware) + staging_root = own_snapshot( middleware, task_name, snapshot, logger=logger, list_snapshots=list_snapshots, @@ -1215,7 +1336,7 @@ def cleanup_task(middleware, task_name, logger=None, list_snapshots=None): ) # The SURVIVORS, not the trees we asked to delete. Writing the original list # back would keep re-sweeping trees that are already gone. - _write_sidecar(staging_root, survivors) + _write_sidecar(staging_root, survivors, logger=logger) return _remove_sidecar(staging_root) @@ -1224,7 +1345,7 @@ def cleanup_task(middleware, task_name, logger=None, list_snapshots=None): # ── offline cleanup (uninstall.sh / recover.sh) ─────────────────────────────── -def cleanup_all(base=None, runner=_run, mounts_file="/proc/self/mounts", +def cleanup_all(base=None, runner=None, mounts_file=None, glob_fn=None, read_sidecar=_read_sidecar): """Tear down every staging tree. Used by uninstall.sh and recover.sh. @@ -1235,6 +1356,8 @@ def cleanup_all(base=None, runner=_run, mounts_file="/proc/self/mounts", Returns ``(lines, errors)``: report lines to print, and unmount errors. """ + mounts_file = mounts_file or MOUNTS_FILE + runner = runner or _run import glob as _glob base = base or STAGING_BASE diff --git a/tests/test_compat.py b/tests/test_compat.py index 450b3c1..32b8bc4 100644 --- a/tests/test_compat.py +++ b/tests/test_compat.py @@ -416,3 +416,142 @@ class TestMiddlewareMethodsWeCall: })) whys = " ".join(p["why"] for p in r[NESTED]["problems"]) assert "orphan" in whys + + +class TestTheMethodCheckIsNotJustANamespaceCheck: + """compat must verify the METHOD, not merely that the namespace still exists. + + Deleting the method check entirely used to leave all 304 tests green -- so the + "namespace AND method" claim was unenforced and silently revertible. It is the + half of the predicate that catches iX gutting a method while keeping its service, + which they have already done to `pool.snapshot.do_update` on master. + """ + + def test_a_namespace_that_no_longer_defines_delete_is_broken(self): + gutted = ( + "class PoolSnapshotService(CRUDService):\n" + " class Config:\n" + " namespace = 'pool.snapshot'\n" + " def query(self, filters, options):\n pass\n" + # do_delete is GONE -- the service is still registered and still a + # CRUDService, so it still INHERITS a callable `delete`. + ) + r = check_files(with_(**{ + "plugins/pool_/snapshot.py": gutted, + "plugins/zfs_/snapshot.py": None, # no fallback either + })) + assert is_broken(r[NESTED]), ( + "a namespace with no delete must be BROKEN. Checking only that the " + "namespace exists would apply the patch to a box that cannot sweep its " + "own snapshots." + ) + + def test_the_alternative_still_saves_it_when_only_the_primary_is_gutted(self): + gutted = ( + "class PoolSnapshotService(CRUDService):\n" + " class Config:\n" + " namespace = 'pool.snapshot'\n" + " def query(self, filters, options):\n pass\n" + ) + r = check_files(with_(**{ + "plugins/pool_/snapshot.py": gutted, + "plugins/zfs_/snapshot.py": ZFS_ERA_SNAPSHOT, + })) + assert r[NESTED]["ok"], r[NESTED]["problems"] + + +class TestUnreadableIsNeverOkAndNeverBroken: + """A rate limit is not a regression, and it is not a clean bill of health either. + + compat runs ~30 unauthenticated GitHub requests per matrix; 429 is a real outcome. + It also runs at BOOT against the installed tree, where a read can fail with EACCES. + + * treating unreadable as BROKEN repaints the README, files a bug report, and + makes apply.sh refuse the module on a box where it works. + * treating it as OK injects a module whose delete may be gone. + + Both mutations used to pass the whole suite. + """ + + def test_both_spellings_unreadable_is_unknown_not_broken(self): + r = check_files(with_(**{ + "plugins/pool_/snapshot.py": Unreadable("HTTP 429"), + "plugins/zfs_/snapshot.py": Unreadable("HTTP 429"), + })) + assert not is_broken(r[NESTED]), "a 429 is not iX deleting the snapshot service" + assert r[NESTED]["unknown"] + + def test_an_unreadable_primary_with_a_healthy_alternative_is_ok(self): + r = check_files(with_(**{ + "plugins/pool_/snapshot.py": Unreadable("HTTP 429"), + "plugins/zfs_/snapshot.py": ZFS_ERA_SNAPSHOT, + })) + assert r[NESTED]["ok"], r[NESTED]["problems"] + assert not r[NESTED]["unknown"], ( + "one spelling answered the question; the other's 429 is irrelevant" + ) + + def test_a_missing_primary_with_an_unreadable_alternative_is_unknown(self): + # We cannot tell whether the box is broken. Saying either would be a guess. + r = check_files(with_(**{ + "plugins/pool_/snapshot.py": None, + "plugins/zfs_/snapshot.py": Unreadable("HTTP 429"), + })) + assert not is_broken(r[NESTED]) + assert r[NESTED]["unknown"] + + +class TestGetServiceIsChecked: + """The runtime resolves the snapshot namespace through `middleware.get_service`. + + It is not a plugin method, so the manifest had no way to express it and never + checked it. If it vanishes, `_can_delete` reports BOTH namespaces unusable and + every nested backup fails -- on a box the preflight had declared healthy. + """ + + def test_a_middleware_without_get_service_is_broken(self): + r = check_files(with_(**{"utils/plugins.py": None})) + assert is_broken(r[NESTED]) + details = " ".join(p["detail"] for p in r[NESTED]["problems"]) + assert "get_service" in details + + +class TestATransientNetworkBlipDoesNotWakeAnybody: + """The fingerprint must digest what iX BROKE, not what GitHub failed to serve. + + `unknown` problems (a 429 on one of ~30 unauthenticated fetches, an EACCES at boot) + used to be folded into an already-broken module's problem list, so one blip flipped + the fingerprint, `compat_publish` rewrote the issue body, and the next clean run + rewrote it back. Daily churn is what teaches people to ignore the bot -- which is + the whole thing this fingerprint exists to prevent. + """ + + def _rows(self, files): + return [{"ref": "master", "modules": check_files(files)}] + + def test_an_unreadable_file_does_not_change_the_fingerprint_of_a_broken_ref(self): + broken = with_(**{ + "plugins/cloud/snapshot.py": + "async def create_snapshot(name, path, middleware):\n return 1, 2\n", + }) + clean = compat.fingerprint(self._rows(broken)) + + blipped = dict(broken) + blipped["rclone/remote/b2.py"] = Unreadable("HTTP 429") + assert compat.fingerprint(self._rows(blipped)) == clean, ( + "a rate-limited fetch changed the fingerprint, so the bot rewrites the " + "issue body and then rewrites it back tomorrow" + ) + + def test_a_REAL_new_finding_still_changes_it(self): + # ...and the anti-noise measure must not have made it deaf. + broken = with_(**{ + "plugins/cloud/snapshot.py": + "async def create_snapshot(name, path, middleware):\n return 1, 2\n", + }) + worse = dict(broken) + worse["plugins/cloud_backup/restic.py"] = ( + "class ResticConfig:\n cmd: list\n\n" + "def get_restic_config(entry, credentials):\n pass\n" + ) + assert compat.fingerprint(self._rows(worse)) != compat.fingerprint(self._rows(broken)) diff --git a/tests/test_truecloud_nested.py b/tests/test_truecloud_nested.py index af4dcd7..7167b0a 100644 --- a/tests/test_truecloud_nested.py +++ b/tests/test_truecloud_nested.py @@ -62,7 +62,26 @@ def never_touch_the_real_system(monkeypatch): raise AssertionError(f"real system command in a unit test: {cmd!r}") monkeypatch.setattr(tn, "_run", forbidden) + + # ...and the REAL mount table, which is the other half. Nineteen tests were + # reading /proc/self/mounts: harmless here, but on the NAS a name that happened to + # match would send `release_snapdirs`/`teardown` off to run a real `umount`. + # + # Patching the module attribute only works because these are late-bound now. A + # default argument (`mounts_file="/proc/self/mounts"`) is frozen into __defaults__ + # at def time and monkeypatching cannot reach it -- which is exactly why the first + # version of this fixture looked like it worked and did not. + monkeypatch.setattr(tn, "MOUNTS_FILE", os.devnull) + + # ...and never really sleep. The retry loop waits 5s between attempts for ZFS's + # automount window to expire; a test that hits it burns 20 real seconds and tells + # you nothing. (Same frozen-default trap: `sleep=time.sleep` in the signature could + # not be intercepted at all until it was late-bound.) + slept = [] + monkeypatch.setattr(tn.time, "sleep", lambda s: slept.append(s)) + yield + assert not attempted, ( "this test ran real system commands: " + "; ".join(repr(c) for c in attempted) @@ -233,20 +252,49 @@ class TestSnapshotTreeNames: assert snapshot_tree_names("Tap", self.ALL) == [] -class _FakeSnapshotService: - """What `middleware.get_service("")` hands back. +class _FrameworkCRUDService: + """Stands in for middlewared's real `CRUDService` base class. - It carries a `delete` (or `do_delete`) attribute and nothing else, because that - is the ONLY thing the runtime inspects: `snapshot_service()` asks "can this - namespace delete for me?", not "is this namespace registered?". A service object - with no delete must be REFUSED — iX has already gutted a method while keeping its - service (`pool.snapshot.do_update` on master), and settling for the weaker - question is how the runtime and `tools/compat.py` would come to disagree. + This shape is load-bearing, and a fake without it is worse than no fake at all. + + The real CRUDService defines `delete` on the BASE class and dispatches to + `self.do_delete` at call time, so a bound `delete` exists on EVERY subclass — + including one whose `do_delete` iX has deleted. A fake that is just a bare object + with a `delete` attribute cannot express that, so a runtime check that asks + `hasattr(service, "delete")` would look CORRECT against the fake while being + useless against the real thing. That is exactly what happened: the first version + of this fix passed its test and did nothing on a real box. + + `__module__` is set to middlewared's real framework package because that is how + `_defines_delete` tells plumbing apart from an implementation. + """ + + def delete(self, *args, **kwargs): # the generic dispatcher -> self.do_delete + raise NotImplementedError + + +_FrameworkCRUDService.__module__ = "middlewared.service.crud_service" + + +class _FakeSnapshotService(_FrameworkCRUDService): + """What `middleware.get_service("")` hands back: a plugin CRUDService. + + `delete_method=None` models the dangerous case — iX guts the concrete method but + leaves the service registered (they have already done this to + `pool.snapshot.do_update` on master). The inherited `delete` is still there and + still callable; only the implementation is gone. """ def __init__(self, delete_method): if delete_method: - setattr(self, delete_method, lambda *a, **kw: None) + # Define it on the CLASS, not the instance: `_defines_delete` walks the + # MRO's __dict__s, exactly as it must against a real service. + cls = type( + "FakePluginSnapshotService", (_FrameworkCRUDService,), + {delete_method: lambda self, *a, **kw: None}, + ) + cls.__module__ = "middlewared.plugins.pool_.snapshot" + self.__class__ = cls class FakeMiddleware: @@ -381,9 +429,11 @@ class TestDeleteSnapshotTree: deletes = [a for m, a in mw.calls if m.endswith(".delete")] assert len(deletes) == 1, "should be ONE recursive call, not one per snapshot" assert deletes[0][1] == {"recursive": True} - assert listed == [], ( - "the fast path enumerated. On the real pool that is a `zfs list` over 2148 " - "snapshots on every clean run, for nothing." + assert listed == ["Tap"], ( + "the fast path must enumerate EXACTLY ONCE -- to CONFIRM the tree is gone. " + "Zero would mean trusting a delete that returned without raising, and a " + "silent no-op delete then makes cleanup_task drop the sidecar and orphan " + "~250 snapshots forever. More than once is waste." ) def test_survives_recursive_and_enumeration_failure_by_deleting_the_parent(self): @@ -1290,7 +1340,7 @@ class TestTheProductionWiringIsWhatWeThinkItIs: return super().call_sync(method, *args) tn.delete_snapshot_tree(NoRecursive(["Tap@snap"]), "Tap@snap") - assert called == ["Tap"], ( + assert called and set(called) == {"Tap"}, ( "delete_snapshot_tree's fallback sweep must enumerate from ZFS by default. " "If it defaults to a middleware query, it cannot see the internal datasets " "and orphans one snapshot per hidden dataset on every run." @@ -1302,7 +1352,9 @@ class TestTheProductionWiringIsWhatWeThinkItIs: monkeypatch.setattr(tn, "STAGING_BASE", str(tmp_path)) tn.gc_stale_snapshots(mw, "cloud_backup-5", "Tap@cloud_backup-5-2026", mounts_file=str(mounts)) - assert called == ["Tap"], "the GC must enumerate from ZFS by default too" + assert called and set(called) == {"Tap"}, ( + "the GC must enumerate from ZFS by default too" + ) def test_the_injected_block_enumerates_from_ZFS_not_middleware(self): # apply.sh is a shell file holding the Python that gets injected into @@ -1314,14 +1366,23 @@ class TestTheProductionWiringIsWhatWeThinkItIs: assert "_tc_nested.query_filesystems(" in src, ( "the staging plan must be built from query_filesystems() (which reads ZFS)" ) - for filtered in ("pool.dataset.query", "pool.snapshot.query", - "zfs.dataset.query", "zfs.snapshot.query"): - assert f'"{filtered}"' not in src, ( - f"apply.sh calls {filtered}. Middleware's queries apply a visibility " - f"policy and hide ix-apps/*, .system/*, .ix-virt/* -- 84 of 270 " - f"datasets on a real pool, including live app data. Enumerating from " - f"them omits those datasets from the backup SILENTLY." - ) + + # Match the METHOD NAME however it is quoted. An earlier version of this test + # only looked for the double-quoted form, so a single-quoted + # `call_sync('pool.snapshot.query')` -- including one passed in as the sweep's + # lister, which is the catastrophic case -- sailed straight through it. + import re + code = "\n".join( + ln for ln in src.splitlines() if not ln.lstrip().startswith("#") + ) + offenders = re.findall(r"\b(?:pool|zfs)\.(?:dataset|snapshot)\.query\b", code) + assert not offenders, ( + f"apply.sh references {sorted(set(offenders))}. Middleware's queries apply " + f"a visibility policy and hide ix-apps/*, .system/*, .ix-virt/* -- 84 of " + f"270 datasets on a real pool, including live app data. Enumerating from " + f"them omits those datasets from the backup SILENTLY, and sweeping from " + f"them orphans one snapshot per hidden dataset on every run." + ) class TestTheSnapshotNamespaceIsResolvedNotAssumed: @@ -1367,7 +1428,16 @@ class TestTheSnapshotNamespaceIsResolvedNotAssumed: class GuttedPoolSnapshot(FakeMiddleware): def get_service(self, name): if name == "pool.snapshot": - return object() # registered, but no delete on it + # Registered, and `delete` IS still there -- inherited from + # CRUDService, which dispatches to a `do_delete` that no longer + # exists. This is the shape middlewared actually produces, and a + # naive `hasattr(service, "delete")` says YES to it. + gutted = _FakeSnapshotService(None) + assert callable(gutted.delete), ( + "the fake must keep the inherited dispatcher, or it cannot " + "reproduce the bug" + ) + return gutted if name == "zfs.snapshot": return super().get_service("zfs.snapshot") raise KeyError(name) @@ -1428,9 +1498,6 @@ class TestWeOwnTheSweepEvenWhenWeDoNotStage: def test_own_snapshot_records_a_snapshot_it_did_not_stage(self, tmp_path, monkeypatch): monkeypatch.setattr(tn, "STAGING_BASE", str(tmp_path)) - mounts = tmp_path / "mounts" - mounts.write_text("") - mw = FakeMiddleware(["Tap@cloud_backup-5-2026", "Tap/vm-zvol@cloud_backup-5-2026"]) root = tn.own_snapshot(mw, "cloud_backup-5", "Tap@cloud_backup-5-2026", list_snapshots=mw.list_snapshots) @@ -1442,8 +1509,6 @@ class TestWeOwnTheSweepEvenWhenWeDoNotStage: def test_the_recorded_snapshot_is_then_actually_swept(self, tmp_path, monkeypatch): monkeypatch.setattr(tn, "STAGING_BASE", str(tmp_path)) - mounts = tmp_path / "mounts" - mounts.write_text("") # A recursive snapshot of a dataset whose only child is a ZVOL: exactly the # 26 case. Nothing to stage, but the children are real. @@ -1479,3 +1544,157 @@ class TestWeOwnTheSweepEvenWhenWeDoNotStage: "not ours) and deletes only the parent -- so every child is orphaned, with " "no sidecar and no GC, on every run." ) + + +class TestASilentNoOpDeleteCannotDropTheSidecar: + """A delete that returns without raising is not proof anything was destroyed. + + iX has already gutted `pool.snapshot.do_update` on master into a no-op whose body + is commented out and which returns None. An AST check still sees the `def`; a + callable check still sees the method. If `do_delete` ever goes the same way, the + recursive delete returns cleanly, `delete_snapshot_tree` reports no survivors, + `cleanup_task` removes the sidecar -- the only record -- and ~250 snapshots are + orphaned forever with the backup reporting SUCCESS. + """ + + def test_a_delete_that_does_nothing_is_caught_and_reported(self): + class NoOpDelete(FakeMiddleware): + def call_sync(self, method, *args): + self.calls.append((method, args)) + return None # "succeeds", destroys nothing + + mw = NoOpDelete(["Tap@snap", "Tap/apps@snap", "Tap/apps/lidarr@snap"]) + survivors = tn.delete_snapshot_tree( + mw, "Tap@snap", list_snapshots=mw.list_snapshots, sleep=lambda _s: None, + ) + + assert sorted(survivors) == sorted( + ["Tap@snap", "Tap/apps@snap", "Tap/apps/lidarr@snap"]), ( + "a no-op delete must be REPORTED as survivors, so cleanup_task keeps the " + "sidecar and the next run reclaims them. Returning [] here silently " + "orphans the entire tree." + ) + + def test_an_unconfirmable_delete_keeps_owning_the_tree(self): + # If ZFS cannot be read we cannot confirm the delete did anything. Claiming a + # clean sweep makes cleanup_task DROP the sidecar -- and if the delete had in + # fact done nothing, the tree is orphaned with no record of it, forever. + # + # The two mistakes are not symmetric. A false survivor self-heals: the sidecar + # is kept, the next run reclaims it, the delete raises "does not exist", and + # the record clears. A lost record is permanent. So when in doubt, keep owning. + mw = FakeMiddleware(["Tap@snap"]) + + def cannot_enumerate(_dataset): + raise tn.ZfsError("pool I/O is currently suspended") + + assert tn.delete_snapshot_tree( + mw, "Tap@snap", list_snapshots=cannot_enumerate, sleep=lambda _s: None, + ) == ["Tap@snap"] + + +class TestTheMalformedRowGuard: + """`zfs list -H` neither quotes nor escapes. A tab in a mountpoint splits wrong. + + Dropping such a row would remove a dataset from the staging plan without it + appearing in `skipped` either -- the cardinal-rule failure, on the newest code + path. Two mutations (silently filtering the row; dropping the `fields=` argument) + used to pass the whole suite. + """ + + @staticmethod + def _runner(stdout): + class R: + returncode = 0 + stderr = "" + R.stdout = stdout + return lambda cmd: R() + + def test_a_row_with_the_wrong_field_count_RAISES(self): + # A mountpoint containing a tab -> 4 fields, not 3. + bad = "scratch\t/mnt/scratch\tyes\nscratch/odd\t/mnt/od\td\tyes\n" + with pytest.raises(tn.ZfsError, match="tab-separated"): + tn.query_filesystems(runner=self._runner(bad)) + + def test_the_error_names_the_offending_row(self): + bad = "a\tb\tc\nbroken\trow\n" + with pytest.raises(tn.ZfsError, match="broken"): + tn.query_filesystems(runner=self._runner(bad)) + + def test_the_field_count_is_actually_enforced_for_snapshots_too(self): + with pytest.raises(tn.ZfsError): + tn.list_snapshot_names("Tap", runner=self._runner("ok\nnot\tok\n")) + + def test_query_filesystems_asks_zfs_for_filesystems_only(self): + # Dropping `-t filesystem` would drag in volumes and snapshots, which the + # planner would then try to stage. + seen = [] + + def runner(cmd): + seen.append(cmd) + return self._runner("Tap\t/mnt/Tap\tyes\n")(cmd) + + tn.query_filesystems(runner=runner) + assert "-t" in seen[0] and "filesystem" in seen[0] + assert "name,mountpoint,mounted" in seen[0] + + +class TestTheGarbageCollectorIsActuallyWiredIn: + """The GC is the ONLY recovery path when the sidecar itself is gone. + + The sidecar lives in /run (tmpfs), so a reboot mid-backup destroys it and orphans + the whole tree with nothing pointing at it. `own_snapshot` is the GC's only + production caller -- and stubbing that call out used to pass all 304 tests, i.e. + the GC could have been silently disconnected. + """ + + def test_own_snapshot_runs_the_collector(self, tmp_path, monkeypatch): + monkeypatch.setattr(tn, "STAGING_BASE", str(tmp_path)) + ran = [] + monkeypatch.setattr( + tn, "gc_stale_snapshots", + lambda *a, **kw: ran.append(a[1]) or [], + ) + mw = FakeMiddleware(["Tap@new"]) + tn.own_snapshot(mw, "cloud_backup-5", "Tap@new", + list_snapshots=mw.list_snapshots) + assert ran == ["cloud_backup-5"], ( + "own_snapshot did not run the garbage collector. It is the only thing that " + "ever finds a tree whose sidecar was lost to a reboot." + ) + + def test_a_collected_orphan_is_carried_into_the_sidecar_if_it_survives( + self, tmp_path, monkeypatch + ): + monkeypatch.setattr(tn, "STAGING_BASE", str(tmp_path)) + monkeypatch.setattr( + tn, "gc_stale_snapshots", lambda *a, **kw: ["Tap/x@busy-orphan"], + ) + mw = FakeMiddleware(["Tap@new"]) + root = tn.own_snapshot(mw, "cloud_backup-5", "Tap@new", + list_snapshots=mw.list_snapshots) + assert "Tap/x@busy-orphan" in tn._read_sidecar(root), ( + "an orphan the GC could not delete must be RECORDED, or the next run has " + "no idea it exists" + ) + + +class TestTheServiceIsResolvedLazily: + """`_Snapshots.service` resolves on first use, not in the constructor. + + Eager resolution looks harmless and is not: `gc_stale_snapshots` would raise inside + its own broad `except` and silently collect nothing, and `delete_snapshot_tree` + would raise `StagingError` out of the constructor -- outside its try -- instead of + returning survivors. + """ + + def test_constructing_it_against_a_hopeless_middleware_does_not_raise(self): + class Neither(FakeMiddleware): + def get_service(self, name): + raise KeyError(name) + + snaps = tn._Snapshots(Neither()) # must not raise + assert snaps.names is not None + + with pytest.raises(StagingError): + snaps.delete("Tap@snap") # ...only the MUTATION refuses diff --git a/tools/compat.py b/tools/compat.py index 7a991d0..e9e51eb 100644 --- a/tools/compat.py +++ b/tools/compat.py @@ -494,7 +494,10 @@ def check_source(a: Assumption, src: str | None) -> tuple[str, str | None]: breaks a box that was working. """ if src is None: - return "broken", f"{a.path} does not exist" + # Name the SYMBOL, not just the file. Whoever reads the bug report needs to + # know what the patch can no longer reach, and "utils/plugins.py does not + # exist" does not tell them that `get_service` is gone. + return "broken", f"{a.path} does not exist, so `{a.symbol}` is gone" try: tree = ast.parse(src) @@ -629,6 +632,7 @@ def check(loader, modules=None) -> dict: out[a.module]["unknown"] = True out[a.module]["problems"].append({ "id": a.id, "detail": f"could not read {a.path}: {e}", "why": a.why, + "state": "unknown", }) continue @@ -636,12 +640,12 @@ def check(loader, modules=None) -> dict: if status == "broken": out[a.module]["ok"] = False out[a.module]["problems"].append({ - "id": a.id, "detail": detail, "why": a.why, + "id": a.id, "detail": detail, "why": a.why, "state": "broken", }) elif status == "unknown": out[a.module]["unknown"] = True out[a.module]["problems"].append({ - "id": a.id, "detail": detail, "why": a.why, + "id": a.id, "detail": detail, "why": a.why, "state": "unknown", }) # The methods the injected code CALLS, not just the symbols it wraps. @@ -680,11 +684,13 @@ def check(loader, modules=None) -> dict: out[c.module]["unknown"] = True out[c.module]["problems"].append({ "id": c.id, "detail": "; ".join(details), "why": c.why, + "state": "unknown", }) else: out[c.module]["ok"] = False out[c.module]["problems"].append({ "id": c.id, "detail": "; ".join(details), "why": c.why, + "state": "broken", }) for module, (path, phrase, native_when_present) in NATIVE_PROBES.items(): @@ -1026,6 +1032,12 @@ def fingerprint(rows: list[dict]) -> str: for mod, m in r["modules"].items() if is_broken(m) for p in m["problems"] + # `unknown` problems are things we could not READ (a 429, an EACCES), not + # things iX changed. On a ref that is broken for some other reason they would + # otherwise join the digest, so one transient network blip rewrites the issue + # body and the next clean run rewrites it back. That is the daily-noise + # failure this fingerprint exists to prevent, wearing a different hat. + if p.get("state", "broken") == "broken" ) return hashlib.sha256(repr(findings).encode()).hexdigest()[:16]