fix(backup): wait for the backup slot on the update path, and stop blaming the backup

hermes_cli/backup.py

@@ -159,14 +159,46 @@ class _SQLiteBackupTimeout(RuntimeError):
     """Raised when a SQLite snapshot remains busy past its deadline."""
 
 
+# Default wait for the shared backup slot.  Short on purpose: an interactive
+# `hermes backup` should fail fast rather than hang behind a scheduled one.
+_BACKUP_LOCK_DEFAULT_TIMEOUT = 0.25
+
+# Wait for the slot on the `hermes update` path.  A pre-update backup is the
+# only rollback an update has, so it is worth blocking for: losing a 0.25s race
+# with a concurrent snapshot used to silently skip the backup and continue the
+# update unprotected.  Bounded so a wedged backup process cannot stall an update
+# indefinitely.
+_PRE_UPDATE_LOCK_TIMEOUT = 180.0
+
+# Emit one "still waiting" line after this long so a multi-minute wait does not
+# look like a hang.
+_BACKUP_LOCK_WAIT_NOTICE_AFTER = 2.0
+
+
 @contextmanager
-def _backup_operation_lock(hermes_home: Path, timeout_seconds: float = 0.25):
+def _backup_operation_lock(
+    hermes_home: Path,
+    timeout_seconds: float = _BACKUP_LOCK_DEFAULT_TIMEOUT,
+):
     """Acquire one cross-process backup slot for full and quick snapshots."""
     lock_path = hermes_home / ".backup.lock"
     lock_path.parent.mkdir(parents=True, exist_ok=True)
     handle = lock_path.open("a+b")
     acquired = False
-    deadline = time.monotonic() + max(0.0, timeout_seconds)
+    started = time.monotonic()
+    deadline = started + max(0.0, timeout_seconds)
+    notified = False
+
+    def _notice() -> None:
+        nonlocal notified
+        if notified or time.monotonic() - started < _BACKUP_LOCK_WAIT_NOTICE_AFTER:
+            return
+        notified = True
+        logger.warning(
+            "Waiting for the Hermes backup slot (another backup is running); "
+            "up to %.0fs.",
+            max(0.0, timeout_seconds),
+        )
     try:
         if os.name == "nt":
             import msvcrt
@@ -183,6 +215,7 @@ def _backup_operation_lock(hermes_home: Path, timeout_seconds: float = 0.25):
                 except (OSError, PermissionError):
                     if time.monotonic() >= deadline:
                         raise BackupInProgressError("another Hermes backup is already running")
+                    _notice()
                     time.sleep(0.05)
         else:
             import fcntl
@@ -195,6 +228,7 @@ def _backup_operation_lock(hermes_home: Path, timeout_seconds: float = 0.25):
                 except (BlockingIOError, OSError):
                     if time.monotonic() >= deadline:
                         raise BackupInProgressError("another Hermes backup is already running")
+                    _notice()
                     time.sleep(0.05)
 
         yield
@@ -1315,10 +1349,11 @@ def create_quick_snapshot(
     hermes_home: Optional[Path] = None,
     keep: Optional[int] = None,
     max_file_size: Optional[int] = None,
+    lock_timeout: float = _BACKUP_LOCK_DEFAULT_TIMEOUT,
 ) -> Optional[str]:
     """Create one atomic quick snapshot while holding the shared backup slot."""
     home = hermes_home or get_hermes_home()
-    with _backup_operation_lock(home):
+    with _backup_operation_lock(home, timeout_seconds=lock_timeout):
         return _create_quick_snapshot_locked(
             label=label,
             hermes_home=home,
@@ -1819,13 +1854,26 @@ def run_quick_backup(args) -> None:
 # Shared full-zip backup helper
 # ---------------------------------------------------------------------------
 
-def _write_full_zip_backup(out_path: Path, hermes_root: Path) -> Optional[Path]:
-    """Single-flight wrapper for automatic full zip backups."""
+def _write_full_zip_backup(
+    out_path: Path,
+    hermes_root: Path,
+    lock_timeout: float = _BACKUP_LOCK_DEFAULT_TIMEOUT,
+    raise_if_busy: bool = False,
+) -> Optional[Path]:
+    """Single-flight wrapper for automatic full zip backups.
+
+    ``raise_if_busy`` lets a caller tell "another backup holds the slot" apart
+    from "there was nothing to back up / the write failed".  Both used to
+    collapse into ``None``, so ``hermes update`` reported a lock conflict as
+    "no files found or write failed".
+    """
     try:
-        with _backup_operation_lock(hermes_root):
+        with _backup_operation_lock(hermes_root, timeout_seconds=lock_timeout):
             return _write_full_zip_backup_locked(out_path, hermes_root)
     except BackupInProgressError as exc:
         logger.warning("Full-zip backup skipped: %s", exc)
+        if raise_if_busy:
+            raise
         return None
 
 
@@ -1977,6 +2025,8 @@ def _prune_pre_update_backups(backup_dir: Path, keep: int) -> int:
 def create_pre_update_backup(
     hermes_home: Optional[Path] = None,
     keep: int = _PRE_UPDATE_DEFAULT_KEEP,
+    lock_timeout: float = _PRE_UPDATE_LOCK_TIMEOUT,
+    raise_if_busy: bool = False,
 ) -> Optional[Path]:
     """Create a full zip backup of HERMES_HOME under ``backups/``.
 
@@ -1986,7 +2036,14 @@ def create_pre_update_backup(
 
     Returns the path to the created zip, or ``None`` if no files were
     found or the backup could not be created.  Never raises — the caller
-    (``hermes update``) should continue even if the backup fails.
+    (``hermes update``) should continue even if the backup fails — except
+    when ``raise_if_busy`` is set, which re-raises
+    :class:`BackupInProgressError` so the caller can say so accurately.
+
+    Waits up to ``lock_timeout`` seconds for the shared backup slot
+    (``_PRE_UPDATE_LOCK_TIMEOUT``, far longer than the interactive default):
+    an update that silently skips its own rollback point is worse than an
+    update that waits.
     """
     hermes_root = hermes_home or get_default_hermes_root()
     if not hermes_root.is_dir():
@@ -2002,7 +2059,12 @@ def create_pre_update_backup(
     stamp = datetime.now().strftime("%Y-%m-%d-%H%M%S")
     out_path = backup_dir / f"{_PRE_UPDATE_PREFIX}{stamp}.zip"
 
-    result = _write_full_zip_backup(out_path, hermes_root)
+    result = _write_full_zip_backup(
+        out_path,
+        hermes_root,
+        lock_timeout=lock_timeout,
+        raise_if_busy=raise_if_busy,
+    )
     if result is None:
         return None
 

hermes_cli/update_cmd.py

@@ -2831,6 +2831,7 @@ def _run_pre_update_backup(args) -> Optional[str]:
     snapshot_id = None
     try:
         from hermes_cli.backup import (
+            _PRE_UPDATE_LOCK_TIMEOUT,
             _quick_snapshot_root,
             create_quick_snapshot,
             verify_sqlite_integrity,
@@ -2845,6 +2846,7 @@ def _run_pre_update_backup(args) -> Optional[str]:
             label="pre-update",
             keep=_PRE_UPDATE_SNAPSHOT_KEEP,
             max_file_size=_PRE_UPDATE_SNAPSHOT_MAX_FILE_SIZE,
+            lock_timeout=_PRE_UPDATE_LOCK_TIMEOUT,
         )
 
         # After the snapshot, verify the source state.db is still intact.
@@ -2903,7 +2905,11 @@ def _run_pre_update_backup(args) -> Optional[str]:
         return snapshot_id
 
     try:
-        from hermes_cli.backup import create_pre_update_backup
+        from hermes_cli.backup import (
+            _PRE_UPDATE_LOCK_TIMEOUT,
+            BackupInProgressError,
+            create_pre_update_backup,
+        )
     except Exception as exc:
         print(
             f"⚠ Pre-update backup: could not load backup module ({exc}); continuing update."
@@ -2921,7 +2927,31 @@ def _run_pre_update_backup(args) -> Optional[str]:
     print("◆ Creating pre-update backup...")
     t0 = _time.monotonic()
     try:
-        out_path = create_pre_update_backup(keep=int(_keep))
+        # Pass the timeout explicitly rather than leaning on the default: a
+        # default argument binds at def time, which makes the wait impossible to
+        # override and impossible to test without actually waiting it out.
+        out_path = create_pre_update_backup(
+            keep=int(_keep),
+            lock_timeout=_PRE_UPDATE_LOCK_TIMEOUT,
+            raise_if_busy=True,
+        )
+    except BackupInProgressError:
+        # Distinct from a failed write: another process held the backup slot for
+        # the whole wait.  Saying "no files found" here sent a past investigation
+        # looking for a broken backup that was working fine.
+        print(
+            "  ⚠ Backup skipped: another Hermes backup held the backup slot "
+            "for the full wait."
+        )
+        print(
+            "    Nothing is wrong with the backup itself. Re-run 'hermes update "
+            "--backup' once it finishes,"
+        )
+        print(
+            "    or run 'hermes backup' by hand before updating. Continuing with update."
+        )
+        print()
+        return snapshot_id
     except Exception as exc:  # defensive — helper already swallows, but just in case
         print(f"  ⚠ Backup failed: {exc}")
         print("  Continuing with update.")
@@ -2931,7 +2961,10 @@ def _run_pre_update_backup(args) -> Optional[str]:
     elapsed = _time.monotonic() - t0
 
     if out_path is None:
-        print("  ⚠ Backup skipped (no files found or write failed); continuing update.")
+        print(
+            "  ⚠ Backup skipped: nothing to archive, or the archive could not "
+            "be written; continuing update."
+        )
         print()
         return snapshot_id
 

tests/hermes_cli/test_backup.py

@@ -1518,6 +1518,39 @@ def test_config_full_mode(self, hermes_home, capsys):
         assert "Creating pre-update backup" in out
         assert len(self._zips(hermes_home)) == 1
 
+    def test_full_mode_names_lock_contention_instead_of_blaming_the_backup(
+        self, hermes_home, capsys, monkeypatch
+    ):
+        """When another process owns the backup slot for the whole wait, say so.
+
+        This used to print "no files found or write failed", which sent an
+        investigation looking for a broken backup that was working fine.
+        """
+        import hermes_cli.backup as backup_mod
+
+        self._set_mode(hermes_home, "full")
+        # Don't actually wait out the update-path timeout in a test.
+        monkeypatch.setattr(backup_mod, "_PRE_UPDATE_LOCK_TIMEOUT", 0)
+
+        from hermes_cli.main import _run_pre_update_backup
+
+        import time as _t
+
+        started = _t.monotonic()
+        with backup_mod._backup_operation_lock(hermes_home):
+            _run_pre_update_backup(Namespace(no_backup=False, backup=True))
+        elapsed = _t.monotonic() - started
+
+        # The patched timeout must actually reach the call. A default argument
+        # binds at def time, so a timeout passed that way is unoverridable and
+        # this test would sit through the real 180s wait instead of failing.
+        assert elapsed < 30, f"pre-update backup ignored the patched timeout ({elapsed:.0f}s)"
+
+        out = capsys.readouterr().out
+        assert "another Hermes backup held the backup slot" in out
+        assert "no files found" not in out
+        assert not self._zips(hermes_home)
+
 
 
 

tests/hermes_cli/test_backup_stability.py

@@ -10,6 +10,7 @@
     _atomic_output_path,
     _backup_operation_lock,
     _write_full_zip_backup,
+    create_pre_update_backup,
     create_quick_snapshot,
     list_quick_snapshots,
 )
@@ -103,3 +104,63 @@ def test_failed_automatic_backup_preserves_previous_archive(tmp_path, monkeypatc
     assert _write_full_zip_backup(archive, home) is None
     assert archive.read_bytes() == b"previous-valid-backup"
     assert list(tmp_path.glob(".*.partial")) == []
+
+
+def test_busy_slot_is_distinguishable_from_a_failed_write(tmp_path) -> None:
+    """A held lock and an unwritable archive both returned None, so callers
+    could not tell "another backup is running" from "the backup is broken".
+    ``raise_if_busy`` separates them."""
+    home = tmp_path / ".hermes"
+    home.mkdir()
+    (home / "config.yaml").write_text("model: {}\n", encoding="utf-8")
+    archive = tmp_path / "automatic.zip"
+
+    with _backup_operation_lock(home):
+        # Default: still swallowed, so existing callers are unaffected.
+        assert _write_full_zip_backup(archive, home, lock_timeout=0) is None
+        assert not archive.exists()
+
+        with pytest.raises(BackupInProgressError):
+            _write_full_zip_backup(archive, home, lock_timeout=0, raise_if_busy=True)
+
+
+def test_pre_update_backup_reports_a_busy_slot_when_asked(tmp_path) -> None:
+    home = tmp_path / ".hermes"
+    home.mkdir()
+    (home / "config.yaml").write_text("model: {}\n", encoding="utf-8")
+
+    with _backup_operation_lock(home):
+        assert create_pre_update_backup(hermes_home=home, lock_timeout=0) is None
+
+        with pytest.raises(BackupInProgressError):
+            create_pre_update_backup(
+                hermes_home=home, lock_timeout=0, raise_if_busy=True
+            )
+
+    # Slot free again: the same call now produces a real archive, which is the
+    # point — the skip was never about the backup being broken.
+    out = create_pre_update_backup(hermes_home=home, lock_timeout=0)
+    assert out is not None and out.exists()
+
+
+def test_pre_update_backup_waits_for_the_slot(tmp_path, monkeypatch) -> None:
+    """The update path must wait for a busy slot rather than lose a 0.25s race
+    and skip the only rollback point the update has."""
+    import hermes_cli.backup as backup_mod
+
+    home = tmp_path / ".hermes"
+    home.mkdir()
+    (home / "config.yaml").write_text("model: {}\n", encoding="utf-8")
+
+    waited: list[float] = []
+    real_lock = backup_mod._backup_operation_lock
+
+    def recording_lock(hermes_home, timeout_seconds=backup_mod._BACKUP_LOCK_DEFAULT_TIMEOUT):
+        waited.append(timeout_seconds)
+        return real_lock(hermes_home, timeout_seconds=timeout_seconds)
+
+    monkeypatch.setattr(backup_mod, "_backup_operation_lock", recording_lock)
+
+    assert create_pre_update_backup(hermes_home=home) is not None
+    assert waited == [backup_mod._PRE_UPDATE_LOCK_TIMEOUT]
+    assert backup_mod._PRE_UPDATE_LOCK_TIMEOUT > backup_mod._BACKUP_LOCK_DEFAULT_TIMEOUT