From bda1fe44453975b8567b9ddb1fe6566ac0e855b1 Mon Sep 17 00:00:00 2001
From: Lukas <lukas.pupkalipinski@lpl-mind.de>
Date: Mon, 25 May 2026 13:48:34 +0200
Subject: [PATCH] Fix scheduler next_run_time None check; add debug logging

- Fix race condition: next_run_time only available after scheduler.start()
- Handle None gracefully in logging
- Add debug logging to _perform_rescan and _run_rescan_job
- Document scheduler troubleshooting in DEVELOPMENT.md
---
 docs/DEVELOPMENT.md                      | 44 ++++++++++++++++++++++++
 src/server/services/scheduler_service.py |  8 +++--
 2 files changed, 50 insertions(+), 2 deletions(-)

diff --git a/docs/DEVELOPMENT.md b/docs/DEVELOPMENT.md
index 8ac3920..10a8447 100644
--- a/docs/DEVELOPMENT.md
+++ b/docs/DEVELOPMENT.md
@@ -231,6 +231,50 @@ DNS checks are warnings because failures can be transient. anime_directory error
 5. Monitor next run: `GET /health` → `scheduler_next_run`
 6. If problem repeats, increase `misfire_grace_time` in `scheduler_service.py`.
 
+#### Scheduler not firing (no events at scheduled time)
+
+If the scheduler appears configured but never triggers:
+
+1. **Verify scheduler.db contains the job:**
+   ```bash
+   sqlite3 data/scheduler.db "SELECT id, next_run_time FROM apscheduler_jobs;"
+   ```
+   - `next_run_time` should be in the future
+   - If it's in the past, the server was down when the job should have fired
+
+2. **Check application logs for scheduler startup:**
+   ```
+   grep "Scheduler service started" fastapi_app.log
+   ```
+   - If missing, the scheduler failed to start — check for errors above this line
+   - If present, scheduler started successfully
+
+3. **Verify APScheduler events in logs:**
+   ```
+   grep "apscheduler.executors.default" fastapi_app.log
+   ```
+   - `Running job` = job triggered
+   - `executed successfully` = job completed
+   - No output = job never fired
+
+4. **Test manual trigger:**
+   ```bash
+   curl -X POST http://localhost:8000/api/scheduler/trigger-rescan -H "Authorization: Bearer <token>"
+   ```
+   - If manual trigger works but cron doesn't, the issue is APScheduler configuration
+
+5. **Check next_run_time via health endpoint:**
+   ```bash
+   curl http://localhost:8000/health | jq .scheduler_next_run
+   ```
+   - If `null`, the job is not scheduled
+   - If set, the scheduler knows when to run next
+
+6. **Check timezone handling:**
+   - APScheduler uses UTC internally
+   - The schedule_time config (e.g., "03:00") is interpreted as UTC
+   - If you expect local time, adjust the schedule_time accordingly
+
 #### Startup health check failures
 
 If `/health` returns `unhealthy` status:
diff --git a/src/server/services/scheduler_service.py b/src/server/services/scheduler_service.py
index 366b1b3..4de197b 100644
--- a/src/server/services/scheduler_service.py
+++ b/src/server/services/scheduler_service.py
@@ -116,11 +116,13 @@ class SchedulerService:
         # Startup recovery: if the server was down at the scheduled time and
         # the job is within the misfire window, APScheduler will run it
         # automatically.  Log the scheduled time for visibility.
+        # Note: next_run_time is only available AFTER scheduler.start()
         job = self._scheduler.get_job(_JOB_ID)
-        if job and job.next_run_time:
+        if job:
+            next_run = job.next_run_time
             logger.info(
                 "Scheduler next run",
-                next_run=job.next_run_time.isoformat(),
+                next_run=next_run.isoformat() if next_run else None,
             )
 
     async def stop(self) -> None:
@@ -349,6 +351,7 @@ class SchedulerService:
 
     async def _perform_rescan(self) -> None:
         """Execute a library rescan and optionally trigger auto-download."""
+        logger.info("Scheduler _perform_rescan entered", scan_in_progress=self._scan_in_progress)
         if self._scan_in_progress:
             logger.warning("Skipping rescan: previous scan still in progress")
             return
@@ -443,6 +446,7 @@ class SchedulerService:
 
 async def _run_rescan_job() -> None:
     """Module-level job entry point — delegates to the current service."""
+    logger.info("APScheduler triggered _run_rescan_job")
     svc = get_scheduler_service()
     await svc._perform_rescan()