tracking: review SQLite backup stall timeout

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
 
 
 # ---------------------------------------------------------------------------

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):