Each firing stored last_run_at = the moment the ~60 s loop noticed it, and the next was due a whole interval after that, so every firing's lateness carried into the next: Nightly Docker Prune moved from 05:44:45 to 05:47:05 over six days. A firing now stores its due slot, the latest last_run_at + k * interval not after now (due_slot), for both a launch and a skipped firing. Missed slots after an outage are skipped, not run in a burst. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
101 lines
3.9 KiB
Python
101 lines
3.9 KiB
Python
# steward/ansible/scheduler.py
|
|
"""Fire due Ansible schedules. Driven by the core ScheduledTask loop (~60s)."""
|
|
from __future__ import annotations
|
|
|
|
import logging
|
|
from datetime import datetime, timedelta, timezone
|
|
|
|
from sqlalchemy import select
|
|
|
|
from steward.ansible.runner import run_in_flight, trigger_run
|
|
from steward.models.ansible_schedule import AnsibleSchedule
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
|
|
def is_due(schedule: AnsibleSchedule, now: datetime) -> bool:
|
|
"""True when an enabled schedule has never run or its interval has elapsed.
|
|
|
|
Cadence is measured from the previous *fire* time (last_run_at), not run
|
|
completion, so a long-running playbook doesn't cause catch-up storms.
|
|
"""
|
|
if not schedule.enabled:
|
|
return False
|
|
if schedule.last_run_at is None:
|
|
return True
|
|
return (now - schedule.last_run_at).total_seconds() >= schedule.interval_seconds
|
|
|
|
|
|
def due_slot(schedule: AnsibleSchedule, now: datetime) -> datetime:
|
|
"""The due time a firing at `now` belongs to, kept as last_run_at.
|
|
|
|
The latest last_run_at + k * interval not after now, so the next one is
|
|
due a whole interval after this slot rather than after whenever the ~60 s
|
|
loop happened to notice it. Counting from `now` added each firing's
|
|
lateness to the next, and a daily schedule crept later every day (#5432).
|
|
Missed slots (Steward was down) are skipped, not run in a burst.
|
|
"""
|
|
if schedule.last_run_at is None or not schedule.interval_seconds:
|
|
return now
|
|
whole = (now - schedule.last_run_at).total_seconds() // schedule.interval_seconds
|
|
return schedule.last_run_at + timedelta(seconds=whole * schedule.interval_seconds)
|
|
|
|
|
|
async def run_due_schedules(app) -> int:
|
|
"""Trigger every due schedule once. Returns the number launched. A due
|
|
schedule whose previous run hasn't finished skips this firing."""
|
|
now = datetime.now(timezone.utc)
|
|
async with app.db_sessionmaker() as db:
|
|
schedules = (await db.execute(
|
|
select(AnsibleSchedule).where(AnsibleSchedule.enabled.is_(True))
|
|
)).scalars().all()
|
|
|
|
fired = 0
|
|
for s in schedules:
|
|
if not is_due(s, now):
|
|
continue
|
|
slot = due_slot(s, now)
|
|
async with app.db_sessionmaker() as db:
|
|
busy = await run_in_flight(db, s.last_run_id)
|
|
if busy:
|
|
# One run at a time per schedule (#5158). This firing is skipped,
|
|
# not deferred, so the cadence holds; last_run_id still names the
|
|
# run that's going.
|
|
async with app.db_sessionmaker() as db:
|
|
async with db.begin():
|
|
fresh = await db.get(AnsibleSchedule, s.id)
|
|
if fresh:
|
|
fresh.last_run_at = slot
|
|
fresh.last_error = "Skipped: the previous run was still going"
|
|
logger.info("Schedule %s (%s) skipped: run %s still going",
|
|
s.id, s.name, s.last_run_id)
|
|
continue
|
|
run = None
|
|
err: str | None = None
|
|
try:
|
|
run, _source, err = await trigger_run(
|
|
app,
|
|
source_name=s.source_name,
|
|
playbook_path=s.playbook_path,
|
|
inventory_scope=s.inventory_scope,
|
|
params=s.params,
|
|
triggered_by=None,
|
|
origin="schedule",
|
|
origin_id=s.id,
|
|
)
|
|
except Exception:
|
|
logger.exception("Schedule %s (%s) failed to launch", s.id, s.name)
|
|
err = "launch error"
|
|
|
|
async with app.db_sessionmaker() as db:
|
|
async with db.begin():
|
|
fresh = await db.get(AnsibleSchedule, s.id)
|
|
if fresh:
|
|
fresh.last_run_at = slot
|
|
fresh.last_run_id = run.id if run else None
|
|
fresh.last_error = err
|
|
if run:
|
|
fired += 1
|
|
logger.info("Schedule %s (%s) fired run %s", s.id, s.name, run.id)
|
|
return fired
|