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 <noreply@anthropic.com>
This commit is contained in:
@@ -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)
|
||||
|
||||
+11
-3
@@ -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
|
||||
|
||||
@@ -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())
|
||||
@@ -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 = []
|
||||
|
||||
@@ -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")
|
||||
@@ -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())
|
||||
|
||||
|
||||
@@ -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)]
|
||||
|
||||
Reference in New Issue
Block a user