diff --git a/goodwe_controller/DECISIONS/SAFETY-112-waiting-for-home-assistant.md b/goodwe_controller/DECISIONS/SAFETY-112-waiting-for-home-assistant.md new file mode 100644 index 0000000..abbee27 --- /dev/null +++ b/goodwe_controller/DECISIONS/SAFETY-112-waiting-for-home-assistant.md @@ -0,0 +1,98 @@ +# SAFETY-112 - control waits for Home Assistant to finish starting + +**Status: for review.** Tests: `test_safety112.py`, `test_messages.py`. +Control is unchanged. The add-on now says plainly that it is waiting. + +## Cause + +The Supervisor's proxy refuses every add-on request with 502 until Core's +state is `RUNNING`. The add-on reads every battery reading and writes every +power request through that proxy, so it cannot control until then. Readings +that are already live inside Home Assistant do not help. + +Source, Supervisor 2026.08.0 (the image the live site ran at CFG-04): + +- `supervisor/api/proxy.py`, `APIProxy.api()` (REST, used for reads and + `number.set_value`) and `APIProxy.websocket()` both start with + `if not await self.sys_homeassistant.api.check_api_state(): raise HTTPBadGateway`. +- `supervisor/homeassistant/api.py`, `check_api_state()` returns + `state.core_state == "RUNNING" or state.offline_db_migration`. The state + comes from Core's `/api/core/state`. +- Upstream `main` has the same gate in both handlers (read 2026-10-13). +- A Core restart restarts only the Core container + (`homeassistant/core.py`, `restart()`). The add-on keeps running. + +The add-on itself has no wait. Nothing in `app/` reads Core's state or waits +for an event. The loop reads its inputs every second, a 502 gives `None`, +and missing inputs give 0 W. P1 backoff is not involved: the live site reads +the meter straight from the HomeWizard (`homewizard_local`), not through Home +Assistant. + +## Measured + +Repro stack `safety112-*`, all removed afterwards: + +- Home Assistant 2026.9.4, as live. +- A test integration whose `async_setup` sleeps, so Core stays `NOT_RUNNING`. +- A fake meter and two fake inverters that update every 2 s from load. +- The Supervisor's own `APIProxy` and `HomeAssistantAPI` from the 2026.08.0 + image. Only the add-on token lookup, Core's access token and the container + check are stubbed. +- The add-on on `meter_source: homewizard_local` against a fake HomeWizard. + +Times are seconds after `docker restart` of Home Assistant: + +| run | Core `NOT_RUNNING` | entities live in HA | Core `RUNNING` | proxy 502 | first write | wait from live readings | +|---|---|---|---|---|---|---| +| base 3050fa5, N=2 | 13.1 | 17.1 | 253.1 | 0.9-252.7 (1 132 requests) | 254.7 | 237.6 | +| base 3050fa5, N=1 | 13.1 | 18.1 | 256.1 | 1.5-255.1 (573 requests) | 257.2 | 239.1 | +| this change, N=2 | 12.2 | 17.2 | 313.2 | 1.4-312.5 (1 406 requests) | 317.6 | 300.4 | +| this change, N=1 | 12.2 | 17.2 | 255.2 | 1.2-254.1 (571 requests) | 257.1 | 240.0 | + +The first write comes 1.0-4.4 s after `RUNNING`, so the whole wait is the +proxy's. With a 400 s sleep Core moved on at 300.88 s on its own (bootstrap's +stage timeout), so one slow integration holds the start for about 5 minutes +at most. The live start took 414 s. + +Before this change the page said "Not ready — Battery level: no usable +reading", which sends the reader to Developer Tools for an entity that is +fine. + +## Rule + +1. No way around the Supervisor. The add-on still talks to Home Assistant + only through the proxy. +2. While the proxy does not answer on the API (`hass.OUTAGE.waiting()`), the + first status row is red: "Home Assistant is not answering, perhaps it is + still starting. Control resumes by itself when it answers." The banner + reads "Not ready — Waiting for Home Assistant to finish starting". The Home + pill reads "Waiting for Home Assistant", in English and Dutch. +3. A safety stop, a stalled control loop or shadow mode keeps its own banner + and state over the wait, because none of them clears by itself. +4. The log has one WARNING when Home Assistant stops answering, an INFO line + every 5 minutes while it is down, and an INFO line with the length of the + wait when it answers again. +5. Only the API counts. The meter websocket alone does not, because the meter + has its own row. + +## Why it is safe + +The change is text only. `cycle()`, the writes, the heartbeat, the stand-down +on shutdown and every watchdog are untouched. `test_safety112.py` part 3 shows +the same targets and writes with the flag on and off, for N=1 and N=2. + +## Open, for the owner + +The add-on cannot control while Home Assistant starts. These ways around it +were not taken: + +- **Talk to Core directly with a long-lived token** (`http://homeassistant:8123`). + Core's own API answers while `NOT_RUNNING`. In the repro `/api/core/state` + answered from 12-13 s, and a direct `number.set_value` 10 s into + `NOT_RUNNING` returned 200 and set the value. The cost is a secret stored + at every client site, which `hass.py` exists to avoid. +- **Talk to the control board directly** (ESPHome native API), so control + does not need Home Assistant at all. This is a large change. +- **Remove the slow start at the site.** On 2026-10-12 the Solis + integration's discovery held the start. Fixing or disabling it shortens the + wait there, but not on a client site with another slow integration. diff --git a/goodwe_controller/DOCS.md b/goodwe_controller/DOCS.md index cab7a8c..18876e0 100644 --- a/goodwe_controller/DOCS.md +++ b/goodwe_controller/DOCS.md @@ -3478,6 +3478,7 @@ for a new install*. | Row starts with | What it tells you | |---|---| +| Home Assistant is not answering | Home Assistant is not passing readings or power requests on, usually because it is still starting. The add-on cannot control until then. It resumes by itself. Nothing to do unless it lasts. | | Control | When control last ran. Red when it has stopped running: the control board then sets the inverter to 0 W. | | Meter | The grid reading, its age, how many readings were refused, and how long its value has not changed. Just after a start it is amber and *waiting for the first reading*. Red means no reading for longer than the limit. | | Stuck-meter check | Whether the add-on can warn you about a stuck meter. | @@ -3536,6 +3537,13 @@ reason code, and its full figures are on the DEBUG line right after it and in (TARIFF-11), in words. - **Solar production** reads `pv_entity` or `pv_entities` (TEL-11/12). The *Reversed-sign solar entities* setting is `pv_invert_entities` (TEL-14). +- **Home Assistant is not answering** (SAFETY-112): the Supervisor answers + 502 to every add-on read, write and websocket until Home Assistant is + RUNNING, even when its entities are already live. A slow integration at + start-up therefore holds control for as long as it holds Home Assistant's + start. The log has one WARNING, a "Still waiting" INFO line every 5 + minutes and "answers again after …" at the end. See + `DECISIONS/SAFETY-112-waiting-for-home-assistant.md`. - **Shadow mode** (SAFETY-10): the banner turns red when a latch is up (circulating power, or a site or per-inverter sign trip), and that latch keeps its own red row. diff --git a/goodwe_controller/app/hass.py b/goodwe_controller/app/hass.py index 2f75fa7..d32ec0b 100644 --- a/goodwe_controller/app/hass.py +++ b/goodwe_controller/app/hass.py @@ -11,6 +11,8 @@ import time import aiohttp +from . import messages + _LOG = logging.getLogger("goodwe.hass") CORE_API = "http://supervisor/core/api" @@ -19,6 +21,7 @@ BAD_STATES = ("unknown", "unavailable", "none", "") # What the Supervisor's proxy answers while Home Assistant restarts. UNAVAILABLE = (502, 503, 504) STATES_TIMEOUT_S = 10 # UX-13's entity list, like every other read here +STILL_WAITING_S = 300 # SAFETY-112: one reminder line per 5 minutes down class Outage: @@ -29,15 +32,30 @@ class Outage: ("502, message='Bad Gateway', url=URL(...)", "Received message 8:1000 is not str"). Now the first channel to fail says it once at WARNING, the raw text goes to DEBUG, and the last channel to recover says so at INFO. + + SAFETY-112: the Supervisor answers 502 for every read, write and + websocket until Home Assistant has finished starting, however live its + entities already are (DECISIONS/SAFETY-112-waiting-for-home-assistant.md). + So an outage also says, every STILL_WAITING_S, that it is still on, and + `waiting()` puts it on the status page. """ def __init__(self): self.down_on = set() + self.since = None # monotonic start of this outage + self._told = None # when the last "still waiting" line went def down(self, channel: str, what: str, detail) -> None: + now = time.monotonic() if not self.down_on: _LOG.warning("Home Assistant is not answering (%s), perhaps it is " - "restarting. The add-on keeps trying.", what) + "still starting. Control waits and resumes by itself.", + what) + self.since = self._told = now + elif now - self._told >= STILL_WAITING_S: + self._told = now + _LOG.info("Still waiting for Home Assistant to finish starting, " + "%s so far.", messages.duration(now - self.since)) self.down_on.add(channel) _LOG.debug("Home Assistant not answering on %s: %s", channel, detail) @@ -45,7 +63,13 @@ class Outage: if channel in self.down_on: self.down_on.discard(channel) if not self.down_on: - _LOG.info("Home Assistant answers again.") + _LOG.info("Home Assistant answers again after %s.", + messages.duration(time.monotonic() - self.since)) + + def waiting(self) -> bool: + """True while Home Assistant's API does not answer. The API, not the + meter websocket: every battery reading and every write rides on it.""" + return "api" in self.down_on OUTAGE = Outage() diff --git a/goodwe_controller/app/homeview.py b/goodwe_controller/app/homeview.py index 6814691..0e2ebfa 100644 --- a/goodwe_controller/app/homeview.py +++ b/goodwe_controller/app/homeview.py @@ -909,13 +909,14 @@ def month_peak(c, now): return out -def state_of(c, level, shadow): +def state_of(c, level, shadow, waiting=False): """One word for the pill and the banner's colour: running, shadow, - stopped, alarm or warning.""" + stopped, alarm, waiting or warning. `waiting`: the red headline is + Home Assistant still starting (SAFETY-112), which needs nobody.""" if shadow: return "shadow" if level == "bad": - return "alarm" + return "waiting" if waiting else "alarm" if not c.auto: return "stopped" if level == "warn": @@ -924,20 +925,22 @@ def state_of(c, level, shadow): def build(c, *, level: str, checks: list, now: datetime | None = None, - lang: str = "en", held: bool | None = None) -> dict: + lang: str = "en", held: bool | None = None, + waiting: bool = False) -> dict: """The structured half of `/status`, in `lang` (UX-13 P5). Pure reads of the controller.""" _LANG[0] = uitext.lang_of(lang) try: - return _build(c, level=level, checks=checks, now=now, held=held) + return _build(c, level=level, checks=checks, now=now, held=held, + waiting=waiting) finally: _LANG[0] = "en" -def _build(c, *, level, checks, now, held=None): +def _build(c, *, level, checks, now, held=None, waiting=False): now = now or datetime.now(timezone.utc) shadow = bool(c.shadow) - kind = state_of(c, level, shadow) + kind = state_of(c, level, shadow, waiting) # A red banner means every inverter is at 0 W (the status cascade), so # nothing is planned until it clears. Shadow mode still plans: it is # what the add-on would do. `held` False: an alarm while control runs @@ -1332,7 +1335,7 @@ def _samples() -> list: out += [("title", mode_word(k)) for k in words["modes"]] out += [("title", mode_house()), ("title", attn_shadow()), ("line", attn_shadow_body())] - for k in ("running", "shadow", "stopped", "alarm", "warning"): + for k in ("running", "shadow", "stopped", "alarm", "waiting", "warning"): out += [("title", pill(k)), ("line", banner_sub(k))] for sh in (False, True): out += [("title", tile_solar(v, s)) for v, s in diff --git a/goodwe_controller/app/main.py b/goodwe_controller/app/main.py index e79fd32..cc47cf5 100644 --- a/goodwe_controller/app/main.py +++ b/goodwe_controller/app/main.py @@ -69,7 +69,7 @@ from . import messages from .freeze import ( FreezeWatchdog, FreezeWatchdogConfig, looks_frozen, rail_unreachable, rail_w, ) -from .hass import CORE_API, HomeAssistant +from .hass import CORE_API, OUTAGE, HomeAssistant # ⚠️ `LINK_STALE_S` IS RE-EXPORTED DELIBERATELY. `live_units()` reasons about it # and two checks read `app.main.LINK_STALE_S` to build a stale link, so the # window an operator would look up here is the one the roster actually uses. @@ -6590,6 +6590,14 @@ class Controller: else: out.append({"ok": True, "warn": False, "id": "controller", "text": messages.row_controller_ran(_pass_age)}) + # SAFETY-112. The headline unless control has stalled: while the + # Supervisor gives 502 (Home Assistant not yet RUNNING) no reading or + # write gets through, and the rows below that need it follow from it. + if OUTAGE.waiting(): + out.insert(1 if out[0]["ok"] is False else 0, + {"ok": False, "warn": False, "id": "home_assistant", + "banner": messages.banner_ha_waiting(), + "text": messages.row_ha_waiting()}) if self.p1_enabled: age = self.p1.published_age_s if (self.p1.stale and self.p1.age_s() is None @@ -7099,7 +7107,7 @@ class Controller: # control goes on, so it neither reads "Not ready" nor holds the page. runs = [c for c in bad if c.get("runs")] bad = [c for c in bad if not c.get("runs")] - running_alarm = False + running_alarm = waiting = False # --- SAFETY-10, AND IT IS FIRST IN THE CASCADE ----------------------- # "The battery is NOT being controlled" is the one sentence on this # page that may never be displaced by another condition. A banner that @@ -7150,6 +7158,10 @@ class Controller: # headline nobody reads. UX-08: without the key, the banner takes # the row's first sentence, so it stays a headline. level, banner = "bad", messages.banner_not_ready(bad[0]) + # SAFETY-112: nothing to do but wait, so Home says that instead + # of "Needs you now". Only when it IS the headline: a safety stop + # above outranks it and still needs a person. + waiting = bad[0].get("id") == "home_assistant" elif not self.auto: level, banner = "warn", messages.banner_stopped() elif runs: @@ -7296,7 +7308,7 @@ class Controller: # fields are served alone (the page then shows the installer details). try: out.update(homeview.build(self, level=level, checks=checks, - lang=lang, held=held)) + lang=lang, held=held, waiting=waiting)) except Exception: # noqa: BLE001 # Once per process at ERROR: the page polls every 3 s. if not getattr(self, "_home_failed", False): diff --git a/goodwe_controller/app/messages.py b/goodwe_controller/app/messages.py index 27f959d..5dd84ea 100644 --- a/goodwe_controller/app/messages.py +++ b/goodwe_controller/app/messages.py @@ -436,6 +436,17 @@ def banner_shadow(latched: bool) -> str: return "Shadow mode: the battery is not controlled. Inverters stay at 0 W." +def banner_ha_waiting() -> str: + """SAFETY-112: the Supervisor passes nothing on until Home Assistant has + finished starting, so the add-on can neither read nor write.""" + return "Waiting for Home Assistant to finish starting" + + +def row_ha_waiting() -> str: + return ("Home Assistant is not answering, perhaps it is still starting. " + "Control resumes by itself when it answers.") + + # Rows: control and the meter. "Control" is what the add-on does, as in # "start control" (STYLE.md section 4). def row_controller_starting() -> str: @@ -1055,6 +1066,10 @@ def status_samples() -> list: ("banner_setup_only", None, banner_setup_only()), ("row_setup_only", AMBER, row_setup_only()), ("banner_shadow", None, banner_shadow(True)), + ("banner_not_ready", None, banner_not_ready( + {"text": row_ha_waiting(), "banner": banner_ha_waiting()})), + ("banner_ha_waiting", None, banner_ha_waiting()), + ("row_ha_waiting", RED, row_ha_waiting()), ("row_controller_starting", GREEN, row_controller_starting()), ("row_controller_ran", GREEN, row_controller_ran(2)), ("row_controller_stalled", RED, row_controller_stalled(45, 30)), diff --git a/goodwe_controller/app/static/app.js b/goodwe_controller/app/static/app.js index e5354b8..06f201a 100644 --- a/goodwe_controller/app/static/app.js +++ b/goodwe_controller/app/static/app.js @@ -100,7 +100,7 @@ } function renderPill() { const st = S.state || null; - const dot = st ? ({ running: "", shadow: " warn", stopped: " warn", warning: " warn", alarm: " bad" }[st.kind] ?? " warn") + const dot = st ? ({ running: "", shadow: " warn", stopped: " warn", warning: " warn", alarm: " bad", waiting: " warn" }[st.kind] ?? " warn") : (S.level === "ok" ? "" : S.level === "bad" ? " bad" : " warn"); const words = st ? [st.pill, st.ran].filter(Boolean).join(". ") : S.setup_only === true ? t("setup_only.name") : S.banner; $("#pill").replaceChildren(h("span", { class: "dot" + dot, "aria-hidden": "true" }), h("span", {}, words)); @@ -399,7 +399,7 @@ $("#batt-how").hidden = !modes; const docs = $("#batt-docs"); if (S.control && S.control.docs_url) { docs.href = S.control.docs_url; docs.hidden = false; } else docs.hidden = true; - if (S.state && ["shadow", "stopped", "alarm"].includes(S.state.kind)) banner($("#batt-banner"), S.level, S.state.pill, S.state.sub, S.level === "bad" ? "alert" : null); + if (S.state && ["shadow", "stopped", "alarm", "waiting"].includes(S.state.kind)) banner($("#batt-banner"), S.level, S.state.pill, S.state.sub, S.level === "bad" ? "alert" : null); else $("#batt-banner").replaceChildren(); keepFocus(() => { $("#bcards").replaceChildren(...S.batteries.map(batteryCard)); diff --git a/goodwe_controller/app/ui_text/en.json b/goodwe_controller/app/ui_text/en.json index 40b6f28..7d26926 100644 --- a/goodwe_controller/app/ui_text/en.json +++ b/goodwe_controller/app/ui_text/en.json @@ -267,6 +267,7 @@ "shadow": "Shadow mode", "stopped": "Stopped", "alarm": "Needs you now", + "waiting": "Waiting for Home Assistant", "warning": "Running, with a warning" }, "banner_sub": { @@ -274,6 +275,7 @@ "shadow": "The plans below say what the add-on would do.", "stopped": "Start control below when you are ready.", "alarm": "See Needs attention below for what to do.", + "waiting": "Control resumes by itself when Home Assistant answers.", "warning": "See Needs attention below." }, "tile": { @@ -431,6 +433,7 @@ "stopped": "Control is stopped. Every inverter is at 0 W." }, "attn": { + "home_assistant": "Home Assistant is not answering", "controller": "Control is not running", "meter": "Meter reading", "meter_frozen": "Meter reading may be stuck", diff --git a/goodwe_controller/app/ui_text/nl.json b/goodwe_controller/app/ui_text/nl.json index 2748196..69f7a42 100644 --- a/goodwe_controller/app/ui_text/nl.json +++ b/goodwe_controller/app/ui_text/nl.json @@ -230,8 +230,8 @@ "zero_held": "Op 0 W gehouden", "zero_going": "Gaat naar 0 W", "verdict": {"held": "Op 0 W gehouden", "stopped": "Gestopt", "cycle": "Vandaag maandelijkse cyclus", "trade": "Handelt op prijs", "house": "Volgt het huis"}, - "pill": {"running": "Actief", "shadow": "Schaduwmodus", "stopped": "Gestopt", "alarm": "Heeft u nu nodig", "warning": "Actief, met een waarschuwing"}, - "banner_sub": {"running": "De batterijen volgen het plan hieronder.", "shadow": "De plannen hieronder tonen wat de add-on zou doen.", "stopped": "Start de regeling hieronder als u klaar bent.", "alarm": "Zie Vraagt aandacht hieronder voor wat u moet doen.", "warning": "Zie Vraagt aandacht hieronder."}, + "pill": {"running": "Actief", "shadow": "Schaduwmodus", "stopped": "Gestopt", "alarm": "Heeft u nu nodig", "waiting": "Wacht op Home Assistant", "warning": "Actief, met een waarschuwing"}, + "banner_sub": {"running": "De batterijen volgen het plan hieronder.", "shadow": "De plannen hieronder tonen wat de add-on zou doen.", "stopped": "Start de regeling hieronder als u klaar bent.", "alarm": "Zie Vraagt aandacht hieronder voor wat u moet doen.", "waiting": "De regeling gaat vanzelf verder zodra Home Assistant antwoordt.", "warning": "Zie Vraagt aandacht hieronder."}, "tile": {"not_set_up": "Niet ingesteld", "no_reading": "Geen meting", "producing": "Produceert", "not_producing": "Produceert niet", "needs_solar": "Zonnemeting nodig", "not_adding_up": "Metingen kloppen niet", "using": "Verbruikt", "taking": "Neemt af van het net", "feeding": "Injecteert", "balanced": "In evenwicht", "giving": "Levert stroom", "charging": "Laadt", "resting": "Rust"}, "now": { "no_reading": "Geen meting van deze batterij.", @@ -354,6 +354,7 @@ "peak_not_covered": "Geen piekgrens: deze meter meet geen kwartieren.", "control": {"shadow": "Schaduwmodus: elke omvormer blijft op 0 W.", "running": "De regeling is actief.", "stopped": "De regeling is gestopt. Elke omvormer staat op 0 W."}, "attn": { + "home_assistant": "Home Assistant antwoordt niet", "controller": "Regeling is niet actief", "meter": "Meting van de meter", "meter_frozen": "Meter staat mogelijk vast", diff --git a/goodwe_controller/test_messages.py b/goodwe_controller/test_messages.py index f6cd1c2..c0fd4ae 100644 --- a/goodwe_controller/test_messages.py +++ b/goodwe_controller/test_messages.py @@ -1469,8 +1469,11 @@ _info = [r.getMessage() for r in _out if r.levelno == logging.INFO] check(f"a Home Assistant restart is one plain WARNING line, and one INFO line " f"when both connections are back ({_warn}, {_info})", _warn[:1] == ["Home Assistant is not answering (error 502), perhaps it " - "is restarting. The add-on keeps trying."] - and _info == ["Home Assistant answers again."] and len(_warn) == 2) + "is still starting. Control waits and resumes by itself."] + and len(_info) == 1 + and re.fullmatch(r"Home Assistant answers again after \d+ seconds\.", + _info[0]) is not None and len(_warn) == 2) +# SAFETY-112's reminder and its timing are graded in test_safety112.py. check("...and the library's own text is kept, at DEBUG", any("Received message 8:1000" in r.getMessage() for r in _out if r.levelno == logging.DEBUG) diff --git a/goodwe_controller/test_safety112.py b/goodwe_controller/test_safety112.py new file mode 100644 index 0000000..bdb6a9b --- /dev/null +++ b/goodwe_controller/test_safety112.py @@ -0,0 +1,332 @@ +"""SAFETY-112: waiting for Home Assistant to finish starting. `python3 -B test_safety112.py` + +The Supervisor answers 502 to every add-on read, write and websocket until +Home Assistant is RUNNING (DECISIONS/SAFETY-112-waiting-for-home-assistant.md), +so the add-on cannot control then. This file grades what it says meanwhile: + +1. The log: one WARNING when Home Assistant stops answering, one INFO line + every 5 minutes while it stays down, one INFO line with the wait when it + answers again. Only the API channel counts as "waiting". +2. The status page, N=1 and N=2: the waiting row is first and red, and is the + banner. Home says "Waiting for Home Assistant" in English and Dutch, not + "Needs you now", unless a safety stop outranks it. +3. Control is unchanged: the same readings give the same writes with the + waiting flag on or off. + +Mutating a module this file grades? Read MUTATION.md first (purge __pycache__). +""" + +import asyncio +import logging +from types import SimpleNamespace + +from app import hass as _hass +from app import messages +from app.main import Controller + +fails = [] + + +def check(name, cond): + print(f" {'ok ' if cond else 'FAIL'} {name}") + if not cond: + fails.append(name) + + +class _Rec(logging.Handler): + def __init__(self): + super().__init__(logging.DEBUG) + self.records = [] + + def emit(self, record): + self.records.append(record) + + +def captured(fn): + rec, lg = _Rec(), logging.getLogger("goodwe.hass") + old = lg.level + lg.addHandler(rec) + lg.setLevel(logging.DEBUG) + try: + fn() + finally: + lg.removeHandler(rec) + lg.setLevel(old) + return [(r.levelno, r.getMessage()) for r in rec.records + if r.levelno >= logging.INFO] + + +class Clock: + """`hass.time` stand-in: only `monotonic` is read by Outage.""" + + def __init__(self): + self.t = 1000.0 + + def monotonic(self): + return self.t + + +def with_clock(fn): + clock, real = Clock(), _hass.time + _hass.time = SimpleNamespace(monotonic=clock.monotonic) + try: + return fn(clock) + finally: + _hass.time = real + + +# --------------------------------------------------------------------------- # +print("1. the log while Home Assistant does not answer") +W, I = logging.WARNING, logging.INFO + + +def outage(clock): + o = _hass.Outage() + o.down("api", "error 502", "read sensor.x: 502") + for t in (1, 60, 299): + clock.t = 1000 + t + o.down("api", "error 502", "read sensor.x: 502") + clock.t = 1300 + o.down("api", "error 502", "") # 5 minutes: the first reminder + clock.t = 1301 + o.down("websocket", "the meter connection closed", "") + clock.t = 1599 + o.down("api", "error 502", "") # 299 s after the reminder: none + clock.t = 1600 + o.down("api", "error 502", "") # 10 minutes: the second + clock.t = 1640 + o.up("api") + o.up("websocket") # 640 s in all + clock.t = 2000 + o.down("api", "no connection", "") # a new outage starts afresh + clock.t = 2030 + o.up("api") + + +lines = with_clock(lambda c: captured(lambda: outage(c))) +check(f"one WARNING per outage, in plain words ({lines})", + [m for lv, m in lines if lv == W] == [ + "Home Assistant is not answering (error 502), perhaps it is still " + "starting. Control waits and resumes by itself.", + "Home Assistant is not answering (no connection), perhaps it is " + "still starting. Control waits and resumes by itself."]) +check("one 'still waiting' line per 5 minutes down, with the time so far", + [m for lv, m in lines if lv == I and m.startswith("Still")] == [ + "Still waiting for Home Assistant to finish starting, 5 minutes " + "so far.", + "Still waiting for Home Assistant to finish starting, 10 minutes " + "so far."]) +check("one INFO line when the last channel is back, with the wait, and a new " + "outage counts from its own start", + [m for lv, m in lines if lv == I and m.startswith("Home")] == [ + "Home Assistant answers again after 11 minutes.", + "Home Assistant answers again after 30 seconds."]) + + +def channels(_clock): + o = _hass.Outage() + seen = [o.waiting()] + o.down("websocket", "the meter connection closed", "") + seen.append(o.waiting()) + o.down("api", "error 502", "") + seen.append(o.waiting()) + o.up("websocket") + seen.append(o.waiting()) + o.up("api") + seen.append(o.waiting()) + return seen + + +check("waiting() follows the API channel only, not the meter websocket", + with_clock(channels) == [False, False, True, True, False]) + + +# --------------------------------------------------------------------------- # +print("2. the status page, N=1 and N=2") + + +class _Hass: + session = None + token = "" + + def __init__(self): + self.writes = [] + + async def limits(self, _e): + return (-5000.0, 5000.0, 1.0) + + async def number(self, _e, invert=False): + return None # what a 502 read gives + + async def state(self, _e): + return None + + async def set_number(self, e, v): + self.writes.append((e, float(v))) + return False # what a 502 write gives + + async def call(self, *_a): + return False + + async def states(self): + return None + + +class _Store: + def __init__(self): + self.data = {} + + def set(self, k, v): + self.data[k] = v + + def get(self, k, d=None): + return self.data.get(k, d) + + def set_time(self, k, v): + self.data[k] = v.isoformat() + + def get_time(self, k): + return None + + +class _Pub: + enabled = False + + def publish(self, *_a, **_k): + pass + + def close(self): + pass + + +ONE = {"setpoint_entity": "number.sp", "meter_entity": "sensor.grid", + "soc_entity": "sensor.soc", "batt_entity": "sensor.batt", + "meter_source": "off", "max_w": 5000, "shadow_mode": "off", + "maintenance_enabled": False, "stale_input_s": 15} +TWO = dict(ONE, setpoint_entity="", soc_entity="", batt_entity="", inverters=[ + {"name": "inverter-a", "setpoint_entity": "number.a", "soc_entity": + "sensor.soc_a", "batt_entity": "sensor.batt_a", "max_w": 2500, + "bms_soc_floor": 10}, + {"name": "inverter-b", "setpoint_entity": "number.b", "soc_entity": + "sensor.soc_b", "batt_entity": "sensor.batt_b", "max_w": 2500, + "bms_soc_floor": 10}]) + + +def make(opts, hass=None): + c = Controller(dict(opts), hass or _Hass(), _Store(), _Pub(), + stop=asyncio.Event()) + c.auto = True + for inv in c.inverters: + inv.dev_min, inv.dev_max = -5000.0, 5000.0 + return c + + +def waiting_on(): + _hass.OUTAGE.down_on = {"api"} + _hass.OUTAGE.since = _hass.OUTAGE._told = _hass.time.monotonic() + + +def waiting_off(): + _hass.OUTAGE.down_on = set() + + +BANNER = "Not ready — Waiting for Home Assistant to finish starting" +for label, opts in (("N=1", ONE), ("N=2", TWO)): + c = make(opts) + waiting_off() + plain = c.checks() + pay_off = c.status_payload() + waiting_on() + rows = c.checks() + pay = c.status_payload() + pay_nl = c.status_payload(lang="nl") + waiting_off() + check(f"{label}: no waiting row while Home Assistant answers", + not [r for r in plain if r.get("id") == "home_assistant"] + and pay_off["state"]["kind"] != "waiting") + check(f"{label}: while it does not, the waiting row is first and red", + rows[0] == {"ok": False, "warn": False, "id": "home_assistant", + "banner": messages.banner_ha_waiting(), + "text": messages.row_ha_waiting()} + and rows[1:] == plain) + check(f"{label}: ...and it is the banner ({pay['banner']!r})", + pay["banner"] == BANNER and pay["level"] == "bad") + check(f"{label}: Home says waiting, not 'Needs you now' " + f"({pay['state']['pill']!r}, {pay['state']['sub']!r})", + pay["state"]["kind"] == "waiting" + and pay["state"]["pill"] == "Waiting for Home Assistant" + and pay["state"]["sub"] == "Control resumes by itself when Home " + "Assistant answers.") + check(f"{label}: ...and in Dutch ({pay_nl['state']['pill']!r})", + pay_nl["state"]["pill"] == "Wacht op Home Assistant" + and pay_nl["state"]["sub"] == "De regeling gaat vanzelf verder " + "zodra Home Assistant antwoordt.") + check(f"{label}: Needs attention lists it first, with its own title", + pay["attention"][0]["id"] == "home_assistant" + and pay["attention"][0]["title"] == "Home Assistant is not answering" + and pay_nl["attention"][0]["title"] == "Home Assistant antwoordt " + "niet") + +# A safety stop outranks the wait: it still needs a person. +c = make(TWO) +c.inverters[1].sign_wd.tripped = True +waiting_on() +pay = c.status_payload() +waiting_off() +check(f"a safety stop keeps its banner and 'Needs you now' over the wait " + f"({pay['banner']!r}, {pay['state']['kind']!r})", + pay["banner"] == messages.banner_direction(True) + and pay["state"]["kind"] == "alarm") +# A stalled control loop does not resume by itself, so it stays the headline. +c = make(ONE) +c.loop_pass_mono = 0.0 +waiting_on() +rows, pay = c.checks(), c.status_payload() +waiting_off() +check(f"a stalled control loop stays first and keeps 'Needs you now' " + f"({pay['banner']!r})", + [r["id"] for r in rows[:2]] == ["controller", "home_assistant"] + and pay["state"]["kind"] == "alarm") +c = make(dict(ONE, shadow_mode="on")) +waiting_on() +pay = c.status_payload() +waiting_off() +check("shadow mode keeps its own state over the wait", + pay["state"]["kind"] == "shadow") + + +# --------------------------------------------------------------------------- # +print("3. control is unchanged by the waiting flag") + + +def run(opts, flag): + async def go(): + h = _Hass() + c = make(opts, h) + (waiting_on if flag else waiting_off)() + targets = [] + for _ in range(4): + await c.read_inputs() + await c.cycle() + await c.send_heartbeats(asyncio.get_running_loop().time(), 10.0) + targets.append(c.target) + waiting_off() + return targets, h.writes + return asyncio.run(go()) + + +for label, opts in (("N=1", ONE), ("N=2", TWO)): + off, on = run(opts, False), run(opts, True) + check(f"{label}: same targets and writes with the flag on or off " + f"({on[0]}, {len(on[1])} writes)", off == on) + check(f"{label}: ...and every write while Home Assistant does not answer " + f"asks 0 W", on[1] and all(v == 0.0 for _e, v in on[1])) + + +print() +if fails: + print(f"{len(fails)} FAILED") + for f in fails: + print(" -", f) + raise SystemExit(1) +print("all passed")