From 400e91a0d8f6b21bf47c8a6f0c96d04f00144c64 Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Fri, 9 Oct 2026 16:48:19 -0400 Subject: [PATCH] fix(host_agent): a post that reached Steward counts as the agent seen, even if storing it failed (#5514) At 20:25-20:39Z the NFS storage under steward_db slowed badly (checkpoint sync 4.6 s, then 70.7 s with one file at 21.9 s, against the usual 0.002 s). Ingest commits stalled past the agent's 10 s timeout and were dropped, and last_seen_at, written in that same transaction, went with them. Agents posting every few seconds read as silent for 3 minutes, and "Agent offline" fired and emailed for all three hosts. Ingest now notes each agent's arrival in memory right after the (read-only) registration lookup, before any write; seconds_since_seen counts from the later of last_seen_at and that arrival. Co-Authored-By: Claude Opus 5.5 --- docs/plugins/host-agent-design.md | 2 ++ plugins/host_agent/routes.py | 3 +++ plugins/host_agent/scheduler.py | 27 ++++++++++++++++++---- tests/plugins/host_agent/test_scheduler.py | 21 +++++++++++++++++ 4 files changed, 49 insertions(+), 4 deletions(-) diff --git a/docs/plugins/host-agent-design.md b/docs/plugins/host-agent-design.md index 39199c6..b53942c 100644 --- a/docs/plugins/host-agent-design.md +++ b/docs/plugins/host-agent-design.md @@ -205,6 +205,8 @@ One `ScheduledTask` running every 60 seconds that flags `HostAgentRegistration` **Note:** the existing alerts system can fire on "no metric for N seconds" which is arguably a cleaner signal. The scheduled task may end up redundant once alert rules exist. Build it anyway as a minimal safety net; it's one query plus one update. +**As built:** the task records `host_agent//seconds_since_seen` each minute, and "Agent offline" is an ordinary alert rule on it (`> 180`). It counts from the later of `last_seen_at` and the agent's newest post to *arrive* (kept in memory, `scheduler.arrivals`). `last_seen_at` is written in the ingest's own transaction, so a post Steward received but couldn't store (its storage stalled, #5514) would otherwise read as the agent's silence. Nothing counts from before Steward last started watching without a break (#5441). + ### `METRIC_CATALOG` registration Add to `steward/alerts/routes.py`: diff --git a/plugins/host_agent/routes.py b/plugins/host_agent/routes.py index ee94985..2134773 100644 --- a/plugins/host_agent/routes.py +++ b/plugins/host_agent/routes.py @@ -24,6 +24,7 @@ from steward.core.time_range import parse_range, RANGE_OPTIONS from steward.models.hosts import Host from steward.models.metrics import PluginMetric from .models import HostAgentRegistration +from .scheduler import arrivals # Query helpers live in a model-free module so integration tests can import them # without the plugin-loader double-registration guard tripping (see metrics_query). from .metrics_query import ( @@ -242,6 +243,8 @@ async def ingest(): )).scalar_one_or_none() if host is None: return _error(401, "invalid_token") + # The agent reached us: that holds even if storing its post fails (#5514). + arrivals(current_app)[reg.host_id] = received_at accepted = 0 metric_rows: list[PluginMetric] = [] diff --git a/plugins/host_agent/scheduler.py b/plugins/host_agent/scheduler.py index 9005175..2f246a8 100644 --- a/plugins/host_agent/scheduler.py +++ b/plugins/host_agent/scheduler.py @@ -15,8 +15,24 @@ from .models import HostAgentRegistration logger = logging.getLogger(__name__) +def arrivals(app) -> dict[str, datetime]: + """{host id: when its agent's newest post reached Steward}, in memory (#5514). + + last_seen_at is written in the ingest's own transaction, so when Steward + can't store a post (its storage stalls and the request is dropped) the + agent's report is lost with it, and an agent posting every few seconds read + as offline. A post that arrived is the agent reaching Steward; storing it + is Steward's part. Set before any write, so it holds however slow they are. + """ + got = getattr(app, "_agent_arrivals", None) + if got is None: + got = app._agent_arrivals = {} + return got + + def seconds_since_seen(regs: Iterable, host_names: dict[str, str], - now: datetime, watching_since: datetime | None = None + now: datetime, watching_since: datetime | None = None, + arrived: dict[str, datetime] | None = None ) -> list[tuple[str, float]]: """(host name, seconds since its agent last reported) per registration. @@ -25,12 +41,14 @@ def seconds_since_seen(regs: Iterable, host_names: dict[str, str], `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. + quiet that long while Steward watched. `arrived` (arrivals(app)) counts a + post Steward received but couldn't store as the agent seen (#5514). """ out = [] for r in regs: name = host_names.get(r.host_id) - seen = r.last_seen_at or r.created_at + seen = max((t for t in (r.last_seen_at or r.created_at, (arrived or {}).get(r.host_id)) + if t is not None), default=None) if name is None or seen is None: continue if watching_since is not None: @@ -53,7 +71,8 @@ async def record_seconds_since_seen(app) -> None: 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, watching_since): + for name, seconds in seconds_since_seen(regs, host_names, now, watching_since, + arrivals(app)): 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/tests/plugins/host_agent/test_scheduler.py b/tests/plugins/host_agent/test_scheduler.py index ce1ab5e..00e566f 100644 --- a/tests/plugins/host_agent/test_scheduler.py +++ b/tests/plugins/host_agent/test_scheduler.py @@ -50,3 +50,24 @@ def test_steward_s_own_outage_is_not_the_agent_s_silence(): 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)] + + +def test_a_post_that_arrived_but_was_not_stored_counts_as_seen(): + """#5514: Steward's storage stalled and dropped the agents' posts, so + last_seen_at (written with them) stayed old, and agents posting every few + seconds read as offline. Arriving is the agent's part; the later of the + two counts. An agent with no arrival keeps its stored age.""" + regs = [FakeReg("h1", NOW - timedelta(minutes=4), NOW - timedelta(days=9)), + FakeReg("h2", NOW - timedelta(minutes=4), NOW - timedelta(days=9)), + FakeReg("h3", NOW - timedelta(seconds=10), NOW - timedelta(days=9))] + arrived = {"h1": NOW - timedelta(seconds=5), "h3": NOW - timedelta(minutes=2)} + assert seconds_since_seen(regs, NAMES, NOW, arrived=arrived) == [ + ("nas", 5.0), ("web", 240.0), ("db", 10.0)] + + +def test_arrivals_are_kept_per_app(): + from types import SimpleNamespace + from plugins.host_agent.scheduler import arrivals + app, other = SimpleNamespace(), SimpleNamespace() + arrivals(app)["h1"] = NOW + assert arrivals(app) == {"h1": NOW} and arrivals(other) == {}