From a9bf4b7f1654d3de79db74e40146f3bdded3a9fe Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Thu, 8 Oct 2026 21:45:47 -0400 Subject: [PATCH] fix(alerts): Steward's own outage no longer reads as every agent going silent (#5441) After Steward or its database was down, every agent's age and every series' last sample were old, so all agent-offline rules fired and all rules went no-data at once, clearing a minute later. With per-account alert email that would have mailed everyone a dozen notices per restart. A periodic job now ticks a Watch (steward/core/watch.py) once it has reached the database; the Watch says since when runs have been unbroken (process start, or the end of a gap over 120 s). seconds_since_seen and the no-data sweep count silence from no earlier than that, so a source must stay quiet while Steward is watching before it counts as silent. Co-Authored-By: Claude Opus 5.5 --- plugins/host_agent/scheduler.py | 15 ++++-- steward/core/alerts.py | 14 +++-- steward/core/watch.py | 43 +++++++++++++++ tests/core/test_alert_no_data.py | 13 +++++ tests/core/test_watch.py | 32 ++++++++++++ tests/integration/test_alert_no_data.py | 61 ++++++++++++++++++++++ tests/plugins/host_agent/test_scheduler.py | 11 ++++ 7 files changed, 183 insertions(+), 6 deletions(-) create mode 100644 steward/core/watch.py create mode 100644 tests/core/test_watch.py diff --git a/plugins/host_agent/scheduler.py b/plugins/host_agent/scheduler.py index 09e84ec..9005175 100644 --- a/plugins/host_agent/scheduler.py +++ b/plugins/host_agent/scheduler.py @@ -8,6 +8,7 @@ from sqlalchemy import select from steward.core.alerts import MetricBatch from steward.core.scheduler import ScheduledTask +from steward.core.watch import watch from steward.models.hosts import Host from .models import HostAgentRegistration @@ -15,11 +16,16 @@ logger = logging.getLogger(__name__) def seconds_since_seen(regs: Iterable, host_names: dict[str, str], - now: datetime) -> list[tuple[str, float]]: + now: datetime, watching_since: datetime | None = None + ) -> list[tuple[str, float]]: """(host name, seconds since its agent last reported) per registration. An agent that has never reported counts from when it was registered. A - registration whose host is gone is skipped. + registration whose host is gone is skipped. Nothing counts from before + `watching_since`, when Steward last started watching without a break: an + agent can't report while Steward is down, so that time is not its silence + (#5441). An agent that is really gone reads as offline once it has been + quiet that long while Steward watched. """ out = [] for r in regs: @@ -27,6 +33,8 @@ def seconds_since_seen(regs: Iterable, host_names: dict[str, str], seen = r.last_seen_at or r.created_at if name is None or seen is None: continue + if watching_since is not None: + seen = max(seen, watching_since) out.append((name, max(0.0, (now - seen).total_seconds()))) return out @@ -38,13 +46,14 @@ async def record_seconds_since_seen(app) -> None: async with app.db_sessionmaker() as session: async with session.begin(): regs = (await session.execute(select(HostAgentRegistration))).scalars().all() + watching_since = watch(app, "host_agent_seconds_since_seen").tick(now) if not regs: return host_names = dict((await session.execute( select(Host.id, Host.name).where(Host.id.in_([r.host_id for r in regs])) )).all()) batch = MetricBatch() - for name, seconds in seconds_since_seen(regs, host_names, now): + for name, seconds in seconds_since_seen(regs, host_names, now, watching_since): batch.add(source_module="host_agent", resource_name=name, metric_name="seconds_since_seen", value=seconds, recorded_at=now) await batch.record(session) diff --git a/steward/core/alerts.py b/steward/core/alerts.py index 552f7f6..f6589cc 100644 --- a/steward/core/alerts.py +++ b/steward/core/alerts.py @@ -18,6 +18,7 @@ from steward.models.alerts import ( MaintenanceWindow, ) from steward.core.formatting import human_duration +from steward.core.watch import watch from steward.models.metrics import PluginMetric, PluginMetricLatest if TYPE_CHECKING: @@ -297,13 +298,19 @@ def no_data_after(interval: float | None) -> float: def silent_since(last_sample_at: datetime | None, interval: float | None, - watching_since: datetime, now: datetime) -> datetime | None: + watching_since: datetime, now: datetime, + awake_since: datetime | None = None) -> datetime | None: """When a series went silent, or None while it is still reporting. A series that has never had a sample counts from when the rule started - watching it (created, changed or re-enabled). + watching it (created, changed or re-enabled). Nothing counts from before + `awake_since`, when Steward last started watching without a break: no + sample can arrive while Steward is down, so its own outage is not the + series' silence (#5441). """ last = last_sample_at or watching_since + if awake_since is not None: + last = max(last, awake_since) limit = timedelta(seconds=no_data_after(interval)) return last + limit if now - last > limit else None @@ -632,6 +639,7 @@ async def check_silence(app: "Quart") -> None: .join(AlertRule, AlertState.rule_id == AlertRule.id) .where(AlertRule.enabled.is_(True), AlertState.no_data_since.is_(None)) )).all() + awake_since = watch(app, "alert_silence").tick(now) if not rows: return windows = (await session.execute( @@ -641,7 +649,7 @@ async def check_silence(app: "Quart") -> None: for state, rule in rows: watching_since = max(rule.created_at, state.last_transition_at) since = silent_since(state.last_sample_at, state.sample_interval_s, - watching_since, now) + watching_since, now, awake_since) if since is None: continue state.no_data_since = since diff --git a/steward/core/watch.py b/steward/core/watch.py new file mode 100644 index 0000000..7efb504 --- /dev/null +++ b/steward/core/watch.py @@ -0,0 +1,43 @@ +"""Since when Steward has been watching without a break (#5441). + +Silence is measured by Steward: an agent's age is now minus its last report, +a series is silent once no sample has arrived for a while. While Steward (or +its database) is down nothing arrives, so on its return every agent and every +series looks silent at once, and every agent-offline and no-data alert used to +fire together for an outage that was Steward's own. + +A periodic job ticks its Watch each run, once it has reached the database. +The Watch answers "since when have I been running without a break": since +the process started, or since the end of a gap longer than GAP_S between +ticks (the database was down, the loop stalled). Silence is then counted from +no earlier than that, so a source has to stay quiet while Steward is +watching before it counts as silent. +""" +from __future__ import annotations + +from datetime import datetime + +# Two missed 60 s ticks. A gap this long means Steward was not watching; a +# shorter one only delays a real alert by the length of the gap. +GAP_S = 120.0 + + +class Watch: + def __init__(self) -> None: + self.since: datetime | None = None + self.last: datetime | None = None + + def tick(self, now: datetime) -> datetime: + """Record a run at `now`; return since when runs have been unbroken.""" + if self.since is None or self.last is None or (now - self.last).total_seconds() > GAP_S: + self.since = now + self.last = now + return self.since + + +def watch(app, name: str) -> Watch: + """The app's Watch for one periodic job, made on first use.""" + watches = getattr(app, "_watches", None) + if watches is None: + watches = app._watches = {} + return watches.setdefault(name, Watch()) diff --git a/tests/core/test_alert_no_data.py b/tests/core/test_alert_no_data.py index 418d61b..6360b2d 100644 --- a/tests/core/test_alert_no_data.py +++ b/tests/core/test_alert_no_data.py @@ -60,6 +60,19 @@ def test_silent_since(last_ago, interval, watch_ago, silent_after): assert got == (last or watch) + timedelta(seconds=silent_after) +def test_steward_s_own_outage_is_not_the_series_silence(): + """#5441: a series last sampled 18 minutes ago, while Steward has only been + back for 2 minutes, is not silent yet; once Steward has watched it for + three of its gaps with nothing arriving, it is, from then.""" + last = NOW - timedelta(minutes=18) + watch = NOW - timedelta(days=1) + assert silent_since(last, 60, watch, NOW, awake_since=NOW - timedelta(minutes=2)) is None + awake = NOW - timedelta(minutes=6) + assert silent_since(last, 60, watch, NOW, awake_since=awake) == awake + timedelta(seconds=300) + # A sample since Steward came back is what counts, when there is one. + assert silent_since(NOW - timedelta(minutes=1), 60, watch, NOW, awake_since=awake) is None + + class _Session: def __init__(self): self.added = [] diff --git a/tests/core/test_watch.py b/tests/core/test_watch.py new file mode 100644 index 0000000..2ddef16 --- /dev/null +++ b/tests/core/test_watch.py @@ -0,0 +1,32 @@ +"""Since when Steward has been watching without a break (#5441): a job's +Watch starts at its first run, holds across runs a minute apart, and starts +again after a gap long enough to mean Steward was not watching.""" +from datetime import datetime, timedelta, timezone +from types import SimpleNamespace as NS + +from steward.core.watch import GAP_S, Watch, watch + +T0 = datetime(2026, 10, 9, 2, 0, tzinfo=timezone.utc) + + +def test_the_first_run_starts_the_watch_and_steady_runs_keep_it(): + w = Watch() + assert w.tick(T0) == T0 + for minute in range(1, 30): + assert w.tick(T0 + timedelta(minutes=minute)) == T0 + + +def test_a_gap_longer_than_two_missed_runs_starts_it_again(): + w = Watch() + w.tick(T0) + assert w.tick(T0 + timedelta(seconds=GAP_S)) == T0 # just within + back = T0 + timedelta(seconds=2 * GAP_S + 1) + assert w.tick(back) == back # Steward was away + assert w.tick(back + timedelta(minutes=1)) == back + + +def test_each_job_has_its_own_watch_on_its_own_app(): + a, b = NS(), NS() + assert watch(a, "x") is watch(a, "x") + assert watch(a, "x") is not watch(a, "y") + assert watch(a, "x") is not watch(b, "x") diff --git a/tests/integration/test_alert_no_data.py b/tests/integration/test_alert_no_data.py index 02792b8..8db3901 100644 --- a/tests/integration/test_alert_no_data.py +++ b/tests/integration/test_alert_no_data.py @@ -26,6 +26,7 @@ def test_silence_is_marked_once_and_cleared_by_data(app): from sqlalchemy import select, update from steward.alerts import service as alert_svc from steward.core import alerts + from steward.core.watch import watch from steward.models.alerts import AlertEvent, AlertRule, AlertState, AlertStateEnum from steward.models.metrics import PluginMetric from steward.models.users import User, UserRole @@ -77,6 +78,9 @@ def test_silence_is_marked_once_and_cleared_by_data(app): assert st.sample_interval_s == pytest.approx(60) assert st.last_sample_at == now - timedelta(minutes=18) + # Steward has been watching all along (#5441 covers a fresh start). + w = watch(app, "alert_silence") + w.since, w.last = now - timedelta(days=1), datetime.now(timezone.utc) await alerts.check_silence(app) await alerts.check_silence(app) # already marked: nothing more await asyncio.sleep(0) @@ -123,3 +127,60 @@ def test_silence_is_marked_once_and_cleared_by_data(app): with patch.object(alerts, "_dispatch_notification", fake_dispatch): asyncio.run(_go()) + + +def test_a_series_quiet_only_while_steward_was_down_is_not_silent(app): + """#5441: Steward comes back to a series last sampled 18 minutes ago. Its + outage is not the series' silence, so nothing is marked; once Steward has + watched for three of the series' gaps with nothing arriving, it is.""" + from sqlalchemy import select + from steward.alerts import service as alert_svc + from steward.core import alerts + from steward.core.watch import watch + from steward.models.alerts import AlertEvent, AlertState + from steward.models.users import User, UserRole + + sent = [] + + async def fake_dispatch(app_, notif_type, rule, value, event_id, note=None): + sent.append((rule.id, notif_type)) + + async def _go(): + tag = uuid.uuid4().hex[:8] + res = f"back-{tag}" + now = datetime.now(timezone.utc) + async with app.db_sessionmaker() as s: + async with s.begin(): + user = User(username=f"bk-{tag}", email=f"bk-{tag}@test", password_hash="x", + role=UserRole.admin) + s.add(user) + await s.flush() + fields = await alert_svc.rule_fields( + s, name=f"back {tag}", source_module="host_agent", resource_name=res, + metric_name="cpu_pct", operator=">", threshold=90, notify_no_data=True) + rule_id = (await alert_svc.add_rule(s, fields, created_by=user.id)).id + await s.flush() + st = (await s.execute(select(AlertState).where(AlertState.rule_id == rule_id))).scalar_one() + st.last_sample_at, st.sample_interval_s = now - timedelta(minutes=18), 60.0 + + async def marks(): + async with app.db_sessionmaker() as s: + st = (await s.execute(select(AlertState).where(AlertState.rule_id == rule_id))).scalar_one() + n = len((await s.execute(select(AlertEvent).where(AlertEvent.rule_id == rule_id))).all()) + return st.no_data_since, n + + await alerts.check_silence(app) # the first run since Steward started + await asyncio.sleep(0) + assert await marks() == (None, 0) and (rule_id, "no_data") not in sent + + # Six quiet minutes later (as if), Steward has watched long enough. + w = watch(app, "alert_silence") + w.since = now - timedelta(minutes=6) + await alerts.check_silence(app) + await asyncio.sleep(0) + assert await marks() == (w.since + timedelta(seconds=300), 1) + assert sent.count((rule_id, "no_data")) == 1 + + with patch.object(alerts, "_dispatch_notification", fake_dispatch): + asyncio.run(_go()) + diff --git a/tests/plugins/host_agent/test_scheduler.py b/tests/plugins/host_agent/test_scheduler.py index a1b910b..ce1ab5e 100644 --- a/tests/plugins/host_agent/test_scheduler.py +++ b/tests/plugins/host_agent/test_scheduler.py @@ -39,3 +39,14 @@ def test_a_clock_ahead_of_ours_reads_as_just_seen(): def test_empty_input(): assert seconds_since_seen([], NAMES, NOW) == [] + + +def test_steward_s_own_outage_is_not_the_agent_s_silence(): + """#5441: agents that last reported 10 minutes ago, while Steward has only + been back for a minute, are a minute old; an agent heard since then keeps + its own age.""" + back = NOW - timedelta(minutes=1) + regs = [FakeReg("h1", NOW - timedelta(minutes=10), NOW - timedelta(days=9)), + FakeReg("h2", NOW - timedelta(seconds=20), NOW - timedelta(days=9)), + FakeReg("h3", None, NOW - timedelta(days=9))] + assert seconds_since_seen(regs, NAMES, NOW, back) == [("nas", 60.0), ("web", 20.0), ("db", 60.0)]