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
This commit is contained in:
@@ -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`
|
5. Monitor next run: `GET /health` → `scheduler_next_run`
|
||||||
6. If problem repeats, increase `misfire_grace_time` in `scheduler_service.py`.
|
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
|
#### Startup health check failures
|
||||||
|
|
||||||
If `/health` returns `unhealthy` status:
|
If `/health` returns `unhealthy` status:
|
||||||
|
|||||||
@@ -116,11 +116,13 @@ class SchedulerService:
|
|||||||
# Startup recovery: if the server was down at the scheduled time and
|
# Startup recovery: if the server was down at the scheduled time and
|
||||||
# the job is within the misfire window, APScheduler will run it
|
# the job is within the misfire window, APScheduler will run it
|
||||||
# automatically. Log the scheduled time for visibility.
|
# automatically. Log the scheduled time for visibility.
|
||||||
|
# Note: next_run_time is only available AFTER scheduler.start()
|
||||||
job = self._scheduler.get_job(_JOB_ID)
|
job = self._scheduler.get_job(_JOB_ID)
|
||||||
if job and job.next_run_time:
|
if job:
|
||||||
|
next_run = job.next_run_time
|
||||||
logger.info(
|
logger.info(
|
||||||
"Scheduler next run",
|
"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:
|
async def stop(self) -> None:
|
||||||
@@ -349,6 +351,7 @@ class SchedulerService:
|
|||||||
|
|
||||||
async def _perform_rescan(self) -> None:
|
async def _perform_rescan(self) -> None:
|
||||||
"""Execute a library rescan and optionally trigger auto-download."""
|
"""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:
|
if self._scan_in_progress:
|
||||||
logger.warning("Skipping rescan: previous scan still in progress")
|
logger.warning("Skipping rescan: previous scan still in progress")
|
||||||
return
|
return
|
||||||
@@ -443,6 +446,7 @@ class SchedulerService:
|
|||||||
|
|
||||||
async def _run_rescan_job() -> None:
|
async def _run_rescan_job() -> None:
|
||||||
"""Module-level job entry point — delegates to the current service."""
|
"""Module-level job entry point — delegates to the current service."""
|
||||||
|
logger.info("APScheduler triggered _run_rescan_job")
|
||||||
svc = get_scheduler_service()
|
svc = get_scheduler_service()
|
||||||
await svc._perform_rescan()
|
await svc._perform_rescan()
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user