diff --git a/keel/commands/update.py b/keel/commands/update.py index 11d685d..3d4f39a 100644 --- a/keel/commands/update.py +++ b/keel/commands/update.py @@ -110,9 +110,32 @@ "keel_trader", ) -_HTTP_TIMEOUT_SEC = 15 +#: Per-socket-operation timeout, NOT a deadline for the whole transfer -- `urlopen` applies it +#: to each read. Raised from 15 with #675's retries: a shared CDN that goes quiet briefly is the +#: common case, and 30-with-retries recovers from more of it than 60-without while giving up on +#: a genuinely dead host sooner. +_HTTP_TIMEOUT_SEC = 30 _SUBPROCESS_TIMEOUT_SEC = 600 +#: How many times a TRANSPORT failure is retried before the update is abandoned (#675). Three +#: attempts, because the failure this exists for is a momentary stall: one retry is often the +#: same second, and a fourth is waiting on something that is not coming back. +_DOWNLOAD_ATTEMPTS = 3 + +#: Seconds to wait before each retry. A tuple rather than a formula so the total added latency +#: of a doomed update is legible at a glance: 4 seconds, once, not an unbounded backoff. +_RETRY_BACKOFF_SEC = (1.0, 3.0) + +#: HTTP statuses worth retrying: the server said "not now", not "no". Everything else is an +#: ANSWER -- a 404 is the wrong URL and a 403 is the rate limit `_http_get` names with its own +#: workaround, and retrying either burns time or budget to be told the same thing again. +#: +#: 429 is deliberately ABSENT even though it is transient. On the unauthenticated releases +#: endpoint it means the 60-requests/hour budget is spent, and spending it faster is the one +#: response that cannot help; `_http_get` already turns it into an operator-readable message +#: pointing at the manual procedure, which needs no API call at all. +_RETRYABLE_STATUS = frozenset({500, 502, 503, 504}) + class UpdateError(Exception): """An honest, operator-readable failure of the update procedure (never a guess).""" @@ -176,6 +199,46 @@ def parse_release(payload: bytes | str) -> ReleaseInfo: return ReleaseInfo(tag=doc["tag_name"], assets=tuple(assets)) +def _is_retryable(exc: Exception) -> bool: + """Whether `exc` is a stall worth asking again about, or an answer that will not change. + + **`urllib.error.HTTPError` is a subclass of `OSError`**, so the obvious `except OSError: + retry` retries a 404 and a 403 as eagerly as a dropped connection. It is the trap this + function exists to avoid: a 404 means the URL is wrong and three attempts make it wrong + three times, and a 403 on the unauthenticated releases endpoint is the rate limit, where + retrying spends the very budget that ran out. + + So an HTTPError is judged by its STATUS and everything else -- a timeout, a reset, a DNS + failure, anything `urlopen` raises without a response behind it -- is transport, and + transport is retried. + """ + if isinstance(exc, urllib.error.HTTPError): + return exc.code in _RETRYABLE_STATUS + return isinstance(exc, OSError) + + +def _with_retries[T](attempt: Callable[[], T], *, sleep: Callable[[float], None] = time.sleep) -> T: + """Run `attempt`, retrying a transport failure up to `_DOWNLOAD_ATTEMPTS` times (#675). + + Re-raises the LAST exception rather than a wrapper, so every caller's own error message -- + `_http_get`'s rate-limit text, `_download_file`'s URL -- survives unchanged. This function + decides only WHETHER to ask again, never what to say when the answer is final. + + `sleep` is a parameter because the alternative is a test suite that really waits four + seconds per retry pin. + """ + last: Exception | None = None + for index in range(_DOWNLOAD_ATTEMPTS): + try: + return attempt() + except Exception as exc: # noqa: BLE001 -- re-raised below; the filter is `_is_retryable` + if not _is_retryable(exc) or index == _DOWNLOAD_ATTEMPTS - 1: + raise + last = exc + sleep(_RETRY_BACKOFF_SEC[min(index, len(_RETRY_BACKOFF_SEC) - 1)]) + raise last if last is not None else AssertionError("unreachable") + + def _http_get(url: str) -> bytes: """GET `url` with keel's own user agent, honestly. A rate-limit (HTTP 403/429 on this unauthenticated endpoint) is named as what it is, with the workaround.""" @@ -183,9 +246,12 @@ def _http_get(url: str) -> bytes: url, headers={"Accept": "application/vnd.github+json", "User-Agent": "keel-self-update"}, ) - try: + def attempt() -> bytes: with urllib.request.urlopen(request, timeout=_HTTP_TIMEOUT_SEC) as response: - return response.read() + return bytes(response.read()) + + try: + return _with_retries(attempt) except urllib.error.HTTPError as exc: if exc.code in (403, 429): raise UpdateError( @@ -566,9 +632,12 @@ def backup_path( def _download_file(url: str, dest: Path) -> None: """Download a public asset URL to `dest`, with the read BOUNDED at `_MAX_DOWNLOAD_BYTES`. The production seam; tests inject.""" - try: + def attempt() -> bytes: with urllib.request.urlopen(url, timeout=_HTTP_TIMEOUT_SEC) as response: - payload = response.read(_MAX_DOWNLOAD_BYTES + 1) + return bytes(response.read(_MAX_DOWNLOAD_BYTES + 1)) + + try: + payload = _with_retries(attempt) except OSError as exc: raise UpdateError(f"could not download {url}: {exc}") from exc if len(payload) > _MAX_DOWNLOAD_BYTES: @@ -789,20 +858,22 @@ def say(line: str) -> None: + ", ".join(path.name for path in superseded) ) - # BACKUPS FIRST -- before any download, before any install: if anything after - # this point half-happens, the databases' pre-update state exists on disk. Each - # is a consistent SQLite snapshot, and a same-second name never overwrites one. - occupied = {p.name for p in plan.launch_dir.glob("*.bak-before-*")} - backups: list[Path] = [] - for db_path in plan.db_paths: - dest = backup_path(db_path, plan.target_version, ts, occupied=occupied) - backup_file(db_path, dest) - occupied.add(dest.name) - backups.append(dest) - say(f"backed up {db_path.name} -> {dest.name}") - if not plan.db_paths: - say("no keel*.db databases in the launch folder -- nothing to back up") - + # DOWNLOAD FIRST, THEN BACK UP -- and this inverts what this function used to do, so the + # argument belongs here rather than in the issue that moved it (#676). + # + # The old order backed up every database before fetching anything, on the reasoning that + # "if anything after this point half-happens, the databases' pre-update state exists on + # disk". That guarantee is real and it is UNCHANGED by this order, because a download + # cannot make anything half-happen TO A DATABASE: `_download_file` writes only into + # `Release/`. The only steps that touch a database are the install (which replaces the + # running binary) and the migrate, and both still run after every backup exists. + # + # What the old order did do is spend the expensive, irreversible work before the cheap, + # failure-prone one. On 2026-09-01 a transient stall on the FIRST of five wheels threw away + # ~466 MB of `sqlite3.backup()` across three databases -- and because backups are + # timestamped and deliberately never deleted, the retry left a second full set behind + # rather than reusing the first. A failed download now costs nothing but the partial wheel + # the handler below already removes. plan.release_dir.mkdir(parents=True, exist_ok=True) wheel_paths: list[Path] = [] try: @@ -826,14 +897,30 @@ def say(line: str) -> None: "removed the partial wheel file(s) from Release/ -- a torn download must " "not poison a later rollback" ) + # EMPTY, and that is the change: no database was touched, so there is nothing to + # report and nothing on disk to clean up. return UpdateResult( ok=False, steps=tuple(steps), error=str(exc), rolled_back=False, - backups=tuple(backups), + backups=(), ) + # Every wheel is on disk. NOW back up -- before the install, which is the first step that + # can change a database. Each is a consistent SQLite snapshot, and a same-second name never + # overwrites one. + occupied = {p.name for p in plan.launch_dir.glob("*.bak-before-*")} + backups: list[Path] = [] + for db_path in plan.db_paths: + dest = backup_path(db_path, plan.target_version, ts, occupied=occupied) + backup_file(db_path, dest) + occupied.add(dest.name) + backups.append(dest) + say(f"backed up {db_path.name} -> {dest.name}") + if not plan.db_paths: + say("no keel*.db databases in the launch folder -- nothing to back up") + new_keel = console_entry(plan.venv_python) installed = False # whether the wheels FINISHED installing (uv returned success) try: @@ -964,7 +1051,7 @@ def gate_detail(plan: UpdatePlan) -> str: PURE.""" return ( f"launch folder {plan.launch_dir}: download the production wheels to " - f"{plan.release_dir}, back up every keel database first " + f"{plan.release_dir}, back up every keel database once they are all on disk " f"(.bak-before-{plan.latest_version}-, never deleted by the updater), " f"install them into the RUNNING venv ({plan.venv_python}) -- the binary this " "process is running RIGHT NOW is replaced -- then migrate and verify. This " @@ -1040,10 +1127,10 @@ def render_plan_lines(plan: UpdatePlan) -> list[str]: lines.append(f" download to: {plan.release_dir}") if plan.db_paths: names = ", ".join(path.name for path in plan.db_paths) - lines.append(f" back up first (never deleted): {names}") + lines.append(f" then back up (never deleted): {names}") lines.append(f" backups named: .bak-before-{plan.latest_version}-") else: - lines.append(" back up first: no keel*.db databases in the launch folder") + lines.append(" then back up: no keel*.db databases in the launch folder") lines.append(f" install into the RUNNING venv: {plan.venv_python}") lines.append(" then: migrate every database with the new build, verify with") lines.append(f" `keel versions` (every distribution at {plan.latest_version}),") diff --git a/tests/commands/test_update.py b/tests/commands/test_update.py index bbe886d..ac8a834 100644 --- a/tests/commands/test_update.py +++ b/tests/commands/test_update.py @@ -27,6 +27,7 @@ import sqlite3 import subprocess +import urllib.error from pathlib import Path from typing import Any @@ -170,13 +171,19 @@ def __init__(self, launch_dir: Path) -> None: self.events: list[tuple[str, Any]] = [] self.fail_verify = False self.fail_verify_with = "verify exploded" + self.fail_download_with: str | None = None self.fail_install_with: str | None = None self.fail_migrate_with: str | None = None self.installs = 0 def download(self, url: str, dest: Path) -> None: + # The backups present AT DOWNLOAD TIME. Since #676 this is empty on every wheel -- + # downloads run first now -- and it is recorded rather than dropped because the tuple + # is what makes a future re-reordering visible in `events` instead of silent. baks = sorted(p.name for p in self.launch_dir.glob("*.bak-before-0.7.0-*")) self.events.append(("download", dest.name, tuple(baks))) + if self.fail_download_with is not None: + raise up.UpdateError(self.fail_download_with) dest.write_bytes(b"new-wheel-bytes") def install(self, venv_python: Path, wheels: Any) -> None: @@ -1308,3 +1315,219 @@ def test_cli_packaged_network_failure_is_calm_and_not_an_error( assert "could not check" in result.output.lower() assert "0.6.0" in result.output assert up.RELEASES_URL in result.output + + +# -- transport retries (#675) -------------------------------------------------------------------- +# +# One transient stall used to abandon the whole update. On 2026-09-01 the live deployment failed +# on the FIRST of five wheels with "The read operation timed out"; the asset was healthy the +# whole time -- HTTP 200, 51,701 bytes, 0.82s a minute later, download counter still 0. + + +def _slept() -> tuple[list[float], Any]: + """A `sleep` double that records instead of waiting. A suite that really backs off spends + four seconds per retry pin.""" + waits: list[float] = [] + return waits, waits.append + + +def test_a_transport_stall_is_retried_and_the_second_attempt_wins() -> None: + calls: list[int] = [] + + def attempt() -> str: + calls.append(len(calls)) + if len(calls) == 1: + raise TimeoutError("The read operation timed out") + return "payload" + + waits, sleep = _slept() + assert up._with_retries(attempt, sleep=sleep) == "payload" + assert len(calls) == 2 + assert waits == [1.0], "the first retry must back off before asking again" + + +def test_retries_are_bounded_and_the_last_failure_is_what_the_operator_sees() -> None: + """Re-raises the LAST exception, not a wrapper: every caller's own message -- + `_http_get`'s rate-limit text, `_download_file`'s URL -- has to survive.""" + calls: list[int] = [] + + def attempt() -> str: + calls.append(len(calls)) + raise ConnectionResetError("connection reset by peer") + + waits, sleep = _slept() + with pytest.raises(ConnectionResetError, match="connection reset by peer"): + up._with_retries(attempt, sleep=sleep) + assert len(calls) == up._DOWNLOAD_ATTEMPTS + assert waits == [1.0, 3.0], "a doomed update waits 4 seconds total, once, and gives up" + + +@pytest.mark.parametrize("status", [404, 403, 401]) +def test_an_http_answer_that_will_not_change_is_not_retried(status: int) -> None: + """**The trap this guards.** `urllib.error.HTTPError` is a subclass of `OSError`, so the + obvious `except OSError: retry` retries a 404 as eagerly as a dropped connection -- three + times wrong instead of once. A 403 is worse than pointless: on the unauthenticated releases + endpoint it IS the rate limit, so retrying spends the budget that just ran out. + """ + calls: list[int] = [] + + def attempt() -> str: + calls.append(len(calls)) + raise urllib.error.HTTPError("http://x", status, "nope", {}, None) # type: ignore[arg-type] + + waits, sleep = _slept() + with pytest.raises(urllib.error.HTTPError): + up._with_retries(attempt, sleep=sleep) + assert len(calls) == 1, f"HTTP {status} is an answer, not a stall -- it must not be retried" + assert waits == [] + + +@pytest.mark.parametrize("status", sorted(up._RETRYABLE_STATUS)) +def test_a_server_side_status_is_retried(status: int) -> None: + """502/503 from a CDN is the same transient event as a timeout, wearing a status code.""" + calls: list[int] = [] + + def attempt() -> str: + calls.append(len(calls)) + if len(calls) == 1: + raise urllib.error.HTTPError("http://x", status, "later", {}, None) # type: ignore[arg-type] + return "payload" + + waits, sleep = _slept() + assert up._with_retries(attempt, sleep=sleep) == "payload" + assert len(calls) == 2 + + +def test_429_is_deliberately_not_retried() -> None: + """Transient, and still the one response retrying cannot help: it means the 60-per-hour + budget is spent. `_http_get` turns it into a message naming the manual procedure, which + needs no API call at all -- that message is the useful answer, not a fourth request.""" + assert 429 not in up._RETRYABLE_STATUS + + +def test_the_rate_limit_message_survives_the_retry_wrapper(monkeypatch) -> None: + """Two-sided with the branch `_http_get` has always had: the wrapper decides only WHETHER + to ask again, never what to say when the answer is final.""" + + def boom(*args: Any, **kwargs: Any) -> Any: + raise urllib.error.HTTPError("http://x", 403, "rate limited", {}, None) # type: ignore[arg-type] + + monkeypatch.setattr(up.urllib.request, "urlopen", boom) + with pytest.raises(up.UpdateError, match="rate-limited by the GitHub API"): + up._http_get("http://x") + + +# -- a failed download costs no backup (#676) ---------------------------------------------------- + + +def test_a_failed_download_leaves_no_database_backup_on_disk(tmp_path: Path) -> None: + """The reordering, pinned by its consequence rather than by call order. + + Backups used to run first, so a stall on the first of five wheels threw away ~466 MB of + `sqlite3.backup()` across three databases -- and because backups are timestamped and never + deleted, the retry left a second full set behind rather than reusing the first. + """ + launch = _deployment(tmp_path) + plan = _plan(launch) + ops = _FakeOps(launch) + ops.fail_download_with = "The read operation timed out" + + result, _steps = _run(plan, ops) + + assert result.ok is False + assert result.backups == (), ( + f"a failed download reported backups {[b.name for b in result.backups]} -- the " + "expensive work ran before the step most likely to fail" + ) + assert list(launch.glob("*.bak-before-*")) == [], ( + "a failed download left database backups on disk; each retry adds another full set " + "and the updater never deletes them" + ) + + +def test_download_file_itself_retries_a_stall(monkeypatch, tmp_path: Path) -> None: + """`_with_retries` being correct proves nothing about `_download_file` USING it. + + Every retry test above calls the helper directly, so removing the call from the production + downloader leaves all of them green -- which is exactly what a mutation run showed. This + exercises the real function. + """ + attempts: list[int] = [] + + class _Response: + def __enter__(self) -> _Response: + return self + + def __exit__(self, *exc: object) -> None: + return None + + def read(self, _limit: int) -> bytes: + return b"wheel-bytes" + + def urlopen(url: str, timeout: int | None = None) -> _Response: + attempts.append(len(attempts)) + if len(attempts) == 1: + raise TimeoutError("The read operation timed out") + return _Response() + + monkeypatch.setattr(up.urllib.request, "urlopen", urlopen) + monkeypatch.setattr(up.time, "sleep", lambda _s: None) + dest = tmp_path / "keel_core-0.13.2-py3-none-any.whl" + + up._download_file("http://x/wheel.whl", dest) + + assert len(attempts) == 2, "the production downloader does not retry" + assert dest.read_bytes() == b"wheel-bytes" + + +def test_http_get_itself_retries_a_stall(monkeypatch) -> None: + """And the releases-API read, which fails the update before it has even started.""" + attempts: list[int] = [] + + class _Response: + def __enter__(self) -> _Response: + return self + + def __exit__(self, *exc: object) -> None: + return None + + def read(self) -> bytes: + return b"{}" + + def urlopen(request: object, timeout: int | None = None) -> _Response: + attempts.append(len(attempts)) + if len(attempts) == 1: + raise ConnectionResetError("connection reset by peer") + return _Response() + + monkeypatch.setattr(up.urllib.request, "urlopen", urlopen) + monkeypatch.setattr(up.time, "sleep", lambda _s: None) + + assert up._http_get("http://x") == b"{}" + assert len(attempts) == 2, "the releases-API read does not retry" + + +def test_a_failed_download_does_not_claim_backups_left_by_an_EARLIER_run(tmp_path: Path) -> None: + """`backups=()` has to mean "this run took none", not "the glob found none". + + The sibling test proves nothing on its own: with no prior backups on disk, an + implementation that globbed `*.bak-before-*` would also return empty. A real launch folder + is the opposite case -- `~/keel` holds 7 GB of them going back to 0.9.1 -- so the + distinction is the normal state, not an edge case, and reporting someone else's backup as + this run's would send an operator to restore from the wrong file. + """ + launch = _deployment(tmp_path) + stale = launch / "keel.db.bak-before-0.6.9-20260101-000000" + stale.write_bytes(b"an older run's backup") + plan = _plan(launch) + ops = _FakeOps(launch) + ops.fail_download_with = "The read operation timed out" + + result, _steps = _run(plan, ops) + + assert result.ok is False + assert result.backups == (), ( + f"reported {[b.name for b in result.backups]} as this run's backups -- they belong to " + "an earlier update and this run took none" + ) + assert stale.is_file(), "an earlier run's backup must never be touched"