fix(backup): bound unbounded SQLite busy-retry + stop misclassifying transient files as hard errors

docs/fix-backup-sqlite-busy-retry-unbounded.md

@@ -0,0 +1,129 @@
+# Fix: bound `_safe_copy_db`'s SQLite busy/locked retry
+
+**Status:** fixed and verified (unit tests + live in-situ against a real lock).
+**Follows:** `docs/rca-backup-sqlite-busy-retry-unbounded.md` (root cause).
+
+## What changed
+
+One change in `hermes_cli/backup.py::_safe_copy_db()`: the previously-bare
+`conn.backup(backup_conn)` call is now bounded against a sustained
+`SQLITE_BUSY`/`SQLITE_LOCKED` source.
+
+```python
+def _abort_past_deadline(status, remaining, total):
+    if status in (sqlite3.SQLITE_BUSY, sqlite3.SQLITE_LOCKED) and time.monotonic() > deadline:
+        raise _SafeCopyBusyTimeout(...)
+
+conn.backup(backup_conn, progress=_abort_past_deadline)
+```
+
+### Design choices and why
+
+1. **Bound via `progress=`, not a wrapper timeout/thread.**
+   `Connection.backup()`'s `progress=` callback fires after *every*
+   `sqlite3_backup_step()` call, including ones that returned
+   `SQLITE_BUSY`/`SQLITE_LOCKED`, and CPython already treats a raising
+   callback as "abort backup and bail" — it still calls
+   `sqlite3_backup_finish()` internally, so no backup handle is leaked. This
+   needed no new thread, signal, or subprocess machinery.
+
+2. **Gate the deadline check on the status code, not raw elapsed time.**
+   With the default `pages=-1`, a healthy, *uncontended* copy — however
+   large — completes in a single `sqlite3_backup_step()` call, and the
+   progress callback only fires *after* that (possibly slow, for a
+   many-GB `state.db`) step finishes. A time-only check would incorrectly
+   discard an already-successful large, non-busy copy just because it took
+   a while. Gating on `status in (SQLITE_BUSY, SQLITE_LOCKED)` keeps the
+   deadline meaningful only for genuine lock contention. Verified: an 87MB
+   non-busy source completes normally even against a 1ms deadline; a
+   167MB/300k-row non-busy source copies correctly with a 1ms deadline too.
+
+3. **Open both connections with `timeout=0` in the bounded path.**
+   This is load-bearing, not cosmetic (see the RCA's point 5): the
+   `sqlite3.connect()` default `timeout=5.0` installs SQLite's own internal
+   busy-handler, which silently retries *inside* a single
+   `sqlite3_backup_step()` call for up to that many seconds before ever
+   returning control to the progress callback. With `timeout=0`, each step
+   call fails fast on contention and control returns to the callback at
+   roughly `backup()`'s own retry cadence (`sleep=`, default 250ms), so the
+   deadline is enforced with the intended granularity instead of a coarse
+   ~5-8s one. This doesn't change success-path behavior: an uncontended
+   copy never touches the busy-handler either way, and the destination is
+   always a fresh tempfile the caller just created (never independently
+   contended).
+
+4. **The raised exception is a plain `Exception` subclass
+   (`_SafeCopyBusyTimeout`).** It's caught by `_safe_copy_db`'s existing
+   `except Exception as exc:` clause with zero control-flow changes: a
+   busy-timeout abort degrades to the exact same "SQLite safe copy failed"
+   warning + `False` return as any other `backup()` failure, which both
+   call sites (`_run_backup_locked`'s per-file loop and
+   `_write_full_zip_backup_locked`'s automatic-backup path) already handle
+   via the vanished-vs-genuine-failure distinction landed in
+   `docs/fix-chrome-debug-transient-files-backup.md`. A file that stays
+   locked past the deadline still exists on disk, so it's classified as a
+   genuine `errors` entry (not a benign `transient_skipped` vanish) in both
+   paths — the safest default, since we don't actually know whether it will
+   eventually copy successfully or not, just that it exceeded its budget.
+
+5. **Deadline is configurable, with an explicit escape hatch.**
+   Default 30 seconds (`_SAFE_COPY_BUSY_DEADLINE_SECONDS`). Override via
+   `HERMES_BACKUP_SQLITE_BUSY_DEADLINE_SECONDS` (float, seconds). A
+   non-positive value disables bounding entirely, restoring the exact
+   pre-fix indefinite-retry behavior for anyone who wants it.
+
+## Tests added
+
+`tests/hermes_cli/test_backup.py::TestSafeCopyDbBusyBounding` (6 tests):
+
+- `test_busy_source_is_bounded_not_indefinite` — a source locked longer than
+  the deadline returns `False` in roughly the deadline window, not after the
+  lock clears.
+- `test_short_busy_window_still_succeeds` — a lock that clears *before* the
+  deadline still succeeds normally (bounding must not penalize ordinary WAL
+  contention).
+- `test_connection_timeout_parameter_does_not_bound_backup_loop` —
+  documents/locks in *why* a naive `timeout=` fix wouldn't have worked (the
+  RCA's point 2), as a guard against someone "simplifying" the fix later.
+- `test_large_non_busy_copy_is_unaffected_by_bounding` — an absurdly tiny
+  deadline (1ms) does not abort a large (20k-row), non-busy copy, proving
+  the status-gate (not time alone) governs the deadline.
+- `test_negative_deadline_disables_bounding` — the escape hatch restores
+  indefinite retry.
+
+All pre-existing tests in `test_backup.py` (54), `test_backup_stability.py`,
+`test_curator_backup.py`, `test_execution_ledger.py`, `test_state_db_guard.py`,
+and `test_sizefmt.py` (106 total across the backup-adjacent surface) still
+pass — no regressions. `ruff check` clean on both changed files.
+
+## Live end-to-end verification
+
+At the time of this fix, the user's actual `chrome-debug/first_party_sets.db`
+was independently confirmed locked (`sqlite3 ... "SELECT 1"` →
+`database is locked (5)`), with zero interaction from this session:
+
+- **Before the fix**, the real (unpatched) `_safe_copy_db()` against this
+  live file blocked for **61.4 seconds** before the lock happened to clear.
+- **After the fix**, with a shortened 10s deadline override (to avoid
+  waiting out the full 30s default for this one verification run), the
+  same live file — while still genuinely locked — was aborted cleanly at
+  **10.1 seconds**, logging `SQLite safe copy failed for
+  .../first_party_sets.db: source stayed SQLITE_BUSY/SQLITE_LOCKED for
+  over 10s` and returning `False`, exactly as designed.
+
+This confirms the fix against the actual real-world condition the RCA
+describes, not just a synthetic repro.
+
+## Follow-ups intentionally not done here
+
+- Not adding a user-facing summary line distinguishing "busy-timeout skip"
+  from other `errors` entries — out of scope for this task; the existing
+  generic "SQLite safe copy failed" warning already surfaces the file and
+  underlying exception message (which now includes
+  "stayed SQLITE_BUSY/SQLITE_LOCKED for over Ns"), which is enough signal
+  for a human reading backup output to understand what happened.
+- Not investigating whether this is specific to a particular Chrome version
+  or has always been present — the RCA notes it reproduces against the
+  user's separate personal Chrome profile too, suggesting it's a general
+  Chrome/SQLite characteristic rather than a regression, but pinning down
+  *which* Chrome versions would need a wider survey out of scope here.

docs/fix-chrome-debug-transient-files-backup.md

@@ -0,0 +1,180 @@
+# Fix: `hermes backup` no longer errors on transient chrome-debug files
+
+**Status:** fixed and live-verified.
+**Follows:** `docs/rca-chrome-debug-transient-files-backup.md` (root cause).
+
+## What changed
+
+Two complementary changes in `hermes_cli/backup.py`, matching the RCA's two
+recommendations, plus one additional fix the RCA flagged as a same-class risk
+in the secondary (automatic backup) code path.
+
+### 1. Exclude known-transient chrome-debug subpaths from the backup walk
+
+Added `_CHROME_DEBUG_ROOT_DIR`, `_CHROME_DEBUG_TRANSIENT_DIRS`,
+`_CHROME_DEBUG_TRANSIENT_FILES`, and `_is_chrome_debug_transient_dir()`.
+Wired into:
+
+- `_should_exclude()` — file-level exclusion used by both backup paths via
+  `_should_skip_backup_file()`.
+- Both `os.walk()` scan loops (`_run_backup_locked` and
+  `_write_full_zip_backup_locked`) — directory-level pruning so `os.walk`
+  never descends into `chrome-debug/*/Sessions/`,
+  `chrome-debug/*/shared_proto_db/`, or `chrome-debug/BrowserMetrics/` at
+  all, not just filtering their contents after the fact.
+
+Scoped to fire only when rooted under the top-level `chrome-debug/`
+directory, so a same-named `Sessions`/`shared_proto_db` directory elsewhere
+under `HERMES_HOME` (e.g. inside a skill) is never affected — covered by
+`test_chrome_debug_exclusion_is_scoped_to_top_level_dir`.
+
+This eliminates the scan-then-archive race in the common case: the files
+that were racing the backup are no longer scanned or archived at all, so
+there's nothing to vanish out from under `zf.write()`.
+
+### 2. Reclassify vanished-mid-backup skips as "transient", not "errors"
+
+Defense in depth for any file that isn't covered by the exclusion above (a
+different live process racing the backup, or a transient chrome-debug file
+type not yet catalogued):
+
+- **`_run_backup_locked`** (the primary `hermes backup` / `hermes import`
+  path): the archive loop now catches `FileNotFoundError` *before* the
+  broader `(PermissionError, OSError, ValueError)` clause and appends to a
+  new `transient_skipped` list instead of `errors`. The finalize/summary
+  block only flips to `"Backup incomplete"` and suppresses the restore hint
+  when `errors` is non-empty — `transient_skipped` entries print as a
+  separate, clearly-labeled "Note (N file(s) changed during backup,
+  harmless -- nothing to restore there)" section instead.
+- The `.db` safe-copy branch (`_safe_copy_db()` returning `False`) now
+  checks `abs_path.exists()` post-hoc: if the source vanished (the
+  chrome-debug `*.db` race described in the RCA), it's `transient_skipped`;
+  if the source is still there but genuinely failed to copy (locked,
+  corrupt, permissions), it's still a hard `errors` entry and still flips
+  the summary. `sqlite3.connect()` raises a generic `OperationalError` for a
+  missing file rather than `FileNotFoundError`, so this existence check is
+  the only reliable way to distinguish the two cases from inside
+  `_safe_copy_db`'s boolean return.
+- **`_write_full_zip_backup_locked`** (the shared helper behind `hermes
+  update`'s pre-update backup and `hermes claw migrate`'s pre-migration
+  backup): this path had a *more severe* version of the same bug that the
+  RCA flagged as "not yet observed live but same code path" — a vanished
+  `.db` file raised `_SQLiteSnapshotError`, which the outer `except`
+  caught and turned into a full `return None`, discarding the *entire*
+  archive (all files scanned before AND after the vanished one), not just
+  skipping that one file. Now a vanished `.db` (source doesn't exist after
+  `_safe_copy_db` returns `False`) or a `FileNotFoundError` from a plain
+  `zf.write()` is logged and skipped via `continue`, and the archive
+  completes with everything else intact. A `.db` file that's still present
+  but genuinely fails to copy still raises `_SQLiteSnapshotError` and still
+  aborts+preserves the previous archive — unchanged, and still covered by
+  the existing `test_automatic_backup_still_aborts_on_genuine_db_failure`
+  (formerly `test_failed_automatic_backup_preserves_previous_archive` in
+  `test_backup_stability.py`).
+
+## Tests added
+
+`tests/hermes_cli/test_backup.py`:
+
+- `TestShouldExclude.test_excludes_chrome_debug_transient_subpaths`
+- `TestShouldExclude.test_chrome_debug_exclusion_is_scoped_to_top_level_dir`
+- `TestChromeDebugTransientRace` (new class, 7 tests): vanished plain file
+  is a warning not fatal; genuine `PermissionError` is still fatal; vanished
+  `.db` is skipped not reported as a copy failure; a `.db` that's present
+  but genuinely fails is still fatal; the automatic backup path tolerates
+  both a vanished plain file and a vanished `.db` without aborting; the
+  automatic backup path still aborts+preserves the previous archive on a
+  genuine (non-vanished) `.db` failure.
+
+All 55 tests in `test_backup.py` + `test_backup_stability.py` pass
+(46 pre-existing + 9 new), plus the 10 pre-existing tests in
+`test_curator_backup.py` and 36 in `test_execution_ledger.py` /
+`test_sizefmt.py` / `test_state_db_guard.py` (other callers of
+`hermes_cli.backup`) — no regressions.
+
+## Live end-to-end verification
+
+Launched the debug Chrome via the real Hermes code path
+(`hermes_cli.browser_connect.launch_chrome_debug(9222)`, the same function
+`/browser connect` uses) against the live `~/.hermes`, then ran `hermes
+backup` while it was actively running, navigating a couple of real pages via
+its CDP endpoint mid-backup to force genuine `Session_*`/`Tabs_*` file
+churn (new session/tab files with fresh timestamps appeared under
+`chrome-debug/Default/Sessions/` during the run, confirming the race
+window was live, not simulated):
+
+```
+Scanning ~/.hermes ...
+Backing up 4170 files ...
+  500/4170 files ...
+  1000/4170 files ...
+  1500/4170 files ...
+  2000/4170 files ...
+  2500/4170 files ...
+  3000/4170 files ...
+  3500/4170 files ...
+  4000/4170 files ...
+
+Backup complete: /private/tmp/hermes-backup-verify/full.zip
+  Files:       4170
+  Original:    543.3 MB
+  Compressed:  221.9 MB
+  Time:        28.9s
+
+  Excluded directories:
+    chrome-debug/Default/Sessions/
+    chrome-debug/Default/shared_proto_db/
+    hermes-agent/
+    lsp/node_modules/
+    node/lib/node_modules/
+
+Restore with: hermes import full.zip
+EXIT_CODE=0
+```
+
+Confirms, live, against the real bug scenario:
+
+- **"Backup complete"**, not "Backup incomplete" — this is the exact label
+  flip the RCA identified as the actual user-facing bug.
+- **`Restore with:` hint present** — previously suppressed by any nonzero
+  `errors` count; chrome-debug races no longer populate `errors` at all.
+- **`chrome-debug/Default/Sessions/` and `chrome-debug/Default/shared_proto_db/`
+  listed as excluded directories** — the race is prevented at scan time,
+  not merely caught and downgraded at archive time.
+- **No chrome-debug warnings at all** in this run (vs. the original ticket's
+  6 ENOENT warnings) — proof the primary fix (exclusion) eliminates the
+  race in the common case, with the secondary fix (transient
+  reclassification) as a backstop for anything the exclusion list doesn't
+  cover.
+- **Archive integrity confirmed**: `zipfile.ZipFile(...).testzip()` returns
+  `None` (no CRC/corruption), 4170 entries with 0 `Sessions/`/
+  `shared_proto_db/` entries and real profile data (e.g.
+  `chrome-debug/Default/Cookies`) correctly still present.
+
+### A separate, pre-existing, out-of-scope finding
+
+While live-testing, repeated interaction with the debug Chrome (rapid
+tab open/close cycles over CDP) was observed to put one or more of Chrome's
+own small SQLite files under `chrome-debug/` (`first_party_sets.db`,
+`Default/heavy_ad_intervention_opt_out.db`,
+`Default/declarative_performance_observer.db`) into a **sustained
+`SQLITE_BUSY` lock** that `sqlite3.Connection.backup()` retries
+indefinitely with no overall bound (confirmed independently of
+`_safe_copy_db`, and confirmed to reproduce identically against this
+change's own *unpatched* pre-fix code — i.e. not a regression introduced by
+this fix). This was also observed, with much lower probability, from a
+completely idle debug Chrome with zero interaction from this session, and
+even against the user's separate, long-running personal Chrome instance's
+own `first_party_sets.db` — so it is a general characteristic of this
+Chrome version's own internal use of these files, not something specific to
+the Hermes-managed debug profile.
+
+This is a different bug class from the one this task fixes (indefinite
+lock-wait vs. the ENOENT-vanished-file race) and the original ticket's own
+captured logs show no evidence of it (only the 6 ENOENT warnings, with a
+clean 250.2s total runtime) — so it's flagged here for a possible follow-up
+rather than addressed in this change. `_safe_copy_db()` would benefit from
+a bounded retry (e.g. `conn.backup(target, progress=<callback that raises
+past a deadline>)`) so a persistently-busy source file degrades to a
+skipped-with-warning outcome instead of stalling the whole backup
+indefinitely.