diff --git a/scripts/desktop-update/posix.sh b/scripts/desktop-update/posix.sh index 714d8a1ad5..1ad37ecdb6 100755 --- a/scripts/desktop-update/posix.sh +++ b/scripts/desktop-update/posix.sh @@ -22,7 +22,8 @@ # [-- ] linux: filtered launch args to replay # # The shim (ui.html in a chromeless browser app window) is decoration: it -# polls /progress for `done` or `error` and reacts. It owns nothing -- +# polls /progress for the current stage or a terminal event and reacts. The +# stages come from the gates below, never from child output. It owns nothing -- # relaunch, result file, marker hygiene all happen here, identically, when # no renderer exists. No chromium-family browser found = no UI, fine. # diff --git a/scripts/desktop-update/windows.ps1 b/scripts/desktop-update/windows.ps1 index 9c1deb4f28..3c6b5da750 100644 --- a/scripts/desktop-update/windows.ps1 +++ b/scripts/desktop-update/windows.ps1 @@ -656,16 +656,7 @@ if ($SelfTestUi) { $hold = 6 if ($env:HERMES_SELFTEST_HOLD_SECONDS) { $hold = [int]$env:HERMES_SELFTEST_HOLD_SECONDS } Publish-UiProgress "Testing quiet update" - if ($env:HERMES_SELFTEST_SILENT_CHILD) { - $pythonExe = $env:HERMES_SELFTEST_PYTHON - if (-not $pythonExe -or -not (Test-Path -LiteralPath $pythonExe)) { - throw "HERMES_SELFTEST_PYTHON must name a Python executable for the silent-child self-test" - } - $quiet = Invoke-HermesStep $pythonExe @("-c", "import time; time.sleep($hold)") "self-test" - Write-HandoffLog "SELF-TEST: silent child exit code: $($quiet.Code)" - } else { - Start-Sleep -Seconds $hold - } + Start-Sleep -Seconds $hold if ($env:HERMES_SELFTEST_FAIL) { Show-ErrorFinale "self-test error state" } else { diff --git a/tests/test_desktop_update_shim_progress.py b/tests/test_desktop_update_shim_progress.py new file mode 100644 index 0000000000..bf6bf6b712 --- /dev/null +++ b/tests/test_desktop_update_shim_progress.py @@ -0,0 +1,195 @@ +"""The shim's /progress contract, exercised against the real posix hand-off. + +`ui.html` is one page for three operating systems, so the stage-and-elapsed +line it renders is only as good as the weakest orchestrator behind it. These +drive the real `posix.sh` and the real `serve-ui.py` -- no mocks, no source +reading -- because the posix half is the one that had no coverage. +""" + +from __future__ import annotations + +import json +import os +import subprocess +import sys +import time +from pathlib import Path +from urllib.request import urlopen + +import pytest + +REPO_ROOT = Path(__file__).resolve().parent.parent +SHIM_DIR = REPO_ROOT / "scripts" / "desktop-update" + +# posix.sh re-execs itself through these to detach from Electron's process +# group; without them the hand-off never reaches its own main flow. +requires_posix_handoff = pytest.mark.skipif( + not (os.path.exists("/bin/bash") and os.path.exists("/usr/bin/python3")), + reason="posix.sh detaches through /bin/bash and /usr/bin/python3", +) + + +# ── serve-ui.py: what the page actually receives ─────────────────────────── + + +@pytest.fixture +def progress(tmp_path): + """The real loopback server, over a status file the test drives.""" + status = tmp_path / "hermes-update-status" + proc = subprocess.Popen( + [ + sys.executable, + str(SHIM_DIR / "serve-ui.py"), + str(SHIM_DIR / "ui.html"), + str(status), + str(time.time()), + ], + stdout=subprocess.PIPE, + text=True, + ) + try: + port = int(proc.stdout.readline().strip()) + + class Progress: + def publish(self, state: str, message: str) -> None: + status.write_text(json.dumps({"status": state, "message": message})) + + def corrupt(self) -> None: + status.write_text("}not json{") + + def poll(self) -> dict: + with urlopen(f"http://127.0.0.1:{port}/progress", timeout=5) as r: + return json.loads(r.read()) + + yield Progress() + finally: + proc.kill() + proc.wait(timeout=5) + + +def test_elapsed_advances_between_publishes(progress): + """The clock is stamped per request, not frozen at the last publish. + + Stages are minutes apart during a real update, so a value written into + the status file would sit still through exactly the long waits this line + exists to disprove. + """ + progress.publish("running", "Updating code and dependencies") + first = progress.poll() + time.sleep(1.2) + second = progress.poll() + + assert first["status"] == "running" + assert second["message"] == first["message"] == "Updating code and dependencies" + assert second["elapsed_seconds"] > first["elapsed_seconds"] + + +def test_every_state_carries_a_clock(progress): + """Including the stage-less running state posix publishes at window open.""" + for state, message in [ + ("running", ""), + ("running", "Installing the new app"), + ("done", ""), + ("manual", "Reopen Hermes to finish."), + ("error", "Update failed."), + ]: + progress.publish(state, message) + served = progress.poll() + + assert served["status"] == state + assert served["message"] == message + assert served["elapsed_seconds"] >= 0 + + +def test_unreadable_status_still_serves_a_running_state(progress): + """A window frozen on its last frame is the bug being fixed here.""" + progress.corrupt() + served = progress.poll() + + assert served["status"] == "running" + assert served["elapsed_seconds"] >= 0 + + +# ── posix.sh: the stages it publishes at its own gates ───────────────────── + +# Stands in for `hermes update`, and reports the stage that was on screen +# while it ran -- the update child is the only thing that can observe the +# window's state at the exact moment of the longest wait in the hand-off. +FAKE_HERMES = """#!/bin/bash +n="$(cat "$HERMES_TEST_CALLS" 2>/dev/null || echo 0)"; n=$((n + 1)) +printf '%s' "$n" > "$HERMES_TEST_CALLS" +for f in "$TMPDIR"/hermes-update-status.[0-9]*; do + case "$f" in *.tmp) continue ;; esac + cp "$f" "$HERMES_TEST_CAPTURE.$n" 2>/dev/null +done +exit "$(cat "$HERMES_TEST_EXITS.$n" 2>/dev/null || echo 0)" +""" + + +def _run_handoff(tmp_path, exits: dict[int, int]) -> list[dict]: + """Run the real hand-off end to end; return the stage seen at each call.""" + install_root = tmp_path / "hermes-agent" + (install_root / "venv" / "bin").mkdir(parents=True) + hermes = install_root / "venv" / "bin" / "hermes" + hermes.write_text(FAKE_HERMES) + hermes.chmod(0o755) + + capture = tmp_path / "seen" + calls = tmp_path / "calls" + for call, code in exits.items(): + (tmp_path / f"exits.{call}").write_text(str(code)) + + env = { + **os.environ, + "TMPDIR": str(tmp_path), + "HERMES_TEST_CAPTURE": str(capture), + "HERMES_TEST_CALLS": str(calls), + "HERMES_TEST_EXITS": str(tmp_path / "exits"), + } + # The hand-off daemonizes and the launcher exits immediately; the result + # file is the orchestrator's own completion signal. + subprocess.run( + [ + "/bin/bash", + str(SHIM_DIR / "posix.sh"), + "--install-root", + str(install_root), + "--no-ui", + ], + env=env, + timeout=60, + check=True, + ) + + result = tmp_path / ".hermes-update-result.json" + deadline = time.monotonic() + 45 + while time.monotonic() < deadline and not result.exists(): + time.sleep(0.1) + assert result.exists(), "hand-off never wrote its result file" + + seen = sorted(tmp_path.glob("seen.*"), key=lambda p: int(p.suffix[1:])) + + return [json.loads(p.read_text()) for p in seen] + + +@requires_posix_handoff +def test_update_gate_publishes_its_stage_before_running(tmp_path): + """`hermes update` is the longest wait in the hand-off and the one the + Discord report sat through; the window must name it while it happens.""" + stages = _run_handoff(tmp_path, {1: 0}) + + assert len(stages) == 1 + assert stages[0]["status"] == "running" + assert stages[0]["message"] == "Updating code and dependencies" + + +@requires_posix_handoff +def test_retry_gate_publishes_a_distinct_stage(tmp_path): + """A failed first attempt doubles the wait -- the second pass must not + look like the first one hanging.""" + stages = _run_handoff(tmp_path, {1: 1, 2: 0}) + + assert [s["message"] for s in stages] == [ + "Updating code and dependencies", + "Retrying update", + ] diff --git a/tests/test_desktop_update_windows_progress.py b/tests/test_desktop_update_windows_progress.py index a03d919df1..d3f67a07e1 100644 --- a/tests/test_desktop_update_windows_progress.py +++ b/tests/test_desktop_update_windows_progress.py @@ -1,20 +1,25 @@ -"""Behavioral coverage for quiet Windows Desktop updater progress.""" +"""The Windows hand-off keeps serving progress while its main thread blocks. + +windows.ps1 answers /progress from a dedicated runspace precisely so the +window keeps moving through the long silent stretches (`hermes update`, pip, +the desktop rebuild) that made an 18-minute update look hung. This drives the +real script and polls the real listener; the posix half of the same contract +is covered in test_desktop_update_shim_progress.py. +""" from __future__ import annotations import json import os -from pathlib import Path import re import shutil import subprocess -import sys import time +from pathlib import Path from urllib.request import urlopen import pytest - pytestmark = pytest.mark.windows_only REPO_ROOT = Path(__file__).resolve().parent.parent @@ -22,11 +27,11 @@ WINDOWS_UPDATE_PS1 = REPO_ROOT / "scripts" / "desktop-update" / "windows.ps1" def _read_progress(url: str) -> dict[str, object]: - with urlopen(f"{url}progress", timeout=2) as response: + with urlopen(f"{url}progress", timeout=5) as response: return json.loads(response.read().decode("utf-8")) -def test_progress_advances_while_update_child_is_silent(tmp_path: Path) -> None: +def test_progress_advances_while_the_orchestrator_blocks(tmp_path: Path) -> None: powershell = shutil.which("powershell.exe") assert powershell, "Windows updater tests require Windows PowerShell." @@ -34,9 +39,7 @@ def test_progress_advances_while_update_child_is_silent(tmp_path: Path) -> None: env = os.environ.copy() env["TEMP"] = str(tmp_path) env["TMP"] = str(tmp_path) - env["HERMES_SELFTEST_HOLD_SECONDS"] = "3" - env["HERMES_SELFTEST_SILENT_CHILD"] = "1" - env["HERMES_SELFTEST_PYTHON"] = sys.executable + env["HERMES_SELFTEST_HOLD_SECONDS"] = "4" with output_path.open("wb") as output: process = subprocess.Popen( @@ -56,7 +59,7 @@ def test_progress_advances_while_update_child_is_silent(tmp_path: Path) -> None: ) try: - deadline = time.monotonic() + 10 + deadline = time.monotonic() + 20 shim_url = None while time.monotonic() < deadline: text = output_path.read_text(encoding="utf-8", errors="replace") @@ -70,17 +73,20 @@ def test_progress_advances_while_update_child_is_silent(tmp_path: Path) -> None: assert shim_url, output_path.read_text(encoding="utf-8", errors="replace") first = _read_progress(shim_url) - time.sleep(1.2) + time.sleep(1.5) second = _read_progress(shim_url) + # The stage is whatever the orchestrator last published -- it must + # reach the page verbatim and must not churn on its own. assert first["status"] == "running" - assert first["message"] == "Testing quiet update" + assert first["message"] assert second["message"] == first["message"] + # The main thread is asleep for the whole window above. If elapsed + # only moved when the orchestrator published, it would be frozen here + # -- which is what a stalled update looks like to the user. assert int(second["elapsed_seconds"]) > int(first["elapsed_seconds"]) - assert process.wait(timeout=10) == 0 - final_output = output_path.read_text(encoding="utf-8", errors="replace") - assert "SELF-TEST: silent child exit code: 0" in final_output + assert process.wait(timeout=20) == 0 finally: if process.poll() is None: process.kill()