**Phase 05 final pass — all criteria met; whole project 100 % green.**
Verified (live upsd + isolated simulator):
- Real `apc`/`cyberpower`: Charge/Load/Runtime are the card's three largest elements (38.4 px vs 15.2 px next), coloured only by API `severity` — live right now 100 % ok / 79.0 % **warn** / 5m **fail**; glyph fill = charge (100/100 viewBox units, `--ok` token), `<title>` "apc: Charge 100 percent, on line"; SIMULATED hidden; battery °C `n/a` uncoloured; every button disabled with its reason; `confirm_text: DANGER` on power-cutting commands; **0 non-GET requests** → `data/logs/ups-verify-live-{card,full}.png`.
- Simulator on `:8091` (own `/tmp` DB, killed after): caution dialog → Cancel, dangerous dialog → Run disabled until `DANGER` → Cancel, **0 POSTs**; one deliberate quick test *to the sim only* flipped the card to `OB` (glyph `stroke-dasharray="7 5"`, "on battery", health "discharging, on battery") then `OL CHRG` (bolt) then `OL` → `ups-verify-sim-{dialog-caution,dialog-danger,onbattery-button,onbattery-page,charging-button}.png`; glyph matrix `ups-glyph-*.png` (100/mid/low/unknown/empty/unrated, dark/light/200 %) present; `grep -c "function battery"` = 1.
Defects found in earlier work and fixed:
1. **`poller.py` could stop polling in silence** — 4 of 6 dev-server sources had frozen `attempts` (ages 12–38 min) while `/api/health` still said `ok: true`: the store-write half of `run_once` was outside the `try`, and a dead task's exception is never retrieved. Now `_commit()` moves `last_ok` only after the write lands, `_store_refused()` reports it (`ok:false`, real reason, one `store-error` event + one `recording` on recovery, payload kept), and `_loop()` catches anything that escapes and keeps polling — 4 new tests in `tests/test_poller.py`.
2. **`nut_sim.py` (modified by this phase) sat at 83 % coverage**; its whole command path was untested. Added tests (every advertised command implemented, unknown → `ValueError`, alarms → card + `assess()` fail, `NUT_SIMULATE` truthy rule) and fixed two model lies: `beeper.*` answered OK while changing nothing (now publishes `ups.beeper.status` enabled/muted/disabled) and a finished self-test never wrote `ups.test.result` (aborted writes none). → 100 %.
3. `nut_sim.from_env()` was dead code duplicating `app._truthy`; `app.py` now builds the simulator through it, so the enable gate lives once.
Tests / lint (exact): `bash .agents/validate.sh` → **EXIT=0** — `uv run pytest --cov --cov-fail-under=94` **543 passed, 8 skipped, coverage 97.91 %**; `uv run ruff check src tests agent` clean; `uv run pyright` 0 errors; `node --check` clean; repo hygiene clean. `uv run pytest -m live --live` **with `.env.dev` sourced → 8 passed** (one earlier run: 2 transient `9121/snapshot timed out` against the 4 s `HOST_TIMEOUT`; three later runs 8/8). `uv pip list --outdated` empty. Dev server restarted on the final code: `health ok`, 6/6 sources fresh.
Docs: AGENTS.md — invariant 4 extended ("nothing may stop polling in silence" + store-refusal semantics), `poller.py`/`nut_sim.py` responsibility lines, 533→543 and 96.9 %→97.9 %, "~97 %"→"~98 %". README.md — poller bullet gained the same guarantee, Testing gained "source `.env.dev` before `-m live --live`" (bare runs skip 7 of 8 live tests, which reads like a pass), Battery-test section gained the `deploy/nut-sudoers` install line and the read-before-write warning.
Notes/deviations: no live instant command was ever sent to real hardware (the four gates leave them disabled — AGENTS gap 1 unchanged); the on-battery proof was driven through the real button against `NUT_SIMULATE=1`, which is stronger than the NOTES hand-driven states. `NOTES-verify.md` under `todo/` left untouched per instructions. Next phase: **none** — 05 is the last in the PLAN.md roadmap.
326 lines
14 KiB
Python
326 lines
14 KiB
Python
"""The poll loop: isolation, last-good-value, and events that mark transitions only.
|
|
|
|
These three behaviours are why the dashboard can be trusted when something is broken, so
|
|
they are asserted directly rather than through HTTP:
|
|
|
|
* a source that throws must not take the loop, the hub, or its neighbours down;
|
|
* a failed poll keeps the previous payload and is marked stale — never zeroed;
|
|
* ok→fail and fail→ok each write exactly one event; 500 more failures write nothing;
|
|
* maintenance failing is logged, because a silent rollup failure means every long-window
|
|
chart is quietly empty (that bug is what the logging was added for).
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import asyncio
|
|
import logging
|
|
import sqlite3
|
|
import time
|
|
from collections.abc import Iterator
|
|
from typing import Any
|
|
|
|
import pytest
|
|
|
|
from dashboards.poller import Hub, Job, Result
|
|
from dashboards.rates import RateEstimator
|
|
from dashboards.store import Event, Sample, SampleStore
|
|
|
|
|
|
@pytest.fixture
|
|
def store(tmp_path: Any) -> Iterator[SampleStore]:
|
|
instance = SampleStore(tmp_path / "poller.sqlite3")
|
|
try:
|
|
yield instance
|
|
finally:
|
|
instance.close()
|
|
|
|
|
|
def ok_result(value: float = 1.0) -> Result:
|
|
return Result(payload={"value": value},
|
|
samples=[Sample("host", "gw", "cpu.usage_pct", value, time.time())])
|
|
|
|
|
|
async def failing() -> Result:
|
|
raise ConnectionError("agent is down")
|
|
|
|
|
|
async def test_a_successful_poll_stores_payload_samples_and_health(store) -> None:
|
|
job = Job("host:gw", "system", "gw", 0.5, lambda: asyncio.sleep(0, ok_result(7.0)))
|
|
outcome = await job.run_once(store)
|
|
assert outcome is True, job.state.error
|
|
assert job.state.ok is True and job.state.error is None
|
|
assert job.state.payload == {"value": 7.0}
|
|
assert job.state.successes == 1 and job.state.samples_written == 1
|
|
assert job.state.latency_ms is not None
|
|
assert store.recent_events(limit=5) == [], "a first successful poll is not a recovery"
|
|
|
|
|
|
async def test_a_failing_poll_keeps_the_last_good_payload(store) -> None:
|
|
"""The UI shows `stale 12s` against real numbers; it must not show zeros or n/a."""
|
|
job = Job("host:gw", "system", "gw", 0.5, lambda: asyncio.sleep(0, ok_result(7.0)))
|
|
await job.run_once(store)
|
|
job.fn = failing
|
|
assert await job.run_once(store) is False
|
|
assert job.state.ok is False
|
|
assert job.state.payload == {"value": 7.0}, "a dead host must not blank its last values"
|
|
assert job.state.error == "ConnectionError: agent is down"
|
|
assert job.state.as_json()["age_seconds"] is not None
|
|
|
|
|
|
async def test_transitions_write_one_event_each_and_spam_writes_none(store) -> None:
|
|
job = Job("host:gw", "system", "gw", 0.5, lambda: asyncio.sleep(0, ok_result()),
|
|
grace_failures=1)
|
|
await job.run_once(store)
|
|
job.fn = failing
|
|
for _ in range(5):
|
|
await job.run_once(store)
|
|
events = store.recent_events(limit=50)
|
|
down = [event for event in events if event.kind == "unreachable"]
|
|
assert len(down) == 1, "five consecutive failures must not log five events"
|
|
assert down[0].host == "gw", "events carry the display label, not the internal job key"
|
|
assert down[0].severity == "error"
|
|
|
|
job.fn = lambda: asyncio.sleep(0, ok_result())
|
|
await job.run_once(store)
|
|
events = store.recent_events(limit=50)
|
|
up = [event for event in events if event.kind == "reachable"]
|
|
assert len(up) == 1
|
|
assert up[0].message == "gw is answering again after 5 failures"
|
|
|
|
|
|
async def test_one_failure_reads_as_a_failure_not_failures(store) -> None:
|
|
job = Job("host:gw", "system", "gw", 0.5, lambda: asyncio.sleep(0, ok_result()))
|
|
await job.run_once(store)
|
|
job.fn = failing
|
|
await job.run_once(store)
|
|
job.fn = lambda: asyncio.sleep(0, ok_result())
|
|
await job.run_once(store)
|
|
up = [event for event in store.recent_events(limit=50) if event.kind == "reachable"]
|
|
assert up[0].message.endswith("after 1 failure")
|
|
|
|
|
|
async def test_grace_allows_a_blip_without_an_event(store) -> None:
|
|
"""One failure inside the grace window must not page anybody."""
|
|
job = Job("host:gw", "system", "gw", 0.5, failing, grace_failures=2)
|
|
await job.run_once(store)
|
|
assert store.recent_events(limit=10) == []
|
|
await job.run_once(store)
|
|
events = store.recent_events(limit=10)
|
|
assert [event.kind for event in events] == ["unreachable"]
|
|
assert events[0].severity == "warn", "never answered is a config problem, not an outage"
|
|
assert "never answered" in events[0].message
|
|
for _ in range(4):
|
|
await job.run_once(store)
|
|
assert len(store.recent_events(limit=10)) == 1, "one event per outage, not per poll"
|
|
|
|
|
|
async def test_a_slow_poll_never_overlaps_itself(store) -> None:
|
|
calls = 0
|
|
gate = asyncio.Event()
|
|
|
|
async def slow() -> Result:
|
|
nonlocal calls
|
|
calls += 1
|
|
await gate.wait()
|
|
return ok_result()
|
|
|
|
job = Job("host:gw", "system", "gw", 0.5, slow)
|
|
first = asyncio.create_task(job.run_once(store))
|
|
await asyncio.sleep(0.01)
|
|
assert await job.run_once(store) is False, "an overlapping poll double-counts rates"
|
|
gate.set()
|
|
assert await first is True
|
|
assert calls == 1
|
|
|
|
|
|
async def test_a_counter_that_resets_is_reported_not_silently_negative() -> None:
|
|
"""The reset path is what ships: an agent restart must not read as negative throughput."""
|
|
rates = RateEstimator(span=10.0)
|
|
first, _ = rates.rate("cpu.total", 1000.0, now=100.0)
|
|
assert first is None, "one sample cannot produce a rate"
|
|
second, window = rates.rate("cpu.total", 2000.0, now=110.0)
|
|
assert second == pytest.approx(100.0) and window == pytest.approx(10.0)
|
|
after, _ = rates.rate("cpu.total", 5.0, now=120.0) # agent restarted
|
|
assert after is None, "a reset counter must read n/a, never as negative throughput"
|
|
|
|
|
|
async def test_the_hub_runs_every_job_and_stops_cleanly(store) -> None:
|
|
counts = {"a": 0, "b": 0}
|
|
|
|
async def good(key: str) -> Result:
|
|
counts[key] += 1
|
|
return ok_result()
|
|
|
|
hub = Hub(store)
|
|
hub.add(Job("host:a", "system", "a", 0.5, lambda: good("a")))
|
|
hub.add(Job("host:b", "system", "b", 0.5, failing))
|
|
hub.add(Job("llm:off", "llm", "off", 0.5, failing, enabled=False))
|
|
hub.start()
|
|
try:
|
|
await asyncio.sleep(1.2)
|
|
finally:
|
|
await hub.stop()
|
|
assert counts["a"] >= 2, "a neighbour that throws must not slow the healthy one"
|
|
states = {state["key"]: state for state in hub.states()}
|
|
assert states["host:a"]["ok"] is True
|
|
assert states["host:b"]["ok"] is False
|
|
assert states["llm:off"]["configured"] is False, "not configured is not the same as broken"
|
|
assert hub.jobs["host:b"].state.failures >= 1
|
|
|
|
|
|
async def test_states_can_be_filtered_to_one_dashboard(store) -> None:
|
|
hub = Hub(store)
|
|
hub.add(Job("host:a", "system", "a", 0.5, lambda: asyncio.sleep(0, ok_result())))
|
|
hub.add(Job("nut", "ups", "NUT server", 0.5, lambda: asyncio.sleep(0, ok_result())))
|
|
assert [s["key"] for s in hub.states("ups")] == ["nut"]
|
|
|
|
|
|
async def test_maintenance_failure_is_logged_not_swallowed(store, monkeypatch,
|
|
caplog: pytest.LogCaptureFixture) -> None:
|
|
"""A broken rollup means every chart past the raw window is empty. Retrying quietly
|
|
turned a data-loss bug into nothing at all — this is the regression that added the log."""
|
|
def boom() -> dict[str, int]:
|
|
raise RuntimeError("no such table: sample_rollup")
|
|
|
|
monkeypatch.setattr(store, "maintain", boom)
|
|
hub = Hub(store)
|
|
task = asyncio.create_task(hub._maintain_loop(interval=0.02))
|
|
try:
|
|
with caplog.at_level(logging.ERROR, logger="dashboards.poller"):
|
|
await asyncio.sleep(0.15)
|
|
finally:
|
|
task.cancel()
|
|
with pytest.raises(asyncio.CancelledError):
|
|
await task
|
|
assert "store maintenance failed" in caplog.text
|
|
assert "no such table" in caplog.text, "the log line must carry the real reason"
|
|
|
|
|
|
async def test_maintenance_runs_from_the_hub_and_records_its_pass(store) -> None:
|
|
hub = Hub(store)
|
|
calls = []
|
|
store.maintain = lambda: calls.append(1) or {"to_minute": 0, "to_hour": 0, # type: ignore[method-assign]
|
|
"pruned": 0}
|
|
task = asyncio.create_task(hub._maintain_loop(interval=0.02))
|
|
try:
|
|
await asyncio.sleep(0.1)
|
|
finally:
|
|
task.cancel()
|
|
with pytest.raises(asyncio.CancelledError):
|
|
await task
|
|
assert calls, "the maintenance loop must actually call maintain"
|
|
|
|
|
|
async def test_events_written_by_a_job_land_in_the_store(store) -> None:
|
|
event = Event(1_700_000_000.0, "ups", "cyberpower", "status", "warn", "OL → OB")
|
|
job = Job("nut", "ups", "NUT server", 0.5,
|
|
lambda: asyncio.sleep(0, Result(payload={}, events=[event])))
|
|
await job.run_once(store)
|
|
assert [e.message for e in store.recent_events(limit=5)] == ["OL → OB"]
|
|
|
|
|
|
class RefusingStore(SampleStore):
|
|
"""A store that turns good polls away for a while — what SQLite does when it is locked.
|
|
|
|
This is not hypothetical: the dev server lost four sources at once this way, and nothing
|
|
in the UI, the health record or the event log said so.
|
|
"""
|
|
|
|
def __init__(self, path: Any, refusals: int) -> None:
|
|
super().__init__(path)
|
|
self.refusals = refusals
|
|
|
|
def add_many(self, samples: Any) -> int:
|
|
if self.refusals > 0:
|
|
self.refusals -= 1
|
|
raise sqlite3.OperationalError("database is locked")
|
|
return super().add_many(samples)
|
|
|
|
|
|
async def test_a_store_that_refuses_a_good_poll_is_reported_not_survived_silently(
|
|
tmp_path: Any, caplog: pytest.LogCaptureFixture) -> None:
|
|
"""A source whose history is not landing is broken, and must read that way.
|
|
|
|
The upstream answered, so the freshest payload stays on the card; everything else says the
|
|
opposite of healthy — `ok: false`, the real reason in `error`, and `last_ok` frozen so the
|
|
page ages the numbers instead of calling a write failure a live source.
|
|
"""
|
|
store = RefusingStore(tmp_path / "locked.sqlite3", refusals=0)
|
|
try:
|
|
job = Job("nut", "ups", "NUT server", 0.5, lambda: asyncio.sleep(0, ok_result(42.0)))
|
|
assert await job.run_once(store) is True, "the first poll writes before the store turns nasty"
|
|
store.refusals = 1
|
|
with caplog.at_level(logging.ERROR, logger="dashboards.poller"):
|
|
assert await job.run_once(store) is False
|
|
assert job.state.ok is False
|
|
assert job.state.error and "database is locked" in job.state.error
|
|
assert job.state.payload == {"value": 42.0}, "a refused write must not blank the card"
|
|
assert job.state.last_ok is not None and job.state.last_attempt is not None
|
|
assert job.state.last_attempt >= job.state.last_ok
|
|
assert "could not record a good poll" in caplog.text
|
|
finally:
|
|
store.close()
|
|
|
|
|
|
async def test_a_refusing_store_keeps_the_loop_polling_and_says_so_once(
|
|
tmp_path: Any, caplog: pytest.LogCaptureFixture) -> None:
|
|
store = RefusingStore(tmp_path / "locked.sqlite3", refusals=2)
|
|
try:
|
|
job = Job("nut", "ups", "NUT server", 0.5, lambda: asyncio.sleep(0, ok_result()))
|
|
with caplog.at_level(logging.ERROR, logger="dashboards.poller"):
|
|
for _ in range(3):
|
|
await job.run_once(store)
|
|
assert job.state.ok is True, "the third poll got through, so the source is ok again"
|
|
assert job.state.last_ok is not None
|
|
kinds = [e.kind for e in store.recent_events(limit=10)]
|
|
assert kinds.count("store-error") == 1, "one line per outage, not one per refused poll"
|
|
assert "recording" in kinds, "the recovery must be as visible as the failure"
|
|
assert "could not record a good poll" in caplog.text
|
|
assert "database is locked" in caplog.text, "the log must carry the real reason"
|
|
finally:
|
|
store.close()
|
|
|
|
|
|
async def test_last_good_payload_survives_a_refused_write(tmp_path: Any) -> None:
|
|
"""Invariant 4 with the store, not the upstream, at fault: keep the numbers, age them."""
|
|
store = RefusingStore(tmp_path / "locked.sqlite3", refusals=99)
|
|
try:
|
|
job = Job("nut", "ups", "NUT server", 0.5, lambda: asyncio.sleep(0, ok_result(42.0)))
|
|
await job.run_once(store)
|
|
assert job.state.payload == {"value": 42.0}, "a refused write must not blank the card"
|
|
assert job.state.last_ok is None, "and it must not be called current either"
|
|
assert job.state.error and "the store refused it" in job.state.error
|
|
assert job.state.attempts == 1
|
|
finally:
|
|
store.close()
|
|
|
|
|
|
async def test_an_unexpected_error_cannot_kill_the_poll_loop(
|
|
store, caplog: pytest.LogCaptureFixture) -> None:
|
|
"""The task *is* a source's polling; an escaping bug must not retire it in silence.
|
|
|
|
Four dev-server sources once stopped advancing `attempts` while `/api/health` went on
|
|
reporting them `ok` — an exception that escaped the loop body, retrieved by nobody. This
|
|
guard is the reason that class of failure can only ever be loud.
|
|
"""
|
|
job = Job("host:gw", "system", "gw", 0.5, lambda: asyncio.sleep(0, ok_result()))
|
|
real = job.run_once
|
|
calls = 0
|
|
|
|
async def exploding(incoming: SampleStore) -> bool:
|
|
nonlocal calls
|
|
calls += 1
|
|
if calls == 1:
|
|
raise RuntimeError("a bug in the bookkeeping")
|
|
return await real(incoming)
|
|
|
|
job.run_once = exploding # type: ignore[method-assign]
|
|
with caplog.at_level(logging.ERROR, logger="dashboards.poller"):
|
|
job.start(store)
|
|
try:
|
|
await asyncio.sleep(1.4) # the interval floor is 0.5s, so this is ~3 polls
|
|
finally:
|
|
await job.stop()
|
|
assert calls >= 2, "the loop must still be calling the poll body after the escape"
|
|
assert job.state.attempts >= 1 and job.state.ok is True, "and the next poll must have landed"
|
|
assert "raised outside its own error handling" in caplog.text
|