feat: Scheduler, Laufprotokoll, Aufräumen und Gesundheitsprüfung

APScheduler-Jobs je Regel mit Startversatz und Jitter, Protokoll in
runs/run_items mit Regelzählern, Aufräumen nach Aufbewahrungsfrist,
Health-Auswertung für /healthz und Verdrahtung des Dienststarts.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

src/netmover/app_state.py

@@ -0,0 +1,83 @@
+"""Verdrahtung aller Bausteine – einmal pro Prozess.
+
+Start: Datenbank migrieren → Schlüssel laden → Anbindungen mit ``auto_mount``
+wiederherstellen (Ergebnis protokollieren) → erst dann Scheduler starten.
+Ende: Scheduler stoppen, Mounts **nicht** aushängen (andere könnten sie nutzen).
+"""
+
+from __future__ import annotations
+
+from datetime import datetime
+
+from netmover.config import Settings
+from netmover.crypto import SecretBox, load_or_create_key
+from netmover.db import make_engine, make_session_factory, upgrade
+from netmover.health import Health, check_health
+from netmover.logging_setup import event, get_logger
+from netmover.models import utcnow
+from netmover.mounting.backend import MountBackend
+from netmover.mounting.fake import FakeMountBackend
+from netmover.mounting.linux import LinuxMountBackend
+from netmover.mounting.manager import MountManager, RestoreResult
+from netmover.mover.runner import RuleRunner
+from netmover.notify import Notifier
+from netmover.runs import RunService
+from netmover.scheduler import RuleScheduler
+
+log = get_logger(__name__)
+
+
+def make_backend(settings: Settings) -> MountBackend:
+    if settings.mount_backend == "fake":
+        return FakeMountBackend(settings.data_dir / "fake")
+    return LinuxMountBackend(settings.run_dir)
+
+
+class NetMover:
+    def __init__(
+        self,
+        settings: Settings,
+        backend: MountBackend | None = None,
+        notifier: Notifier | None = None,
+    ) -> None:
+        self.settings = settings
+        settings.data_dir.mkdir(parents=True, exist_ok=True)
+        url = settings.effective_database_url
+        upgrade(url)
+        self.db_engine = make_engine(url)
+        self.session_factory = make_session_factory(self.db_engine)
+        self.secrets = SecretBox(load_or_create_key(settings.secret_key_path))
+        self.backend = backend or make_backend(settings)
+        self.notifier = notifier or Notifier(self.session_factory)
+        self.mounts = MountManager(
+            self.session_factory,
+            self.backend,
+            self.secrets,
+            settings.mount_base,
+            notifier=self.notifier.mount_event,
+        )
+        self.runner = RuleRunner(self.session_factory, self.mounts)
+        self.runs = RunService(self.session_factory, self.runner, self.notifier)
+        self.scheduler = RuleScheduler(self.session_factory, self.runs)
+        self.started_at: datetime = utcnow()
+        self.restore_results: list[RestoreResult] = []
+
+    def start(self) -> None:
+        """Muss im laufenden Event-Loop aufgerufen werden (AsyncIOScheduler)."""
+        self.started_at = utcnow()
+        self.restore_results = self.mounts.restore_all()
+        ok = sum(r.ok for r in self.restore_results)
+        event(log, "startup.mounts_restored", ok=ok, failed=len(self.restore_results) - ok)
+        self.scheduler.start()
+
+    def stop(self) -> None:
+        self.scheduler.shutdown()
+        self.db_engine.dispose()
+
+    def health(self) -> Health:
+        return check_health(
+            self.session_factory,
+            scheduler_running=self.scheduler.running,
+            last_heartbeat=self.scheduler.last_heartbeat,
+            service_started=self.started_at,
+        )

src/netmover/health.py

@@ -0,0 +1,75 @@
+"""Gesundheitszustand für ``/healthz`` und die Statusseite (Fallstrick 9).
+
+Ein Werkzeug, das nichts mehr tut, darf nicht wie eines aussehen, das nichts zu
+tun hat. Deshalb:
+
+* der Scheduler muss leben (Herzschlag nicht älter als 3 Minuten),
+* keine aktive Anbindung im Fehlerzustand,
+* keine aktive Regel, deren letzter erfolgreicher Lauf länger als das Dreifache
+  ihres Intervalls zurückliegt. Bezugspunkt ist der späteste von letztem Erfolg,
+  Anlage der Regel und Dienststart – sonst wäre direkt nach einem Neustart alles rot.
+"""
+
+from __future__ import annotations
+
+from dataclasses import dataclass, field
+from datetime import datetime, timedelta
+
+from sqlalchemy import select
+from sqlalchemy.orm import Session, sessionmaker
+
+from netmover.db import session_scope
+from netmover.models import Mount, MountState, Rule, utcnow
+
+STALE_FACTOR = 3
+HEARTBEAT_MAX_AGE = timedelta(minutes=3)
+
+
+@dataclass
+class Health:
+    ok: bool = True
+    problems: list[str] = field(default_factory=list)
+    stale_rules: set[int] = field(default_factory=set)
+
+    def fail(self, problem: str) -> None:
+        self.ok = False
+        self.problems.append(problem)
+
+
+def rule_is_stale(rule: Rule, service_started: datetime, now: datetime) -> bool:
+    if not rule.enabled:
+        return False
+    reference = max(
+        d for d in (rule.last_success_at, rule.created_at, service_started) if d is not None
+    )
+    return now - reference > timedelta(seconds=STALE_FACTOR * rule.interval_seconds)
+
+
+def check_health(
+    session_factory: sessionmaker[Session],
+    *,
+    scheduler_running: bool,
+    last_heartbeat: datetime | None,
+    service_started: datetime,
+    now: datetime | None = None,
+) -> Health:
+    now = now or utcnow()
+    health = Health()
+    if not scheduler_running:
+        health.fail("Scheduler läuft nicht")
+    elif last_heartbeat is None or now - last_heartbeat > HEARTBEAT_MAX_AGE:
+        health.fail("Scheduler reagiert nicht (kein Herzschlag)")
+    with session_scope(session_factory) as s:
+        for m in s.scalars(select(Mount).where(Mount.enabled.is_(True))):
+            if m.state is MountState.ERROR:
+                health.fail(f"Anbindung „{m.name}“ im Fehlerzustand: {m.last_error or ''}".strip())
+        for r in s.scalars(select(Rule).where(Rule.enabled.is_(True))):
+            if rule_is_stale(r, service_started, now):
+                health.stale_rules.add(r.id)
+                ago = (
+                    "noch nie"
+                    if r.last_success_at is None
+                    else f"seit {r.last_success_at:%Y-%m-%d %H:%M} UTC"
+                )
+                health.fail(f"Regel „{r.name}“: kein erfolgreicher Lauf {ago}")
+    return health

src/netmover/runs.py

@@ -0,0 +1,171 @@
+"""Läufe ausführen und protokollieren.
+
+Pro Lauf eine Zeile in ``runs`` (auch für übersprungene Termine, Fallstrick 8),
+die Einzeldateien in ``run_items``. Danach die Regelzähler:
+
+* ``last_run_at`` – jeder Lauf außer übersprungenen,
+* ``last_success_at`` – Status ``ok`` oder ``partial`` (das Werkzeug hat gearbeitet),
+* ``consecutive_failures`` – ``error`` und ``partial`` zählen hoch, ``ok`` setzt zurück.
+
+Ein manuell gestarteter Probelauf verändert keine Zähler.
+"""
+
+from __future__ import annotations
+
+from datetime import datetime, timedelta
+
+from sqlalchemy import delete, select
+from sqlalchemy.orm import Session, sessionmaker
+
+from netmover.db import session_scope
+from netmover.logging_setup import event, get_logger
+from netmover.models import FileFailure, Rule, Run, RunItem, RunStatus, RunTrigger, utcnow
+from netmover.mover.engine import RunResult
+from netmover.mover.runner import RuleRunner
+from netmover.notify import Notifier
+from netmover.settings_store import load_settings
+
+log = get_logger(__name__)
+
+MAX_ITEMS_PER_RUN = 2000
+SUCCESS = frozenset({RunStatus.OK, RunStatus.PARTIAL})
+FAILURE = frozenset({RunStatus.ERROR, RunStatus.PARTIAL})
+
+
+class RunService:
+    def __init__(
+        self,
+        session_factory: sessionmaker[Session],
+        runner: RuleRunner,
+        notifier: Notifier | None = None,
+    ) -> None:
+        self.session_factory = session_factory
+        self.runner = runner
+        self.notifier = notifier
+
+    def execute(
+        self,
+        rule_id: int,
+        trigger: RunTrigger = RunTrigger.SCHEDULE,
+        dry_run: bool | None = None,
+    ) -> int | None:
+        """Führt die Regel aus, protokolliert den Lauf und liefert die Run-ID
+        (None, wenn die Regel inzwischen gelöscht wurde)."""
+        started = utcnow()
+        result = self.runner.run(rule_id, dry_run=dry_run)
+        finished = utcnow()
+        count_it = not (trigger is RunTrigger.MANUAL and dry_run)
+        return self.record(rule_id, trigger, result, started, finished, update_counters=count_it)
+
+    def record(
+        self,
+        rule_id: int,
+        trigger: RunTrigger,
+        result: RunResult,
+        started: datetime,
+        finished: datetime,
+        *,
+        update_counters: bool = True,
+    ) -> int | None:
+        notify: tuple[str, bool, int, str] | None = None
+        with session_scope(self.session_factory) as s:
+            rule = s.get(Rule, rule_id)
+            if rule is None:
+                return None
+            message = result.message
+            items = result.items
+            if len(items) > MAX_ITEMS_PER_RUN:
+                extra = len(items) - MAX_ITEMS_PER_RUN
+                items = items[:MAX_ITEMS_PER_RUN]
+                note = f"{extra} weitere Dateien nicht einzeln protokolliert"
+                message = f"{message}; {note}" if message else note
+            run = Run(
+                rule_id=rule_id,
+                started_at=started,
+                finished_at=finished,
+                status=result.status,
+                trigger=trigger,
+                dry_run=result.dry_run,
+                seen=result.seen,
+                moved=result.moved,
+                skipped=result.skipped,
+                failed=result.failed,
+                message=message,
+            )
+            s.add(run)
+            s.flush()
+            s.add_all(
+                RunItem(
+                    run_id=run.id,
+                    src=i.src,
+                    dst=i.dst,
+                    status=i.status,
+                    size=i.size,
+                    message=i.message,
+                )
+                for i in items
+            )
+            if update_counters and result.status is not RunStatus.SKIPPED:
+                previous = rule.consecutive_failures
+                rule.last_run_at = finished
+                if result.status in SUCCESS:
+                    rule.last_success_at = finished
+                if result.status in FAILURE:
+                    rule.consecutive_failures += 1
+                    notify = (rule.name, True, rule.consecutive_failures, self._summary(result))
+                else:
+                    rule.consecutive_failures = 0
+                    if previous:
+                        notify = (rule.name, False, previous, "")
+            run_id = run.id
+            rule_name = rule.name
+
+        level = 20 if result.status in (RunStatus.OK, RunStatus.SKIPPED) else 30
+        if result.status is RunStatus.OK and not result.items:
+            level = 10  # leere Läufe alle 30 s nur auf DEBUG
+        event(
+            log,
+            "run.finished",
+            level=level,
+            rule=rule_name,
+            run=run_id,
+            status=result.status.value,
+            trigger=trigger.value,
+            dry_run=result.dry_run,
+            seen=result.seen,
+            moved=result.moved,
+            skipped=result.skipped,
+            failed=result.failed,
+            took_ms=int((finished - started).total_seconds() * 1000),
+            message=result.message or "",
+        )
+        if notify is not None and self.notifier is not None:
+            self.notifier.rule_result(*notify)
+        return run_id
+
+    @staticmethod
+    def _summary(result: RunResult) -> str:
+        if result.status is RunStatus.ERROR:
+            return result.message or "Lauf fehlgeschlagen"
+        failed = [i for i in result.items if i.status.value == "failed"][:5]
+        lines = [f"{result.failed} Datei(en) fehlgeschlagen:"]
+        lines += [f"• {i.src}: {i.message}" for i in failed]
+        return "\n".join(lines)
+
+
+def cleanup(session_factory: sessionmaker[Session], now: datetime | None = None) -> dict[str, int]:
+    """Protokolle älter als die Aufbewahrungsfrist löschen (Items per CASCADE),
+    dazu Fehlerzähler, die seitdem nicht mehr angefasst wurden."""
+    days = load_settings(session_factory).retention_days
+    cutoff = (now or utcnow()) - timedelta(days=days)
+    with session_scope(session_factory) as s:
+        old_ids = list(s.scalars(select(Run.id).where(Run.started_at < cutoff)))
+        for i in range(0, len(old_ids), 500):
+            chunk = old_ids[i : i + 500]
+            s.execute(delete(RunItem).where(RunItem.run_id.in_(chunk)))
+            s.execute(delete(Run).where(Run.id.in_(chunk)))
+        failures = s.execute(delete(FileFailure).where(FileFailure.last_attempt_at < cutoff))
+        removed_failures = getattr(failures, "rowcount", 0) or 0
+    stats = {"runs": len(old_ids), "file_failures": removed_failures}
+    event(log, "cleanup.done", retention_days=days, **stats)
+    return stats

src/netmover/scheduler.py

@@ -0,0 +1,146 @@
+"""Zeitsteuerung mit APScheduler (``AsyncIOScheduler``).
+
+* Ein Job pro aktiver Regel im jeweiligen Intervall. Erster Start mit kleinem
+  zufälligem Versatz, dazu Jitter pro Termin – damit nicht alle Regeln
+  gleichzeitig starten (Fallstrick 8).
+* Die Läufe selbst sind blockierend und laufen in einem eigenen Thread-Pool,
+  nie im Event-Loop. Überlappung regelt der Lock im :class:`RuleRunner`, der den
+  übersprungenen Termin auch protokolliert – deshalb ``max_instances`` > 1.
+* Herzschlag-Job für ``/healthz`` und stündliches Aufräumen der Protokolle.
+"""
+
+from __future__ import annotations
+
+import asyncio
+import random
+from concurrent.futures import ThreadPoolExecutor
+from datetime import UTC, datetime, timedelta
+
+from apscheduler.schedulers.asyncio import AsyncIOScheduler
+from apscheduler.triggers.interval import IntervalTrigger
+from sqlalchemy import select
+from sqlalchemy.orm import Session, sessionmaker
+
+from netmover.db import session_scope
+from netmover.logging_setup import event, get_logger
+from netmover.models import Rule, RunTrigger, utcnow
+from netmover.runs import RunService, cleanup
+
+log = get_logger(__name__)
+
+MAX_START_OFFSET = 10.0
+HEARTBEAT_SECONDS = 30
+CLEANUP_SECONDS = 3600
+
+
+def _job_id(rule_id: int) -> str:
+    return f"rule:{rule_id}"
+
+
+class RuleScheduler:
+    def __init__(
+        self,
+        session_factory: sessionmaker[Session],
+        service: RunService,
+        *,
+        rng: random.Random | None = None,
+        workers: int = 8,
+    ) -> None:
+        self.session_factory = session_factory
+        self.service = service
+        self._rng = rng or random.Random()  # noqa: S311 – nur Startversatz
+        self._executor = ThreadPoolExecutor(max_workers=workers, thread_name_prefix="nm-run")
+        self.scheduler = AsyncIOScheduler(
+            timezone=UTC,
+            job_defaults={"coalesce": True, "max_instances": 3},
+        )
+        self._intervals: dict[int, int] = {}
+        self.last_heartbeat: datetime | None = None
+
+    # -- Lebenszyklus ---------------------------------------------------------------
+
+    def start(self) -> None:
+        self.scheduler.start()
+        self.heartbeat()
+        self.scheduler.add_job(
+            self.heartbeat, IntervalTrigger(seconds=HEARTBEAT_SECONDS), id="heartbeat"
+        )
+        self.scheduler.add_job(
+            self._cleanup,
+            IntervalTrigger(seconds=CLEANUP_SECONDS, start_date=utcnow() + timedelta(minutes=1)),
+            id="cleanup",
+        )
+        self.sync()
+        event(log, "scheduler.started", rules=len(self._intervals))
+
+    def shutdown(self) -> None:
+        if self.scheduler.running:
+            self.scheduler.shutdown(wait=False)
+        # Laufende Worker nicht abwarten: abgebrochene Übertragungen hinterlassen
+        # höchstens .part-Dateien, die Quelle bleibt unangetastet.
+        self._executor.shutdown(wait=False, cancel_futures=True)
+        event(log, "scheduler.stopped")
+
+    @property
+    def running(self) -> bool:
+        return bool(self.scheduler.running)
+
+    def heartbeat(self) -> None:
+        self.last_heartbeat = utcnow()
+
+    # -- Regeln -------------------------------------------------------------------------
+
+    def sync(self) -> None:
+        """Jobs an die Regeln in der Datenbank angleichen (nach jeder Änderung)."""
+        with session_scope(self.session_factory) as s:
+            wanted = {
+                rid: interval
+                for rid, interval in s.execute(
+                    select(Rule.id, Rule.interval_seconds).where(Rule.enabled.is_(True))
+                ).all()
+            }
+        for rid in list(self._intervals):
+            if rid not in wanted:
+                if self.scheduler.get_job(_job_id(rid)):
+                    self.scheduler.remove_job(_job_id(rid))
+                del self._intervals[rid]
+        for rid, interval in wanted.items():
+            if self._intervals.get(rid) == interval and self.scheduler.get_job(_job_id(rid)):
+                continue
+            offset = self._rng.uniform(0, min(float(interval), MAX_START_OFFSET))
+            trigger = IntervalTrigger(
+                seconds=interval,
+                start_date=utcnow() + timedelta(seconds=offset),
+                jitter=max(1, min(5, interval // 10)),
+            )
+            self.scheduler.add_job(
+                self._run_rule,
+                trigger,
+                args=[rid],
+                id=_job_id(rid),
+                name=f"Regel {rid}",
+                replace_existing=True,
+                misfire_grace_time=interval,
+            )
+            self._intervals[rid] = interval
+
+    def next_run(self, rule_id: int) -> datetime | None:
+        job = self.scheduler.get_job(_job_id(rule_id))
+        return job.next_run_time if job is not None else None
+
+    async def _run_rule(self, rule_id: int) -> None:
+        loop = asyncio.get_running_loop()
+        await loop.run_in_executor(
+            self._executor, self.service.execute, rule_id, RunTrigger.SCHEDULE
+        )
+
+    async def run_now(self, rule_id: int, dry_run: bool | None = None) -> int | None:
+        """„Jetzt ausführen“ / „Probelauf“ aus der Oberfläche."""
+        loop = asyncio.get_running_loop()
+        return await loop.run_in_executor(
+            self._executor, self.service.execute, rule_id, RunTrigger.MANUAL, dry_run
+        )
+
+    async def _cleanup(self) -> None:
+        loop = asyncio.get_running_loop()
+        await loop.run_in_executor(self._executor, cleanup, self.session_factory)