diff --git a/steward/core/alerts.py b/steward/core/alerts.py index f656e9f..573be15 100644 --- a/steward/core/alerts.py +++ b/steward/core/alerts.py @@ -250,9 +250,14 @@ async def record_metrics(session: AsyncSession, rows: list[PluginMetric], phases key=lambda r: r.recorded_at) muted = _muted_by(windows, rule) resumed = _track_samples(alert_state, samples, now) + # A silence ends when Steward hears of it: an agent's flushed backlog + # brings samples hours old, and stamping their events at their own + # times put the resume inside the silence it ends (#5720). + back = resumed is not None for sample in samples: + at = max(sample.recorded_at, now) if back else sample.recorded_at notifications = await _evaluate_rule(session, rule, alert_state, sample.value, - sample.recorded_at, note=muted, resumed=resumed) + at, note=muted, resumed=resumed) resumed = None # said once, with the first sample back if muted: continue @@ -319,7 +324,13 @@ def _track_samples(state: AlertState, samples: list[PluginMetric], now: datetime series had been marked no_data, clear the mark and return the note saying so ("data resumed after 15m silent"); the first sample's evaluation records it, in one event with whatever that sample does to the rule - (#5442).""" + (#5442). + + A resumed series counts as last heard `now`, when Steward heard it, not at + its newest sample's time: a backlog flushed a few samples a post is hours + old, and judging silence by it marked the series silent again between + posts, so one silence was resumed twice (#5720). The rest of the backlog + then reads as late samples, which teach the cadence nothing.""" for sample in samples: if state.last_sample_at is not None: if sample.recorded_at <= state.last_sample_at: @@ -331,6 +342,7 @@ def _track_samples(state: AlertState, samples: list[PluginMetric], now: datetime return None note = f"data resumed after {human_duration((now - state.no_data_since).total_seconds())} silent" state.no_data_since = None + state.last_sample_at = max(state.last_sample_at or now, now) return note diff --git a/tests/core/test_alert_no_data.py b/tests/core/test_alert_no_data.py index d3bc325..9af8b4a 100644 --- a/tests/core/test_alert_no_data.py +++ b/tests/core/test_alert_no_data.py @@ -151,3 +151,19 @@ def test_muted_by_names_the_window_that_covers_the_rule(): assert _muted_by(windows[:1], rule) is None assert _muted_by([NS(name="all", scope_source=None, scope_resource=None)], rule) == ( "notification muted: maintenance window all") + + +def test_a_flushed_backlog_counts_as_heard_when_it_arrives(): + """#5720: an agent's backlog, flushed a couple of samples a post, is hours + old. Judged by its newest sample, the series read silent again between + posts and resumed twice. It counts as heard when Steward heard it, and the + rest of the backlog reads as late.""" + st = _state(last_sample_at=NOW - timedelta(hours=3), sample_interval_s=60, + no_data_since=NOW - timedelta(hours=2, minutes=55)) + note = _track_samples(st, _samples((2 * 3600 + 60, 5.0), (2 * 3600, 5.0)), NOW) + assert note == "data resumed after 2h 55m silent" + assert st.last_sample_at == NOW + assert silent_since(st.last_sample_at, st.sample_interval_s, NOW, NOW) is None + # The next post of the same backlog is late: no gap, no second resume. + assert _track_samples(st, _samples((2 * 3600 - 60, 5.0)), NOW) is None + assert st.last_sample_at == NOW