diff --git a/.env.example b/.env.example index 638a5a3..702c5ac 100644 --- a/.env.example +++ b/.env.example @@ -17,6 +17,8 @@ STEAMCMD_BATCH_SIZE=25 STEAMCMD_TIMEOUT_SECONDS=1800 REFRESH_INTERVAL_SECONDS=3600 REFRESH_ON_STARTUP=true +# Hard ceiling for the first full Workshop download (12 hours). +INITIAL_DOWNLOAD_TIMEOUT_SECONDS=43200 MODLIST_GAME_VERSION=1.6 # Optional bearer token required by POST /api/refresh when set. PROGRESSION_ADMIN_TOKEN= diff --git a/Dockerfile b/Dockerfile index f0cb456..2f27237 100644 --- a/Dockerfile +++ b/Dockerfile @@ -27,7 +27,8 @@ ENV PROGRESSION_HOST=0.0.0.0 \ STEAMCMD_PATH=/opt/steamcmd/steamcmd.sh \ STEAMCMD_WORKSHOP_DIR=/opt/steamcmd/steamapps/workshop/content/294100 \ REFRESH_INTERVAL_SECONDS=3600 \ - REFRESH_ON_STARTUP=true + REFRESH_ON_STARTUP=true \ + INITIAL_DOWNLOAD_TIMEOUT_SECONDS=43200 VOLUME ["/srv/progression/.data", "/opt/steamcmd/steamapps"] EXPOSE 8000 diff --git a/compose.yaml b/compose.yaml index 3979e55..7860bf2 100644 --- a/compose.yaml +++ b/compose.yaml @@ -8,6 +8,7 @@ services: environment: PROGRESSION_ADMIN_TOKEN: ${PROGRESSION_ADMIN_TOKEN:-} MODLIST_GAME_VERSION: ${MODLIST_GAME_VERSION:-1.6} + INITIAL_DOWNLOAD_TIMEOUT_SECONDS: ${INITIAL_DOWNLOAD_TIMEOUT_SECONDS:-43200} volumes: - progression-data:/srv/progression/.data - progression-workshop:/opt/steamcmd/steamapps diff --git a/deploy/.env.example b/deploy/.env.example index 4c553e1..51e4dcb 100644 --- a/deploy/.env.example +++ b/deploy/.env.example @@ -20,4 +20,6 @@ STEAMCMD_BATCH_SIZE=25 STEAMCMD_TIMEOUT_SECONDS=1800 REFRESH_INTERVAL_SECONDS=3600 REFRESH_ON_STARTUP=true +# Hard ceiling for the first full Workshop download (12 hours). +INITIAL_DOWNLOAD_TIMEOUT_SECONDS=43200 diff --git a/deploy/README.md b/deploy/README.md index a07cdfa..b77397a 100644 --- a/deploy/README.md +++ b/deploy/README.md @@ -15,3 +15,8 @@ docker compose up -d The SQLite database and Steam Workshop files are stored in named Docker volumes and survive image upgrades. To update later, run the same two commands again. +On a new deployment, the hourly refresh timer stays paused while the first full +Workshop download runs. Its hard limit defaults to 12 hours and can be changed +with `INITIAL_DOWNLOAD_TIMEOUT_SECONDS`. Follow the per-mod title, Workshop ID, +result, and completion percentage in Dockhand or with `docker compose logs -f`. + diff --git a/deploy/compose.yaml b/deploy/compose.yaml index 0cfdc2e..00ab6b8 100644 --- a/deploy/compose.yaml +++ b/deploy/compose.yaml @@ -23,6 +23,7 @@ services: STEAMCMD_TIMEOUT_SECONDS: ${STEAMCMD_TIMEOUT_SECONDS:-1800} REFRESH_INTERVAL_SECONDS: ${REFRESH_INTERVAL_SECONDS:-3600} REFRESH_ON_STARTUP: ${REFRESH_ON_STARTUP:-true} + INITIAL_DOWNLOAD_TIMEOUT_SECONDS: ${INITIAL_DOWNLOAD_TIMEOUT_SECONDS:-43200} volumes: - progression-data:/srv/progression/.data - progression-workshop:/opt/steamcmd/steamapps diff --git a/progression_backend/app.py b/progression_backend/app.py index 6132ba6..ee9df05 100644 --- a/progression_backend/app.py +++ b/progression_backend/app.py @@ -83,7 +83,10 @@ def create_app(settings: Settings | None = None) -> FastAPI: ) service = RefreshService(settings, database, runner=runner) coordinator = RefreshCoordinator( - service, settings.refresh_interval_seconds, settings.refresh_on_startup + service, + settings.refresh_interval_seconds, + settings.refresh_on_startup, + settings.initial_download_timeout_seconds, ) @asynccontextmanager diff --git a/progression_backend/config.py b/progression_backend/config.py index 3109e80..fcfbd64 100644 --- a/progression_backend/config.py +++ b/progression_backend/config.py @@ -38,6 +38,7 @@ class Settings: steamcmd_timeout_seconds: int refresh_interval_seconds: int refresh_on_startup: bool + initial_download_timeout_seconds: int game_version: str admin_token: str | None collections: dict[str, str] @@ -71,6 +72,9 @@ class Settings: 60, int(os.getenv("REFRESH_INTERVAL_SECONDS", "3600")) ), refresh_on_startup=_as_bool(os.getenv("REFRESH_ON_STARTUP"), True), + initial_download_timeout_seconds=max( + 60, int(os.getenv("INITIAL_DOWNLOAD_TIMEOUT_SECONDS", "43200")) + ), game_version=os.getenv("MODLIST_GAME_VERSION", "1.6").strip() or "1.6", admin_token=os.getenv("PROGRESSION_ADMIN_TOKEN") or None, collections={ diff --git a/progression_backend/refresh.py b/progression_backend/refresh.py index 1cb0eb5..ccea53d 100644 --- a/progression_backend/refresh.py +++ b/progression_backend/refresh.py @@ -1,8 +1,10 @@ from __future__ import annotations import asyncio +import logging import time import uuid +from collections.abc import Callable from datetime import datetime, timedelta, timezone from typing import Any @@ -12,6 +14,14 @@ from .steam_api import SteamWorkshopClient, WorkshopDetails from .workshop import SteamCmdRunner, directory_size, parse_about_xml, utc_now +logger = logging.getLogger("uvicorn.error") +ProgressCallback = Callable[[dict[str, Any]], None] + + +class InitialDownloadTimeout(RuntimeError): + pass + + def _batches(values: list[str], size: int) -> list[list[str]]: return [values[index : index + size] for index in range(0, len(values), size)] @@ -33,6 +43,16 @@ class RefreshService: settings.steamcmd_timeout_seconds, ) + def needs_initial_download(self) -> bool: + rows = self.database.current_mods() + if not rows: + return True + return any( + row.get("status") != "ready" + or not (self.settings.workshop_content_dir / row["workshop_id"]).is_dir() + for row in rows + ) + def _store_metadata( self, detail: WorkshopDetails, @@ -104,9 +124,22 @@ class RefreshService: "last_downloaded_at": utc_now() if downloaded else None, } - def refresh(self, run_id: str, trigger: str) -> None: + def refresh( + self, + run_id: str, + trigger: str, + *, + initial_download: bool = False, + overall_timeout_seconds: int | None = None, + progress: ProgressCallback | None = None, + ) -> None: started_at = utc_now() started = time.monotonic() + deadline = ( + started + overall_timeout_seconds + if initial_download and overall_timeout_seconds is not None + else None + ) self.database.create_run(run_id, trigger, started_at) metrics: dict[str, Any] = { "collection_items": 0, @@ -123,7 +156,24 @@ class RefreshService: "error": None, } + def report(**values: Any) -> None: + if progress: + progress(values) + + def remaining_time() -> float | None: + if deadline is None: + return None + remaining = deadline - time.monotonic() + if remaining <= 0: + raise InitialDownloadTimeout( + "The initial Workshop download reached its " + f"{overall_timeout_seconds}-second limit" + ) + return remaining + try: + report(stage="collections", completed_mods=0, total_mods=0, percent=0.0) + remaining_time() collection_ids = list(self.settings.collections.values()) response = self.steam.get_collections(collection_ids) named_collections: dict[str, tuple[str, list[str]]] = {} @@ -177,6 +227,25 @@ class RefreshService: self.database.upsert_mods(metadata_rows) metrics["downloads_requested"] = len(targets) + total_targets = len(targets) + completed_targets = 0 + title_by_id = { + workshop_id: details[workshop_id].title + for workshop_id in targets + if workshop_id in details + } + report( + stage="downloading" if targets else "inspecting", + completed_mods=0, + total_mods=total_targets, + percent=100.0 if not targets else 0.0, + ) + if initial_download: + logger.info( + "Initial Workshop download started: %d mods, %.1f-hour hard limit", + total_targets, + (overall_timeout_seconds or 0) / 3600, + ) if targets and not self.runner.available(): reason = ( f"SteamCMD was not found at '{self.settings.steamcmd_path}'. " @@ -195,40 +264,116 @@ class RefreshService: metrics["downloads_failed"] += 1 self.database.upsert_mods(inspection_rows) else: - for batch_number, batch in enumerate( - _batches(targets, self.settings.steamcmd_batch_size), start=1 - ): - result = self.runner.run_batch(batch) - self.database.add_download_attempt( - { - "run_id": run_id, - "batch_number": batch_number, - "item_count": len(batch), - "workshop_ids": batch, - "started_at": result.started_at, - "finished_at": result.finished_at, - "elapsed_seconds": result.elapsed_seconds, - "exit_code": result.exit_code, - "status": result.status, - "output_tail": result.output_tail, - } + download_queue = list(targets) + ready_target_ids: set[str] = set() + batch_number = 0 + pass_number = 1 + while download_queue: + batches = _batches( + download_queue, self.settings.steamcmd_batch_size ) - inspection_rows = [] - for workshop_id in batch: - failure = ( - "SteamCMD reported a download failure" - if workshop_id in result.failed_ids - else None + for pass_batch_number, batch in enumerate(batches, start=1): + remaining = remaining_time() + batch_number += 1 + logger.info( + "%s pass %d batch %d/%d starting (%d mods): %s", + "Initial Workshop download" + if initial_download + else "Workshop refresh", + pass_number, + pass_batch_number, + len(batches), + len(batch), + ", ".join( + f"{title_by_id.get(workshop_id, 'Unknown mod')} " + f"[{workshop_id}]" + for workshop_id in batch + ), ) - success, values = self._inspection_values( - workshop_id, downloaded=True, forced_error=failure + result = self.runner.run_batch( + batch, timeout_seconds=remaining ) - inspection_rows.append(values) - if success: - metrics["downloads_succeeded"] += 1 - else: - metrics["downloads_failed"] += 1 - self.database.upsert_mods(inspection_rows) + self.database.add_download_attempt( + { + "run_id": run_id, + "batch_number": batch_number, + "item_count": len(batch), + "workshop_ids": batch, + "started_at": result.started_at, + "finished_at": result.finished_at, + "elapsed_seconds": result.elapsed_seconds, + "exit_code": result.exit_code, + "status": result.status, + "output_tail": result.output_tail, + } + ) + inspection_rows = [] + for workshop_id in batch: + failure = ( + "SteamCMD reported a download failure" + if workshop_id in result.failed_ids + else None + ) + success, values = self._inspection_values( + workshop_id, downloaded=True, forced_error=failure + ) + inspection_rows.append(values) + if success: + metrics["downloads_succeeded"] += 1 + ready_target_ids.add(workshop_id) + else: + metrics["downloads_failed"] += 1 + completed_targets = len(ready_target_ids) + percent = round( + (completed_targets / max(total_targets, 1)) * 100, + 1, + ) + title = title_by_id.get(workshop_id, "Unknown mod") + outcome = "ready" if success else "failed" + report( + stage="downloading", + completed_mods=completed_targets, + total_mods=total_targets, + percent=percent, + current_workshop_id=workshop_id, + current_title=title, + current_status=outcome, + ) + logger.info( + "%s %d/%d (%.1f%%) %s: %s [%s]", + "Initial mod download" + if initial_download + else "Mod refresh", + completed_targets, + total_targets, + percent, + outcome, + title, + workshop_id, + ) + self.database.upsert_mods(inspection_rows) + remaining_time() + + if not initial_download: + break + download_queue = [ + workshop_id + for workshop_id in download_queue + if workshop_id not in ready_target_ids + ] + if download_queue: + remaining = remaining_time() + retry_delay = min(30.0, remaining or 30.0) + logger.warning( + "Initial Workshop download pass %d left %d mods; " + "retrying in %.0f seconds", + pass_number, + len(download_queue), + retry_delay, + ) + time.sleep(retry_delay) + remaining_time() + pass_number += 1 # Re-inspect ready cached items whose metadata has never been parsed by this backend. current = self.database.mod_map(unique_ids) @@ -259,12 +404,37 @@ class RefreshService: metrics["error"] = ( f"{metrics['unique_items'] - metrics['ready_items']} items are not ready" ) + report( + stage=metrics["status"], + completed_mods=completed_targets, + total_mods=total_targets, + percent=round( + (completed_targets / max(total_targets, 1)) * 100, 1 + ) + if total_targets + else 100.0, + ) except Exception as error: # noqa: BLE001 - the run must always persist a terminal state metrics["status"] = "failed" metrics["error"] = str(error) metrics["bytes_after"] = directory_size(self.settings.workshop_content_dir) metrics["cache_bytes"] = metrics["bytes_after"] + metrics["bytes_downloaded"] = max( + metrics["bytes_after"] - metrics["bytes_before"], 0 + ) + report(stage="failed", error=str(error)) + logger.error( + "%s failed: %s", + "Initial Workshop download" if initial_download else "Workshop refresh", + error, + ) finally: + if metrics["unique_items"]: + metrics["ready_items"] = sum( + 1 + for row in self.database.current_mods() + if row.get("status") == "ready" + ) elapsed = max(time.monotonic() - started, 0.001) metrics["elapsed_seconds"] = round(elapsed, 3) metrics["average_mbps"] = round( @@ -272,20 +442,37 @@ class RefreshService: ) metrics["finished_at"] = utc_now() self.database.finish_run(run_id, metrics) + logger.info( + "%s finished: status=%s, ready=%d/%d, elapsed=%.1fs, " + "cache=%d bytes", + "Initial Workshop download" if initial_download else "Workshop refresh", + metrics["status"], + metrics["ready_items"], + metrics["unique_items"], + elapsed, + metrics["cache_bytes"], + ) class RefreshCoordinator: def __init__( - self, service: RefreshService, interval_seconds: int, refresh_on_startup: bool + self, + service: RefreshService, + interval_seconds: int, + refresh_on_startup: bool, + initial_download_timeout_seconds: int = 43200, ): self.service = service self.interval_seconds = interval_seconds self.refresh_on_startup = refresh_on_startup + self.initial_download_timeout_seconds = initial_download_timeout_seconds self.current_run_id: str | None = None self.next_refresh_at: str | None = None self._refresh_task: asyncio.Task[None] | None = None self._scheduler_task: asyncio.Task[None] | None = None self._stop = asyncio.Event() + self._active_initial_download = False + self._progress: dict[str, Any] | None = None async def start(self) -> None: if self._scheduler_task: @@ -303,19 +490,48 @@ class RefreshCoordinator: return self.current_run_id or "", False run_id = uuid.uuid4().hex self.current_run_id = run_id + initial_download = self.service.needs_initial_download() + self._active_initial_download = initial_download + self._progress = { + "stage": "starting", + "completed_mods": 0, + "total_mods": 0, + "percent": 0.0, + } + + def update_progress(values: dict[str, Any]) -> None: + self._progress = {**(self._progress or {}), **values} async def run() -> None: try: - await asyncio.to_thread(self.service.refresh, run_id, trigger) + await asyncio.to_thread( + self.service.refresh, + run_id, + trigger, + initial_download=initial_download, + overall_timeout_seconds=( + self.initial_download_timeout_seconds + if initial_download + else None + ), + progress=update_progress, + ) finally: self.current_run_id = None + self._active_initial_download = False self._refresh_task = asyncio.create_task(run()) return run_id, True + async def _wait_for_initial_download(self, started: bool) -> None: + if started and self._active_initial_download and self._refresh_task: + self.next_refresh_at = None + await asyncio.shield(self._refresh_task) + async def _scheduler_loop(self) -> None: if self.refresh_on_startup: - await self.trigger("startup") + _, started = await self.trigger("startup") + await self._wait_for_initial_download(started) while not self._stop.is_set(): next_time = datetime.now(timezone.utc) + timedelta( seconds=self.interval_seconds @@ -324,7 +540,8 @@ class RefreshCoordinator: try: await asyncio.wait_for(self._stop.wait(), timeout=self.interval_seconds) except asyncio.TimeoutError: - await self.trigger("scheduled") + _, started = await self.trigger("scheduled") + await self._wait_for_initial_download(started) def state(self) -> dict[str, Any]: return { @@ -332,4 +549,11 @@ class RefreshCoordinator: "current_run_id": self.current_run_id, "next_refresh_at": self.next_refresh_at, "interval_seconds": self.interval_seconds, + "initial_download": bool( + self._active_initial_download + and self._refresh_task + and not self._refresh_task.done() + ), + "initial_download_timeout_seconds": self.initial_download_timeout_seconds, + "progress": dict(self._progress) if self._progress else None, } diff --git a/progression_backend/static/app.js b/progression_backend/static/app.js index e7ab46b..e30e915 100644 --- a/progression_backend/static/app.js +++ b/progression_backend/static/app.js @@ -108,9 +108,19 @@ function renderServiceState(data) { const ready = Number(data.totals?.ready_mods || 0); element.className = "service-state"; - if (data.scheduler?.running) { + const progress = data.scheduler?.progress || {}; + const progressPercent = Number(progress.percent || 0); + + if (data.scheduler?.initial_download) { element.classList.add("working"); - label.textContent = "Updating now"; + label.textContent = progress.total_mods + ? `Downloading first-time mods · ${Math.round(progressPercent)}%` + : "Downloading first-time mods"; + } else if (data.scheduler?.running) { + element.classList.add("working"); + label.textContent = progress.total_mods + ? `Updating now · ${Math.round(progressPercent)}%` + : "Updating now"; } else if (data.latest_run?.status === "failed") { element.classList.add("failed"); label.textContent = "Update needs attention"; @@ -166,12 +176,22 @@ function renderDashboard(data) { } const updatedAt = data.rml_updated_at; - $("#last-updated").textContent = data.scheduler?.running ? "Updating now" : formatRelativeDate(updatedAt); + const progress = data.scheduler?.progress || {}; + const initialDownload = Boolean(data.scheduler?.initial_download); + $("#last-updated").textContent = initialDownload + ? `Downloading ${Math.round(Number(progress.percent || 0))}%` + : (data.scheduler?.running ? "Updating now" : formatRelativeDate(updatedAt)); $("#last-updated").title = formatDate(updatedAt); state.rmlReady = total > 0 && ready === total && !data.scheduler?.running; const nextRefresh = data.scheduler?.next_refresh_at; - if (data.scheduler?.running) { + if (initialDownload) { + const completed = Number(progress.completed_mods || 0).toLocaleString(); + const target = Number(progress.total_mods || 0).toLocaleString(); + $("#update-detail").textContent = progress.total_mods + ? `First-time download: ${completed} of ${target} mods. Hourly checks begin after it finishes.` + : "Preparing the first-time Workshop download. Hourly checks are paused."; + } else if (data.scheduler?.running) { $("#update-detail").textContent = "The hourly Workshop refresh is currently running."; } else if (!state.rmlReady) { $("#update-detail").textContent = "The current RML is being prepared from the latest Workshop data."; diff --git a/progression_backend/static/index.html b/progression_backend/static/index.html index 3f7c14d..86c4520 100644 --- a/progression_backend/static/index.html +++ b/progression_backend/static/index.html @@ -90,14 +90,13 @@ diff --git a/progression_backend/static/styles.css b/progression_backend/static/styles.css index 41fabf4..1f5ca7f 100644 --- a/progression_backend/static/styles.css +++ b/progression_backend/static/styles.css @@ -48,18 +48,28 @@ html { min-width: 320px; background: var(--bg); } body { + position: relative; min-width: 320px; min-height: 100vh; margin: 0; - background: - radial-gradient(circle at 85% 8%, rgba(84, 114, 79, .12), transparent 27rem), - linear-gradient(180deg, #171717 0, #101214 100%); + background: #0b0b0c url("/art/Desolation.png") center / cover fixed no-repeat; color: var(--text); font-family: var(--font-ui); font-size: 16px; line-height: 1.5; } +body::before { + content: ""; + position: fixed; + z-index: 0; + inset: 0; + pointer-events: none; + background: + radial-gradient(circle at center, rgba(21, 21, 21, .08), rgba(21, 21, 21, .76) 72%), + linear-gradient(rgba(21, 21, 21, .36), rgba(21, 21, 21, .66)); +} + button, input { font: inherit; } button { color: inherit; } img { display: block; max-width: 100%; } @@ -117,6 +127,8 @@ h1, h2, p { margin: 0; } .is-ready .intro { opacity: 0; visibility: hidden; } .page-shell { + position: relative; + z-index: 1; width: min(1220px, calc(100% - 48px)); margin: 0 auto; padding-bottom: 26px; @@ -146,9 +158,13 @@ h1, h2, p { margin: 0; } font-size: .78rem; font-weight: 800; letter-spacing: .08em; + line-height: 1.3; + text-align: right; text-transform: uppercase; } +.service-state span:last-child { max-width: 300px; } + .state-dot { width: 8px; height: 8px; @@ -352,20 +368,22 @@ footer { font-size: .76rem; } -.footer-meta { display: flex; align-items: center; gap: 10px; } +.footer-credits { margin-left: auto; display: flex; align-items: center; gap: 10px; } .art-credit { padding: 4px 8px; border: 1px solid #484848; border-radius: 999px; color: #999; font-family: var(--font-serif); font-style: italic; } .hr-link { - display: inline-flex; + width: 42px; + height: 42px; + display: block; align-items: center; - gap: 10px; - color: #f16365; + flex: 0 0 auto; text-decoration: none; - transition: color .16s ease, transform .16s ease; + transition: transform .16s ease, filter .16s ease; } -.hr-link:hover { color: #ff7b7d; transform: translateY(-1px); } -.hr-link img { width: 42px; height: 42px; object-fit: contain; } +.hr-link:hover { transform: translateY(-1px); filter: brightness(1.12); } +.hr-link:focus-visible { outline: 3px solid rgba(241, 99, 101, .28); outline-offset: 3px; border-radius: 5px; } +.hr-link img { width: 100%; height: 100%; object-fit: contain; } .wizard { width: min(820px, calc(100% - 30px)); @@ -578,9 +596,9 @@ footer { @media (max-width: 700px) { .page-shell { width: min(calc(100% - 24px), 1220px); } - .site-header { min-height: 78px; } - .brand { width: min(67vw, 330px); } - .service-state { font-size: 0; } + .site-header { min-height: 78px; gap: 12px; } + .brand { width: min(59vw, 330px); } + .service-state { max-width: 36vw; font-size: .62rem; } .hero { grid-template-columns: 1fr; } .hero-copy { padding: 30px 24px; } .hero-art { min-height: 180px; border-top: 1px solid rgba(255,255,255,.09); border-left: 0; } @@ -588,7 +606,6 @@ footer { .freshness { grid-template-columns: 1fr; } .freshness small { grid-column: auto; } footer { align-items: flex-start; gap: 10px; } - .hr-link span { display: none; } .wizard { width: min(100% - 18px, 820px); max-height: 94vh; } .wizard-header { min-height: 66px; padding-left: 18px; } .wizard-progress { padding: 16px 16px 14px; } @@ -611,7 +628,7 @@ footer { .count-grid { grid-template-columns: 1fr; } .count-card { min-height: 100px; } .start-button { min-height: 78px; padding-left: 16px; } - .footer-meta { align-items: flex-start; flex-direction: column; gap: 5px; } + .footer-credits { gap: 6px; } .wizard-actions { display: grid; grid-template-columns: 1fr 1.5fr; } .button, .button-download { min-width: 0; } } diff --git a/progression_backend/workshop.py b/progression_backend/workshop.py index 3e382cb..b5e690a 100644 --- a/progression_backend/workshop.py +++ b/progression_backend/workshop.py @@ -4,6 +4,7 @@ import re import shutil import subprocess import time +from math import ceil import xml.etree.ElementTree as ET from dataclasses import dataclass from datetime import datetime, timezone @@ -115,7 +116,11 @@ class SteamCmdRunner: def available(self) -> bool: return self.executable_path() is not None - def run_batch(self, workshop_ids: list[str]) -> SteamCmdBatchResult: + def run_batch( + self, + workshop_ids: list[str], + timeout_seconds: float | None = None, + ) -> SteamCmdBatchResult: executable = self.executable_path() if not executable: raise FileNotFoundError( @@ -142,6 +147,9 @@ class SteamCmdRunner: exit_code: int | None = None status = "completed" output = "" + timeout = self.timeout_seconds + if timeout_seconds is not None: + timeout = max(1, min(timeout, ceil(timeout_seconds))) try: completed = subprocess.run( command, @@ -150,7 +158,7 @@ class SteamCmdRunner: text=True, encoding="utf-8", errors="replace", - timeout=self.timeout_seconds, + timeout=timeout, check=False, shell=False, ) diff --git a/tests/test_backend.py b/tests/test_backend.py index 7886606..7859b2b 100644 --- a/tests/test_backend.py +++ b/tests/test_backend.py @@ -1,6 +1,8 @@ from __future__ import annotations +import asyncio import tempfile +import threading import unittest import xml.etree.ElementTree as ET from pathlib import Path @@ -19,7 +21,7 @@ from progression_backend.modlist import ( parse_active_mods, workshop_items, ) -from progression_backend.refresh import RefreshService +from progression_backend.refresh import RefreshCoordinator, RefreshService from progression_backend.steam_api import WorkshopDetails from progression_backend.workshop import SteamCmdBatchResult, parse_about_xml, utc_now @@ -45,11 +47,15 @@ class FakeSteam: class FakeRunner: def __init__(self, content_dir: Path): self.content_dir = content_dir + self.last_timeout_seconds: float | None = None def available(self) -> bool: return True - def run_batch(self, workshop_ids: list[str]) -> SteamCmdBatchResult: + def run_batch( + self, workshop_ids: list[str], timeout_seconds: float | None = None + ) -> SteamCmdBatchResult: + self.last_timeout_seconds = timeout_seconds for workshop_id in workshop_ids: about = self.content_dir / workshop_id / "About" about.mkdir(parents=True) @@ -72,6 +78,32 @@ class FakeRunner: ) +class FailingRunner: + def __init__(self) -> None: + self.calls = 0 + self.last_timeout_seconds: float | None = None + + def available(self) -> bool: + return True + + def run_batch( + self, workshop_ids: list[str], timeout_seconds: float | None = None + ) -> SteamCmdBatchResult: + self.calls += 1 + self.last_timeout_seconds = timeout_seconds + timestamp = utc_now() + return SteamCmdBatchResult( + workshop_ids=workshop_ids, + started_at=timestamp, + finished_at=timestamp, + elapsed_seconds=0.001, + exit_code=1, + status="failed", + failed_ids=set(workshop_ids), + output_tail="Download failed", + ) + + class BackendTests(unittest.TestCase): @patch("progression_backend.app.requests.get") def test_latest_windows_release_includes_prereleases(self, get: Mock) -> None: @@ -182,6 +214,7 @@ class BackendTests(unittest.TestCase): steamcmd_timeout_seconds=60, refresh_interval_seconds=3600, refresh_on_startup=False, + initial_download_timeout_seconds=43200, game_version="1.6", admin_token=None, collections={"Core": "1", "Content": "2", "Cosmetics": "3"}, @@ -189,13 +222,21 @@ class BackendTests(unittest.TestCase): ) database = Database(settings.database_path) database.initialize() + runner = FakeRunner(settings.workshop_content_dir) service = RefreshService( settings, database, steam=FakeSteam(), - runner=FakeRunner(settings.workshop_content_dir), + runner=runner, + ) + progress_events: list[dict] = [] + service.refresh( + "test-run", + "test", + initial_download=True, + overall_timeout_seconds=10, + progress=progress_events.append, ) - service.refresh("test-run", "test") run = database.fetch_one( "SELECT * FROM refresh_runs WHERE id = ?", ("test-run",) @@ -209,6 +250,52 @@ class BackendTests(unittest.TestCase): self.assertEqual(mod["steam_app_id"], "294100") generated = workshop_items([mod]) self.assertEqual(generated[0].workshop_id, "123456") + self.assertIsNotNone(runner.last_timeout_seconds) + self.assertLessEqual(runner.last_timeout_seconds or 0, 10) + self.assertEqual(progress_events[-1]["stage"], "completed") + self.assertEqual(progress_events[-1]["percent"], 100.0) + + def test_initial_download_stops_at_overall_timeout(self) -> None: + with tempfile.TemporaryDirectory() as directory: + root = Path(directory) + settings = Settings( + host="127.0.0.1", + port=8000, + database_path=root / "progression.db", + steamcmd_path="steamcmd", + workshop_content_dir=root / "workshop" / "294100", + steamcmd_batch_size=25, + steamcmd_timeout_seconds=60, + refresh_interval_seconds=3600, + refresh_on_startup=False, + initial_download_timeout_seconds=43200, + game_version="1.6", + admin_token=None, + collections={"Core": "1", "Content": "2", "Cosmetics": "3"}, + static_dir=root, + ) + database = Database(settings.database_path) + database.initialize() + runner = FailingRunner() + service = RefreshService( + settings, database, steam=FakeSteam(), runner=runner # type: ignore[arg-type] + ) + + service.refresh( + "timeout-run", + "startup", + initial_download=True, + overall_timeout_seconds=0.25, # type: ignore[arg-type] + ) + + run = database.fetch_one( + "SELECT * FROM refresh_runs WHERE id = ?", ("timeout-run",) + ) + self.assertIsNotNone(run) + self.assertEqual(run["status"], "failed") + self.assertIn("initial Workshop download reached", run["error"]) + self.assertEqual(runner.calls, 1) + self.assertLessEqual(runner.last_timeout_seconds or 0, 0.25) def test_api_serves_dashboard_and_reports_empty_modlist(self) -> None: with tempfile.TemporaryDirectory() as directory: @@ -224,6 +311,7 @@ class BackendTests(unittest.TestCase): steamcmd_timeout_seconds=60, refresh_interval_seconds=3600, refresh_on_startup=False, + initial_download_timeout_seconds=43200, game_version="1.6", admin_token=None, collections={"Core": "1", "Content": "2", "Cosmetics": "3"}, @@ -233,7 +321,13 @@ class BackendTests(unittest.TestCase): self.assertEqual(client.get("/").status_code, 200) self.assertEqual(client.get("/art/GameTitle.png").status_code, 200) self.assertEqual(client.get("/api/health").json()["status"], "ok") - self.assertIn("rml_updated_at", client.get("/api/status").json()) + dashboard = client.get("/api/status").json() + self.assertIn("rml_updated_at", dashboard) + self.assertIn("initial_download", dashboard["scheduler"]) + self.assertEqual( + dashboard["scheduler"]["initial_download_timeout_seconds"], + 43200, + ) response = client.get("/api/modlists/vanilla") self.assertEqual(response.status_code, 409) @@ -252,5 +346,58 @@ class BackendTests(unittest.TestCase): self.assertEqual(response.headers["location"], release_url) +class SlowInitialService: + def __init__(self) -> None: + self.started = threading.Event() + self.release = threading.Event() + self.needs_download = True + self.received_timeout: int | None = None + + def needs_initial_download(self) -> bool: + return self.needs_download + + def refresh(self, run_id: str, trigger: str, **options: object) -> None: + self.received_timeout = options.get("overall_timeout_seconds") # type: ignore[assignment] + progress = options.get("progress") + if callable(progress): + progress( + { + "stage": "downloading", + "completed_mods": 1, + "total_mods": 4, + "percent": 25.0, + } + ) + self.started.set() + self.release.wait(timeout=2) + self.needs_download = False + + +class CoordinatorTests(unittest.IsolatedAsyncioTestCase): + async def test_initial_download_pauses_hourly_scheduler(self) -> None: + service = SlowInitialService() + coordinator = RefreshCoordinator( + service, 3600, True, initial_download_timeout_seconds=43200 # type: ignore[arg-type] + ) + await coordinator.start() + started = await asyncio.to_thread(service.started.wait, 1) + self.assertTrue(started) + + active = coordinator.state() + self.assertTrue(active["initial_download"]) + self.assertIsNone(active["next_refresh_at"]) + self.assertEqual(active["progress"]["percent"], 25.0) + self.assertEqual(service.received_timeout, 43200) + + service.release.set() + if coordinator._refresh_task: + await asyncio.wait_for(coordinator._refresh_task, timeout=1) + await asyncio.sleep(0.01) + completed = coordinator.state() + self.assertFalse(completed["initial_download"]) + self.assertIsNotNone(completed["next_refresh_at"]) + await coordinator.stop() + + if __name__ == "__main__": unittest.main()