diff --git a/news/config.py b/news/config.py index f2c357b..c9626ad 100644 --- a/news/config.py +++ b/news/config.py @@ -113,6 +113,8 @@ class Config: "max_alerts_per_group_per_day": r.get("max_alerts_per_group_per_day", 1), "important_per_day": r.get("important_per_day", 2), "important_per_night": r.get("important_per_night", 1), + "interest_min_gap_minutes": r.get("interest_min_gap_minutes", 75), + "important_min_gap_minutes": r.get("important_min_gap_minutes", 30), "interest_threshold": r.get("interest_threshold", 2.0), "important_threshold": r.get("important_threshold", 2.0), "digest_floor": r.get("digest_floor", 0.5), diff --git a/news/digest.py b/news/digest.py index 828feb6..9ce403c 100644 --- a/news/digest.py +++ b/news/digest.py @@ -13,11 +13,14 @@ relevance, importance, vetoes -- is embeddings and arithmetic. from __future__ import annotations import json +import logging import os from dataclasses import dataclass import httpx +logger = logging.getLogger(__name__) + @dataclass class LlmConfig: @@ -62,10 +65,14 @@ def _extract_json_object(text: str) -> dict: def write_prose(client: httpx.Client, cfg: LlmConfig, stories: list[dict]) -> str | None: """One call. Returns None on any failure, and the caller falls back to a template -- the digest must never depend on a model being reachable.""" - if not cfg.enabled or not stories: + if not cfg.enabled: + logger.info("digest prose disabled in config") + return None + if not stories: return None key = os.environ.get(cfg.api_key_env) if not key: + logger.warning("digest prose skipped: %s is unset", cfg.api_key_env) return None try: resp = client.post( @@ -88,8 +95,14 @@ def write_prose(client: httpx.Client, cfg: LlmConfig, stories: list[dict]) -> st briefing = _extract_json_object(content).get("briefing") if isinstance(briefing, str) and briefing.strip(): return briefing.strip() - except Exception: # noqa: BLE001 - the digest ships regardless + except Exception as exc: # noqa: BLE001 - the digest ships regardless + # Fail open, but never silently. The first production digest fell back to + # the templated list every morning and the only clue was + # "LLM unavailable or disabled" -- the actual cause was a 60s timeout + # against a call that takes ~70s, which cost a debugging session to find. + logger.warning("digest prose unavailable (%s): %s", type(exc).__name__, exc) return None + logger.warning("digest prose call returned no usable briefing") return None diff --git a/news/route.py b/news/route.py index bc1e06e..2a728a2 100644 --- a/news/route.py +++ b/news/route.py @@ -19,6 +19,7 @@ from __future__ import annotations import sqlite3 from dataclasses import dataclass from datetime import datetime, time, timedelta +from zoneinfo import ZoneInfo from .score import ClusterScore @@ -41,7 +42,31 @@ def _parse_hhmm(value: str) -> time: return time(int(hh), int(mm)) +def local_now(now: datetime, delivery: dict) -> datetime: + """UTC instant -> the reader's wall clock. + + Quiet hours and the digest hour are wall-clock decisions, and the router is + handed a UTC `now`. Comparing UTC hours against "22:00-07:00" silenced + notifications from 18:00 local and released the whole day's budget at 03:00 + local -- which is exactly the 3:39am avalanche this was reported as. + + The timezone is read from config rather than the TZ environment variable, + because TZ fails silently: `America/Louisville` resolves on the Arch host but + does NOT exist in a Debian container, where only + `America/Kentucky/Louisville` is shipped. The container fell back to UTC and + printed "America" as its zone abbreviation. + """ + name = delivery.get("timezone") + if not name: + return now + try: + return now.astimezone(ZoneInfo(name)) + except Exception: # noqa: BLE001 - an unknown zone must not stop delivery + return now + + def in_quiet_hours(now: datetime, quiet: dict) -> bool: + """`now` must already be in the reader's local time -- see `local_now`.""" start = _parse_hhmm(quiet.get("start", "22:00")) end = _parse_hhmm(quiet.get("end", "07:00")) minute = now.hour * 60 + now.minute @@ -74,7 +99,7 @@ def route( """ groups = groups or {} quiet = delivery.get("quiet_hours", {}) - quiet_now = in_quiet_hours(now, quiet) + quiet_now = in_quiet_hours(local_now(now, delivery), quiet) may_wake = bool(delivery.get("importance_may_wake", True)) day_ago = now - timedelta(days=1) @@ -83,6 +108,22 @@ def route( night_budget = routing.get("important_per_night", 1) - _sent_since( con, IMPORTANT, now - timedelta(hours=10)) + # Minimum spacing. Budgets alone let a whole day's allowance fire in a single + # cycle -- six notifications landed in the same minute. A gap per lane turns + # the budget into a rate. + def _last_sent(lane: str) -> datetime | None: + row = con.execute( + "SELECT MAX(created_at) AS t FROM notification_log WHERE lane=?", (lane,) + ).fetchone() + return datetime.fromisoformat(row["t"]) if row and row["t"] else None + + def _gap_ok(lane: str, minutes: int) -> bool: + last = _last_sent(lane) + return last is None or (now - last) >= timedelta(minutes=minutes) + + interest_gap_ok = _gap_ok(INTEREST, routing.get("interest_min_gap_minutes", 75)) + important_gap_ok = _gap_ok(IMPORTANT, routing.get("important_min_gap_minutes", 30)) + already = { r["cluster_id"] for r in con.execute( @@ -156,6 +197,9 @@ def route( continue if s.importance_score < routing.get("important_threshold", 2.0): continue + if not important_gap_ok: + defer(s, "important-too-soon") + continue if important_budget <= 0: defer(s, "important-budget-exhausted") continue @@ -168,6 +212,7 @@ def route( continue night_budget -= 1 important_budget -= 1 + important_gap_ok = False # one per cycle; the rest wait for the gap take_group(s, "importance") settle(s, IMPORTANT, f"importance:{s.importance.block}", s.importance_score) @@ -183,6 +228,9 @@ def route( if quiet_now: defer(s, "quiet-hours") continue + if not interest_gap_ok: + defer(s, "interest-too-soon") + continue if interest_budget <= 0: defer(s, "interest-budget-exhausted") continue @@ -190,6 +238,7 @@ def route( defer(s, f"group-quota:{group_of(s, 'interest')}") continue interest_budget -= 1 + interest_gap_ok = False # one per cycle; the rest wait for the gap take_group(s, "interest") settle(s, INTEREST, f"interest:{s.interest.block}", s.interest_score) diff --git a/profile/config.toml b/profile/config.toml index 1fe033e..fc84b88 100644 --- a/profile/config.toml +++ b/profile/config.toml @@ -88,6 +88,12 @@ important_per_day = 2 # Hard cap on waking the reader during quiet hours, inside important_per_day. important_per_night = 1 +# Minimum spacing between sends on a lane. Budgets alone are not a rate: without +# these the whole day's allowance fires in one cycle, and six notifications +# arrived in the same minute. +interest_min_gap_minutes = 75 +important_min_gap_minutes = 30 + # Thresholds are in z-score units -- "how many standard deviations above normal # for this block", not raw cosine. Calibrate with `news simulate`, which reports # the notifications-per-day these values would actually have produced. @@ -141,4 +147,6 @@ enabled = true base_url = "http://litellm:4000" model = "news/glm-5.3-flash" api_key_env = "NEWS_LITELLM_KEY" -timeout_secs = 60 +# 180, not 60: the real digest payload (28 stories) took 70.3s to generate, so a +# 60s timeout failed every morning and silently fell back to the templated list. +timeout_secs = 180 diff --git a/profile/profile.toml b/profile/profile.toml index d713c93..881fa0f 100644 --- a/profile/profile.toml +++ b/profile/profile.toml @@ -443,6 +443,11 @@ probes = [ [delivery] digest_hour = "08:45" quiet_hours = { start = "22:00", end = "07:00" } +# Read from config, NOT from the TZ environment variable. "America/Louisville" +# resolves on the Arch host but does not exist inside a Debian container, which +# ships only the canonical name below -- so TZ silently fell back to UTC and +# quiet hours ran 18:00-03:00 local. +timezone = "America/Kentucky/Louisville" # The importance lane MAY override quiet hours. The interest lane never may. importance_may_wake = true # No format filter: Connor reads analysis, wire copy, investigations AND opinion, diff --git a/pyproject.toml b/pyproject.toml index 8255296..e965ada 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -12,6 +12,12 @@ dependencies = [ "jinja2>=3.1", "uvicorn>=0.30", "python-multipart>=0.0.9", + "tomlkit>=0.13", + # Quiet hours and the digest hour are wall-clock decisions. System zoneinfo + # is normally present, but this makes the zone lookup independent of the + # base image -- Debian ships no America/Louisville, only the canonical + # America/Kentucky/Louisville. + "tzdata>=2024.1", "tomlkit>=0.15.1", ] diff --git a/tests/test_route.py b/tests/test_route.py index 3d8ee27..e478362 100644 --- a/tests/test_route.py +++ b/tests/test_route.py @@ -154,3 +154,55 @@ def test_quiet_hours_wrap_midnight(hhmm, expected): h, m = map(int, hhmm.split(":")) now = datetime(2026, 9, 8, h, m, tzinfo=UTC) assert in_quiet_hours(now, {"start": "22:00", "end": "07:00"}) is expected + + +# --- timezone and pacing ----------------------------------------------------- + +DELIVERY_TZ = {**DELIVERY, "timezone": "America/Kentucky/Louisville"} + + +def test_quiet_hours_use_local_time_not_utc(con): + """Regression for the 3:39am avalanche. + + 22:00-07:00 was compared against UTC hours, so notifications were silenced + from 18:00 local and the day's whole budget was released at 03:00 local. + """ + # 23:00 UTC == 19:00 EDT: awake locally, but "quiet" if you compare UTC. + evening = datetime(2026, 9, 9, 23, 0, tzinfo=UTC) + out = route(con, [mk("a", interest=9.0)], ROUTING, DELIVERY_TZ, evening) + assert lanes(out)["a"] == INTEREST, "19:00 local is not quiet hours" + + # 03:30 UTC == 23:30 EDT: genuinely quiet locally. + night = datetime(2026, 9, 10, 3, 30, tzinfo=UTC) + out = route(con, [mk("b", interest=9.0)], ROUTING, DELIVERY_TZ, night) + assert lanes(out)["b"] == DIGEST + assert out[0].reason == "quiet-hours" + + +def test_an_unknown_timezone_does_not_stop_delivery(con): + delivery = {**DELIVERY, "timezone": "Mars/Olympus_Mons"} + out = route(con, [mk("a", interest=9.0)], ROUTING, delivery, NOW) + assert lanes(out)["a"] in (INTEREST, DIGEST) # decided, not crashed + + +def test_only_one_notification_per_lane_per_cycle(con): + """Budgets are not a rate. Six notifications once arrived in the same minute.""" + scores = [mk(f"i{n}", interest=9.0 - n) for n in range(4)] + out = lanes(route(con, scores, {**ROUTING, "interest_per_day": 4}, + DELIVERY_TZ, NOW)) + assert sum(1 for v in out.values() if v == INTEREST) == 1 + assert out["i0"] == INTEREST, "the strongest candidate takes the slot" + + +def test_a_second_send_waits_for_the_gap(con): + con.execute( + "INSERT INTO notification_log (cluster_id,lane,score,created_at) VALUES (?,?,?,?)", + ("earlier", INTEREST, 5.0, (NOW - timedelta(minutes=10)).isoformat())) + out = route(con, [mk("a", interest=9.0)], ROUTING, DELIVERY_TZ, NOW) + assert lanes(out)["a"] == DIGEST + assert out[0].reason == "interest-too-soon" + + # Once the gap has elapsed it goes through. + later = NOW + timedelta(minutes=80) + out2 = route(con, [mk("a", interest=9.0)], ROUTING, DELIVERY_TZ, later) + assert lanes(out2)["a"] == INTEREST diff --git a/uv.lock b/uv.lock index 9e70b17..f4009d7 100644 --- a/uv.lock +++ b/uv.lock @@ -565,6 +565,7 @@ dependencies = [ { name = "python-multipart" }, { name = "starlette" }, { name = "tomlkit" }, + { name = "tzdata" }, { name = "uvicorn" }, ] @@ -584,7 +585,9 @@ requires-dist = [ { name = "numpy", specifier = ">=1.26" }, { name = "python-multipart", specifier = ">=0.0.9" }, { name = "starlette", specifier = ">=0.37" }, + { name = "tomlkit", specifier = ">=0.13" }, { name = "tomlkit", specifier = ">=0.15.1" }, + { name = "tzdata", specifier = ">=2024.1" }, { name = "uvicorn", specifier = ">=0.30" }, ] @@ -1032,6 +1035,15 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/49/d3/b8441a820a491ddfc024b0b0cf0393375b75ea13866d9c66727e54c2fc80/typing_extensions-4.16.0-py3-none-any.whl", hash = "sha256:481caa481374e813c1b176ada14e97f1f67a4539ce9cfeb3f350d78d6370c2e8", size = 45571, upload-time = "2026-07-02T08:40:04.659Z" }, ] +[[package]] +name = "tzdata" +version = "2026.3" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/92/ff/5a28bdfd8c3ebec42564ac7d0e54ca3db65044a9314a97f9564fa7a1e926/tzdata-2026.3.tar.gz", hash = "sha256:4a1518b8993086a7982523e071643f3c0e5f213e75b21318e78bcabfff9d1415", size = 198674, upload-time = "2026-07-10T08:50:37.887Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/e5/6d/b53b99a9f2766d095985947a5782f1702cabb129a34f7a802d7197af832f/tzdata-2026.3-py2.py3-none-any.whl", hash = "sha256:dc096730c87af6cab1b171c9d532be840741ff5d459015e7f6947bd7d7e54931", size = 348168, upload-time = "2026-07-10T08:50:36.46Z" }, +] + [[package]] name = "urllib3" version = "2.7.0"