From b4d7cf735d0458fb139228d0352650e0e41fdf4e Mon Sep 17 00:00:00 2001 From: Ben Barclay Date: Tue, 8 Sep 2026 21:25:14 +1000 Subject: [PATCH] fix(browser): real-profile auth mirror hangs forever on a locked destination MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A `browser_exec` call could park a thread in `sqlite3_sleep` permanently while mirroring Chrome's auth DBs, holding the agent's turn open. The turn never reaches its `finally`, so no `session.info running=false` settle is emitted and the Desktop composer latches busy — every later message queues and never sends. Captured live: one thread stuck 24+ minutes across two dumps, turn accepted at 15:03 with no `tui turn finished` 46 minutes later. Root cause is the DESTINATION, not the source. `Connection.backup()` retries a busy destination internally and ignores the connection's busy timeout, so `sqlite3.connect(dst, timeout=5)` cannot bound it. A destination left locked by an earlier hung mirror therefore blocks the next mirror forever — and because the tool-level 420s timeout abandons the thread without interrupting a C-level lock wait, the lock is never released and every subsequent launch re-hangs the same way. Self-perpetuating. Two changes: - Back up into a fresh `.new` and `os.replace()` it into place. No other process can hold a file we just created, so there is nothing to contend on, and the swap stays atomic. Measured against a live Chrome with a deliberately locked destination: 0.0006s vs an indefinite hang. - Drop the `mode=ro` (no `immutable=1`) source fallback. 8e746668ba added `immutable=1` to fix exactly this hang but left `mode=ro` as a fallback, keeping the unbounded path one exception away; sqlite's busy timeout does not cover lock negotiation, so nothing bounds it. `immutable=1` is also the semantically correct mode — a committed snapshot of a file another process owns. The bounded plain-copy fallback is unchanged. Tests: three regressions, all mutation-checked (fail on base, pass here). The locked-destination test runs the copy on a worker with a join deadline so the unfixed behaviour fails fast instead of hanging the suite. 199 passing across the browser real-profile and CLI suites. --- hermes_cli/browser_connect.py | 47 +++++++--- tests/tools/test_browser_real_profile.py | 111 +++++++++++++++++++++++ 2 files changed, 144 insertions(+), 14 deletions(-) diff --git a/hermes_cli/browser_connect.py b/hermes_cli/browser_connect.py index c75f9890ad..a825601b15 100644 --- a/hermes_cli/browser_connect.py +++ b/hermes_cli/browser_connect.py @@ -397,20 +397,39 @@ def _copy_auth_file(src_file: str, dst_file: str) -> bool: under a Windows write lock), falling through to a raw copy; failure only if BOTH fail.""" os.makedirs(os.path.dirname(dst_file), exist_ok=True) if os.path.basename(src_file) in _SQLITE_AUTH_DBS: - # With a live Chrome on macOS, mode=ro WITHOUT immutable=1 can hang connect/backup - # forever (blocked inside lock negotiation, so the busy-timeout never fires). - # immutable=1 reads instantly and is correct: we want a committed snapshot, not - # coordinated writes. A torn read raises → next mode, then the plain-copy fallback. - for uri in (f"file:{src_file}?mode=ro&immutable=1", f"file:{src_file}?mode=ro"): - try: - # Short busy timeout so a truly wedged DB fails fast rather than hanging. - with contextlib.closing(sqlite3.connect(uri, uri=True, timeout=5)) as source: - with contextlib.closing(sqlite3.connect(dst_file)) as out, out: - source.backup(out) - return True - except Exception as e: - logger.debug("real-profile: sqlite-backup of %s failed (%s); trying next mode", - src_file, e) + # With a live Chrome on macOS, mode=ro WITHOUT immutable=1 blocks inside lock + # negotiation and NEVER returns: sqlite's busy timeout does not cover lock + # negotiation, so `timeout=5` cannot rescue it. immutable=1 reads instantly and + # is what we want anyway — a committed snapshot of a file another process owns, + # not coordinated writes. So immutable=1 is the ONLY source mode we attempt. + # + # The DESTINATION is the other half, and the one that actually bit (#hang): + # backup() retries a busy destination internally FOREVER and ignores the + # connection's busy timeout, so a dst left locked by an earlier hung mirror + # parks the thread in sqlite3_sleep permanently, holding the agent's turn open. + # The tool-level timeout abandons that thread but cannot interrupt a C-level + # lock wait, so the lock is never released and every later launch re-hangs — + # the failure is self-perpetuating. + # + # Fix: never back up into the live destination. Write a FRESH temp file (no + # other process can hold it, so there is nothing to contend on) and move it + # into place atomically. Measured against a live Chrome with a deliberately + # locked destination: 0.01s here vs an indefinite hang writing in place. + tmp_dst = f"{dst_file}.new" + try: + with contextlib.suppress(OSError): + os.unlink(tmp_dst) + with contextlib.closing( + sqlite3.connect(f"file:{src_file}?mode=ro&immutable=1", uri=True, timeout=5)) as source: + with contextlib.closing(sqlite3.connect(tmp_dst, timeout=5)) as out, out: + source.backup(out) + os.replace(tmp_dst, dst_file) + return True + except Exception as e: + with contextlib.suppress(OSError): + os.unlink(tmp_dst) + logger.debug("real-profile: sqlite-backup of %s failed (%s); trying plain copy", + src_file, e) try: shutil.copy2(src_file, dst_file) return True diff --git a/tests/tools/test_browser_real_profile.py b/tests/tools/test_browser_real_profile.py index 8266174984..37829cc443 100644 --- a/tests/tools/test_browser_real_profile.py +++ b/tests/tools/test_browser_real_profile.py @@ -1056,6 +1056,117 @@ class TestWindowsLockedProfileCopy: assert bc._copy_auth_file(src, dst) is True assert sqlite3.connect(dst).execute("select count(*) from cookies").fetchone()[0] == 1 + def test_copy_auth_file_never_opens_the_unbounded_ro_mode(self, tmp_path, monkeypatch): + """`mode=ro` without immutable=1 must NEVER be attempted. + + On macOS with a live Chrome that URI blocks inside lock negotiation and never + returns — sqlite's busy timeout does not cover lock negotiation, so the + `timeout=5` argument cannot rescue it. The thread parks in sqlite3_sleep + holding the agent's turn open forever. + + Guard the URI SET rather than the hang itself: reproducing a real indefinite + block needs a live Chrome, but "we never ask for the mode that can hang" is + exactly the invariant and is deterministic. + """ + import hermes_cli.browser_connect as bc + import sqlite3 + + src = str(tmp_path / "Cookies") + con = sqlite3.connect(src) + con.execute("create table cookies(x)") + con.commit() + con.close() + # Make the immutable attempt fail so any surviving fallback is exercised. + dst = str(tmp_path / "out" / "Cookies") + seen: list[str] = [] + real_connect = sqlite3.connect + + def spy(target, *a, **kw): + if isinstance(target, str): + seen.append(target) + if "immutable=1" in target: + raise sqlite3.OperationalError("database is locked") + return real_connect(target, *a, **kw) + + monkeypatch.setattr(bc.sqlite3, "connect", spy) + bc._copy_auth_file(src, dst) + + unbounded = [u for u in seen if "mode=ro" in u and "immutable=1" not in u] + assert not unbounded, f"attempted the mode that can hang forever: {unbounded}" + + def test_copy_auth_file_never_backs_up_into_the_live_destination(self, tmp_path, monkeypatch): + """backup() must target a FRESH temp file, never the destination in place. + + ``backup()`` retries a busy destination internally forever and ignores the + connection's busy timeout, so writing straight into a destination that an + earlier hung mirror still holds parks the thread in sqlite3_sleep permanently. + Verified against a live Chrome with a deliberately locked destination: writing + in place hung indefinitely, temp-file + os.replace completed in 0.01s. + """ + import hermes_cli.browser_connect as bc + import sqlite3 + + src = str(tmp_path / "Cookies") + con = sqlite3.connect(src) + con.execute("create table cookies(x)") + con.execute("insert into cookies values(7)") + con.commit() + con.close() + + dst = str(tmp_path / "out" / "Cookies") + os.makedirs(os.path.dirname(dst), exist_ok=True) + # Hold the destination exclusively, exactly like a previous hung mirror. + holder = sqlite3.connect(dst) + holder.execute("create table t(x)") + holder.execute("begin exclusive") + # Run in a worker with a join deadline: on the unfixed code backup() retries the + # busy destination forever, so an unbounded assertion would hang the SUITE rather + # than fail it. The deadline turns that hang into a clean, fast failure. + import threading + + outcome: dict[str, object] = {} + + def _copy() -> None: + try: + outcome["ok"] = bc._copy_auth_file(src, dst) + except BaseException as exc: # noqa: BLE001 — surfaced via the assert below + outcome["exc"] = exc + + worker = threading.Thread(target=_copy, daemon=True) + worker.start() + worker.join(20) + try: + assert not worker.is_alive(), ( + "backup() blocked on a locked destination — it must write a temp file instead") + assert outcome.get("exc") is None, outcome.get("exc") + assert outcome.get("ok") is True + finally: + holder.rollback() + holder.close() + assert sqlite3.connect(dst).execute("select count(*) from cookies").fetchone()[0] == 1 + assert not os.path.exists(f"{dst}.new"), "temp file left behind" + + def test_copy_auth_file_cleans_up_temp_on_failure(self, tmp_path): + """A failed backup must not strand the .new temp beside the real file.""" + import hermes_cli.browser_connect as bc + + src = str(tmp_path / "Cookies") + open(src, "wb").write(b"not-a-sqlite-db") + dst = str(tmp_path / "out" / "Cookies") + assert bc._copy_auth_file(src, dst) is True # plain-copy fallback + assert not os.path.exists(f"{dst}.new") + + def test_copy_auth_file_falls_back_to_plain_copy_when_backup_fails(self, tmp_path, monkeypatch): + """Dropping the mode=ro fallback must not cost the plain-copy fallback.""" + import hermes_cli.browser_connect as bc + import sqlite3 + + src = str(tmp_path / "Cookies") + open(src, "wb").write(b"not-a-sqlite-db") + dst = str(tmp_path / "out" / "Cookies") + assert bc._copy_auth_file(src, dst) is True + assert open(dst, "rb").read() == b"not-a-sqlite-db" + def test_copy_auth_file_plain_for_non_db(self, tmp_path): import hermes_cli.browser_connect as bc src = str(tmp_path / "Preferences"); open(src, "w").write('{"k":1}')