"""Controller methods that read the inputs: meter, packs, PV, forecast. Moved unchanged from app/main.py (MAINT-21). DECISIONS/MAIN-orchestration.md.""" import asyncio import logging import time from datetime import datetime, timezone from .arbiter import actuator_for from . import solarfc from . import freshness from . import lateness from . import messages from . import pv as pv_read from .price import brussels, price_option, provider_configured from .price_chain import uses_chain from .static_tariff import static_status from .rows import tariff_plan_row _LOG = logging.getLogger("goodwe") # UX-11: a quiet meter logs at most one WARNING this often (on `ha_signed` a # healthy meter can go 42-97 s between changes). METER_QUIET_REPEAT_S = 600.0 _mono = time.monotonic # patched by the checks; asyncio keeps the real one # OPT-04: the background tariff refresh. `static_tariff.resolve_tariff()` may # do an HTTPS fetch, and a supplier's TLS timeout on the control tick could # starve the ESP32 heartbeat into layer 1. So the tick NEVER awaits a fetch: it # reads `self.tariff_plan`, which this task assigns. # The cadence is not about how often prices change (day-ahead publishes once, # 14-16 h CET; 30 min picks it up inside the hour with 48 fetches a day). # DECISIONS/MAIN-orchestration.md. TARIFF_REFRESH_S = 1800.0 # The age bound is a different question from the refresh: a failed refresh # still stores a plan (the 11.4 static fallback, provisional). The bound covers # the refresh task dying and a stale plan standing as current. Three missed # refreshes, for `p1.max_age_s`'s reason. TARIFF_MAX_AGE_S = 3 * TARIFF_REFRESH_S # OPT-27: the forecast sensors' last fresh readings (`solarfc.Hold`), so an # evening restart keeps the night plan's figure. FC_HOLD_KEY = "solar_fc_hold" FORECAST_READ_S = 60.0 class InputsMixin: def _readings_late(self, standing_w): """SAFETY-128: update the answer gate; seconds the late verdict has stood, or None. DECISIONS/SAFETY-128-late-readings.md.""" a = self.answer if self._now_mono is None: return None a.observe(self._now_mono, standing_w, self.site_batt_w, grid_w=self.grid, exempt=bool(self.batt_refused) or any( i.refused or ( i.batt is not None and abs(i.standing_w()) >= lateness.ANSWER_W and abs(i.batt - i.idle_w) < lateness.ANSWER_W) for i in self.inverters), idle_w=self._site_idle_w()) if a.late_seen != self._late_logged: self._late_logged = a.late_seen if a.late_seen: self.log_event("readings late - holding", hint=messages.hint("readings_late")) _LOG.warning("Home Assistant readings arrive late, so control " "holds the batteries: READINGS_LATE.") _LOG.debug("READINGS_LATE: the readings show a power request " "%.0f s after it is sent.", a.delay_s) else: self.log_event("readings on time", hint=messages.hint( "readings_back")) _LOG.info("Home Assistant readings are on time again.") return a.late_s(self._now_mono) @property def inputs_ok(self) -> bool: """The site meter, and EVERY pack's own two readings: every pack, not the live ones. A unit whose SoC did not answer cannot be graded for the maintenance FSM or the pack floor, and 11.1 rule 1 for a missing input is command zero and keep commanding.""" if self.grid is None or not self.inverters: return False return all(inv.soc is not None and inv.batt is not None for inv in self.inverters) def missing_reading(self) -> str: """UX-11: the first reading `inputs_ok` finds missing, in words.""" if self.grid is None or not self.inverters: return "meter" for inv in self.inverters: of = "" if len(self.inverters) == 1 else f" from {inv.name}" if inv.batt is None: return f"battery power{of}" if inv.soc is None: return f"battery level{of}" return "input" # -- io ------------------------------------------------------------------ @property def pv_roster(self) -> tuple: """Every configured PV production entity, or `()` (TEL-11/TEL-12). ONE reading of the options, `pv.entities()`, the same call `mqtt.optional_keys()` makes, so what is ANNOUNCED, READ and CHECKED cannot disagree; it replaced a `pv_entity` property.""" return pv_read.entities(self.o) async def _read_pv(self) -> None: """This cycle's SITE PV production, or an ABSENCE with a reason (TEL-11/12). `pv.total()` makes "one of three absent" an absence of the SITE figure. It assigns on EVERY call including failing ones (a stale value must not survive a failure), and uses `hass.state()` not `hass.number()` because the UNIT is half of the answer.""" # TEL-12: every entity in ONE gather. Read serially, three slow sensors # would add three 10 s timeouts to a cycle that feeds the ESP32 # heartbeat; telemetry must have no foot in the control path. roster = self.pv_roster states = await asyncio.gather( *(self.hass.state(entity) for entity in roster)) self.pv_w, self.pv_why, self.pv_parts = pv_read.total( list(zip(roster, states)), pv_read.inverted(self.o)) # UX-54: kept for the Forecast tab only. It must never cost a cycle. try: self.solar_today.add(datetime.now(timezone.utc), self.pv_w) except Exception: # noqa: BLE001 _LOG.debug("measured solar not kept", exc_info=True) def _peak_fc_unit_log(self, fault) -> None: """SAFETY-118. One WARNING when the peak forecast's unit cannot be read in watts, and again only if the unit changes; the unit is on DEBUG.""" if fault == self._peak_fc_fault: return self._peak_fc_fault = fault if fault is None: _LOG.info("The 15-minute demand forecast is used again.") elif fault == "": _LOG.warning("The 15-minute demand forecast has no unit, so it " "is not used.") else: _LOG.warning("The 15-minute demand forecast is not in a power " "unit, so it is not used.") _LOG.debug("The 15-minute demand forecast reads in %r.", fault) async def _read_forecast(self) -> None: """OPT-11 P4: the solar forecast sensors (`solarfc.read()`). A failed or stale read is no forecast, never a zero.""" # OPT-17: every member of both days in one gather. ents = self.fc_entities + self.fc_tomorrow_entities states = await asyncio.gather(*(self.hass.state(e) for e in ents)) n = len(self.fc_entities) now = datetime.now(timezone.utc) fc, why, gaps = solarfc.read_sum( list(zip(self.fc_entities, states[:n])), list(zip(self.fc_tomorrow_entities, states[n:])), now, hold=self.fc_hold) if self.fc_hold.changed: self.fc_hold.changed = False self.store.set(FC_HOLD_KEY, self.fc_hold.dump()) # A member is named only in a sum of several; one entity reads as # before. Logged once per episode: on a change, never every read. gaps = tuple(g for g in gaps if len( self.fc_entities if g[0] == "today" else self.fc_tomorrow_entities) > 1) was_kept = bool(self.solar_fc is not None and self.solar_fc.kept) if (fc is None) != (self.solar_fc is None) \ or why != self.solar_fc_why or gaps != self.solar_fc_gaps \ or bool(fc is not None and fc.kept) != was_kept: self.log_event( "solar forecast: " + ( "none (" + str(why) + ")" if fc is None else f"read, kept from {brussels(fc.at):%H:%M}" if fc.kept else "read") + "".join(f", {d} {e} not usable ({w})" for d, _i, e, w in gaps), hint=messages.hint( "forecast_none" if fc is None else "forecast_no_tomorrow" if gaps else "forecast_read")) self.solar_fc, self.solar_fc_why = fc, why self.solar_fc_gaps = gaps async def read_inputs(self, now_mono: float | None = None) -> None: """Every input this cycle needs, and SAFETY-37's freshness verdict. `now_mono` is defaulted rather than read inside `_read_unit()` so ONE instant covers every unit in a gather.""" o = self.o now_mono = freshness.monotonic() if now_mono is None else float(now_mono) self._now_mono = now_mono if self.p1_enabled: # P1 is the only authoritative measurement of what the utility sees # (5.1); when stale this is None -> "inputs missing -> command 0 # W". NO fallback to an inverter-side figure: its AC power # correlates 0.998 with battery power and 0.09 with the real meter # (a controller would regulate against its own output). self.grid = self.p1.net_w else: self.grid = await self.hass.number(o.get("meter_entity", ""), bool(o.get("meter_invert"))) # DEV-02: each inverter's own two readings from its own entities, # CONCURRENTLY across units and sequentially within one (a slow entity # must not delay the heartbeat path). The PV reads ride in the same # gather and an empty PV roster appends nothing (no coroutine). # DECISIONS/MAIN-orchestration.md. _reads = [self._read_unit(inv, now_mono) for inv in self.inverters] if self.pv_roster: _reads.append(self._read_pv()) # OPT-11 P4: the solar forecast, in the same gather (a slow sensor must # not delay control), at most once per FORECAST_READ_S. if self.fc_entity is not None and ( self._fc_read_mono is None or now_mono - self._fc_read_mono >= FORECAST_READ_S or now_mono < self._fc_read_mono): self._fc_read_mono = now_mono _reads.append(self._read_forecast()) await asyncio.gather(*_reads) if o.get("peak_forecast_entity"): # SAFETY-118: read in its own unit like the PV path, one state # read. No unit or a non-power unit: not used, as if the option # were empty. st = await self.hass.state(o["peak_forecast_entity"]) self.peak_fc, _why = pv_read.watts(st) # A missing reading leaves the unit-fault state as it was. if pv_read.has_reading(st): self._peak_fc_unit_log(pv_read.unit_fault(st)) else: self.peak_fc = None self._peak_fc_fault = None now_e, avg_e = o.get("price_now_entity"), o.get("price_avg_entity") if now_e and avg_e: now_p = await self.hass.number(now_e) avg_p = await self.hass.number(avg_e) self.cheap = (now_p is not None and avg_p is not None and now_p <= avg_p) self._price_gated = True self.tariff_words = "Prices from Home Assistant entities" elif uses_chain(o): # PRICE-01. A provider with fallbacks gives the maintenance gate # its own prices: the current 15-minute price against today's # average, as the Home Assistant pair did. No I/O here: the series # is the one the background refresh stored. # (DECISIONS/MAIN-orchestration-archive.md) self._provider_gate(datetime.now(timezone.utc)) else: # TARIFF-03: 9.2 makes a static day/night tariff a first-class # product and its EMS handling TIME-WINDOW SHIFTING; the one # shiftable load is the maintenance cycle's cheap-window grid # top-up. Synchronous and I/O-free on purpose (the provider-backed # plan is the background task's); validate.py refuses # `static_profile` with the price entities, so the two cannot both # be set. _now = datetime.now(timezone.utc) self.cheap, self.tariff_words = static_status(o, _now) self._price_gated = self._static_gated(o, _now) # TARIFF-11: the provider plan reaches the *Tariff* row here, the only # place the two sources meet. `fresh_tariff_plan()` is an attribute # read and an age comparison against TARIFF_MAX_AGE_S: still no fetch # on this path. _tick = datetime.now(timezone.utc) _standing = self.fresh_tariff_plan(_tick) self.tariff_words = tariff_plan_row( _standing, self.tariff_words, age_s=(None if _standing is None else (_tick - self.tariff_at).total_seconds()), horizon_h=float(price_option(o, "price_horizon_h")), provider=provider_configured(o), max_age_s=TARIFF_MAX_AGE_S) # UX-11: the red meter row says "the add-on log shows why", so a quiet # meter gets one WARNING per episode (at most one per # METER_QUIET_REPEAT_S; the rest DEBUG). Log only: no notification, # decides nothing. if self.p1_enabled: if (self.p1.stale and not self._meter_quiet_logged and self.p1.published_age_s > self.p1.max_age_s): self._meter_quiet_logged = True now = _mono() self._meter_quiet_loud = ( self._meter_quiet_warned is None or now - self._meter_quiet_warned >= METER_QUIET_REPEAT_S) if self._meter_quiet_loud: self._meter_quiet_warned = now _LOG.warning("No meter reading for over %s, so control " "waits and then sets the battery to 0 W.", messages.seconds(self.p1.max_age_s)) else: _LOG.debug("No meter reading for over %s again.", messages.seconds(self.p1.max_age_s)) elif not self.p1.stale and self._meter_quiet_logged: self._meter_quiet_logged = False if self._meter_quiet_loud: _LOG.info("Meter readings are back.") else: _LOG.debug("Meter readings are back.") self.answer.watch(now_mono, [(inv.name, inv.standing_w(), inv.batt) for inv in self.inverters], # SAFETY-128 sum(inv.standing_w() for inv in self.inverters), self.grid) if self.inputs_ok: if self.inputs_bad_since is not None: self.log_event("inputs recovered", hint=messages.hint("inputs_back")) self.inputs_bad_since = None elif self.inputs_bad_since is None: self.inputs_bad_since = datetime.now(timezone.utc) def _driver(self, inv): """`inv`'s driver, wired to this Controller's Home Assistant on first use (SMA-2: bound here, so a unit added later and a swapped `self.hass` are followed). DECISIONS/SMA-2-driver-seam.md.""" drv = inv.driver if not drv.bound(): drv.bind_getter(lambda: self.hass) return drv async def _read_unit(self, inv, now_mono: float) -> None: """One inverter's own SoC and battery power, from ITS OWN entities. SAFETY-37: the POWER reading goes through the freshness gate and the SoC does not, deliberately: `batt` feeds SAFETY-30's per-unit sign check and the delivery check, which a frozen register would fool. The standing command is asked of the unit, not recomputed.""" # SMA-2: the driver reads SoC, then power, as this method always did. inv.soc, raw, _extra = await self._driver(inv).read() was_stale = inv.batt_fresh.stale was_releases = inv.batt_fresh.releases inv.batt_fresh.submit(raw, inv.standing_w(), now_mono) # `inv.batt` is the GATED value: a stale register is a MISSING input, # so the site holds for `stale_input_s` then commands 0 W and keeps # commanding (11.1 rule 1). inv.batt = inv.batt_fresh.reading() # SAFETY-97: learn this unit's idle reading, only while control runs # and nothing says the unit is refusing, stale or faulty. if inv.idle.observe( inv.batt, inv.standing_w(), now_mono, bool(self.auto) and inv.batt is not None and not inv.batt_fresh.stale and not inv.refused and not self.batt_refused and not inv.sign_wd.tripped): inv.store_set("idle_w", round(inv.idle.value, 1)) if inv.batt_fresh.stale and not was_stale: self.log_event(f"STALE {inv.name}: " + inv.batt_fresh.reason, hint=messages.hint("battery_stuck", unit=inv.name)) self._refusal_from_stale(inv, now_mono) # SAFETY-56/57: the stale-reading line names two explanations once, # in `%s`. The escape clause "clears itself when the register # reports a different value" was false for the state this line # announces (the 0 W it announces is what stops the value # changing), so SAFETY-57 rewrote it and SAFETY-56 the diagnosis. # DECISIONS/SAFETY-57-the-exit-from-a-stale-verdict.md. _LOG.error("%s: battery power reading stopped changing, set to " "0 W until it changes, or %.0f s after the command " "drops below %.0f W: %s.", inv.name, inv.batt_fresh.bound.release_s, inv.batt_fresh.bound.move_w, messages.reason_code(inv.batt_fresh.reason)) _LOG.debug("Evidence for %s: %s.", inv.name, inv.batt_fresh.reason) _LOG.debug("%s: the limits are unchanged for %.0f s while asked " "to move: a command over %.0f W that moved over %.0f W.", inv.name, inv.batt_fresh.bound.unchanged_s, inv.batt_fresh.bound.move_w, inv.batt_fresh.bound.move_w) elif inv.batt_fresh.releases > was_releases: # SAFETY-57: reported, never silent: a latch that lets go on a # timer and says nothing cannot be audited, and this one withdraws # a SITE STOP. `release_note()` says nothing has been learned about # the register. self.log_event(f"STALE WITHDRAWN {inv.name}", hint=messages.hint("battery_back", unit=inv.name)) # Not "recovered": nothing is known about the reading yet, so the # line gives the value it holds and the window it is rechecked over # (SAFETY-57). _LOG.warning("%s: the command stayed below %.0f W for %.0f s, so " "battery power reading %+.0f W is used again and " "rechecked over %.0f s.", inv.name, inv.batt_fresh.bound.move_w, inv.batt_fresh.bound.release_s, inv.batt_fresh.held, inv.batt_fresh.bound.unchanged_s) _LOG.debug("SAFETY-57: %s", inv.batt_fresh.release_note(inv.name)) # -- the cycle ----------------------------------------------------------- def actuator_of(self, source: str, inv=None) -> str: """Which actuator a claim from `source` is filed on this cycle. `inv` is the roster entry the claim is ABOUT; left out it is the first inverter (what every per-inverter claim meant at N=1). The classification is not here: `arbiter.CLAIM_SCOPE` decides.""" return actuator_for(source, (inv or self.inverters[0]).name, self.units) def live_units(self) -> tuple: """Which inverters may be commanded THIS TICK, for the allocator. The allocator DROPS what this does not list and the survivors carry the whole site target, so it is reported (`Allocation.dropped`). Answered per tick, never cached (a master goes stale). It answers ONE question: can this controller put a number on this unit's wire. Deliberately not "its sensors are missing". At a roster of ONE, False is a 0 W site.""" now = datetime.now(timezone.utc) live = [] for inv in self.inverters: ok, why = inv.is_live(now) if ok: live.append(inv.name) else: # Level-logged at DEBUG only: `Allocation.dropped` is the # operator-facing surface (edge-logged in cycle()); a line # every second would flush the 40-row action log. _LOG.debug("%s is not commandable this tick: %s", inv.name, why) return tuple(live) def liveness_notes(self) -> list: """Why each unit is or is not commandable, for the status page. SAFETY-37's stale-reading line rides here too: a different fault, a different remedy (a dropped unit is carried by the survivors; a stale power register is a missing input).""" now = datetime.now(timezone.utc) return [n for n in [x for inv in self.inverters for x in (inv.link_note(now), inv.stale_note(), inv.refusal_note())] if n]