diff --git a/hermes_cli/backup.py b/hermes_cli/backup.py index 2a25217160c0..86353f5672af 100644 --- a/hermes_cli/backup.py +++ b/hermes_cli/backup.py @@ -253,26 +253,57 @@ def _should_skip_backup_file(abs_path: Path, rel_path: Path, out_path: Path) -> # SQLite safe copy # --------------------------------------------------------------------------- +_SQLITE_BACKUP_PAGES = 256 +_SQLITE_BACKUP_RETRY_SLEEP_SECONDS = 0.1 +_SQLITE_BACKUP_STALL_TIMEOUT_SECONDS = 30.0 + + def _safe_copy_db(src: Path, dst: Path) -> bool: """Copy a SQLite database safely using the backup() API. Handles WAL mode — produces a consistent snapshot even while the DB is being written to. Fail closed if a consistent snapshot cannot be created: copying only the live main file can omit committed WAL data. + Abort when the backup makes no page progress for a bounded interval so a + persistently locked database cannot stall the whole backup indefinitely. """ conn = None backup_conn = None + copy_succeeded = False try: - conn = sqlite3.connect(f"file:{src}?mode=ro", uri=True) - backup_conn = sqlite3.connect(str(dst)) - conn.backup(backup_conn) + conn = sqlite3.connect(f"file:{src}?mode=ro", uri=True, timeout=0.0) + backup_conn = sqlite3.connect(str(dst), timeout=0.0) + last_progress_at = time.monotonic() + + def _check_progress(status: int, _remaining: int, _total: int) -> None: + nonlocal last_progress_at + if status == sqlite3.SQLITE_DONE: + return + + now = time.monotonic() + if status == sqlite3.SQLITE_OK: + # SQLite returns OK only after successfully copying pages. + last_progress_at = now + return + + if status in (sqlite3.SQLITE_BUSY, sqlite3.SQLITE_LOCKED) and ( + now - last_progress_at >= _SQLITE_BACKUP_STALL_TIMEOUT_SECONDS + ): + raise TimeoutError( + "SQLite backup timed out after " + f"{_SQLITE_BACKUP_STALL_TIMEOUT_SECONDS:g}s without page progress" + ) + + conn.backup( + backup_conn, + pages=_SQLITE_BACKUP_PAGES, + progress=_check_progress, + sleep=_SQLITE_BACKUP_RETRY_SLEEP_SECONDS, + ) + copy_succeeded = True return True except Exception as exc: logger.warning("SQLite safe copy failed for %s: %s", src, exc) - try: - dst.unlink(missing_ok=True) - except OSError: - pass return False finally: for connection in (backup_conn, conn): @@ -281,6 +312,11 @@ def _safe_copy_db(src: Path, dst: Path) -> bool: connection.close() except Exception: pass + if not copy_succeeded: + try: + dst.unlink(missing_ok=True) + except OSError: + pass # --------------------------------------------------------------------------- diff --git a/tests/hermes_cli/test_backup.py b/tests/hermes_cli/test_backup.py index cbac29eae503..47e6b5963b99 100644 --- a/tests/hermes_cli/test_backup.py +++ b/tests/hermes_cli/test_backup.py @@ -3,6 +3,7 @@ import json import os import sqlite3 +import time import zipfile from argparse import Namespace from pathlib import Path @@ -258,7 +259,7 @@ class FailingBackupConnection: def __init__(self, connection): self._connection = connection - def backup(self, _destination): + def backup(self, _destination, **_kwargs): raise sqlite3.OperationalError("forced backup failure") def close(self): @@ -1391,6 +1392,133 @@ def fake_import(name, *a, **kw): # --------------------------------------------------------------------------- class TestSafeCopyDb: + @pytest.mark.timeout(10) + def test_real_exclusive_lock_is_bounded(self, tmp_path, monkeypatch, caplog): + import hermes_cli.backup as backup_mod + + src = tmp_path / "locked.db" + dst = tmp_path / "copy.db" + lock_holder = sqlite3.connect(src) + try: + lock_holder.execute("CREATE TABLE sample (value TEXT)") + lock_holder.commit() + lock_holder.execute("BEGIN EXCLUSIVE") + + monkeypatch.setattr( + backup_mod, "_SQLITE_BACKUP_STALL_TIMEOUT_SECONDS", 0.2 + ) + monkeypatch.setattr( + backup_mod, "_SQLITE_BACKUP_RETRY_SLEEP_SECONDS", 0.01 + ) + + started = time.monotonic() + result = backup_mod._safe_copy_db(src, dst) + elapsed = time.monotonic() - started + finally: + lock_holder.close() + + assert result is False + assert elapsed < 5.0 + assert not dst.exists() + assert str(src) in caplog.text + assert "timed out" in caplog.text.lower() + + def test_persistent_busy_backup_times_out_and_cleans_up( + self, tmp_path, monkeypatch, caplog + ): + import hermes_cli.backup as backup_mod + + src = tmp_path / "locked.db" + dst = tmp_path / "copy.db" + src.touch() + dst.write_bytes(b"partial") + + class FakeConnection: + def __init__(self, *, source=False): + self.source = source + self.closed = False + self.backup_kwargs = None + + def backup(self, _destination, **kwargs): + self.backup_kwargs = kwargs + progress = kwargs.get("progress") + if progress is None: + return + progress(sqlite3.SQLITE_BUSY, 10, 10) + progress(sqlite3.SQLITE_BUSY, 10, 10) + + def close(self): + self.closed = True + + source = FakeConnection(source=True) + destination = FakeConnection() + connections = iter((source, destination)) + monkeypatch.setattr( + backup_mod.sqlite3, "connect", lambda *_args, **_kwargs: next(connections) + ) + clock = iter((0.0, 0.0, 31.0)) + monkeypatch.setattr(backup_mod.time, "monotonic", lambda: next(clock)) + real_unlink = Path.unlink + + def unlink_after_close(path, *args, **kwargs): + if path == dst and not destination.closed: + raise PermissionError("destination is still open") + return real_unlink(path, *args, **kwargs) + + monkeypatch.setattr(Path, "unlink", unlink_after_close) + + assert backup_mod._safe_copy_db(src, dst) is False + assert not dst.exists() + assert source.closed is True + assert destination.closed is True + assert source.backup_kwargs is not None + assert source.backup_kwargs["pages"] > 0 + assert callable(source.backup_kwargs["progress"]) + assert str(src) in caplog.text + assert "timed out" in caplog.text.lower() + + def test_page_progress_refreshes_stall_deadline(self, tmp_path, monkeypatch): + import hermes_cli.backup as backup_mod + + src = tmp_path / "busy-but-progressing.db" + dst = tmp_path / "copy.db" + src.touch() + + class FakeConnection: + def __init__(self, *, source=False): + self.source = source + self.closed = False + + def backup(self, destination, **kwargs): + progress = kwargs["progress"] + progress(sqlite3.SQLITE_OK, 20, 30) + progress(sqlite3.SQLITE_BUSY, 20, 30) + # A concurrent source write can restart SQLite's online backup, + # temporarily increasing the remaining-page count. + progress(sqlite3.SQLITE_OK, 25, 30) + progress(sqlite3.SQLITE_OK, 20, 30) + # SQLITE_OK means pages were copied even if concurrent writes + # leave the reported remaining-page count unchanged. + progress(sqlite3.SQLITE_OK, 20, 30) + progress(sqlite3.SQLITE_BUSY, 20, 30) + progress(sqlite3.SQLITE_DONE, 0, 30) + + def close(self): + self.closed = True + + source = FakeConnection(source=True) + destination = FakeConnection() + connections = iter((source, destination)) + monkeypatch.setattr( + backup_mod.sqlite3, "connect", lambda *_args, **_kwargs: next(connections) + ) + clock = iter((0.0, 20.0, 40.0, 55.0, 70.0, 105.0, 130.0)) + monkeypatch.setattr(backup_mod.time, "monotonic", lambda: next(clock)) + + assert backup_mod._safe_copy_db(src, dst) is True + assert source.closed is True + assert destination.closed is True + def test_copies_valid_database(self, tmp_path): from hermes_cli.backup import _safe_copy_db src = tmp_path / "test.db" @@ -2008,7 +2136,7 @@ class FailingBackupConnection: def __init__(self, connection): self._connection = connection - def backup(self, _destination): + def backup(self, _destination, **_kwargs): raise sqlite3.OperationalError("forced backup failure") def close(self):