From 4fee040a8076e2c1951e77ad8602206abc80e400 Mon Sep 17 00:00:00 2001 From: Elmehdi Aitbrahim Date: Tue, 1 Sep 2026 19:01:55 -0400 Subject: [PATCH] feat(doctor): count the update backups nobody was ever told about (#681) `keel update` copies every `keel*.db` before it installs and NEVER deletes one. That is correct -- `update.py` names them as the data-recovery path, and an updater that pruned its own rollback would be an updater you cannot roll back from. What was missing is that nothing ever told the operator they were there. The live deployment, measured 2026-09-01: 88 files, 7.0 GB in ~/keel plus 408 MB in ~/keel/backups, database backups for 24 releases going back to 0.4.0. Three databases at 130-180 MB, one set per release, roughly one release a week -- so it grows ~470 MB per update and nothing bounds it. A FAILED update wrote a set too until #676 reordered downloads first, so retries used to compound it. 343 GB free today, so this is not urgent. It is INVISIBLE, which is the actual problem: the first signal would be a disk filling during an update, which is the one moment a rollback path matters most. SURFACE, NEVER DELETE, and the fix line is where that is enforced. `doctor` gains `backups.footprint` -- WARN past three per database, OK below, because a handful of recent backups is the design working and warning about three would train the finding to be ignored by the time it matters. The fix text says to prune BY HAND and says keel will not do it, and a test asserts the string offers no `keel backups prune`, no `--prune` and no `rm`. A second test scans `keel/` for any line that both mentions `bak-before` and calls `unlink`/`rmtree`/`os.remove`, so a future change to the rollback guarantee has to delete that test to make it. THE COUNT IS THE ACTIONABLE NUMBER, not the bytes. "keel.db: 23 going back to 0.4.0" says what to do; "7 GB" says only that something is large. A hand-named backup (`keel.db.bak-before-recordflow-...`, which exists in the live folder) is deliberately never sorted as the oldest RELEASE -- reporting the oldest as "recordflow" is both wrong and unactionable, since the operator cannot decide whether to keep a release they cannot name. `keel update`'s plan also names what is already kept, at the one moment the operator is thinking about backups anyway: immediately before another set is written. 9 mutants, 9 killed, and two of them changed the code rather than the tests. Replacing the launch-folder read with an empty footprint passed everything -- the seeded deployment has no backups, so both paths reported `ok` and the finding was never shown reading anywhere real. And the `try/except OSError` around the glob turned out to be UNREACHABLE: `Path.glob` returns an empty iterator for a missing directory and for one at mode 000 alike, so deleting the handler changed nothing. It is gone, with the correction recorded where it was -- what genuinely races is `stat` on a file that vanished between the glob and the read, and that one is guarded where it can actually happen. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01NzuKAe2RVrPt9acVAWjRyL --- keel/commands/doctor.py | 121 ++++++++++++++++++++++++++ keel/commands/update.py | 14 +++ tests/commands/test_doctor.py | 159 ++++++++++++++++++++++++++++++++++ tests/commands/test_update.py | 28 ++++++ 4 files changed, 322 insertions(+) diff --git a/keel/commands/doctor.py b/keel/commands/doctor.py index 64438d9..9df4c8f 100644 --- a/keel/commands/doctor.py +++ b/keel/commands/doctor.py @@ -852,6 +852,122 @@ def orphan_bracket_findings(records: dict[str, Any]) -> list[Finding]: ] +@dataclass(frozen=True) +class BackupFootprint: + """What `keel update` has left behind in one launch folder (#681).""" + + #: `.bak-before-...` files, grouped by the database they were taken from. + per_database: dict[str, int] + total_files: int + total_bytes: int + #: The version stamp of the oldest backup, for the operator's sense of how far back this + #: goes -- "0.4.0" says more about whether to act than a byte count does. + oldest_version: str | None + + +def backup_footprint_findings(footprint: BackupFootprint, *, keep: int = 3) -> list[Finding]: + """Superseded update backups, counted rather than deleted (#681). + + `keel update` copies every database before it installs and NEVER removes one. That is + correct -- `update.py` names them as the data-recovery path, and an updater that pruned its + own rollback would be an updater you cannot roll back from. So this reports and does not + act, and `test_nothing_in_keel_deletes_an_update_backup` is the pin that keeps it that way. + + **The COUNT is the operator-actionable number, not the bytes.** "23 superseded copies of + keel.db, oldest from 0.4.0" tells someone what to do; "7 GB" tells them only that something + is large. The size rides along because a disk filling during an update is the failure mode, + and it is the one moment a rollback path matters most. + + WARN, not FAIL, and never below `keep`: a handful of recent backups is the design working. + What is worth a human's attention is a launch folder still holding the rollback for a + version nobody could install any more. + """ + superseded = {db: n for db, n in footprint.per_database.items() if n > keep} + if not superseded: + return [ + Finding( + "backups.footprint", + OK, + f"{footprint.total_files} update backup(s) retained", + f"{_human_bytes(footprint.total_bytes)}; nothing beyond the {keep} most recent " + "per database", + "-", + ) + ] + described = ", ".join( + f"{db}: {count}" for db, count in sorted(superseded.items(), key=lambda kv: -kv[1]) + ) + since = f" going back to {footprint.oldest_version}" if footprint.oldest_version else "" + return [ + Finding( + "backups.footprint", + WARN, + f"{footprint.total_files} update backups, {_human_bytes(footprint.total_bytes)}", + f"{described}{since} -- `keel update` never deletes one, by design, so they " + "accumulate one set per release", + "review and prune BY HAND: `ls -lhS /*.bak-before-*`. keel will not delete " + "a backup for you -- the release you need is the one before the release that broke", + ) + ] + + +def _human_bytes(count: int) -> str: + """A size an operator reads at a glance. Binary units, one decimal, never scientific.""" + size = float(count) + for unit in ("B", "KiB", "MiB", "GiB"): + if size < 1024 or unit == "GiB": + return f"{size:.1f} {unit}" if unit != "B" else f"{int(size)} B" + size /= 1024 + return f"{size:.1f} GiB" # pragma: no cover - the loop always returns + + +def read_backup_footprint(launch_dir: Path) -> BackupFootprint: + """Measure `launch_dir`'s `.bak-before-*` files. Never raises. + + `doctor` is what an operator runs when something is already wrong, so a launch folder it + cannot read must produce an empty measurement rather than an exception -- a diagnostic that + dies on the state it exists to describe is worse than no diagnostic. + + **No `try` around the glob, and that is a correction rather than an omission.** The first + version wrapped it, on the assumption that a missing or unreadable directory raises. It does + not: `Path.glob` returns an empty iterator for a path that does not exist AND for one with + mode 000, so the handler was unreachable and a mutation deleting it changed nothing -- + which is how it was found. What genuinely races is `stat` on a file that vanished between + the glob and the read, and that one is guarded below where it can actually happen. + """ + per_database: dict[str, int] = {} + total_bytes = 0 + total_files = 0 + versions: list[str] = [] + for path in sorted(launch_dir.glob("*.bak-before-*")): + try: + total_bytes += path.stat().st_size + except OSError: + continue + total_files += 1 + database, _, stamp = path.name.partition(".bak-before-") + per_database[database] = per_database.get(database, 0) + 1 + version = stamp.rsplit("-", 2)[0] if "-" in stamp else stamp + if version: + versions.append(version) + return BackupFootprint( + per_database=per_database, + total_files=total_files, + total_bytes=total_bytes, + oldest_version=min(versions, key=_version_key) if versions else None, + ) + + +def _version_key(stamp: str) -> tuple[int, ...]: + """Sort `0.4.0` before `0.13.2`, and anything unparseable last -- a hand-named backup + (`keel.db.bak-before-recordflow-...`) is not a release and must not claim to be the oldest + one.""" + parts = stamp.split(".") + if len(parts) == 3 and all(p.isdigit() for p in parts): + return (0, *(int(p) for p in parts)) + return (1,) + + def unbooked_exit_findings( open_positions: list[dict[str, Any]], orders: list[dict[str, Any]] ) -> list[Finding]: @@ -1021,6 +1137,7 @@ def gather_findings(repo: Any, config: Any, log_lines: Iterable[str], now_ts: in """ from keel import agent from keel.commands import fetch + from keel.commands import update as update_mod from keel.commands._products import _default_sim_products from keel.execution import executor as executor_mod from keel.execution import guards @@ -1083,6 +1200,10 @@ def gather_findings(repo: Any, config: Any, log_lines: Iterable[str], now_ts: in for key in repo.get_state_keys(reconcile_mod.ORPHAN_BRACKET_PREFIX) } ) + # #681. The LAUNCH FOLDER, resolved the way `keel update` resolves it -- the same directory + # the runbook's four commands run from -- because that is where the updater writes and + # therefore the only place the count means anything. + findings += backup_footprint_findings(read_backup_footprint(update_mod._launch_dir())) # #639: modes are POOLED here, unlike the partial-fill sweep above -- the ledger # invariant belongs to `agent._open_tranche`, which writes it for paper and live alike. findings += unbooked_exit_findings(repo.get_open_positions(), repo.get_orders()) diff --git a/keel/commands/update.py b/keel/commands/update.py index 3d4f39a..11bc150 100644 --- a/keel/commands/update.py +++ b/keel/commands/update.py @@ -1125,6 +1125,20 @@ def render_plan_lines(plan: UpdatePlan) -> list[str]: for name in plan.wheel_names: lines.append(f" wheel: {name}") lines.append(f" download to: {plan.release_dir}") + # #681: what is ALREADY there, named at the one moment the operator is thinking about + # backups anyway -- immediately before another set is written. Reported, never acted on: + # `keel update` does not delete a backup, and this line is not the beginning of one that + # does. A launch folder it cannot read simply contributes nothing. + existing = sorted(plan.launch_dir.glob("*.bak-before-*")) + if existing: + try: + total = sum(path.stat().st_size for path in existing) + except OSError: # pragma: no cover - a file that vanished between glob and stat + total = 0 + lines.append( + f" already kept from earlier updates: {len(existing)} file(s), " + f"{total / (1024 * 1024):.0f} MiB (never deleted by keel -- prune by hand)" + ) if plan.db_paths: names = ", ".join(path.name for path in plan.db_paths) lines.append(f" then back up (never deleted): {names}") diff --git a/tests/commands/test_doctor.py b/tests/commands/test_doctor.py index c583578..452701b 100644 --- a/tests/commands/test_doctor.py +++ b/tests/commands/test_doctor.py @@ -24,6 +24,7 @@ admissibility_findings, allowance_findings, attestation_findings, + backup_footprint_findings, balance_drift_findings, data_health_findings, doctor_exit_code, @@ -32,6 +33,7 @@ orphan_bracket_findings, partial_fill_findings, rail_state_findings, + read_backup_footprint, render_json, trade_scope_findings, unbooked_exit_findings, @@ -584,6 +586,7 @@ def test_gather_findings_covers_every_check_over_a_seeded_db(tmp_path, valid_con "fill.partial", "balance.drift", "bracket.orphan", + "backups.footprint", "ledger.unbooked_exit", "data.missing", "data.stale", @@ -883,3 +886,159 @@ def test_gather_findings_surfaces_a_swept_orphan(tmp_path, valid_config_path) -> (orphan,) = [f for f in findings if f.name == "bracket.orphan"] assert orphan.status == "warn" assert "BTC-USD" in orphan.detail + + +# -- update backups: counted, never deleted (#681) ------------------------------------------------ + + +def _bak(launch: Path, name: str, size: int = 1024) -> None: + (launch / name).write_bytes(b"x" * size) + + +def test_a_launch_folder_with_no_backups_says_so_calmly(tmp_path) -> None: + """A fresh deployment must not be told it has a problem it does not have.""" + (finding,) = backup_footprint_findings(read_backup_footprint(tmp_path)) + + assert finding.name == "backups.footprint" + assert finding.status == "ok" + + +def test_a_handful_of_recent_backups_is_the_design_working(tmp_path) -> None: + """`keel update` is SUPPOSED to leave these. Warning about three would train the finding + to be ignored by the time it matters.""" + for version in ("0.13.0", "0.13.1", "0.13.2"): + _bak(tmp_path, f"keel.db.bak-before-{version}-20260901-120000") + + (finding,) = backup_footprint_findings(read_backup_footprint(tmp_path)) + + assert finding.status == "ok" + + +def test_backups_beyond_the_keep_count_are_surfaced_per_database(tmp_path) -> None: + """The COUNT is the operator-actionable number. "23 copies of keel.db, oldest 0.4.0" says + what to do; a byte total says only that something is large.""" + for version in ("0.4.0", "0.9.1", "0.12.2", "0.13.1", "0.13.2"): + _bak(tmp_path, f"keel.db.bak-before-{version}-20260901-120000") + _bak(tmp_path, "keel-live.db.bak-before-0.13.2-20260901-120000") + + (finding,) = backup_footprint_findings(read_backup_footprint(tmp_path)) + + assert finding.status == "warn" + assert "keel.db: 5" in finding.detail + assert "0.4.0" in finding.detail, "the oldest version is what says how far back this goes" + assert "keel-live.db" not in finding.detail, "one backup is not an accumulation" + + +def test_the_fix_never_tells_keel_to_delete_anything(tmp_path) -> None: + """**The load-bearing test of this finding.** These files are the data-recovery path, and + the release you need is the one before the release that broke. A fix line that offered to + prune them would be the updater deleting its own rollback with extra steps.""" + for version in ("0.4.0", "0.9.1", "0.12.2", "0.13.2"): + _bak(tmp_path, f"keel.db.bak-before-{version}-20260901-120000") + + (finding,) = backup_footprint_findings(read_backup_footprint(tmp_path)) + + assert "BY HAND" in finding.fix + assert "keel will not delete" in finding.fix + for forbidden in ("keel backups prune", "--prune", "rm -rf"): + assert forbidden not in finding.fix + + +def test_nothing_in_keel_deletes_an_update_backup() -> None: + """The pin that outlives this finding. + + `update.py` states that the `.bak-before-*` files are never removed, and every recovery + procedure in the runbook rests on it. A future change that added a prune would be a change + to the rollback guarantee, and it should have to delete this test to make it. + """ + import keel + + root = Path(keel.__file__).resolve().parent + offenders: list[str] = [] + for path in sorted(root.rglob("*.py")): + source = path.read_text(encoding="utf-8") + if "bak-before" not in source: + continue + for line in source.splitlines(): + if "bak-before" not in line: + continue + if any(verb in line for verb in ("unlink", "rmtree", "os.remove", "shutil.move")): + offenders.append(f"{path.name}: {line.strip()}") + assert not offenders, ( + f"something now deletes an update backup: {offenders}. These are the data-recovery " + "path; the release you need is the one before the release that broke." + ) + + +def test_an_unreadable_launch_folder_does_not_break_doctor(tmp_path) -> None: + """`doctor` is what an operator runs when something is already wrong. A diagnostic that + dies on the state it exists to describe is worse than no diagnostic.""" + missing = tmp_path / "not-a-directory" + + footprint = read_backup_footprint(missing) + + assert footprint.total_files == 0 + assert backup_footprint_findings(footprint)[0].status == "ok" + + +def test_a_hand_named_backup_never_claims_to_be_the_oldest_release(tmp_path) -> None: + """`keel.db.bak-before-recordflow-...` exists in the live deployment and is not a version. + + Sorting it as one would report the oldest release as "recordflow", which is both wrong and + unactionable -- the operator cannot decide whether to keep a release they cannot name. + """ + _bak(tmp_path, "keel.db.bak-before-recordflow-20260820T075747") + for version in ("0.9.1", "0.12.2", "0.13.1", "0.13.2"): + _bak(tmp_path, f"keel.db.bak-before-{version}-20260901-120000") + + footprint = read_backup_footprint(tmp_path) + + assert footprint.oldest_version == "0.9.1" + + +def test_gather_findings_reads_the_real_launch_folder(tmp_path, valid_config_path, monkeypatch): + """The wiring, not just the finding. + + A mutation replacing the launch-folder read with an empty footprint passed every test above, + because the seeded deployment has no backups and both paths then report `ok`. The finding + has to be shown reading somewhere real. + + Resolved through `update._launch_dir`, the same seam `keel update` uses, so doctor counts + the folder the updater actually writes to rather than the process's cwd. + """ + from keel.commands import update as update_mod + + launch = tmp_path / "launch" + launch.mkdir() + for version in ("0.4.0", "0.9.1", "0.12.2", "0.13.2"): + (launch / f"keel.db.bak-before-{version}-20260901-120000").write_bytes(b"x" * 4096) + monkeypatch.setattr(update_mod, "_launch_dir", lambda: launch) + + repo = _seeded_repo(tmp_path / "keel.db") + findings = gather_findings(repo, load_config(valid_config_path), [], NOW) + + (footprint,) = [f for f in findings if f.name == "backups.footprint"] + assert footprint.status == "warn", ( + "doctor reported no backups for a folder holding four -- it is not reading the launch " + "folder the updater writes to" + ) + assert "keel.db: 4" in footprint.detail + + +def test_a_folder_keel_cannot_read_measures_as_empty(tmp_path) -> None: + """`Path.glob` returns nothing for a missing directory and for one with mode 000 alike, so + this is a statement about behaviour rather than about a handler -- see the note in + `read_backup_footprint` about the guard that was removed for being unreachable.""" + import os + + unreadable = tmp_path / "sealed" + unreadable.mkdir() + (unreadable / "keel.db.bak-before-0.1.0-1").write_bytes(b"x") + os.chmod(unreadable, 0o000) + try: + footprint = read_backup_footprint(unreadable) + finally: + os.chmod(unreadable, 0o755) + + assert footprint.total_files == 0 + assert read_backup_footprint(tmp_path / "missing").total_files == 0 diff --git a/tests/commands/test_update.py b/tests/commands/test_update.py index ac8a834..0b465b6 100644 --- a/tests/commands/test_update.py +++ b/tests/commands/test_update.py @@ -1531,3 +1531,31 @@ def test_a_failed_download_does_not_claim_backups_left_by_an_EARLIER_run(tmp_pat "an earlier update and this run took none" ) assert stale.is_file(), "an earlier run's backup must never be touched" + + +def test_the_plan_names_the_backups_already_kept(tmp_path: Path) -> None: + """#681: surfaced at the one moment the operator is already thinking about backups — + immediately before another set is written. + + Reported, never acted on. `keel update` does not delete a backup, and this line is not the + beginning of one that does; `tests/commands/test_doctor.py` carries the pin that nothing in + keel ever removes one. + """ + launch = _deployment(tmp_path) + for version in ("0.12.2", "0.13.1"): + (launch / f"keel.db.bak-before-{version}-20260901-120000").write_bytes(b"x" * 2048) + plan = _plan(launch) + + lines = up.render_plan_lines(plan) + + kept = [line for line in lines if "already kept" in line] + assert kept, f"the plan did not name the existing backups: {lines}" + assert "2 file(s)" in kept[0] + assert "never deleted by keel" in kept[0] + + +def test_a_launch_folder_with_no_backups_adds_no_line(tmp_path: Path) -> None: + """A first update must not be told about a footprint it does not have.""" + plan = _plan(_deployment(tmp_path)) + + assert not [line for line in up.render_plan_lines(plan) if "already kept" in line]