FONDLED THE CODE

server/app.py

@@ -23,6 +23,20 @@ from server.slots import build_today
 from server.stats import build_history, check_milestones, compute_stats, MILESTONE_DEFS
 
 NO_STORE = {"Cache-Control": "no-store"}
+
+
+def _configure_logging() -> None:
+    fmt = logging.Formatter("%(levelname)s:     %(message)s")
+    server_log = logging.getLogger("server")
+    if not server_log.handlers:
+        handler = logging.StreamHandler()
+        handler.setFormatter(fmt)
+        server_log.addHandler(handler)
+        server_log.setLevel(logging.INFO)
+        server_log.propagate = False
+
+
+_configure_logging()
 logger = logging.getLogger(__name__)
 
 

server/push.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import json
+import logging
 from typing import Any
 
 import aiosqlite
@@ -9,6 +10,8 @@ from pywebpush import WebPushException, webpush
 from server.db import utc_now_iso
 from server.settings import settings
 
+logger = logging.getLogger(__name__)
+
 
 async def save_subscription(db: aiosqlite.Connection, sub: dict[str, Any]) -> None:
     keys = sub.get("keys", {})
@@ -34,20 +37,42 @@ def _vapid_claims() -> dict[str, str]:
     return {"sub": settings.vapid_claims_email}
 
 
+def _endpoint_label(endpoint: str) -> str:
+    return endpoint[:60] + ("..." if len(endpoint) > 60 else "")
+
+
 async def send_push(
     db: aiosqlite.Connection,
     payload: dict[str, Any],
 ) -> int:
+    tag = payload.get("tag", "?")
+    slot_id = payload.get("slot_id", "?")
+
     if not settings.vapid_private_key or not settings.vapid_public_key:
+        logger.warning("Push skipped slot=%s tag=%s reason=vapid_not_configured", slot_id, tag)
         return 0
 
     subs = await get_subscriptions(db)
+    if not subs:
+        logger.warning("Push skipped slot=%s tag=%s reason=no_subscriptions", slot_id, tag)
+        return 0
+
     sent = 0
+    failed = 0
     dead: list[str] = []
 
+    logger.info(
+        "Push start slot=%s tag=%s subscriptions=%d title=%r",
+        slot_id,
+        tag,
+        len(subs),
+        payload.get("title"),
+    )
+
     for sub in subs:
+        endpoint = sub["endpoint"]
         subscription = {
-            "endpoint": sub["endpoint"],
+            "endpoint": endpoint,
             "keys": {"p256dh": sub["p256dh"], "auth": sub["auth"]},
         }
         try:
@@ -58,15 +83,42 @@ async def send_push(
                 vapid_claims=_vapid_claims(),
             )
             sent += 1
+            logger.info("Push ok slot=%s endpoint=%s", slot_id, _endpoint_label(endpoint))
         except WebPushException as exc:
-            if exc.response and exc.response.status_code in (404, 410):
+            status = exc.response.status_code if exc.response else None
-                dead.append(sub["endpoint"])
+            if status in (404, 410):
+                dead.append(endpoint)
+                logger.info(
+                    "Push dead slot=%s endpoint=%s status=%s",
+                    slot_id,
+                    _endpoint_label(endpoint),
+                    status,
+                )
+            else:
+                failed += 1
+                logger.warning(
+                    "Push failed slot=%s endpoint=%s status=%s error=%s",
+                    slot_id,
+                    _endpoint_label(endpoint),
+                    status,
+                    exc,
+                )
 
     for endpoint in dead:
         await db.execute("DELETE FROM push_subscription WHERE endpoint = ?", (endpoint,))
     if dead:
         await db.commit()
+        logger.info("Push removed %d dead subscription(s)", len(dead))
 
+    logger.info(
+        "Push done slot=%s tag=%s sent=%d failed=%d dead=%d total=%d",
+        slot_id,
+        tag,
+        sent,
+        failed,
+        len(dead),
+        len(subs),
+    )
     return sent
 
 

server/scheduler.py

@@ -4,6 +4,7 @@ import asyncio
 import logging
 from datetime import datetime, timedelta
 
+from apscheduler.events import EVENT_JOB_ERROR, EVENT_JOB_EXECUTED, EVENT_JOB_MISSED
 from apscheduler.schedulers.asyncio import AsyncIOScheduler
 from apscheduler.triggers.cron import CronTrigger
 from apscheduler.triggers.date import DateTrigger
@@ -23,17 +24,21 @@ async def _remind_slot(slot_id: str) -> None:
     config = load_meds_config()
     tz = config.timezone
     day = today_str(tz)
+    logger.info("Reminder triggered slot=%s day=%s", slot_id, day)
     db = await get_db()
     try:
         logs = await get_log_for_day(db, day)
         if slot_id in logs and logs[slot_id]["status"] == "taken":
+            logger.info("Reminder skipped slot=%s day=%s reason=already_taken", slot_id, day)
             return
         slot = next((s for s in config.slots if s.id == slot_id), None)
         if not slot:
+            logger.warning("Reminder skipped slot=%s day=%s reason=unknown_slot", slot_id, day)
             return
         title = f"{slot.label} — Med-Time!"
         body = pick("reminder", label=slot.label, med=slot.meds[0].name if slot.meds else "Medis")
-        await send_slot_reminder(db, slot_id, title, body)
+        sent = await send_slot_reminder(db, slot_id, title, body)
+        logger.info("Reminder finished slot=%s day=%s sent=%d", slot_id, day, sent)
     finally:
         await db.close()
 
@@ -61,12 +66,18 @@ async def _generate_daily_oracle() -> None:
 
 
 async def _evening_check() -> None:
+    logger.info("Evening check triggered")
     db = await get_db()
     try:
         marked = await mark_missed_for_overdue(db)
+        if not marked:
+            logger.info("Evening check done marked=0")
+            return
+        logger.info("Evening check marked missed slots=%s", ",".join(marked))
         for slot_id in marked:
             body = pick("missed")
-            await send_slot_reminder(db, slot_id, "Verpasst?", body)
+            sent = await send_slot_reminder(db, slot_id, "Verpasst?", body)
+            logger.info("Evening reminder slot=%s sent=%d", slot_id, sent)
     finally:
         await db.close()
 
@@ -102,10 +113,26 @@ async def schedule_snooze(slot_id: str, minutes: int) -> str:
     return until.isoformat()
 
 
+def _scheduler_listener(event) -> None:
+    if event.code == EVENT_JOB_MISSED:
+        logger.warning(
+            "Scheduler job missed id=%s scheduled=%s",
+            event.job_id,
+            event.scheduled_run_time,
+        )
+    elif event.code == EVENT_JOB_ERROR:
+        logger.exception("Scheduler job error id=%s", event.job_id)
+    elif event.code == EVENT_JOB_EXECUTED:
+        logger.info("Scheduler job executed id=%s", event.job_id)
+
+
 def start_scheduler() -> None:
     config = load_meds_config()
     tz = config.timezone
 
+    if not scheduler.running:
+        scheduler.add_listener(_scheduler_listener, EVENT_JOB_EXECUTED | EVENT_JOB_MISSED | EVENT_JOB_ERROR)
+
     for slot in config.slots:
         h, m = slot.time.hour, slot.time.minute
         scheduler.add_job(
@@ -115,6 +142,7 @@ def start_scheduler() -> None:
             id=f"remind-{slot.id}",
             replace_existing=True,
         )
+        logger.info("Registered remind job slot=%s at %02d:%02d %s", slot.id, h, m, tz)
 
     scheduler.add_job(
         _evening_check,
@@ -140,3 +168,5 @@ def start_scheduler() -> None:
     if not scheduler.running:
         scheduler.start()
         logger.info("Scheduler started for timezone %s", tz)
+        for job in scheduler.get_jobs():
+            logger.info("Scheduler job id=%s next=%s", job.id, job.next_run_time)