From dc22bd557ca3aa04bfcb9a58ada20b28b56b2536 Mon Sep 17 00:00:00 2001 From: Krzysztof kuhy Rudnicki Date: Sat, 24 Oct 2026 08:36:57 +0200 Subject: [PATCH] fast install: never report a failed run as success; queue the manifest first The BG3 fast install of 2026-10-23 downloaded 160 GB, was refused by the installer, and the web job still ended on a full bar, "Done!" and Succeeded while Steam restarted the download from 0%. - A failed run's reason is read from the installer's own run log (its ERROR lines). A waiting job prints "Failed: fast install of : ", which fails the job; `install` no longer says "Done!" after it. - Daemon-started failures stay on the Dashboard's Fast install card (and in ctl status, `error`) until a new run starts or the game is installed. - install_game writes Steam's "needs downloading" manifest before the installer runs: it only finishes a manifest it finds, so fresh installs were refused for want of one. - Command building moved to _fast_install_cmd (250-line cap). Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01GYmCezqhUjUmMisF5YtM4F --- DOCS-web-control-api.md | 9 +- steam_backlog_enforcer/_ctl_client.py | 1 + steam_backlog_enforcer/_ctl_types.py | 2 + steam_backlog_enforcer/_fast_install.py | 121 +++++++----------- steam_backlog_enforcer/_fast_install_cmd.py | 71 ++++++++++ .../_fast_install_failure.py | 55 ++++++++ .../_fast_install_progress.py | 31 ++++- steam_backlog_enforcer/game_install.py | 26 ++-- steam_backlog_enforcer/main/install.py | 8 +- .../tests/_no_fast_install.py | 14 +- .../tests/test_ctl_client.py | 8 ++ .../tests/test_fast_install_dashboard.py | 66 ++++++++++ .../tests/test_fast_install_failure.py | 54 ++++++++ .../tests/test_fast_install_helpers.py | 43 ++++--- .../tests/test_fast_install_job_wait.py | 17 ++- .../tests/test_fast_install_progress.py | 1 + .../tests/test_fast_install_runs.py | 20 +-- .../tests/test_game_install_queue.py | 50 ++++++++ .../tests/test_main_install.py | 13 ++ .../tests/test_web_daemon.py | 1 + web/src/api/contract.ts | 2 + web/src/screens/Dashboard.test.tsx | 8 ++ web/src/screens/Dashboard.tsx | 22 +++- 23 files changed, 506 insertions(+), 137 deletions(-) create mode 100644 steam_backlog_enforcer/_fast_install_cmd.py create mode 100644 steam_backlog_enforcer/_fast_install_failure.py create mode 100644 steam_backlog_enforcer/tests/test_fast_install_dashboard.py create mode 100644 steam_backlog_enforcer/tests/test_fast_install_failure.py create mode 100644 steam_backlog_enforcer/tests/test_game_install_queue.py diff --git a/DOCS-web-control-api.md b/DOCS-web-control-api.md index 0e345f6..127d7d9 100644 --- a/DOCS-web-control-api.md +++ b/DOCS-web-control-api.md @@ -205,9 +205,12 @@ hard-codes it. `gaming_unblock{phrase}`, `gaming_reset_arm{phrase}`, `gaming_reset_heartbeat{pending_id}`, `gaming_reset_commit{pending_id, phrase}`, `gaming_reset_cancel{pending_id}`, `restart{}`. There is no `stop`. -- `status` also lists the daemon's live steam-game-installer runs as - `fast_installs: [{app_id, name, phase, percent, elapsed_seconds}]`, read - from its log by the enforce loop; `percent` is the current depot's, or null. +- `status` also lists the daemon's steam-game-installer runs as + `fast_installs: [{app_id, name, phase, percent, elapsed_seconds, error}]`, + read from its log by the enforce loop; `percent` is the current depot's, or + null. A failed run stays listed with `phase: "failed"` and `error` set to + the installer's own ERROR lines until a new run starts or the game is fully + installed; `error` is null while a run is live. ## Verification record (2026-10-10) diff --git a/steam_backlog_enforcer/_ctl_client.py b/steam_backlog_enforcer/_ctl_client.py index 90e88d1..1947266 100644 --- a/steam_backlog_enforcer/_ctl_client.py +++ b/steam_backlog_enforcer/_ctl_client.py @@ -140,6 +140,7 @@ def _fast_install_info(run: dict[str, object]) -> FastInstallInfo: phase=str(run["phase"]), percent=None if percent is None else float(cast("float", percent)), elapsed_seconds=int(cast("int", run["elapsed_seconds"])), + error=None if run.get("error") is None else str(run["error"]), ) diff --git a/steam_backlog_enforcer/_ctl_types.py b/steam_backlog_enforcer/_ctl_types.py index 6a3de4f..9869687 100644 --- a/steam_backlog_enforcer/_ctl_types.py +++ b/steam_backlog_enforcer/_ctl_types.py @@ -22,6 +22,8 @@ class FastInstallInfo: phase: str percent: float | None elapsed_seconds: int + # Why the run failed (``phase`` is then ``failed``); None while it runs. + error: str | None = None @dataclass(frozen=True) diff --git a/steam_backlog_enforcer/_fast_install.py b/steam_backlog_enforcer/_fast_install.py index 1aedd3b..809ca9a 100644 --- a/steam_backlog_enforcer/_fast_install.py +++ b/steam_backlog_enforcer/_fast_install.py @@ -27,29 +27,29 @@ from __future__ import annotations from dataclasses import dataclass import logging import os -from pathlib import Path -import pwd -import re import shutil import signal import subprocess import sys import time +from typing import TYPE_CHECKING from steam_backlog_enforcer import _fast_install_progress as _fip from steam_backlog_enforcer import config as _config -from steam_backlog_enforcer._desktop_env import desktop_user_cmd, resolve_desktop_user +from steam_backlog_enforcer._desktop_env import resolve_desktop_user from steam_backlog_enforcer._echo import _echo +from steam_backlog_enforcer._fast_install_cmd import build_cmd, installer_path +from steam_backlog_enforcer._fast_install_failure import failure_reason from steam_backlog_enforcer._steam_restart_guard import game_is_running -from steam_backlog_enforcer._steam_state import STEAMAPPS_PATH +from steam_backlog_enforcer._steam_state import is_game_fully_installed + +if TYPE_CHECKING: + from collections.abc import Callable + from pathlib import Path logger = logging.getLogger(__name__) -_INSTALLER = Path("src", "steam-game-installer", "run.sh") _INSTALLER_LOG = "~/.local/state/steam-game-installer/latest.log" -# Depot content only: the app itself is ours to choose, the language is not -# worth a prompt nobody is there to answer. -_LANGUAGE = "english" # depotdownloader prints a line per finished chunk, so a healthy download is # never silent this long; a login prompt waiting on /dev/null is. STALL_SECONDS = 15 * 60 @@ -67,39 +67,10 @@ class _DetachedRun: _RUNS: list[_DetachedRun] = [] -# Apps whose installer run failed in this process. They go straight to the -# steam:// fallback from then on, so a broken login cannot close Steam on -# every 3-second pass. -_FAILED: set[int] = set() - - -def _installer_path(user: str | None) -> Path | None: - """steam-game-installer's ``run.sh`` in the desktop user's home, if present. - - Resolved from the passwd entry rather than ``Path.home()``: the daemon runs - as root, and the installer, its venv and its credentials are per-user. - """ - try: - home = Path(pwd.getpwnam(user).pw_dir) if user else Path.home() - except KeyError: - return None - path = home / _INSTALLER - return path if path.is_file() else None - - -def _steam_account_name() -> str | None: - """The account Steam itself last signed in with, from ``loginusers.vdf``. - - Read from Steam's own state rather than a copy in the enforcer config, so - it cannot drift from the account that actually owns the games. - """ - path = STEAMAPPS_PATH.parent / "config" / "loginusers.vdf" - try: - content = path.read_text(encoding="utf-8", errors="replace") - except OSError: - return None - match = re.search(r'"AccountName"\s+"([^"]+)"', content) - return match.group(1) if match else None +# Apps whose installer run failed in this process, with the reason. They go +# straight to the steam:// fallback from then on, so a broken login cannot +# close Steam on every 3-second pass. +_FAILED: dict[int, str] = {} def _refusal() -> str | None: @@ -109,32 +80,16 @@ def _refusal() -> str | None: return None -def _build_cmd(installer: Path, app_id: int, user: str | None) -> list[str]: - """The installer invocation, dropped to the desktop user when root.""" - cmd = [ - str(installer), - # install.sh reaches for yay; dependencies are installed once, by hand. - "--no-deps", - "--appid", - str(app_id), - "--yes", - "--language", - _LANGUAGE, - # Finishes the manifest from depotdownloader's own data, under the same - # fail-closed checks: no second login, no 70 GB re-hash by steamcmd. - "--skip-steamcmd", - ] - account = _steam_account_name() - if account: - cmd += ["--username", account] - return desktop_user_cmd(cmd, user) - - def is_fast_installing(app_id: int) -> bool: """Whether this process has a live detached installer run for *app_id*.""" return any(run.app_id == app_id for run in _RUNS) +def fast_install_failure(app_id: int) -> str | None: + """Why this process's installer run for *app_id* failed, if it did.""" + return _FAILED.get(app_id) + + def _stalled(run: _DetachedRun) -> bool: """Whether a live run has printed nothing for :data:`STALL_SECONDS`.""" try: @@ -167,15 +122,16 @@ def poll_fast_installs() -> None: if returncode == 0: logger.info("steam-game-installer finished AppID=%d.", run.app_id) continue - _FAILED.add(run.app_id) + _FAILED[run.app_id] = failure_reason(run.log_path, returncode) + _fip.mark_failed(run.app_id, _FAILED[run.app_id]) logger.warning( - "steam-game-installer failed for AppID=%d (exit %d); falling back " - "to Steam's own download. Log: %s", + "steam-game-installer failed for AppID=%d: %s. Falling back to " + "Steam's own download. Log: %s", run.app_id, - returncode, + _FAILED[run.app_id], run.log_path, ) - _fip.poll_trackers({run.app_id for run in _RUNS}) + _fip.poll_trackers({run.app_id for run in _RUNS}, is_game_fully_installed) def _spawn_detached(cmd: list[str], app_id: int, label: str = "") -> None: @@ -211,12 +167,26 @@ def _wait_detached(app_id: int, label: str) -> bool: time.sleep(_WAIT_POLL_SECONDS) poll_fast_installs() reporter.report(time.monotonic()) - return app_id not in _FAILED + if app_id not in _FAILED: + return True + # "Failed" first: a job takes such a line as its verdict, so the run can + # no longer end on a full progress bar and "Succeeded". + _echo( + f"Failed: fast install of {label}: {_FAILED[app_id]}. Steam's own " + f"download takes over (log: {_INSTALLER_LOG})." + ) + return False -def fast_install(app_id: int, label: str) -> bool: +def fast_install( + app_id: int, label: str, prepare: Callable[[], object] = lambda: None +) -> bool: """Install *app_id* with steam-game-installer. + *prepare* runs once the run is sure to start, before it does: the + installer only finishes a manifest it finds, so this is where a fresh + install gets one. + Returns: True if the game was installed (foreground) or the run was started (detached); False if the caller should fall back to Steam's download. @@ -224,7 +194,7 @@ def fast_install(app_id: int, label: str) -> bool: if app_id in _FAILED: return False user = resolve_desktop_user() - installer = _installer_path(user) + installer = installer_path(user) if installer is None: logger.warning("steam-game-installer not found; using Steam's download.") return False @@ -233,7 +203,8 @@ def fast_install(app_id: int, label: str) -> bool: _echo(f" Fast install of {label} skipped: {reason}.") return False - cmd = _build_cmd(installer, app_id, user) + cmd = build_cmd(installer, app_id, user) + prepare() if not sys.stdin.isatty(): _spawn_detached(cmd, app_id, label) return os.geteuid() == 0 or _wait_detached(app_id, label) @@ -242,9 +213,9 @@ def fast_install(app_id: int, label: str) -> bool: returncode = subprocess.run(cmd, check=False).returncode if returncode == 0: return True - _FAILED.add(app_id) + _FAILED[app_id] = f"exit {returncode}" _echo( - f" steam-game-installer failed (exit {returncode}); falling back to " - f"Steam's own download. Log: {_INSTALLER_LOG}" + f"Failed: fast install of {label} (exit {returncode}, reasons above). " + f"Steam's own download takes over (log: {_INSTALLER_LOG})." ) return False diff --git a/steam_backlog_enforcer/_fast_install_cmd.py b/steam_backlog_enforcer/_fast_install_cmd.py new file mode 100644 index 0000000..ea412f2 --- /dev/null +++ b/steam_backlog_enforcer/_fast_install_cmd.py @@ -0,0 +1,71 @@ +"""How steam-game-installer is invoked: where it lives, as whom, with what argv. + +Split out of :mod:`_fast_install`, which runs and reaps the installer; this +half only decides the command line, every choice it would otherwise prompt for +pinned in advance. +""" + +from __future__ import annotations + +from pathlib import Path +import pwd +import re + +from steam_backlog_enforcer._desktop_env import desktop_user_cmd +from steam_backlog_enforcer._steam_state import STEAMAPPS_PATH + +_INSTALLER = Path("src", "steam-game-installer", "run.sh") + +# Depot content only: the app itself is ours to choose, the language is not +# worth a prompt nobody is there to answer. +_LANGUAGE = "english" + + +def installer_path(user: str | None) -> Path | None: + """steam-game-installer's ``run.sh`` in the desktop user's home, if present. + + Resolved from the passwd entry rather than ``Path.home()``: the daemon runs + as root, and the installer, its venv and its credentials are per-user. + """ + try: + home = Path(pwd.getpwnam(user).pw_dir) if user else Path.home() + except KeyError: + return None + path = home / _INSTALLER + return path if path.is_file() else None + + +def steam_account_name() -> str | None: + """The account Steam itself last signed in with, from ``loginusers.vdf``. + + Read from Steam's own state rather than a copy in the enforcer config, so + it cannot drift from the account that actually owns the games. + """ + path = STEAMAPPS_PATH.parent / "config" / "loginusers.vdf" + try: + content = path.read_text(encoding="utf-8", errors="replace") + except OSError: + return None + match = re.search(r'"AccountName"\s+"([^"]+)"', content) + return match.group(1) if match else None + + +def build_cmd(installer: Path, app_id: int, user: str | None) -> list[str]: + """The installer invocation, dropped to the desktop user when root.""" + cmd = [ + str(installer), + # install.sh reaches for yay; dependencies are installed once, by hand. + "--no-deps", + "--appid", + str(app_id), + "--yes", + "--language", + _LANGUAGE, + # Finishes the manifest from depotdownloader's own data, under the same + # fail-closed checks: no second login, no 70 GB re-hash by steamcmd. + "--skip-steamcmd", + ] + account = steam_account_name() + if account: + cmd += ["--username", account] + return desktop_user_cmd(cmd, user) diff --git a/steam_backlog_enforcer/_fast_install_failure.py b/steam_backlog_enforcer/_fast_install_failure.py new file mode 100644 index 0000000..16d7b21 --- /dev/null +++ b/steam_backlog_enforcer/_fast_install_failure.py @@ -0,0 +1,55 @@ +"""Why a steam-game-installer run failed, in the installer's own words. + +A bare exit status hid the BG3 run of 2026-10-23: 160 GB downloaded, then a +refusal to mark it installed, and the job still read "Succeeded". The console +output ends with ``Run log (send this): ``; that run log tags every line +with its level, so its ERROR lines are exactly the reasons the run gave up. + +Both files are read from the end only: a depotdownloader run writes a line +per downloaded file, tens of megabytes of them. +""" + +from __future__ import annotations + +from pathlib import Path +import re +from typing import Final + +# The reasons and the run log line are printed last; 64 KiB holds them. +_TAIL_BYTES: Final = 1 << 16 +_RUN_LOG: Final = re.compile(r"^Run log(?: \(send this\))?: (/.+)$") +_ERROR: Final = re.compile(r"^\S+ \S+ ERROR\s+[\w.]+: (.*)$") + + +def _tail_lines(path: Path) -> list[str]: + """The last lines of *path* (empty if unreadable), first partial one dropped.""" + try: + with path.open("rb") as log: + size = log.seek(0, 2) + log.seek(max(0, size - _TAIL_BYTES)) + data = log.read() + except OSError: + return [] + lines = data.decode("utf-8", "replace").splitlines() + return lines[1:] if size > _TAIL_BYTES else lines + + +def _run_log_errors(console: list[str]) -> list[str]: + """ERROR messages of the run log the console output names last.""" + for line in reversed(console): + if match := _RUN_LOG.match(line.strip()): + run_log = _tail_lines(Path(match.group(1))) + return [m.group(1).strip() for ln in run_log if (m := _ERROR.match(ln))] + return [] + + +def failure_reason(console_log: Path, returncode: int) -> str: + """One line saying why the run that just wrote *console_log* failed.""" + console = _tail_lines(console_log) + errors = _run_log_errors(console) + if errors: + # Callers add their own full stop. + return " ".join(errors).rstrip(".") + # Died before the installer could log a reason (a traceback, a kill). + last = next((ln.strip() for ln in reversed(console) if ln.strip()), "") + return f"exit {returncode}: {last}" if last else f"exit {returncode}" diff --git a/steam_backlog_enforcer/_fast_install_progress.py b/steam_backlog_enforcer/_fast_install_progress.py index 19a204d..055a66e 100644 --- a/steam_backlog_enforcer/_fast_install_progress.py +++ b/steam_backlog_enforcer/_fast_install_progress.py @@ -40,6 +40,7 @@ from steam_backlog_enforcer._echo import _echo from steam_backlog_enforcer._progress import current_progress if TYPE_CHECKING: + from collections.abc import Callable from pathlib import Path STARTING: Final = "starting" @@ -146,6 +147,9 @@ class InstallTracker: # Live detached runs of this process by app id, with the name to show. The # enforce loop polls them; ctl connection threads read snapshots. _TRACKERS: dict[int, tuple[str, InstallTracker]] = {} +# Failed runs by app id: (name, reason). The daemon has no job to print a +# failure to, so it stays listed until a new run or the game is installed. +_FAILURES: dict[int, tuple[str, str]] = {} _LOCK = threading.Lock() @@ -153,13 +157,25 @@ def track(app_id: int, name: str, log_path: Path, *, offset: int, now: float) -> """Start following a run just spawned with its output at *offset* of the log.""" with _LOCK: _TRACKERS[app_id] = (name, InstallTracker(log_path, offset=offset, started=now)) + _FAILURES.pop(app_id, None) -def poll_trackers(live: set[int]) -> None: - """Read new log lines of the *live* runs and forget every other one.""" +def mark_failed(app_id: int, reason: str) -> None: + """List *app_id*'s run as failed with *reason*, under its tracked name.""" + with _LOCK: + entry = _TRACKERS.get(app_id) + _FAILURES[app_id] = (entry[0] if entry else f"AppID={app_id}", reason) + + +def poll_trackers( + live: set[int], installed: Callable[[int], bool] = lambda _app_id: False +) -> None: + """Read the *live* runs' new lines; drop other runs and *installed* failures.""" with _LOCK: for app_id in [aid for aid in _TRACKERS if aid not in live]: del _TRACKERS[app_id] + for app_id in [aid for aid in _FAILURES if installed(aid)]: + del _FAILURES[app_id] for _name, tracker in _TRACKERS.values(): tracker.poll() @@ -172,9 +188,15 @@ def progress_of(app_id: int, now: float) -> InstallProgress | None: def fast_install_status(now: float) -> list[dict[str, object]]: - """Every tracked run as the ctl ``status`` op reports it (no file I/O).""" + """Every tracked and failed run as the ctl ``status`` op reports it (no I/O).""" with _LOCK: entries = [(aid, name, t.snapshot(now)) for aid, (name, t) in _TRACKERS.items()] + failed = [ + {"app_id": aid, "name": name, "phase": "failed", "percent": None} + | {"elapsed_seconds": 0, "error": reason} + for aid, (name, reason) in _FAILURES.items() + if aid not in _TRACKERS + ] return [ { "app_id": app_id, @@ -182,9 +204,10 @@ def fast_install_status(now: float) -> list[dict[str, object]]: "phase": snap.phase, "percent": None if snap.percent is None else round(snap.percent, 2), "elapsed_seconds": snap.elapsed_seconds, + "error": None, } for app_id, name, snap in entries - ] + ] + failed class WaitReporter: diff --git a/steam_backlog_enforcer/game_install.py b/steam_backlog_enforcer/game_install.py index 4df6f18..3fbb3eb 100644 --- a/steam_backlog_enforcer/game_install.py +++ b/steam_backlog_enforcer/game_install.py @@ -2,6 +2,7 @@ from __future__ import annotations +from functools import partial import logging import os import shutil @@ -168,7 +169,10 @@ def install_game( if ready is not None: return ready - if fast_install(app_id, label): + # The installer only finishes a manifest it finds: queue a fresh install first. + if fast_install( + app_id, label, partial(_queue_download, app_id, game_name, steam_id) + ): return True # Steam already has a download of its own going: let it carry on, rather # than overwrite its manifest with the fabricated one below. @@ -181,6 +185,16 @@ def install_game( return True logger.debug("steam:// protocol failed; falling back to manifest") + if not _queue_download(app_id, game_name, steam_id): + return False + _ensure_steam_running() # so it picks the manifest up + return True + + +def _queue_download(app_id: int, game_name: str, steam_id: str) -> bool: + """Make Steam download *app_id* with a minimal appmanifest; False if unwritable.""" + if is_game_installed(app_id): + return True # Build a minimal appmanifest. StateFlags 1026 = UpdateRequired (2) + # UpdateStarted (1024), which tells Steam "this app needs downloading". manifest_content = ( @@ -219,7 +233,6 @@ def install_game( ) manifest_path = STEAMAPPS_PATH / f"appmanifest_{app_id}.acf" - try: with manifest_path.open("w", encoding="utf-8") as fh: fh.write(manifest_content) @@ -230,13 +243,8 @@ def install_game( if os.geteuid() == 0 and real_user and real_user != "root": uid, gid = _get_uid_gid_for_user(real_user) os.chown(manifest_path, uid, gid) - - logger.info("Created appmanifest for %s — Steam will auto-download", label) + logger.info("Created appmanifest for %s — Steam will auto-download", game_name) except OSError: - logger.exception("Failed to create appmanifest for %s", label) + logger.exception("Failed to create appmanifest for %s", game_name) return False - - # Make sure Steam is running so it picks up the manifest. - _ensure_steam_running() - return True diff --git a/steam_backlog_enforcer/main/install.py b/steam_backlog_enforcer/main/install.py index 30f990f..07e9c7e 100644 --- a/steam_backlog_enforcer/main/install.py +++ b/steam_backlog_enforcer/main/install.py @@ -6,6 +6,7 @@ from typing import TYPE_CHECKING from steam_backlog_enforcer._actions import allowed_app_ids, allowed_games from steam_backlog_enforcer._enforce_loop import get_all_owned_app_ids +from steam_backlog_enforcer._fast_install import fast_install_failure from steam_backlog_enforcer._progress import current_progress from steam_backlog_enforcer._prompter import ( PromptOption, @@ -115,10 +116,13 @@ def cmd_install(config: Config, state: State) -> None: # install_game only *starts* the download (fast installer or steam://); # there is no download-progress loop to report on yet. current_progress().phase(f"Starting install of {name}") - if install_game(app_id, name, config.steam_id, use_steam_protocol=True): + if not install_game(app_id, name, config.steam_id, use_steam_protocol=True): + _echo("Failed to start the install.") + elif fast_install_failure(app_id) is None: _echo("Done!") else: - _echo("Failed to start the install.") + # The fast install already printed its "Failed: ..." line. + _echo("Steam's own download was started instead.") def cmd_hide(config: Config, state: State) -> None: diff --git a/steam_backlog_enforcer/tests/_no_fast_install.py b/steam_backlog_enforcer/tests/_no_fast_install.py index f751b8b..b320c74 100644 --- a/steam_backlog_enforcer/tests/_no_fast_install.py +++ b/steam_backlog_enforcer/tests/_no_fast_install.py @@ -18,7 +18,11 @@ from unittest.mock import patch import pytest -from steam_backlog_enforcer import _fast_install, _fast_install_progress +from steam_backlog_enforcer import ( + _fast_install, + _fast_install_cmd, + _fast_install_progress, +) if TYPE_CHECKING: from collections.abc import Iterator @@ -40,11 +44,14 @@ def _no_fast_install(tmp_path: Path) -> Iterator[None]: _fast_install._RUNS.clear() _fast_install._FAILED.clear() _fast_install_progress._TRACKERS.clear() + _fast_install_progress._FAILURES.clear() patches = [patch(name, return_value=False) for name in _RUNNING_BINDINGS] patches += [ # Absolute, so `home / _INSTALLER` resolves here and never under ~. - patch.object(_fast_install, "_INSTALLER", tmp_path / "no-installer" / "run.sh"), - patch.object(_fast_install, "STEAMAPPS_PATH", fake_steamapps), + patch.object( + _fast_install_cmd, "_INSTALLER", tmp_path / "no-installer" / "run.sh" + ), + patch.object(_fast_install_cmd, "STEAMAPPS_PATH", fake_steamapps), ] for p in patches: p.start() @@ -56,3 +63,4 @@ def _no_fast_install(tmp_path: Path) -> Iterator[None]: _fast_install._RUNS.clear() _fast_install._FAILED.clear() _fast_install_progress._TRACKERS.clear() + _fast_install_progress._FAILURES.clear() diff --git a/steam_backlog_enforcer/tests/test_ctl_client.py b/steam_backlog_enforcer/tests/test_ctl_client.py index ca6ba72..55e92bd 100644 --- a/steam_backlog_enforcer/tests/test_ctl_client.py +++ b/steam_backlog_enforcer/tests/test_ctl_client.py @@ -145,6 +145,14 @@ class TestTypedWrappers: FastInstallInfo(7, "G", "downloading depot 1/8", 46.9, 60), ) + def test_status_failed_fast_install(self) -> None: + run = {"app_id": 7, "name": "G", "phase": "failed", "percent": None} + run |= {"elapsed_seconds": 0, "error": "exit 1"} + data = {"state": "running", "started_at": "t", "pid": 4, "fast_installs": [run]} + with self._call(data): + info = _ctl_client.status() + assert info.fast_installs[0].error == "exit 1" + def test_journal_tail(self) -> None: with self._call({"lines": ["a", 2]}) as call: assert _ctl_client.journal_tail(9) == ["a", "2"] diff --git a/steam_backlog_enforcer/tests/test_fast_install_dashboard.py b/steam_backlog_enforcer/tests/test_fast_install_dashboard.py new file mode 100644 index 0000000..3cb8971 --- /dev/null +++ b/steam_backlog_enforcer/tests/test_fast_install_dashboard.py @@ -0,0 +1,66 @@ +"""Tests for a failed daemon-started fast install staying visible. + +The root daemon has no job to print to: before, a failed run's tracker was +dropped and the Dashboard card simply vanished, as if nothing had happened. +""" + +from __future__ import annotations + +from typing import TYPE_CHECKING +from unittest.mock import MagicMock, patch + +from steam_backlog_enforcer import _fast_install +from steam_backlog_enforcer import _fast_install_progress as fip + +if TYPE_CHECKING: + from pathlib import Path + +PKG = "steam_backlog_enforcer._fast_install" + + +def _failed_run(tmp_path: Path, app_id: int = 7) -> None: + """A tracked daemon run of *app_id* that has just exited 1.""" + log = tmp_path / "log" + log.write_text("Restarting the Steam client...\n") + fip.track(app_id, "Baldur's Gate 3", log, offset=0, now=0.0) + proc = MagicMock(pid=4321) + proc.poll.return_value = 1 + _fast_install._RUNS.append(_fast_install._DetachedRun(app_id, proc, log)) + + +class TestFailedRunsStayListed: + def test_status_carries_the_reason(self, tmp_path: Path) -> None: + _failed_run(tmp_path) + with patch(f"{PKG}.is_game_fully_installed", return_value=False): + _fast_install.poll_fast_installs() + assert fip.fast_install_status(now=9.0) == [ + { + "app_id": 7, + "name": "Baldur's Gate 3", + "phase": "failed", + "percent": None, + "elapsed_seconds": 0, + "error": "exit 1: Restarting the Steam client...", + } + ] + + def test_live_runs_have_no_error(self, tmp_path: Path) -> None: + fip.track(8, "G", tmp_path / "log", offset=0, now=0.0) + fip.poll_trackers({8}) + assert fip.fast_install_status(now=1.0)[0]["error"] is None + + def test_gone_once_the_game_is_installed(self, tmp_path: Path) -> None: + """Steam's own download finished: the failure is history.""" + _failed_run(tmp_path) + with patch(f"{PKG}.is_game_fully_installed", return_value=False): + _fast_install.poll_fast_installs() + with patch(f"{PKG}.is_game_fully_installed", return_value=True): + _fast_install.poll_fast_installs() + assert fip.fast_install_status(now=9.0) == [] + + def test_a_new_run_replaces_the_failure(self, tmp_path: Path) -> None: + _failed_run(tmp_path) + with patch(f"{PKG}.is_game_fully_installed", return_value=False): + _fast_install.poll_fast_installs() + fip.track(7, "Baldur's Gate 3", tmp_path / "log", offset=0, now=0.0) + assert [s["phase"] for s in fip.fast_install_status(now=1.0)] == [fip.STARTING] diff --git a/steam_backlog_enforcer/tests/test_fast_install_failure.py b/steam_backlog_enforcer/tests/test_fast_install_failure.py new file mode 100644 index 0000000..3db8aa2 --- /dev/null +++ b/steam_backlog_enforcer/tests/test_fast_install_failure.py @@ -0,0 +1,54 @@ +"""Tests for _fast_install_failure: a failed run explained in the installer's words. + +The text is the BG3 run of 2026-10-23, which downloaded 160 GB and then +refused; all the job showed was a finished bar and "Succeeded". +""" + +from __future__ import annotations + +from typing import TYPE_CHECKING + +from steam_backlog_enforcer._fast_install_failure import failure_reason + +if TYPE_CHECKING: + from pathlib import Path + +_REFUSAL = ( + "2026-10-23 22:33:13,889 ERROR steam_installer: Refusing to mark " + "Baldur's Gate 3 as installed:\n" + "2026-10-23 22:33:13,889 ERROR steam_installer: - depot(s) 1419654 " + "have no cached manifest -- the download did not finish\n" + "2026-10-23 22:33:13,889 INFO steam_installer: Restarting the Steam client...\n" +) + + +def _console(tmp_path: Path, run_log: Path) -> Path: + console = tmp_path / "fast_install-1000.log" + console.write_text( + f"Run log: {tmp_path / 'old.log'}\n" + " 99.99% /x/Gustav.pak (403.89 Mbit/s)\n" + "Refusing to mark Baldur's Gate 3 as installed:\n" + f"Run log (send this): {run_log}\n" + "Restarting the Steam client...\n" + ) + return console + + +def test_reason_is_the_run_logs_error_lines(tmp_path: Path) -> None: + run_log = tmp_path / "run-1086940.log" + hello = "2026-10-23 22:13:21,605 INFO steam_installer: hi\n" + run_log.write_text(hello + _REFUSAL) + assert failure_reason(_console(tmp_path, run_log), 1) == ( + "Refusing to mark Baldur's Gate 3 as installed: - depot(s) 1419654 have " + "no cached manifest -- the download did not finish" + ) + + +def test_without_a_run_log_the_last_console_line_is_shown(tmp_path: Path) -> None: + console = tmp_path / "fast_install-0.log" + console.write_text("Traceback (most recent call last):\nOSError: disk full\n") + assert failure_reason(console, 1) == "exit 1: OSError: disk full" + + +def test_an_unreadable_console_log_still_names_the_exit(tmp_path: Path) -> None: + assert failure_reason(tmp_path / "missing.log", 3) == "exit 3" diff --git a/steam_backlog_enforcer/tests/test_fast_install_helpers.py b/steam_backlog_enforcer/tests/test_fast_install_helpers.py index 0e4fcea..b149515 100644 --- a/steam_backlog_enforcer/tests/test_fast_install_helpers.py +++ b/steam_backlog_enforcer/tests/test_fast_install_helpers.py @@ -1,4 +1,4 @@ -"""Tests for _fast_install's pure helpers: paths, account, refusal, argv. +"""Tests for the fast install's pure helpers: paths, account, refusal, argv. The run lifecycle (spawn, poll, fast_install) lives in test_fast_install_runs.py to keep both files under the 250-line cap. @@ -10,9 +10,10 @@ from pathlib import Path from types import SimpleNamespace from unittest.mock import MagicMock, patch -from steam_backlog_enforcer import _fast_install, _steam_state +from steam_backlog_enforcer import _fast_install, _fast_install_cmd, _steam_state PKG = "steam_backlog_enforcer._fast_install" +CMD = "steam_backlog_enforcer._fast_install_cmd" class TestInstallerPath: @@ -26,44 +27,44 @@ class TestInstallerPath: # real relative one back so the home join itself is what is tested. relative = Path("src", "steam-game-installer", "run.sh") with ( - patch.object(_fast_install, "_INSTALLER", relative), - patch(f"{PKG}.pwd.getpwnam", return_value=SimpleNamespace(pw_dir=tmp_path)), + patch.object(_fast_install_cmd, "_INSTALLER", relative), + patch(f"{CMD}.pwd.getpwnam", return_value=SimpleNamespace(pw_dir=tmp_path)), ): - assert _fast_install._installer_path("kuhy") == installer + assert _fast_install_cmd.installer_path("kuhy") == installer def test_missing_file_is_none(self, tmp_path: Path) -> None: with patch( - f"{PKG}.pwd.getpwnam", return_value=SimpleNamespace(pw_dir=tmp_path) + f"{CMD}.pwd.getpwnam", return_value=SimpleNamespace(pw_dir=tmp_path) ): - assert _fast_install._installer_path("kuhy") is None + assert _fast_install_cmd.installer_path("kuhy") is None def test_unknown_user_is_none(self) -> None: - with patch(f"{PKG}.pwd.getpwnam", side_effect=KeyError("nobody")): - assert _fast_install._installer_path("nobody") is None + with patch(f"{CMD}.pwd.getpwnam", side_effect=KeyError("nobody")): + assert _fast_install_cmd.installer_path("nobody") is None def test_no_user_uses_own_home(self, tmp_path: Path) -> None: - with patch(f"{PKG}.Path.home", return_value=tmp_path): - assert _fast_install._installer_path(None) is None + with patch(f"{CMD}.Path.home", return_value=tmp_path): + assert _fast_install_cmd.installer_path(None) is None class TestSteamAccountName: """The username comes from Steam's own loginusers.vdf.""" def _write(self, content: str) -> None: - config = _fast_install.STEAMAPPS_PATH.parent / "config" + config = _fast_install_cmd.STEAMAPPS_PATH.parent / "config" config.mkdir(parents=True, exist_ok=True) (config / "loginusers.vdf").write_text(content) def test_reads_account_name(self) -> None: self._write('"users"\n{\n\t"7656"\n\t{\n\t\t"AccountName"\t\t"krzys"\n') - assert _fast_install._steam_account_name() == "krzys" + assert _fast_install_cmd.steam_account_name() == "krzys" def test_no_account_field(self) -> None: self._write('"users"\n{\n}\n') - assert _fast_install._steam_account_name() is None + assert _fast_install_cmd.steam_account_name() is None def test_missing_file(self) -> None: - assert _fast_install._steam_account_name() is None + assert _fast_install_cmd.steam_account_name() is None class TestRefusal: @@ -90,10 +91,10 @@ class TestBuildCmd: def test_with_account(self) -> None: with ( - patch(f"{PKG}._steam_account_name", return_value="krzys"), - patch(f"{PKG}.desktop_user_cmd", side_effect=lambda cmd, _u: cmd), + patch(f"{CMD}.steam_account_name", return_value="krzys"), + patch(f"{CMD}.desktop_user_cmd", side_effect=lambda cmd, _u: cmd), ): - cmd = _fast_install._build_cmd(Path("/i/run.sh"), 42, "kuhy") + cmd = _fast_install_cmd.build_cmd(Path("/i/run.sh"), 42, "kuhy") assert cmd == [ "/i/run.sh", "--no-deps", @@ -109,10 +110,10 @@ class TestBuildCmd: def test_without_account_and_drops_privileges(self) -> None: with ( - patch(f"{PKG}._steam_account_name", return_value=None), - patch(f"{PKG}.desktop_user_cmd", return_value=["wrapped"]) as wrap, + patch(f"{CMD}.steam_account_name", return_value=None), + patch(f"{CMD}.desktop_user_cmd", return_value=["wrapped"]) as wrap, ): - assert _fast_install._build_cmd(Path("/i/run.sh"), 42, "kuhy") == [ + assert _fast_install_cmd.build_cmd(Path("/i/run.sh"), 42, "kuhy") == [ "wrapped" ] argv, user = wrap.call_args.args diff --git a/steam_backlog_enforcer/tests/test_fast_install_job_wait.py b/steam_backlog_enforcer/tests/test_fast_install_job_wait.py index 314cf21..f939eef 100644 --- a/steam_backlog_enforcer/tests/test_fast_install_job_wait.py +++ b/steam_backlog_enforcer/tests/test_fast_install_job_wait.py @@ -51,13 +51,13 @@ class TestJobWaitsForInstaller: def _install(self, tmp_path: Path, spawn: MagicMock, euid: int) -> bool: with ( - patch(f"{PKG}._installer_path", return_value=_ready(tmp_path)), + patch(f"{PKG}.installer_path", return_value=_ready(tmp_path)), patch(f"{PKG}._refusal", return_value=None), patch(f"{PKG}.sys.stdin.isatty", return_value=False), patch(f"{PKG}.os.geteuid", return_value=euid), patch(f"{PKG}._spawn_detached", spawn), patch(f"{PKG}.time.sleep"), - patch(f"{PKG}._echo"), + patch(f"{PKG}._echo") as self.echo, ): return _fast_install.fast_install(7, "G") @@ -67,7 +67,18 @@ class TestJobWaitsForInstaller: def test_failure_falls_back(self, tmp_path: Path) -> None: assert self._install(tmp_path, _fake_spawn(None, 3), 1000) is False - assert {7} == _fast_install._FAILED + assert {7} == set(_fast_install._FAILED) + + def test_failure_is_an_error_line_with_the_reason(self, tmp_path: Path) -> None: + """A job turns a line starting "Failed" into its failed verdict.""" + log = b"Refusing to mark G as installed:\nRestarting the Steam client...\n" + with patch(f"{PKG}._fip.current_progress"): + self._install(tmp_path, _fake_spawn(None, 1, log_text=log), 1000) + echoed = [c.args[0] for c in self.echo.call_args_list] + assert any( + line.startswith("Failed: fast install of G") and "exit 1" in line + for line in echoed + ), echoed def test_progress_is_reported_while_waiting(self, tmp_path: Path) -> None: text = b"Shutting down the Steam client...\r\nDownloading via depot\r\n" diff --git a/steam_backlog_enforcer/tests/test_fast_install_progress.py b/steam_backlog_enforcer/tests/test_fast_install_progress.py index f8a3dc9..bd2ec2b 100644 --- a/steam_backlog_enforcer/tests/test_fast_install_progress.py +++ b/steam_backlog_enforcer/tests/test_fast_install_progress.py @@ -154,6 +154,7 @@ class TestRegistry: "phase": "downloading depot 1/8", "percent": 59.16, "elapsed_seconds": 60, + "error": None, } ] diff --git a/steam_backlog_enforcer/tests/test_fast_install_runs.py b/steam_backlog_enforcer/tests/test_fast_install_runs.py index db16c67..a17dfa3 100644 --- a/steam_backlog_enforcer/tests/test_fast_install_runs.py +++ b/steam_backlog_enforcer/tests/test_fast_install_runs.py @@ -34,13 +34,13 @@ class TestPollFastInstalls: _run(1, 0, tmp_path / "log") _fast_install.poll_fast_installs() assert _fast_install._RUNS == [] - assert set() == _fast_install._FAILED + assert not _fast_install._FAILED def test_failure_is_remembered(self, tmp_path: Path) -> None: _run(2, 3, tmp_path / "log") _fast_install.poll_fast_installs() assert _fast_install._RUNS == [] - assert {2} == _fast_install._FAILED + assert {2} == set(_fast_install._FAILED) def test_live_and_chatty_is_left_alone(self, tmp_path: Path) -> None: log = tmp_path / "log" @@ -123,8 +123,8 @@ class TestFastInstall: return installer def test_previously_failed_goes_straight_to_fallback(self) -> None: - _fast_install._FAILED.add(7) - with patch(f"{PKG}._installer_path") as find: + _fast_install._FAILED[7] = "exit 1" + with patch(f"{PKG}.installer_path") as find: assert _fast_install.fast_install(7, "G") is False find.assert_not_called() @@ -134,7 +134,7 @@ class TestFastInstall: def test_refused(self, tmp_path: Path) -> None: with ( - patch(f"{PKG}._installer_path", return_value=self._ready(tmp_path)), + patch(f"{PKG}.installer_path", return_value=self._ready(tmp_path)), patch(f"{PKG}._refusal", return_value="a game is running"), patch(f"{PKG}._echo") as echo, patch(f"{PKG}.subprocess.run") as run, @@ -145,7 +145,7 @@ class TestFastInstall: def test_no_terminal_spawns_detached(self, tmp_path: Path) -> None: with ( - patch(f"{PKG}._installer_path", return_value=self._ready(tmp_path)), + patch(f"{PKG}.installer_path", return_value=self._ready(tmp_path)), patch(f"{PKG}._refusal", return_value=None), patch(f"{PKG}.sys.stdin.isatty", return_value=False), patch(f"{PKG}._spawn_detached") as spawn, @@ -157,23 +157,23 @@ class TestFastInstall: def test_terminal_runs_in_foreground(self, tmp_path: Path) -> None: with ( - patch(f"{PKG}._installer_path", return_value=self._ready(tmp_path)), + patch(f"{PKG}.installer_path", return_value=self._ready(tmp_path)), patch(f"{PKG}._refusal", return_value=None), patch(f"{PKG}.sys.stdin.isatty", return_value=True), patch(f"{PKG}._echo"), patch(f"{PKG}.subprocess.run", return_value=MagicMock(returncode=0)), ): assert _fast_install.fast_install(7, "G") is True - assert set() == _fast_install._FAILED + assert not _fast_install._FAILED def test_foreground_failure_falls_back(self, tmp_path: Path) -> None: with ( - patch(f"{PKG}._installer_path", return_value=self._ready(tmp_path)), + patch(f"{PKG}.installer_path", return_value=self._ready(tmp_path)), patch(f"{PKG}._refusal", return_value=None), patch(f"{PKG}.sys.stdin.isatty", return_value=True), patch(f"{PKG}._echo") as echo, patch(f"{PKG}.subprocess.run", return_value=MagicMock(returncode=2)), ): assert _fast_install.fast_install(7, "G") is False - assert {7} == _fast_install._FAILED + assert {7} == set(_fast_install._FAILED) assert "exit 2" in echo.call_args.args[0] diff --git a/steam_backlog_enforcer/tests/test_game_install_queue.py b/steam_backlog_enforcer/tests/test_game_install_queue.py new file mode 100644 index 0000000..266995b --- /dev/null +++ b/steam_backlog_enforcer/tests/test_game_install_queue.py @@ -0,0 +1,50 @@ +"""Tests for queueing an install with Steam before the fast installer runs. + +steam-game-installer only finishes a manifest it finds. A fresh install used +to reach it with none (Oct 22, BG3: "nothing to finish"), so the enforcer now +writes Steam's own "needs downloading" manifest first. +""" + +from __future__ import annotations + +from typing import TYPE_CHECKING +from unittest.mock import patch + +from steam_backlog_enforcer.game_install import _queue_download, install_game + +if TYPE_CHECKING: + from collections.abc import Callable + from pathlib import Path + +PKG = "steam_backlog_enforcer.game_install" + + +class TestQueueBeforeFastInstall: + def test_fast_install_gets_a_manifest_to_finish(self, tmp_path: Path) -> None: + """steam-game-installer only finishes a manifest it finds, so a fresh + install is queued with Steam before the installer runs, not after.""" + seen: list[bool] = [] + + def fast(_app_id: int, _label: str, prepare: Callable[[], object]) -> bool: + prepare() + seen.append((tmp_path / "appmanifest_440.acf").exists()) + return True + + with ( + patch(f"{PKG}.STEAMAPPS_PATH", tmp_path), + patch(f"{PKG}.fast_install", side_effect=fast), + patch(f"{PKG}.os.geteuid", return_value=1000), + ): + assert install_game(440, "TF2", "s1", use_steam_protocol=True) is True + assert seen == [True] + + def test_a_manifest_steam_already_has_is_kept(self, tmp_path: Path) -> None: + """Steam's own download in progress: its manifest is never overwritten.""" + manifest = tmp_path / "appmanifest_440.acf" + manifest.write_text('"StateFlags"\t\t"1042"\n') + with ( + patch(f"{PKG}.STEAMAPPS_PATH", tmp_path), + patch("steam_backlog_enforcer._steam_client.STEAMAPPS_PATH", tmp_path), + ): + assert _queue_download(440, "TF2", "s1") is True + assert manifest.read_text() == '"StateFlags"\t\t"1042"\n' diff --git a/steam_backlog_enforcer/tests/test_main_install.py b/steam_backlog_enforcer/tests/test_main_install.py index e7bbcde..851562b 100644 --- a/steam_backlog_enforcer/tests/test_main_install.py +++ b/steam_backlog_enforcer/tests/test_main_install.py @@ -112,6 +112,19 @@ class TestCmdInstall: ): cmd_install(Config(steam_id="i"), state) + def test_failed_fast_install_never_says_done(self) -> None: + """Steam's fallback download started, but the fast one failed: "Done!" + after the "Failed: ..." line was the success the BG3 job showed.""" + state = State(current_app_id=1, current_game_name="G") + with ( + patch(f"{PKG}.is_game_fully_installed", return_value=False), + patch(f"{PKG}.install_game", return_value=True), + patch(f"{PKG}.fast_install_failure", return_value="exit 1"), + patch(f"{PKG}._echo") as echo, + ): + cmd_install(Config(steam_id="i"), state) + echo.assert_called_with("Steam's own download was started instead.") + class TestCmdHide: """Tests for cmd_hide.""" diff --git a/steam_backlog_enforcer/tests/test_web_daemon.py b/steam_backlog_enforcer/tests/test_web_daemon.py index d6037c7..9a9d08c 100644 --- a/steam_backlog_enforcer/tests/test_web_daemon.py +++ b/steam_backlog_enforcer/tests/test_web_daemon.py @@ -91,6 +91,7 @@ class TestDaemonView: "phase": "downloading depot 3/8", "percent": 46.9, "elapsed_seconds": 60, + "error": None, } ] diff --git a/web/src/api/contract.ts b/web/src/api/contract.ts index 136caf4..955efd1 100644 --- a/web/src/api/contract.ts +++ b/web/src/api/contract.ts @@ -173,6 +173,8 @@ export interface FastInstallRun { /** The current depot's percent; null until depotdownloader reports one. */ percent: number | null elapsed_seconds: number + /** Why the run failed (`phase` is then `failed`); null while it runs. */ + error?: string | null } export interface DaemonStatus { diff --git a/web/src/screens/Dashboard.test.tsx b/web/src/screens/Dashboard.test.tsx index f4a11f7..cd7d74e 100644 --- a/web/src/screens/Dashboard.test.tsx +++ b/web/src/screens/Dashboard.test.tsx @@ -114,6 +114,14 @@ describe('Dashboard', () => { expect(screen.getByRole('progressbar', { name: "Baldur's Gate 3 download" })).toHaveClass('bar-indeterminate') }) + it('keeps a failed daemon run on screen with its reason', async () => { + const failed = { ...bg3, phase: 'failed', percent: null, elapsed_seconds: 0, error: 'Refusing to mark it as installed' } + show({ 'GET /api/daemon': daemon([failed]) }) + expect(await screen.findByText("Fast install of Baldur's Gate 3 failed: Refusing to mark it as installed")).toHaveClass('text-danger') + expect(screen.getByText("Steam's own download took over.")).toBeInTheDocument() + expect(screen.queryByRole('progressbar', { name: "Baldur's Gate 3 download" })).not.toBeInTheDocument() + }) + it('stays out of the way when nothing is installing', async () => { show() expect(await screen.findByText('Hollow Knight')).toBeInTheDocument() diff --git a/web/src/screens/Dashboard.tsx b/web/src/screens/Dashboard.tsx index c33e50b..ea68818 100644 --- a/web/src/screens/Dashboard.tsx +++ b/web/src/screens/Dashboard.tsx @@ -55,13 +55,21 @@ function FastInstalls() { if (!runs.length) return null return ( - {runs.map((r) => ( -
-

{fastInstallLine(r)}

- -

{fmtDuration(r.elapsed_seconds)} elapsed

-
- ))} + {runs.map((r) => + r.error ? ( + // The daemon has no job to report to: a failure stays here until Steam finishes. +
+

{`Fast install of ${r.name} failed: ${r.error}`}

+

Steam's own download took over.

+
+ ) : ( +
+

{fastInstallLine(r)}

+ +

{fmtDuration(r.elapsed_seconds)} elapsed

+
+ ), + )} ) }