fix(update): report why the candidate runtime sync failed
The SQLite runtime repair builds its replacement venv with `uv sync --extra all --locked` and, when that fails, reported only "replacement environment did not pass dependency and import smoke tests". The child's diagnosis went to inherited stdout, so it survived in console scrollback and nowhere else: the rejection line the logger records carried the bare exit code, the failure detail the repair returns is generic, and update receipts are built from explicit record_step calls — none of which covers this repair. On an install where the repair cannot succeed, `hermes update` therefore ended at "partially complete" with no reason — the reason being a one-line uv message the user never saw. Forward that sync's output live (unchanged contract: stderr merged into stdout and drained while the child runs, so pre-desktop-update hand-offs cannot deadlock uv on a full stderr pipe) and keep its tail: reject with the child's `error:`/`hint:` lines and announce them, so the console and the log say what to fix. Carrying the reason into RuntimeRepairResult.detail, and therefore into a receipt step, is deliberately out of scope here — separate change, separate PR. Test: the reported reason keeps uv's error + hint and drops the progress noise that precedes them (red before this change, where the reason was the bare exit code).
This commit is contained in:
Ckarey
@@ -19,6 +19,7 @@ import sys
|
||||
import tempfile
|
||||
import time
|
||||
import uuid
|
||||
from collections import deque
|
||||
from dataclasses import dataclass
|
||||
from functools import partial
|
||||
from pathlib import Path
|
||||
@@ -562,6 +563,55 @@ def _smoke_candidate_venv(venv_dir: Path) -> tuple[bool, str, SQLiteRuntimeInfo
|
||||
return True, "", info
|
||||
|
||||
|
||||
# A failed ``uv sync`` prints its diagnosis last, so the tail is the actionable part. Kept
|
||||
# short: the reason travels into a one-line log entry and a one-line console warning.
|
||||
_SYNC_TAIL_LINES = 6
|
||||
_SYNC_REASON_CHARS = 600
|
||||
|
||||
|
||||
def _sync_reason(tail: deque[str]) -> str:
|
||||
"""The actionable part of a failed sync: uv's ``error:`` line and whatever follows it.
|
||||
|
||||
uv prints progress ("Resolving…", "Resolved 259 packages") before the diagnosis, so the raw
|
||||
tail leads with noise; the ``error:``/``hint:`` pair is the part a user can act on.
|
||||
"""
|
||||
parts = [line for line in tail if line.strip()]
|
||||
for index, line in enumerate(parts):
|
||||
if line.lower().startswith(("error:", "error ")):
|
||||
parts = parts[index:]
|
||||
break
|
||||
else:
|
||||
parts = parts[-2:]
|
||||
return " | ".join(parts).strip()[:_SYNC_REASON_CHARS]
|
||||
|
||||
|
||||
def _stream_sync(argv: list[str], *, cwd: Path, env: dict[str, str]) -> tuple[int, str]:
|
||||
"""Run the candidate's locked sync, forwarding output live; return ``(rc, reason)``.
|
||||
|
||||
Streaming is load-bearing, not cosmetic: older desktop update hand-offs drain only the
|
||||
child's stdout while it runs, so a full stderr pipe blocks uv forever — stderr is merged
|
||||
into stdout and forwarded line by line instead of being captured and reprinted at the end.
|
||||
|
||||
The tail is kept anyway. Inherited stdout lands the child's diagnosis in console scrollback
|
||||
ONLY: the rejection line the logger records carried the bare exit code, and the generic
|
||||
"did not pass dependency and import smoke tests" detail the repair returns carries no reason
|
||||
either (receipts quote explicitly recorded steps — none records this repair). Seen in the
|
||||
field, that reads as "hermes update says the SQLite repair failed and never says why".
|
||||
"""
|
||||
proc = subprocess.Popen(
|
||||
list(argv), cwd=cwd, env=env, stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
|
||||
text=True, encoding="utf-8", errors="replace", bufsize=1)
|
||||
tail: deque[str] = deque(maxlen=_SYNC_TAIL_LINES)
|
||||
stream = proc.stdout
|
||||
if stream is not None:
|
||||
for line in stream:
|
||||
tail.append(line.rstrip())
|
||||
sys.stdout.write(line)
|
||||
sys.stdout.flush()
|
||||
status = proc.wait()
|
||||
return status, _sync_reason(tail)
|
||||
|
||||
|
||||
def _stage_candidate_venv(
|
||||
uv_bin: str, *, project_root: Path, generation: Path, python: Path) -> Path | None:
|
||||
runtime_root = project_root / _RUNTIME_DIR_NAME
|
||||
@@ -597,11 +647,15 @@ def _stage_candidate_venv(
|
||||
# reset, so even an update running from an old base executes THIS
|
||||
# copy — unlike the heartbeat helper (main_install_repair.py), which
|
||||
# is imported at startup and only protects bases that ship its twin.
|
||||
synced = subprocess.run(
|
||||
status, reason = _stream_sync(
|
||||
[uv_bin, "sync", "--extra", "all", "--locked", "--python", str(_venv_python(candidate))],
|
||||
cwd=project_root, env=sync_env, stderr=subprocess.STDOUT, check=False)
|
||||
if synced.returncode != 0:
|
||||
return reject("candidate dependency sync failed (rc=%d)", synced.returncode)
|
||||
cwd=project_root, env=sync_env)
|
||||
if status != 0:
|
||||
# `_repair_under_lock`'s failure detail is generic ("did not pass dependency and import
|
||||
# smoke tests"), so the reason is announced here; without it only console scrollback has
|
||||
# the text — the rejection line the log records carries the bare exit code.
|
||||
print(f" ⚠ candidate dependency sync failed (rc={status}): {reason}")
|
||||
return reject("candidate dependency sync failed (rc=%d): %s", status, reason)
|
||||
healthy, detail, _ = _smoke_candidate_venv(candidate)
|
||||
if not healthy:
|
||||
return reject("candidate venv smoke failed: %s", detail)
|
||||
|
||||
@@ -599,6 +599,26 @@ class TestRuntimeRepair:
|
||||
assert leftovers == [], f"no stale markers may remain: {leftovers}"
|
||||
|
||||
|
||||
def _make_candidate_layout(tmp_path):
|
||||
"""The minimal checkout + pinned generation python `_stage_candidate_venv` needs."""
|
||||
root = tmp_path / "checkout"
|
||||
root.mkdir()
|
||||
(root / "uv.lock").write_text("# lock\n", encoding="utf-8")
|
||||
generation = root / ".hermes-runtime" / "python" / "gen"
|
||||
python = generation / "bin" / "python"
|
||||
python.parent.mkdir(parents=True)
|
||||
python.write_text("py", encoding="utf-8")
|
||||
return root, generation, python
|
||||
|
||||
|
||||
def _fake_sync_proc(lines, returncode=0):
|
||||
"""``subprocess.Popen`` stand-in for the candidate sync: text lines on stdout."""
|
||||
proc = MagicMock()
|
||||
proc.stdout = iter(lines)
|
||||
proc.wait.return_value = returncode
|
||||
return proc
|
||||
|
||||
|
||||
class TestStageCandidateVenvCrossPlatform:
|
||||
"""Candidate sync preserves project config and streams progress on every host."""
|
||||
|
||||
@@ -607,21 +627,20 @@ class TestStageCandidateVenvCrossPlatform:
|
||||
|
||||
from hermes_cli.managed_uv import _stage_candidate_venv
|
||||
|
||||
root = tmp_path / "checkout"
|
||||
root.mkdir()
|
||||
(root / "uv.lock").write_text("# lock\n", encoding="utf-8")
|
||||
generation = root / ".hermes-runtime" / "python" / "gen"
|
||||
python = generation / "bin" / "python"
|
||||
python.parent.mkdir(parents=True)
|
||||
python.write_text("py", encoding="utf-8")
|
||||
|
||||
calls = []
|
||||
root, generation, python = _make_candidate_layout(tmp_path)
|
||||
created = []
|
||||
synced = []
|
||||
|
||||
def fake_run(argv, **kwargs):
|
||||
calls.append((list(argv), kwargs))
|
||||
created.append((list(argv), kwargs))
|
||||
return MagicMock(returncode=0)
|
||||
|
||||
def fake_popen(argv, **kwargs):
|
||||
synced.append((list(argv), kwargs))
|
||||
return _fake_sync_proc([])
|
||||
|
||||
with patch("hermes_cli.managed_uv.subprocess.run", side_effect=fake_run), \
|
||||
patch("hermes_cli.managed_uv.subprocess.Popen", side_effect=fake_popen), \
|
||||
patch(
|
||||
"hermes_cli.managed_uv._smoke_candidate_venv",
|
||||
return_value=(True, "", None),
|
||||
@@ -634,18 +653,61 @@ class TestStageCandidateVenvCrossPlatform:
|
||||
)
|
||||
|
||||
assert candidate is not None
|
||||
assert len(calls) == 2
|
||||
venv_argv, venv_kwargs = calls[0]
|
||||
sync_argv, sync_kwargs = calls[1]
|
||||
assert len(created) == 1
|
||||
venv_argv, venv_kwargs = created[0]
|
||||
assert venv_argv[:2] == ["uv", "venv"]
|
||||
assert "--no-config" in venv_argv
|
||||
assert venv_kwargs["env"].get("UV_NO_CONFIG") == "1"
|
||||
sync_argv, sync_kwargs = synced[0]
|
||||
assert sync_argv[:2] == ["uv", "sync"]
|
||||
assert "--locked" in sync_argv
|
||||
assert "--no-config" not in sync_argv
|
||||
assert "UV_NO_CONFIG" not in sync_kwargs["env"]
|
||||
assert sync_kwargs["stderr"] == subprocess.STDOUT
|
||||
|
||||
def test_sync_failure_reports_the_child_reason(self, tmp_path, capsys, caplog):
|
||||
"""A rejected candidate must say WHY — the child's own diagnosis, not a bare rc."""
|
||||
import logging
|
||||
|
||||
from hermes_cli.managed_uv import _stage_candidate_venv
|
||||
|
||||
root, generation, python = _make_candidate_layout(tmp_path)
|
||||
lock_error = [
|
||||
"Resolving despite existing lockfile due to addition of exclude newer exclusion\n",
|
||||
"error: The lockfile at `uv.lock` needs to be updated, but `--locked` was provided.\n",
|
||||
"\n",
|
||||
"hint: To update the lockfile, run `uv lock`.\n",
|
||||
]
|
||||
|
||||
with caplog.at_level(logging.WARNING), \
|
||||
patch("hermes_cli.managed_uv.subprocess.run", return_value=MagicMock(returncode=0)), \
|
||||
patch(
|
||||
"hermes_cli.managed_uv.subprocess.Popen",
|
||||
return_value=_fake_sync_proc(lock_error, returncode=1),
|
||||
), \
|
||||
patch(
|
||||
"hermes_cli.managed_uv._smoke_candidate_venv",
|
||||
return_value=(True, "", None),
|
||||
):
|
||||
candidate = _stage_candidate_venv(
|
||||
"uv",
|
||||
project_root=root,
|
||||
generation=generation,
|
||||
python=python,
|
||||
)
|
||||
|
||||
assert candidate is None
|
||||
console = capsys.readouterr().out
|
||||
# The reason is the child's own diagnosis: the error + hint, without the progress noise
|
||||
# that precedes them. It reaches the console AND the rejection the updater logs.
|
||||
reason_line = next(
|
||||
line for line in console.splitlines() if "dependency sync failed" in line)
|
||||
assert "error: The lockfile at `uv.lock` needs to be updated" in reason_line
|
||||
assert "hint: To update the lockfile, run `uv lock`." in reason_line
|
||||
assert "Resolving despite existing lockfile" not in reason_line
|
||||
assert "candidate dependency sync failed (rc=1)" in caplog.text
|
||||
assert "needs to be updated" in caplog.text
|
||||
|
||||
|
||||
class TestRuntimeCutover:
|
||||
def test_os_lock_blocks_concurrent_repair_and_releases(self, tmp_path):
|
||||
|
||||
Reference in New Issue
Block a user