Log scheduled refresh lifecycle to stdout

This commit is contained in:
Dymas
2026-05-17 21:06:48 +02:00
parent 6168acb272
commit a8d7d3de00
6 changed files with 60 additions and 6 deletions
+4
View File
@@ -1,5 +1,9 @@
# Changelog # Changelog
## 0.31.1 - 2026-05-17
- Added stdout lifecycle logging for scheduled watchlist refresh jobs so container logs now show when a scheduled run is queued, starts, finishes successfully, finishes with errors, gets interrupted, or fails.
## 0.31.0 - 2026-05-17 ## 0.31.0 - 2026-05-17
- Added scheduled background watchlist refresh support so the app can periodically recheck episode counts for tracked anime. - Added scheduled background watchlist refresh support so the app can periodically recheck episode counts for tracked anime.
+2 -1
View File
@@ -2,7 +2,7 @@
A local web UI for a system-wide `ani-cli` install. A local web UI for a system-wide `ani-cli` install.
Current version: `0.31.0` Current version: `0.31.1`
## Project Layout ## Project Layout
@@ -158,6 +158,7 @@ The app currently includes:
- The watchlist page now also avoids re-triggering the same unresolved thumbnail warm-up request on every silent poll cycle while a show's thumbnail state is unchanged. - The watchlist page now also avoids re-triggering the same unresolved thumbnail warm-up request on every silent poll cycle while a show's thumbnail state is unchanged.
- Background `Refresh All` execution with status polling, parallel per-show refresh work, and no inline thumbnail downloads during the bulk job. - Background `Refresh All` execution with status polling, parallel per-show refresh work, and no inline thumbnail downloads during the bulk job.
- Optional scheduled background watchlist refreshes with Config page controls for enable/disable and refresh period. - Optional scheduled background watchlist refreshes with Config page controls for enable/disable and refresh period.
- Scheduled background refresh runs now log queue, start, and completion status to stdout so container logs show whether they finished successfully, with errors, or failed.
- Search and Watchlist polling now use a shared serial browser polling helper so slow responses do not cause overlapping poll requests to pile up in the background. - Search and Watchlist polling now use a shared serial browser polling helper so slow responses do not cause overlapping poll requests to pile up in the background.
- That shared browser polling helper now also tears itself down on page unload and uses chained `setTimeout` scheduling instead of a bare repeating interval. - That shared browser polling helper now also tears itself down on page unload and uses chained `setTimeout` scheduling instead of a bare repeating interval.
- Controlled shutdown and runtime reset now cancel active download workers when waiting for teardown, reducing the chance of orphaned background downloads outliving the web process. - Controlled shutdown and runtime reset now cancel active download workers when waiting for teardown, reducing the chance of orphaned background downloads outliving the web process.
+1 -1
View File
@@ -1 +1 @@
0.31.0 0.31.1
+1 -1
View File
@@ -16,7 +16,7 @@ from uuid import uuid4
PROJECT_ROOT = Path(__file__).resolve().parent PROJECT_ROOT = Path(__file__).resolve().parent
ANI_CLI = os.environ.get("ANI_CLI_BIN") or shutil.which("ani-cli") or "ani-cli" ANI_CLI = os.environ.get("ANI_CLI_BIN") or shutil.which("ani-cli") or "ani-cli"
APP_NAME = "ani-cli-web" APP_NAME = "ani-cli-web"
VERSION = "0.31.0" VERSION = "0.31.1"
ALLANIME_BASE = "allanime.day" ALLANIME_BASE = "allanime.day"
ALLANIME_API = f"https://api.{ALLANIME_BASE}" ALLANIME_API = f"https://api.{ALLANIME_BASE}"
ALLANIME_REFERER = "https://allmanga.to" ALLANIME_REFERER = "https://allmanga.to"
+31 -2
View File
@@ -178,6 +178,9 @@ class WatchlistRefreshJobs:
def _copy_job(self, job): def _copy_job(self, job):
return json.loads(json.dumps(job)) return json.loads(json.dumps(job))
def _stdout_log(self, message):
print(f"[watchlist-refresh] {message}", flush=True)
def _find_locked(self, job_id): def _find_locked(self, job_id):
for job in self.jobs: for job in self.jobs:
if job["id"] == job_id: if job["id"] == job_id:
@@ -192,10 +195,15 @@ class WatchlistRefreshJobs:
active = bool(job and job["status"] in {"pending", "running"}) active = bool(job and job["status"] in {"pending", "running"})
return {"job": self._copy_job(job) if job else None, "running": active} return {"job": self._copy_job(job) if job else None, "running": active}
def start(self): def start(self, source="manual"):
source_name = str(source or "manual").strip().lower() or "manual"
with self.lock: with self.lock:
job = next((candidate for candidate in self.jobs if candidate["status"] in {"pending", "running"}), None) job = next((candidate for candidate in self.jobs if candidate["status"] in {"pending", "running"}), None)
if job is not None: if job is not None:
if source_name == "scheduled":
self._stdout_log(
f"Scheduled refresh skipped because another refresh is already {job['status']} (job={job['id']})."
)
return { return {
"message": "Watchlist refresh already queued." if job["status"] == "pending" else "Watchlist refresh already running.", "message": "Watchlist refresh already queued." if job["status"] == "pending" else "Watchlist refresh already running.",
"job": self._copy_job(job) if job else None, "job": self._copy_job(job) if job else None,
@@ -205,6 +213,7 @@ class WatchlistRefreshJobs:
job = { job = {
"id": os.urandom(16).hex(), "id": os.urandom(16).hex(),
"status": "pending", "status": "pending",
"source": source_name,
"created_at": now, "created_at": now,
"updated_at": now, "updated_at": now,
"started_at": None, "started_at": None,
@@ -220,6 +229,8 @@ class WatchlistRefreshJobs:
self._save_job_locked(job) self._save_job_locked(job)
self.pending.append(job["id"]) self.pending.append(job["id"])
self.wakeup.set() self.wakeup.set()
if source_name == "scheduled":
self._stdout_log(f"Scheduled refresh queued (job={job['id']}).")
return {"message": "Watchlist refresh started.", "job": self._copy_job(job), "created": True} return {"message": "Watchlist refresh started.", "job": self._copy_job(job), "created": True}
def _next_pending(self): def _next_pending(self):
@@ -243,6 +254,7 @@ class WatchlistRefreshJobs:
def _run_job(self, job): def _run_job(self, job):
interrupted = False interrupted = False
source_name = str(job.get("source") or "manual").strip().lower() or "manual"
try: try:
show_ids = self.store.all_show_ids() show_ids = self.store.all_show_ids()
started_at = now_iso() started_at = now_iso()
@@ -256,6 +268,8 @@ class WatchlistRefreshJobs:
job["current_title"] = None job["current_title"] = None
job["message"] = f"Refreshing 0/{len(show_ids)} watchlist entries." job["message"] = f"Refreshing 0/{len(show_ids)} watchlist entries."
self._save_job_locked(job) self._save_job_locked(job)
if source_name == "scheduled":
self._stdout_log(f"Scheduled refresh started (job={job['id']}, total={len(show_ids)}).")
def refresh_one(show_id): def refresh_one(show_id):
title = show_id title = show_id
@@ -320,6 +334,19 @@ class WatchlistRefreshJobs:
else: else:
job["message"] = f"Refreshed {job['completed']} watchlist entries." job["message"] = f"Refreshed {job['completed']} watchlist entries."
self._save_job_locked(job) self._save_job_locked(job)
if source_name == "scheduled":
if interrupted:
self._stdout_log(
f"Scheduled refresh interrupted (job={job['id']}, completed={job['completed']}/{job['total']})."
)
elif job["errors"]:
self._stdout_log(
f"Scheduled refresh finished with errors (job={job['id']}, completed={job['completed']}/{job['total']}, errors={job['errors']})."
)
else:
self._stdout_log(
f"Scheduled refresh finished successfully (job={job['id']}, completed={job['completed']}/{job['total']})."
)
except Exception as exc: except Exception as exc:
finished_at = now_iso() finished_at = now_iso()
with self.lock: with self.lock:
@@ -329,6 +356,8 @@ class WatchlistRefreshJobs:
job["current_title"] = None job["current_title"] = None
job["message"] = f"Watchlist refresh failed: {exc}" job["message"] = f"Watchlist refresh failed: {exc}"
self._save_job_locked(job) self._save_job_locked(job)
if source_name == "scheduled":
self._stdout_log(f"Scheduled refresh failed (job={job['id']}): {exc}")
finally: finally:
with self.lock: with self.lock:
self.current_executor = None self.current_executor = None
@@ -397,7 +426,7 @@ class WatchlistAutoRefreshScheduler:
return remaining return remaining
self.last_attempt_monotonic = now self.last_attempt_monotonic = now
try: try:
result = self.refresh_start_fn() result = self.refresh_start_fn(source="scheduled")
debug_log("watchlist.auto_refresh.tick", result=result) debug_log("watchlist.auto_refresh.tick", result=result)
except Exception as exc: except Exception as exc:
debug_log("watchlist.auto_refresh.error", error=exc) debug_log("watchlist.auto_refresh.error", error=exc)
+21 -1
View File
@@ -461,6 +461,26 @@ class WatchlistRefreshJobTests(unittest.TestCase):
self.assertEqual(second["job"]["id"], first["job"]["id"]) self.assertEqual(second["job"]["id"], first["job"]["id"])
self.assertEqual(second["job"]["status"], "pending") self.assertEqual(second["job"]["status"], "pending")
def test_scheduled_refresh_logs_queue_and_completion(self):
class FakeStore:
def all_show_ids(self):
return ["show-a"]
def refresh(self, _show_id, include_thumbnail=True):
return {"title": "Show A", "status": "updated"}
service = APP.WatchlistRefreshJobs(FakeStore(), start_worker=False)
with mock.patch("builtins.print") as print_mock:
started = service.start(source="scheduled")
job = service._next_pending()
service._run_job(job)
self.assertTrue(started["created"])
logged = "\n".join(call.args[0] for call in print_mock.call_args_list if call.args)
self.assertIn("Scheduled refresh queued", logged)
self.assertIn("Scheduled refresh started", logged)
self.assertIn("Scheduled refresh finished successfully", logged)
def test_refresh_history_marks_pending_jobs_interrupted_after_restart(self): def test_refresh_history_marks_pending_jobs_interrupted_after_restart(self):
class FakeStore: class FakeStore:
def all_show_ids(self): def all_show_ids(self):
@@ -1090,7 +1110,7 @@ class WatchlistAutoRefreshSchedulerTests(unittest.TestCase):
self.assertEqual(scheduler.tick(now_monotonic=100.0), 600) self.assertEqual(scheduler.tick(now_monotonic=100.0), 600)
self.assertEqual(scheduler.tick(now_monotonic=699.0), 1) self.assertEqual(scheduler.tick(now_monotonic=699.0), 1)
self.assertEqual(scheduler.tick(now_monotonic=700.0), 600) self.assertEqual(scheduler.tick(now_monotonic=700.0), 600)
start.assert_called_once() start.assert_called_once_with(source="scheduled")
def test_tick_resets_timer_when_schedule_changes(self): def test_tick_resets_timer_when_schedule_changes(self):
config = { config = {