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 <noreply@anthropic.com>
This commit is contained in:
@@ -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.
|
**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/<host>/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
|
### `METRIC_CATALOG` registration
|
||||||
|
|
||||||
Add to `steward/alerts/routes.py`:
|
Add to `steward/alerts/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.hosts import Host
|
||||||
from steward.models.metrics import PluginMetric
|
from steward.models.metrics import PluginMetric
|
||||||
from .models import HostAgentRegistration
|
from .models import HostAgentRegistration
|
||||||
|
from .scheduler import arrivals
|
||||||
# Query helpers live in a model-free module so integration tests can import them
|
# 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).
|
# without the plugin-loader double-registration guard tripping (see metrics_query).
|
||||||
from .metrics_query import (
|
from .metrics_query import (
|
||||||
@@ -242,6 +243,8 @@ async def ingest():
|
|||||||
)).scalar_one_or_none()
|
)).scalar_one_or_none()
|
||||||
if host is None:
|
if host is None:
|
||||||
return _error(401, "invalid_token")
|
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
|
accepted = 0
|
||||||
metric_rows: list[PluginMetric] = []
|
metric_rows: list[PluginMetric] = []
|
||||||
|
|||||||
@@ -15,8 +15,24 @@ from .models import HostAgentRegistration
|
|||||||
logger = logging.getLogger(__name__)
|
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],
|
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]]:
|
) -> list[tuple[str, float]]:
|
||||||
"""(host name, seconds since its agent last reported) per registration.
|
"""(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
|
`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
|
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
|
(#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 = []
|
out = []
|
||||||
for r in regs:
|
for r in regs:
|
||||||
name = host_names.get(r.host_id)
|
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:
|
if name is None or seen is None:
|
||||||
continue
|
continue
|
||||||
if watching_since is not None:
|
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]))
|
select(Host.id, Host.name).where(Host.id.in_([r.host_id for r in regs]))
|
||||||
)).all())
|
)).all())
|
||||||
batch = MetricBatch()
|
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,
|
batch.add(source_module="host_agent", resource_name=name,
|
||||||
metric_name="seconds_since_seen", value=seconds, recorded_at=now)
|
metric_name="seconds_since_seen", value=seconds, recorded_at=now)
|
||||||
await batch.record(session)
|
await batch.record(session)
|
||||||
|
|||||||
@@ -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("h2", NOW - timedelta(seconds=20), NOW - timedelta(days=9)),
|
||||||
FakeReg("h3", None, 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)]
|
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) == {}
|
||||||
|
|||||||
Reference in New Issue
Block a user