Merge pull request 'UX-10: the last plain-language leftovers (log lines, two table rows, 'Why: Other', red at 0 s)' (#138) from UX-10-plain-leftovers into release/1.0
infra-pin / fresh (push) Successful in 1s

This commit was merged in pull request #138.
This commit is contained in:
2026-09-27 12:18:22 +02:00
33 changed files with 1446 additions and 393 deletions
+1 -1
View File
@@ -7,7 +7,7 @@ This applies to everything a home owner or installer reads: notifications, phone
- **Body**: **one sentence** of at most 25 words, saying what happened and what to do. A **red alarm** may use up to **3 sentences** (70 words, each sentence at most 30 words), so that no action a person must take is lost.
- **Details**: the last line links to the add-on documentation and names the section with the rest: `Details: add-on documentation, section "<title>" under Notifications.` Background, figures, reason codes and history go there or into the log, never into the body.
- **Status row**: one sentence of at most 15 words. A **red** row may use up to 3 sentences (30 words), like a red alarm. It shows the live numbers the reader acts on and never an HA entity id. **Banner**: at most 12 words. **Refusal**: at most 30 words, naming the setting by its label and then its key, as `messages.setting()` writes it: “Inverter rating” (max_w), or “Inverter rating” for inverter-b (inverters.max_w) for one inverter in the list. **Option name**: at most 6 words, not counting the group prefix. **Option description**: at most 30 words. Where a value comes from belongs in DOCS.md.
- **Log line** (WARNING/ERROR): one line, at most 25 words, with the numbers that matter. The reasoning goes on a DEBUG line. Log lines stay in English and are not translated. A reason text a line quotes (`%s`) keeps its own codes, because that is the evidence an installer searches for.
- **Log line** (WARNING/ERROR): one line, at most 25 words, with the numbers that matter. The reasoning goes on a DEBUG line. Log lines stay in English and are not translated. A reason text a line quotes (`%s`) keeps its reason code (`OUTPUT_CLAMP`, `STALE_READING`), because that is the evidence an installer searches for. The reason itself has the shape of a red alarm: at most 3 sentences of at most 30 words. The line as logged has no semicolon, banned word, capitals, "1 times" or "(s)". `test_messages.py` part 6 builds every such reason with the real code and checks it. A line that repeats every cycle is DEBUG. INFO lines carry no section numbers, ISO timestamps or capitals.
- **Refusal length is counted as shown**: a setting placeholder counts as its label and key, and the long cases are driven through the validator (`test_messages.py` part 3).
- **Event line** under the buttons: the plain words of `messages.hint()`, like a green row. The add-on's own action log stays technical and is not shown on the page. Installers read it as `events` in the `status` JSON.
- **Sentences**: one idea each, active voice, present tense, with nothing nested in brackets and no semicolons (a semicolon is a second sentence in disguise). These translate well into Dutch and French.
@@ -61,3 +61,20 @@ The allowlist is empty and its cap is 0 (43 → 0). Every WARNING and ERROR line
10. **The panel's key match** no longer files `inverters.max_w` under the flat `max_w`.
11. **The Supervisor question at start** is one INFO line with a real reason (a timeout's own text is empty, so the error type is named).
12. **DOCS**: a glossary ("Words used on this page") explains control board, isolator and Developer Tools once. Card ids left the headings and sit on a *For installers* line under each. The links to the renamed headings were updated.
# UX-10: the last plain-language leftovers (after the 2d test)
**Unchanged:** every safety behaviour, every alarm's log level (WARNING and ERROR stay), every notification id, trigger and cadence, the banner cascade, and every row colour except the meter row right after a start (item 6).
1. **Why the 2d scan missed the clamp lines.** Part 3 reads a log call's own literal and counts `%s` as one word. The clamp lines are `"…software fault: %s …"`, and the text in `%s` was built elsewhere, by `loop_clamp_note()` and `ClampResult.describe()`. So the scan passed a line whose logged text had a semicolon, "BUG SIGNAL", "clamped" and "1 times". The same was true of every quoted reason. Part 6 closes the gap. It lists every dynamic part of every WARNING+ line as data (a number, a name, a path, a library's own error text) or as a built text, and a new part in neither list fails. Each built text is produced by the real code (the watchdogs, `decide()`, `loop_clamp_note()`, `MigrationReport.explain()`) or, for a family of builders, by every template of it (`PriceRead.no_data`, `Gate.block`). The text and the line as logged are then checked. A mutation shows the 2d clamp text is caught on both clamp lines.
2. **A quoted reason gets the red-alarm shape**, 3 sentences of at most 30 words, and not the 25-word line limit. It is the evidence behind an alarm, and it keeps its code and its limits, which the owner asked to keep. The alarm shape is STYLE.md's existing rule for the texts behind a safety stop, so no new limit was made up. Rewritten: `OUTPUT_CLAMP` (both kinds), `METER_FROZEN`, `CIRCULATING_POWER`, `STALE_READING` (SAFETY-56's two explanations and "cannot tell which" kept, in order), the peak guard's reasons, the state-migration report, the price feed and price history reasons, and the maintenance and trading gate reasons. "Software fault" left the clamp reason, because the ERROR line around it already says it.
3. **Codes are one token.** `PEAK GUARD`, `PEAK GUARD FLOOR-LIMITED` and `PEAK GUARD BLIND` read as capitals, so they are now `PEAK_GUARD`, `PEAK_GUARD_FLOOR_LIMITED` and `PEAK_GUARD_BLIND`, like `OUTPUT_CLAMP`. Nothing in admin/goodwe or in the scripts under `/home/homelab` greps them (checked). `/home/homelab/clampwatch.sh` greps `OUTPUT_CLAMP`, which stays.
4. **Top table.** *Price history* writes "96 prices over 24 hours for 26 Sep", joined by commas. *Tariff* writes the spacing as "one every 15 minutes or every hour". "Not final yet" was dropped, because a plan is provisional exactly when it holds an estimated price (`n_carried` counts the provisional points), so the estimated count already says it.
5. **Levels and noise.** The shadow line of every cycle is DEBUG, and "Shadow mode is on/off" is INFO: it follows a setting or a button, and the banner, hint and event are unchanged. aiohttp's access log is on only at log level debug. A settings warning is logged once per start (a filter on `goodwe.config`, WARNING only, so refusals are untouched), because the validator runs twice at start. When Home Assistant restarts, `hass.Outage` says so in one WARNING line for the REST API and the meter websocket together, puts the library's text on DEBUG, and says at INFO when both answer again. INFO lines lost "§8.3", ISO timestamps, "banked" and "keys ARE", and error texts lost "NOT_OBSERVED", "did NOT land" and "AND".
6. **Display bugs.**
- "Why: Other" during a latched per-inverter stop: `main.py` turns a safety winner into its claim's reason, and "sign disagreement" (and "unsplit", main.py's own refusal to split) had no entry in `WHY_WINNER`. The mapping is now `main.why_key()`, and part 7 finds every `Claim.set()` in the code and checks that every key it can produce has words.
- Red "Meter: no reading for 0 seconds" after a restart: until the first reading arrives, `P1Ingest.stale` is true, and the age is the time since start. The row now reads amber "waiting for the first reading" while that age is inside the limit. **Colour change, justified:** red at 0 s contradicted the limit the same row prints, and once readings exist the row is red only past that limit. Amber, not green, because control waits for the reading. Past the limit it is red as before. `stale` itself, which gates control, is unchanged.
- "A reading is missing for 0 seconds" stuck at 0: with the meter reading gone, the grid value stops changing, so the loop runs a cycle only every `cycle_floor_s`, and the line was computed once per cycle. The age is now counted when the page asks. The hold and its 15 s escalation are unchanged.
7. **Review: the line as logged gets the shape too.** Part 6 first checked the quoted reason alone, so a title, a 2-sentence reason and two tails still logged as 4 sentences ("Power request too high …: OUTPUT_CLAMP: … +5000 W. The command this cycle was +1000 W. Control is still running. Cut back 1 time so far."). Part 6 now also checks the whole line: at most 3 sentences, none over 30 words. The wrappers became one sentence each, the circulation and peak guard reasons two, and `STALE_READING`'s fixed limits moved from the reason to a DEBUG line beside the ERROR (its release clause stays, pinned by test_freshness). The clamp lines for one inverter are pinned at 30 words at most: `OUTPUT_CLAMP: computed +9000 W, cut to the +5000 W rating, command now +2000 W`. Several clamped inverters read as one sentence of asked/sent pairs; which limit bound each is on its own action-log row and in the notification. Totals above 30 words remain on the direction, delivery, frozen-meter and stale lines (up to 74 words). Shortening them is a follow-up: the direction and delivery reasons are also persisted in state.json, and the direction one is pinned byte-for-byte in test_watchdog.
8. **Home Assistant 400 while it loads** now reads "Home Assistant refused number.set_value for number.x (error 400, no details). The entity may still be loading, or the value is out of range." A body with more than "400: Bad Request" is still quoted. Still WARNING, still once a minute, still a failed write.
9. **Witness** (admin/goodwe): the resolved push says "after no answers from … to …", as the resolved card does. The YAML with every title and message stripped is identical.
+19 -18
View File
@@ -1639,7 +1639,7 @@ is the design rather than an accident: it is 1.0 at the top of the quarter and
grows, so the guard is gentlest when its projection rests on the least evidence
and becomes aggressive only once the quarter is nearly measured.
**The ceiling** is `peak_cap_w`, raised to the month's banked peak when that
**The ceiling** is `peak_cap_w`, raised to this month's recorded peak when that
already stands higher — once a month's bill is set at 5013 W, holding later
quarters to 3500 W buys nothing and costs real charging. **That relaxation is
granted only by an OBSERVED reading:** a peak store that cannot be read leaves the
@@ -1716,7 +1716,7 @@ exactly like the SoC drift the monthly maintenance cycle exists to correct.
**nothing more**. See below for what that costs on a real evening.
- **When it binds you are told**, once per episode, with notification
`goodwe_peak_soc_floor` and a red status-page row reading *Battery at its
peak reserve* (`PEAK GUARD FLOOR-LIMITED` in the log): the quarter **will**
peak reserve* (`PEAK_GUARD_FLOOR_LIMITED` in the log): the quarter **will**
go over the ceiling, so shedding load is
the only thing left that changes the bill. Failing to shave is never silent —
the euro figure is the whole point of the guard.
@@ -1758,7 +1758,7 @@ because the guard it bounds is not the thing doing the discharging.
**And the two can happen in the same cycle.** On the high-load block of the same
day (15:00–17:00 UTC) with the pack below the floor, the guard reports
`PEAK GUARD FLOOR-LIMITED` — *"commanding no forced discharge"* — on 49 cycles,
`PEAK_GUARD_FLOOR_LIMITED` — *"there is no forced discharge"* — on 49 cycles,
and on **all 49 of them** the loop is simultaneously being granted a discharge of
up to 2000 W by the arbiter. The status page is telling you the truth about the
guard while the battery empties.
@@ -1848,14 +1848,14 @@ Both are watched. A guard that watched only the emitted value would be silent on
every standard configuration.
**The integrator bound is not a bug, and it is reported as what it is.** It
reads *"the loop's integrator reached its +5000 W anti-windup bound; the loop's
command this cycle was +2000 W"*, titled *"the control loop is at its integrator
bound"*, logged as a `WARNING`, with an amber (not red) status row and its own
notification (`goodwe_integrator_bound`), so it never replaces a BUG SIGNAL
notice still on screen. Brief
engagements after a large load or solar step are normal. If it stays engaged,
check that the battery is following its commands. Only a command over the rating
carries the BUG SIGNAL text, and it has its own notification budget.
reads *"the correction the add-on builds up reached its +5000 W limit,
command now +2000 W"*, titled *"Battery is not keeping up"*, logged
as a `WARNING`, with an amber (not red) status row and its own notification
(`goodwe_integrator_bound`), so it never replaces a software-fault notice still
on screen. Brief engagements after a large load or solar step are normal. If it
stays engaged, check that the battery is following its commands. Only a command
over the rating is logged as a software fault, at `ERROR`, and it has its own
notification budget.
Why: [`DECISIONS/SAFETY-40-the-integrator-bound-is-not-a-bug.md`](DECISIONS/SAFETY-40-the-integrator-bound-is-not-a-bug.md).
### The frozen-meter alarm
@@ -2444,7 +2444,7 @@ since TARIFF-11 that row carries the provider plan itself:
```
Tariff: No fixed tariff set. Price plan from 412 s ago, for 48 hours ahead:
day-ahead prices from the price feed, 60 prices over 33 hours,
36 published and 24 estimated, 900+3600 s apart, not final yet
36 published and 24 estimated, one every 15 minutes or every hour
```
⚠️ **The two halves of that row are not computed at the same moment, and the
@@ -2461,9 +2461,10 @@ Read the plan half as five separate facts: which *product* the feed publishes
and whether it came from the feed or from your fixed tariff, how many
**prices** it carries and how many **whole hours** they cover, how many are
**published** (firm, for their own interval) against **estimated** (carried
from yesterday under §8.3), how far **apart** they are in seconds — `900+3600`
is the normal mixed steady state, quarter-hourly firm points beside hourly
carried ones — and `not final yet` (provisional) whenever any is estimated.
from yesterday under §8.3), and how far **apart** they are — "one every 15
minutes or every hour" is the normal mixed steady state, quarter-hourly firm
points beside hourly carried ones. The plan is provisional exactly when some
prices are estimated, so the estimated count says it.
⚠️ **Points and hours are two different numbers and this row used to print one
of them under the other's name.** `words` was `f"… {len(points)} h"`, so a
@@ -3204,7 +3205,7 @@ ends. That row says how to clear it.
| Row starts with | What it tells you |
|---|---|
| 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. |
| 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. |
| Meter reading may be stuck | See *Meter reading may be stuck* under Notifications. |
| Month peak | This month's highest 15-minute average, when it happened, and how close it is to your peak limit. Amber from 80 %. |
@@ -3244,8 +3245,8 @@ ERROR or WARNING line in the add-on log.
**Check for inverters working against each other** is SAFETY-31, **Delivery
check** SAFETY-42.
- **Month peak** and **15-minute periods measured** are TARIFF-01 and
TARIFF-13. The store's state at start is the INFO line `capacity-tariff peak
store: …`, and the peak guard's full reason is on its log line.
TARIFF-13. The store's state at start is the INFO line `Month peak store:
…`, and the peak guard's full reason is on its log line.
- ***name*: battery power reading stopped changing** is SAFETY-37/56/57. The
ERROR line carries the full `STALE_READING` reason and when it clears.
- The table at the top: **Why** is `messages.why()`, the arbiter's answer in
+4 -4
View File
@@ -246,11 +246,11 @@ class Allocation:
block the failsafe is worse than the hole it closes.
"""
if tick is None or self.tick is None or self.tick != tick:
return (f"the allocation record on hand was made on tick "
f"{self.tick!r} and this is tick {tick!r} - a record whose "
f"envelopes have moved cannot authorise a write")
return (f"the power split on hand is from tick {self.tick!r}, "
f"not this tick {tick!r}, and an old split cannot allow a "
f"write")
if not self.ok:
return f"the allocator refused this tick ({self.explain()})"
return f"no power split was possible this tick ({self.explain()})"
if unit not in self.shares:
return (f"{unit} has no share in this tick's allocation "
f"({self.explain()})")
+5 -4
View File
@@ -325,12 +325,13 @@ class CirculationWatchdog:
return False
self.tripped = True
# UX-10: plain sentences, every figure kept (test_messages.py part 6).
self.reason = (
f"CIRCULATING_POWER: {circ_w:.0f} W measured going round between "
f"the inverters (peak {self.peak_w:.0f} W) for {held:.0f} s "
f"continuously - the meter cannot see it, because it nets to zero "
f"there (limits: over {self.cfg.min_w:.0f} W, held over "
f"{self.cfg.hold_s:.0f} s)")
f"the inverters for {held:.0f} s, peaking at {self.peak_w:.0f} W, "
f"over the limits of {self.cfg.min_w:.0f} W and "
f"{self.cfg.hold_s:.0f} s. The meter cannot see it, because it "
f"nets to zero there")
return True
def held_s(self, now: datetime) -> float:
+35 -16
View File
@@ -142,6 +142,8 @@ import math
from dataclasses import dataclass
from datetime import datetime
from . import messages
# The reason code, distinct from any saturation-freeze code by construction:
# nothing else in this add-on uses it. See "DISTINCT FROM SATURATION".
REASON_CODE = "OUTPUT_CLAMP"
@@ -234,31 +236,46 @@ CLEAR_CYCLES = 3
SUSTAINED_CYCLES = 3
BUG_SIGNAL = ("This is a BUG SIGNAL, not a limit being used: something "
"upstream computed a setpoint the actuator cannot deliver.")
# UX-10: the reasons below are quoted by a WARNING or ERROR line, so they
# follow STYLE.md's rule for a quoted reason (test_messages.py part 6): no
# final full stop, the line adds it. The line around them says "software
# fault" for an over-rating, so the reason does not. Each is one sentence, so
# the logged line stays within 3 sentences and about 30 words.
def loop_clamp_note(d) -> str:
"""The loop-side alarm text for one `control.Decision`, or "".
SAFETY-40: the integrator bound is anti-windup doing its job and says so;
only a command over the rating is a BUG SIGNAL. Every number is the
only a command over the rating is a software fault. Every number is the
decision's own, i.e. from the tick that clamped.
"""
if d.clamped:
return (f"{REASON_CODE}: the loop computed {d.requested_w:+.0f} W, over "
f"the {abs(d.clamped_w):.0f} W rating, and it was clamped to "
f"{d.clamped_w:+.0f} W; the loop's command this cycle was "
f"{d.target_w:+.0f} W. {BUG_SIGNAL}")
return (f"{REASON_CODE}: computed {d.requested_w:+.0f} W, cut to the "
f"{d.clamped_w:+.0f} W rating, command now {d.target_w:+.0f} W")
if d.i_clamped:
return (f"{REASON_CODE}: the loop's integrator reached its "
f"{d.i_bound_w:+.0f} W anti-windup bound; the loop's command "
f"this cycle was {d.target_w:+.0f} W. Brief "
f"engagements after a large load or solar step are normal. If it "
f"persists, check that the battery is following its commands.")
return (f"{REASON_CODE}: the correction the add-on builds up reached "
f"its {d.i_bound_w:+.0f} W limit, command now "
f"{d.target_w:+.0f} W")
return ""
def write_clamp_note(named) -> str:
"""The write-side alarm text: `named` is `[(inverter name or None,
ClampResult)]` for every inverter whose write was cut back this cycle.
One inverter reads as `describe()`. Several read as one sentence of
asked/sent pairs, so the line stays one sentence however many inverters
there are. Which limit cut each one back is on its own action-log row
(`describe()`) and in the notification."""
if len(named) == 1:
name, r = named[0]
return f"{name}: {r.describe()}" if name else r.describe()
return f"{REASON_CODE}: " + ", ".join(
f"{name} asked {r.requested_w:+.0f} W and sent {r.applied_w:+.0f} W"
for name, r in named)
@dataclass(frozen=True)
class ClampResult:
"""What the guard did, with the RAW value preserved.
@@ -275,10 +292,12 @@ class ClampResult:
bound: str = "" # "" | "max_w" | "device" - which stage bit
def describe(self) -> str:
return (f"{REASON_CODE}: the computed setpoint {self.requested_w:+.0f} W "
f"was clamped to {self.applied_w:+.0f} W by the {self.bound} "
f"bound (rating {self.limit_w:.0f} W) - something upstream is "
f"winding")
# The sent value IS the limit that bound, so the rating is not
# repeated: on "max_w" it equals the rating, and on "device" the
# rating was not what cut it back.
return (f"{REASON_CODE}: asked {self.requested_w:+.0f} W and sent "
f"{self.applied_w:+.0f} W, "
f"{messages.LIMIT_WORDS.get(self.bound, self.bound)}")
def is_commandable(value) -> bool:
+8 -6
View File
@@ -424,15 +424,17 @@ class FreezeWatchdog:
# page was telling, printed into the log and the HA notification where
# it would outlive the page.
ceiling = rail_ceiling_w(max_w, dev_min=dev_min, dev_max=dev_max)
# UX-10: plain sentences, every figure kept (test_messages.py part 6).
capped = ("" if ceiling >= abs(float(max_w))
else f", capped from max_w {float(max_w):.0f} W by the "
f"setpoint device's own rating")
f"inverter's own rating")
self.reason = (
f"METER_FROZEN: the meter has answered {float(unchanged_s):.0f} s "
f"without its measurement changing while the command stands at "
f"{float(commanded_w):+.0f} W, at the {ceiling:.0f} W rail{capped} "
f"(limits: unchanged over {self.cfg.hold_s:.0f} s, command over "
f"{rail_w(max_w, dev_min=dev_min, dev_max=dev_max):.0f} W)")
f"METER_FROZEN: the meter has not changed for "
f"{float(unchanged_s):.0f} s while the command is "
f"{float(commanded_w):+.0f} W, at the {ceiling:.0f} W limit"
f"{capped}. Limits: unchanged over {self.cfg.hold_s:.0f} s, "
f"command over "
f"{rail_w(max_w, dev_min=dev_min, dev_max=dev_max):.0f} W")
if self.active:
return False
self.active = True
+19 -24
View File
@@ -594,31 +594,26 @@ class Freshness:
# ("what did the register do" against "can I trust this entity"). One
# helper serving both would have to drop whichever half the other does
# not need, and the half it dropped would be the operator's next step.
self.reason = (
f"STALE_READING: {self.held:+.0f} unchanged for {shown_s:.0f} s "
f"while the standing command moved {moved_w:.0f} W to "
f"{standing_w:+.0f} W. TWO THINGS LOOK LIKE THIS AND THIS GATE "
f"CANNOT TELL THEM APART: the register may have stopped reporting "
f"reality, or the source may be unable to comply with the command "
f"- a pack the BMS is refusing holds still under any setpoint, and "
f"an honest register then reads exactly like a frozen one. Either "
f"way the number cannot be read as this command's effect, so it is "
f"reported as MISSING rather than as a measurement (limits: "
f"unchanged over {self.bound.unchanged_s:.0f} s, command over "
f"{self.bound.move_w:.0f} W and moved by over "
f"{self.bound.move_w:.0f} W)")
# UX-10: two plain sentences (test_messages.py part 6). SAFETY-56's
# two explanations stay, in this order, and so does the admission
# that this check cannot tell them apart. The reading is treated as
# missing either way, which the log line around this says. The
# limits (`self.bound`) are on main.py's DEBUG line beside it, so the
# logged line stays within 3 sentences.
# ⚠️ SAFETY-57, AND THE THREE DURATIONS ARE THREE DIFFERENT FACTS, each
# in its own slot: the register's unchanged time is in the sentence
# above, the WINDOW this verdict actually rests on is here, and so is
# how many times this unit has been round the loop. Without the second
# one the sentence reads as though 92 s of unchanged register were what
# was compared against the 35 s limit, and it was not.
if self.releases:
self.reason += (
f" [re-graded: the {held_s:.0f} s window this verdict rests on "
f"opened when the previous one was withdrawn, not when the "
f"register last moved - this unit has now been graded "
f"{self.releases + 1} times]")
# in its own slot: the register's unchanged time, the WINDOW this
# verdict actually rests on after a release (`regraded`), and how many
# times this unit has been round the loop. Without the second one the
# sentence reads as though 92 s of unchanged register were what was
# compared against the 35 s limit, and it was not.
regraded = (f", checked {self.releases + 1} times over a {held_s:.0f} s "
f"window since the last stop was withdrawn"
if self.releases else "")
self.reason = (
f"STALE_READING: {self.held:+.0f} W unchanged for {shown_s:.0f} s "
f"while the command moved {moved_w:.0f} W to {standing_w:+.0f} W"
f"{regraded}. The reading may have stopped, or the battery may be "
f"unable to follow the command, and this check cannot tell which")
def unchanged_s(self, now_mono) -> float | None:
"""Seconds since an arrival carried a different number. Status page.
+62 -2
View File
@@ -16,6 +16,38 @@ _LOG = logging.getLogger("goodwe.hass")
CORE_API = "http://supervisor/core/api"
SUPERVISOR_API = "http://supervisor"
BAD_STATES = ("unknown", "unavailable", "none", "")
# What the Supervisor's proxy answers while Home Assistant restarts.
UNAVAILABLE = (502, 503, 504)
class Outage:
"""UX-10: Home Assistant not answering, said in one plain line per outage.
A restart takes the REST API and the meter websocket down together, and
each used to log the library's own text for every entity and service
("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.
"""
def __init__(self):
self.down_on = set()
def down(self, channel: str, what: str, detail) -> None:
if not self.down_on:
_LOG.warning("Home Assistant is not answering (%s), perhaps it is "
"restarting. The add-on keeps trying.", what)
self.down_on.add(channel)
_LOG.debug("Home Assistant not answering on %s: %s", channel, detail)
def up(self, channel: str) -> None:
if channel in self.down_on:
self.down_on.discard(channel)
if not self.down_on:
_LOG.info("Home Assistant answers again.")
OUTAGE = Outage()
class HomeAssistant:
@@ -58,10 +90,18 @@ class HomeAssistant:
async with self.session.get(
f"{CORE_API}/states/{entity_id}", headers=self._headers, timeout=10
) as resp:
if resp.status in UNAVAILABLE:
OUTAGE.down("api", f"error {resp.status}",
f"read {entity_id}: {resp.status}")
return None
OUTAGE.up("api")
if resp.status == 404:
return None
resp.raise_for_status()
obj = await resp.json()
except aiohttp.ClientConnectionError as err:
OUTAGE.down("api", "no connection", f"read {entity_id}: {err}")
return None
# SAFETY-61: an undecodable body is an absence like any other failed
# read, never an exception into the control loop.
except (aiohttp.ClientError, TimeoutError, ValueError) as err:
@@ -113,17 +153,37 @@ class HomeAssistant:
f"{CORE_API}/services/{domain}/{service}",
headers=self._headers, json=data, timeout=10,
) as resp:
if resp.status in UNAVAILABLE:
OUTAGE.down("api", f"error {resp.status}",
f"service {domain}.{service}: {resp.status}")
return False
OUTAGE.up("api")
if resp.status >= 400:
body = await resp.text()
# 400 here usually means out-of-range for the entity - the
# value is rejected outright, not clamped. Always log it:
# silently dropped commands are how a controller ends up
# believing something the hardware never did.
# UX-10: plain words. While Home Assistant loads its
# entities it answers 400 with only "400: Bad Request",
# which says nothing, so only a body with more is quoted.
said = body.strip()[:200]
if said.lower() in (f"{resp.status}: {resp.reason}".lower(),
""):
said = "no details"
entity = (data.get("entity_id", "no entity")
if isinstance(data, dict) else "no entity")
self._moan(f"svc:{domain}.{service}",
"service %s.%s rejected (%s): %s",
domain, service, resp.status, body[:200])
"Home Assistant refused %s.%s for %s (error %s, "
"%s). The entity may still be loading, or the "
"value is out of range.", domain, service,
entity, resp.status, said)
return False
return True
except aiohttp.ClientConnectionError as err:
OUTAGE.down("api", "no connection",
f"service {domain}.{service}: {err}")
return False
# ValueError: an undecodable error body (SAFETY-61) is a failed write.
except (aiohttp.ClientError, TimeoutError, ValueError) as err:
self._moan(f"svcerr:{domain}.{service}", "service %s.%s failed: %s",
+134 -78
View File
@@ -49,8 +49,8 @@ from .circulation import (
circulating_w, opposing,
)
from .clamp import (
BUG_SIGNAL as CLAMP_BUG_SIGNAL, REASON_CODE as CLAMP_REASON, ClampWatchdog,
clamp_to_rating, is_commandable, loop_clamp_note,
REASON_CODE as CLAMP_REASON, ClampWatchdog,
clamp_to_rating, is_commandable, loop_clamp_note, write_clamp_note,
)
from . import freshness
from . import messages
@@ -230,6 +230,22 @@ def pack_energy_of(inv):
inv.capacity_kwh, inv.max_w)
def why_key(winner: str, claims) -> str:
"""The key of `messages.WHY_WINNER` for a resolution's winner.
"safety" and "failsafe" each stand for several causes, so for those the
winning claim's own reason is the key ("stopped", "inputs missing", "sign
disagreement"). A failsafe with no claim of its own is the arbiter's "no
claim was made", or main.py's refusal to split the power ("unsplit").
"""
if winner in ("safety", "failsafe"):
return next((c.reason for c in claims
if c.source == winner and c.kind == "set"),
"no claim was made" if not any(
c.kind == "set" for c in claims) else "unsplit")
return winner
def tariff_plan_row(plan, tick_words: str, *, age_s, horizon_h: float,
provider: bool, max_age_s: float) -> str:
"""The *Tariff* status row: the 30 s tick's sentence AND the provider plan.
@@ -544,7 +560,7 @@ class Controller:
# re-arm anything. It is still the difference between a pack that is
# recalibrated on schedule and one that silently is not, which is
# §12's opening sentence, so it is said where an operator looks.
self.log_event("maintenance history did NOT migrate cleanly: "
self.log_event("maintenance history did not move over cleanly: "
+ self.maint_migration.explain(),
hint=messages.hint("maint_history"))
# ⚠️ ONE CONFIG, N MACHINES. The `maintenance_*` options describe the
@@ -596,8 +612,8 @@ class Controller:
for inv in self.inverters:
if inv.sign_wd.tripped:
_LOG.error("%s stays at 0 W after the restart because its "
"power went the wrong way: %s. Start control once "
"you know why.", inv.name,
"power went the wrong way, so find out why before "
"you start control. %s.", inv.name,
inv.sign_wd.reason or "(reason not recorded)")
# --- SAFETY-42 + SAFETY-34 -------------------------------------------
@@ -619,9 +635,9 @@ class Controller:
for inv in self.inverters:
if inv.delivery_wd.tripped:
_LOG.error(
"%s is still marked as not delivering after the restart: "
"%s. Control keeps running, and only stopping and starting "
"control clears this.",
"%s is still marked as not delivering after the restart "
"while control keeps running, and only stopping and "
"starting control clears this. %s.",
inv.name, inv.delivery_wd.reason or "(reason not recorded)")
# --- SAFETY-30: THE SITE HALF OF THE SIGN CHECK ----------------------
@@ -651,9 +667,9 @@ class Controller:
reason=str(store.data.get("site_sign_reason", "") or ""))
if self.site_sign_wd.tripped:
_LOG.error(
"Every inverter stays at 0 W after the restart because the "
"total power went the wrong way: %s. Start control once you "
"know why.",
"After the restart every inverter stays at 0 W, as the total "
"power went the wrong way, so find out why before starting "
"control. %s.",
self.site_sign_wd.reason or "(reason not recorded)")
# And the per-unit detectors are told which question they are asking,
# here as well as in `cycle()`. `checks()` and the status page read
@@ -704,9 +720,9 @@ class Controller:
self._announced_mono = {}
if self.circ_wd.tripped:
_LOG.error(
"Every inverter stays at 0 W after the restart because the "
"inverters worked against each other: %s. Start control once "
"you know why.",
"After the restart every inverter stays at 0 W, as the "
"inverters worked against each other, so find out why before "
"starting control. %s.",
self.circ_wd.reason or "(reason not recorded)")
# SAFETY-03. The output clamp's alarm - see clamp.py for why the clamp
@@ -750,7 +766,7 @@ class Controller:
self.peak = PeakTracker(self.peak_store,
cap_w=float(opts.get("peak_cap_w", 3500)))
self.peak.restore(self.p1.averager)
_LOG.info("capacity-tariff peak store: %s", self.peak.restore_state)
_LOG.info("Month peak store: %s", self.peak.restore_state)
# FCST-04. The §8.3 carry-forward store: the published prices of the
# last few Brussels days, so the hours a day-ahead feed has not printed
@@ -786,7 +802,7 @@ class Controller:
# `.words` read below are unguarded, and a cache that raises here is an
# add-on that does not start.
self.price_history = PriceHistory(price_history_path)
_LOG.info("§8.3 price history: %s", self.price_history.words)
_LOG.info("Price history: %s", self.price_history.words)
# SAFETY-07. The guard TARIFF-01 was built for. It is stateless by
# design (peakguard.py holds no history between calls), so the only
@@ -1071,9 +1087,9 @@ class Controller:
"""
rep = self.store_migration
if rep.ran and not rep.ok:
_LOG.error("The saved safety stops did not copy over cleanly "
"(%s), so they are read again from the older saved "
"state.", rep.explain())
_LOG.error("The saved safety stops did not copy over cleanly, so "
"they are read again from the older saved state: %s.",
rep.explain())
data = getattr(store, "data", {})
legacy_tripped = bool(data.get("sign_tripped", False))
if not legacy_tripped or not self.inverters:
@@ -1212,8 +1228,8 @@ class Controller:
first.store_set("sign_reason", first.sign_wd.reason)
first.store_set("sign_tripped", True)
_LOG.error(
"%s is set to 0 W again, because an older saved safety stop was "
"found: %s. Start control once you know why.",
"%s is set to 0 W again because an older saved safety stop was "
"found, so find out why before you start control. %s.",
first.name, first.sign_wd.reason)
_LOG.debug(
"SAFETY-02 latch guard: the pre-DEV-02 flat key says the "
@@ -1678,6 +1694,22 @@ class Controller:
"""
return packshare.weights(self.pack_energy, target_w)
@property
def why_words(self) -> str:
"""The page's "Why" line. While control waits for a missing reading
the age is counted when the page asks (UX-10), not frozen at the age
the last cycle saw."""
if self._why_waiting_since is not None:
return messages.why_waiting(max(0.0, (
datetime.now(timezone.utc)
- self._why_waiting_since).total_seconds()))
return self._why_words
@why_words.setter
def why_words(self, text: str) -> None:
self._why_words = text
self._why_waiting_since = None
@property
def inputs_ok(self) -> bool:
"""The site meter, and EVERY pack's own two readings.
@@ -1921,11 +1953,18 @@ class Controller:
# learns to skim it.
# UX-08 2d: plain, with SAFETY-57's escape clause kept as an
# ordered pair (time, then power), and the reason still in `%s`.
_LOG.error("%s: battery power reading stopped changing. Inverters "
"go to 0 W until it changes, or %.0f s after the "
"command drops below %.0f W: %s",
# UX-10: one sentence, then the reason's two. Its limits are on
# the DEBUG line below, to keep the line within 3 sentences.
_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, inv.batt_fresh.reason)
_LOG.debug("%s: the limits are unchanged over %.0f s, a command "
"over %.0f W and a move by 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 is a latch no operator can audit - and this
@@ -2078,9 +2117,10 @@ class Controller:
f"refusing to broadcast {float(value):+.0f} W to "
f"{len(targets)} inverters - that is the ARCH-01 fault; "
f"commanding 0 W", hint=messages.hint("all_blocked"))
_LOG.error("Refused to send %+.0f W to all %d inverters at "
"once, so every inverter is set to 0 W. This is a "
"software fault.", float(value), len(targets))
_LOG.error("Refused to send %+.0f W to all %s at once, so "
"every inverter is set to 0 W. This is a software "
"fault.", float(value),
messages.count(len(targets), "inverter"))
_LOG.debug("ARCH-01: a site target handed to each unit is "
"supplied by each of them, so the gain at the meter "
"becomes N times the per-unit gain. Only 0 W may be "
@@ -2154,8 +2194,8 @@ class Controller:
self.log_event(
f"{inv.name}: WRITE REFUSED {value:+.0f} W - commanding 0 W",
hint=messages.hint("write_blocked", unit=inv.name))
_LOG.error("Refused to send %+.0f W to %s (%s), so it is set to "
"0 W instead. This is a software fault.",
_LOG.error("Refused to send %+.0f W to %s, so it is set to 0 W "
"instead, which is a software fault. The reason: %s.",
value, inv.name, refusal)
value = 0.0
@@ -2203,10 +2243,11 @@ class Controller:
# one writer, and this is that writer emitting the value it emits for
# every other refusal.
if self.shadow and value != shadow.WIRE_W:
_LOG.info("SHADOW MODE: not commanding %+.0f W to %s - holding "
"%+.0f W. The decision was reached and recorded; "
"nothing was sent to the inverter.",
value, inv.name, shadow.WIRE_W)
# UX-10: DEBUG, because it repeats every cycle in shadow mode. The
# INFO line when shadow mode comes on says the same once.
_LOG.debug("Shadow mode: would send %+.0f W to %s, and holds "
"%+.0f W. Nothing was sent to the inverter.",
value, inv.name, shadow.WIRE_W)
value = shadow.WIRE_W
changed = (inv.last_write is None or value != inv.last_write)
@@ -2449,8 +2490,8 @@ class Controller:
self.store.set("sign_tripped", True)
self.log_event(f"FAILSAFE {inv.name}: " + inv.sign_wd.reason,
hint=messages.hint("direction", unit=inv.name))
_LOG.error("%s is set to 0 W because its power went the wrong "
"way: %s. Only starting control clears this.",
_LOG.error("%s is set to 0 W until control is started, "
"because its power went the wrong way. %s.",
inv.name, inv.sign_wd.reason)
# ⚠️ THE SITE'S OWN STANDING COMMAND, WHICH IS THE SUM OF THE UNITS'.
# SAFETY-07 and SAFETY-18 both grade a SITE quantity - the quarter-hour
@@ -2497,9 +2538,9 @@ class Controller:
self.store.set("site_sign_tripped", True)
self.log_event("FAILSAFE site: " + self.site_sign_wd.reason,
hint=messages.hint("site_direction"))
_LOG.error("Every inverter is set to 0 W because the total "
"power went the wrong way: %s. Only starting "
"control clears this.", self.site_sign_wd.reason)
_LOG.error("Every inverter is set to 0 W until control is "
"started, because the total power went the wrong "
"way. %s.", self.site_sign_wd.reason)
# --- SAFETY-31, AND IT RUNS BESIDE SAFETY-02 FOR THE SAME REASON -----
# Evaluated EVERY cycle, unconditionally, above the "inputs missing but
@@ -2530,8 +2571,8 @@ class Controller:
self.log_event("CIRCULATING POWER - " + self.circ_wd.reason,
hint=messages.hint("circulating"))
_LOG.error(
"Every inverter is set to 0 W because the inverters worked "
"against each other: %s. Only starting control clears this.",
"Every inverter is set to 0 W until control is started, "
"because the inverters worked against each other. %s.",
self.circ_wd.reason)
# --- SAFETY-42, AND IT RUNS HERE FOR SAFETY-02's AND SAFETY-31's REASON
@@ -2638,9 +2679,9 @@ class Controller:
hint=messages.hint("not_delivering",
unit=inv.name))
_LOG.error(
"%s is not delivering: %s. Nothing was changed and control "
"keeps running, and only stopping and starting control "
"clears this.", inv.name, inv.delivery_wd.reason)
"%s is not delivering while control keeps running, and "
"only stopping and starting control clears this. %s.",
inv.name, inv.delivery_wd.reason)
_LOG.debug(
"SAFETY-42 reports and does not act: commanding a unit "
"that is not listening achieves nothing (HW-01), and the "
@@ -2666,7 +2707,12 @@ class Controller:
# A single missed poll is not a fault. Hold, keep the heartbeat
# going, and give it a few seconds to come back.
self.reason = f"inputs missing {bad_for:.0f}s"
# UX-10: the age is rendered when the page asks, not frozen at
# this cycle's. With the meter reading gone the grid value
# stops changing, so the next cycle is up to cycle_floor_s
# away and the line used to read "0 seconds" all that time.
self.why_words = messages.why_waiting(bad_for)
self._why_waiting_since = now - timedelta(seconds=bad_for)
return
claims = []
@@ -3483,7 +3529,7 @@ class Controller:
# other unit never gets. Loud, every cycle, and it does not change
# the resolution - the arbiter already routed by `actuator`.
_LOG.error("A limit was filed on the wrong inverter, which is a "
"software fault: %s", " / ".join(resolution.scope_errors))
"software fault. %s.", " / ".join(resolution.scope_errors))
if resolution.contradiction:
self.log_event("ARBITER CONTRADICTION - commanding 0 W, see the log",
hint=messages.hint("clash"))
@@ -3505,12 +3551,9 @@ class Controller:
self.reason = resolution.explain()
# UX-08: the same answer in plain words, for the page's "Why" line.
# `reason` stays the technical record the log and the checks read.
_why = resolution.winner
if _why in ("safety", "failsafe"):
_why = next((c.reason for c in claims
if c.source == _why and c.kind == "set"),
"no claim was made" if not any(
c.kind == "set" for c in claims) else "unsplit")
# UX-10: `why_key()` maps a safety winner to its claim's reason, and
# every key it can return has words in messages.WHY_WINNER.
_why = why_key(resolution.winner, claims)
self.why_words = messages.why(_why, resolution.target_w,
resolution.bound_by,
contradiction=resolution.contradiction)
@@ -3692,7 +3735,9 @@ class Controller:
self.o, control_started=self.auto)
+ f"; inverter held at {shadow.WIRE_W:.0f} W",
hint=messages.hint("shadow_on"))
_LOG.warning(
# UX-10: INFO. It follows a setting or a button press, and
# no person has to act on it.
_LOG.info(
"Shadow mode is on, so every inverter stays at %.0f W and "
"nothing the add-on decides is sent. %s.", shadow.WIRE_W,
shadow.why(self.o, control_started=self.auto))
@@ -3701,7 +3746,7 @@ class Controller:
"SHADOW MODE OFF - the battery is being controlled again, "
f"resuming from {shadow.WIRE_W:.0f} W",
hint=messages.hint("shadow_off"))
_LOG.warning(
_LOG.info(
"Shadow mode is off, so the add-on controls the battery "
"again, starting from %.0f W.", shadow.WIRE_W)
if not engaged:
@@ -3776,9 +3821,10 @@ class Controller:
# SAFETY-40: only an over-rating is a bug; the integrator bound is not.
bug = engaged_write or loop_bug
if engaged_write:
reason = (", ".join(f"{inv.name}: {inv.clamp_last.describe()}"
for inv in clamped_units) + ". " + CLAMP_BUG_SIGNAL)
_named = len(self.inverters) > 1
reason = write_clamp_note([(inv.name if _named else None,
inv.clamp_last)
for inv in clamped_units])
facts = [messages.Clamp(inv.name if _named else None,
inv.clamp_last.requested_w,
inv.clamp_last.applied_w,
@@ -3824,16 +3870,19 @@ class Controller:
# SAFETY-40: the integrator bound is anti-windup, not a bug - a
# WARNING and a plainly titled notice, same cadence. Its OWN id, so
# it can never replace a BUG SIGNAL notice still on screen.
_LOG.warning("The battery gives less than asked: %s Held back %d "
"times so far.", self.clamp_wd.reason,
self.clamp_wd.engagements)
_LOG.warning("The battery gives less than asked: %s. Held back %s "
"so far.", self.clamp_wd.reason,
messages.times(self.clamp_wd.engagements))
_LOG.debug("A short hold after a large load or solar step is "
"normal. If it lasts, check that the battery follows "
"its commands.")
await self.hass.call("persistent_notification", "create",
messages.loop_bound().data())
return
_LOG.error(
"Power request too high, which is a software fault: %s Control is "
"still running. Cut back %d times so far.",
self.clamp_wd.reason, self.clamp_wd.engagements)
"Power request too high, a software fault: %s. Cut back %s so "
"far, control runs on.",
self.clamp_wd.reason, messages.times(self.clamp_wd.engagements))
_LOG.debug(
"SAFETY-03: silently clipping this is how a winding integrator "
"reached 14 768 W on this project before. The clamp makes every "
@@ -3878,12 +3927,11 @@ class Controller:
was, self._peak_saturated = self._peak_saturated, saturated
if not saturated or was:
return
self.log_event("PEAK GUARD SATURATED - " + g.reason,
self.log_event("PEAK_GUARD_SATURATED - " + g.reason,
hint=messages.hint("peak_saturated"))
_LOG.error(
"The battery is asked for all it can give, but this 15-minute "
"period still goes over the peak limit: %s. Switch off large "
"loads.", g.reason)
"Switch off large loads, the battery alone cannot keep this "
"15-minute period under the peak limit. %s.", g.reason)
# A fixed notification_id, and a DIFFERENT one from every other alarm
# here - check_meter_frozen() gives the reasoning. A saturated peak guard
# is not a frozen meter and is not an out-of-range setpoint.
@@ -3933,15 +3981,14 @@ class Controller:
was, self._peak_floor_limited = self._peak_floor_limited, limited
if not limited or was:
return
# No prefix: `reason` already opens with PEAK GUARD FLOOR-LIMITED, and
# No prefix: `reason` already opens with PEAK_GUARD_FLOOR_LIMITED, and
# a second copy is the kind of stutter that makes a 40-line action log
# read like boilerplate. The saturated path needs its prefix because its
# reason carries the word in the middle of a sentence, not at the front.
self.log_event(g.reason, hint=messages.hint("peak_reserve"))
_LOG.error(
"The peak guard may not draw the battery lower, so this 15-minute "
"period will go over the peak limit: %s. Switch off large loads.",
g.reason)
"Switch off large loads, the peak guard may not draw the battery "
"lower. %s.", g.reason)
# A fixed notification_id, and a DIFFERENT one from every other alarm
# here - check_meter_frozen() gives the reasoning. A battery at its
# energy floor is not a saturated inverter and is not a frozen meter,
@@ -4101,8 +4148,8 @@ class Controller:
hint=messages.hint("meter_frozen"))
_LOG.error(
"The meter shows the same value while the battery is asked for "
"full power: %s. Control still follows it, so check the meter.",
self.freeze_wd.reason)
"full power, and control still follows it, so check the meter. "
"%s.", self.freeze_wd.reason)
_LOG.debug(
"SAFETY-18: nothing else stops this. The meter still answers, so "
"its age is fresh, the firmware watchdog is fed and the arbiter "
@@ -4216,11 +4263,10 @@ class Controller:
and standing is not None and standing.from_feed)
if keep:
_LOG.warning(
"The price update was incomplete (%s), so the plan "
"from %s, %.0f s ago, is kept until it is %.0f s old.",
plan.words, self.tariff_at,
(now - self.tariff_at).total_seconds(),
TARIFF_MAX_AGE_S)
"The price update was incomplete, so the plan from %s "
"is kept until it is %s old. The update held %s.",
messages.when(brussels(self.tariff_at)),
messages.duration(TARIFF_MAX_AGE_S), plan.words)
else:
self.tariff_plan, self.tariff_at = plan, now
_LOG.info("tariff refreshed: %s", plan.words)
@@ -4231,8 +4277,9 @@ class Controller:
# the same reason and on the same terms.
_LOG.warning(
"The price update failed (%s), so the plan from %s is kept "
"until it is %.0f s old, and trading stops then.",
err, self.tariff_at, TARIFF_MAX_AGE_S)
"until it is %s old, and trading stops then.",
err, messages.when(brussels(self.tariff_at)),
messages.duration(TARIFF_MAX_AGE_S))
with contextlib.suppress(asyncio.TimeoutError):
await asyncio.wait_for(self.stop_event.wait(),
timeout=TARIFF_REFRESH_S)
@@ -4612,7 +4659,16 @@ class Controller:
"text": messages.row_controller_ran(_pass_age)})
if self.p1_enabled:
age = self.p1.published_age_s
if self.p1.stale:
if (self.p1.stale and self.p1.age_s() is None
and age <= self.p1.max_age_s):
# UX-10: no reading yet since the start, still inside the
# limit. Amber, not red: it is not a fault yet, but control
# waits for it. Red at 0 s contradicted the limit the row
# prints. Past the limit it is the red row below, as before.
out.append({"ok": False, "warn": True, "id": "meter",
"text": messages.row_meter_waiting(
self.p1.max_age_s)})
elif self.p1.stale:
# The last error is on the add-on log's WARNING line (p1.py).
out.append({"ok": False, "warn": False, "id": "meter",
"text": messages.row_meter_stale(
+4 -5
View File
@@ -351,7 +351,7 @@ class Maintenance:
the action log rather than watching nothing happen.
"""
if blocked_by:
msg = (f"maintenance: forced start REFUSED on {self.name} - "
msg = (f"maintenance: {self.name} cannot start now, because "
f"{blocked_by}")
_LOG.warning("%s", msg)
return [msg]
@@ -378,10 +378,9 @@ class Maintenance:
"""
if self._deferred != why:
self._deferred = why
msg = (f"maintenance: {self.name} is due and is WAITING its turn - "
f"{why}. It is idle under the control loop and will "
f"recalibrate at the next start hour once the slot is free; "
f"this is not a stalled phase.")
msg = (f"maintenance: {self.name} is due and waits its turn, "
f"because {why}. It starts at the next start hour once the "
f"other battery is done. This is not a stalled phase.")
_LOG.info("%s", msg)
events.append(msg)
return events
+21
View File
@@ -315,6 +315,17 @@ def times(n) -> str:
return "1 time" if int(n) == 1 else f"{int(n)} times"
def count(n, noun, plural=None) -> str:
"""`count(1, "price")` -> `1 price`, `count(3, "price")` -> `3 prices`."""
return f"{int(n)} {noun if int(n) == 1 else plural or noun + 's'}"
def when(at) -> str:
"""`27 Sep at 09:15`, as the page writes a moment. `at` is already in the
time zone the reader wants (the caller passes `price.brussels(t)`)."""
return f"{at.day} {at:%b} at {at:%H:%M}"
def for_unit(unit) -> str:
"""` for inverter-b` on a site with several inverters, else nothing."""
return f" for {unit}" if unit else ""
@@ -383,6 +394,11 @@ def row_controller_stalled(age_s, veto_s) -> str:
f"sets the inverter to 0 W after {seconds(veto_s)}.")
def row_meter_waiting(limit_s) -> str:
"""UX-10: no reading yet since the start, and still inside the limit."""
return f"Meter: waiting for the first reading, limit {seconds(limit_s)}"
def row_meter_stale(age_s, limit_s) -> str:
return (f"Meter: no reading for {seconds(age_s)}, limit "
f"{seconds(limit_s)}. The add-on log shows why.")
@@ -766,6 +782,10 @@ WHY_WINNER = {
"stopped": "Control is stopped",
"inputs missing": "A reading is missing",
"no claim was made": "Nothing asked for power",
# UX-10: the claim reasons main.why_key() can return for a safety or
# failsafe winner. test_messages.py part 7 finds every one in the code.
"sign disagreement": "Safety stop, power went the wrong way",
"unsplit": "The power could not be split, all at 0 W",
}
WHY_LIMIT = {
"peak(quarter peak)": "the peak limit",
@@ -898,6 +918,7 @@ def status_samples() -> list:
("row_controller_ran", GREEN, row_controller_ran(2)),
("row_controller_stalled", RED, row_controller_stalled(45, 30)),
("row_meter_stale", RED, row_meter_stale(40, 10)),
("row_meter_waiting", AMBER, row_meter_waiting(30)),
("row_meter", GREEN, row_meter(-350, 2, 3, 340)),
("row_meter_frozen", RED, row_meter_frozen()),
*(("row_freeze_off", AMBER, row_freeze_off(k)) for k in FREEZE_OFF),
+20 -4
View File
@@ -48,6 +48,7 @@ from datetime import datetime, timezone
import aiohttp
from . import messages
from .hass import OUTAGE
_S = messages.setting # a refusal names the setting by its label (UX-08)
@@ -524,6 +525,16 @@ WS_URL = "ws://supervisor/core/websocket"
BAD_STATES = ("unknown", "unavailable", "none", "")
async def _receive_json(ws):
"""The next JSON message. A socket Home Assistant closed (a restart) is a
ConnectionResetError, not aiohttp's "Received message 8:1000 is not str"."""
msg = await ws.receive()
if msg.type is not aiohttp.WSMsgType.TEXT:
raise ConnectionResetError(
f"Home Assistant closed the connection ({msg.type.name})")
return json.loads(msg.data)
class HaDsmrSource:
"""Subscribes to state_changed for the configured DSMR entities.
@@ -574,8 +585,12 @@ class HaDsmrSource:
backoff = 1.0
except asyncio.CancelledError:
raise
except (aiohttp.ClientError, ConnectionError) as err:
# UX-10: Home Assistant restarting, said once (hass.Outage).
OUTAGE.down("websocket", "the meter connection closed", err)
except Exception as err: # noqa: BLE001 - any transport fault retries
_LOG.warning("P1 HA websocket: %s - reconnecting in %.0fs", err, backoff)
_LOG.warning("The meter connection to Home Assistant failed "
"(%s), trying again in %.0f s.", err, backoff)
finally:
self.connected = False
await asyncio.sleep(backoff)
@@ -583,16 +598,17 @@ class HaDsmrSource:
async def _session_once(self) -> None:
async with self.session.ws_connect(WS_URL, heartbeat=30) as ws:
hello = await ws.receive_json()
hello = await _receive_json(ws)
if hello.get("type") == "auth_required":
await ws.send_json({"type": "auth", "access_token": self.token})
reply = await ws.receive_json()
reply = await _receive_json(ws)
if reply.get("type") != "auth_ok":
raise RuntimeError(f"auth rejected: {reply.get('message', reply)}")
await ws.send_json({"id": 1, "type": "subscribe_events",
"event_type": "state_changed"})
await ws.send_json({"id": 2, "type": "get_states"})
self.connected = True
OUTAGE.up("websocket")
_LOG.info("P1 ingest: subscribed to %s", ", ".join(sorted(self.ids)))
async for msg in ws:
@@ -618,7 +634,7 @@ class HaDsmrSource:
new = data.get("new_state") or {}
self._absorb(data.get("entity_id"), new.get("state"))
self._schedule()
raise RuntimeError("websocket closed")
raise ConnectionResetError("Home Assistant closed the connection")
def _absorb(self, entity_id: str | None, state) -> None:
if not entity_id or entity_id not in self.ids:
+36 -32
View File
@@ -402,27 +402,27 @@ from .tariff import QUARTER_S
# Why the projection may not be graded. Reasons, not booleans: the status page
# and the action log both have to say WHICH, and "blind" alone is unactionable.
BLIND_NO_BLOCK = "no open quarter - the meter has produced no sample yet"
BLIND_NO_BLOCK = "no open 15-minute period, the meter has given no reading yet"
BLIND_COVERAGE = "meter gap"
BLIND_FROZEN = "SAFETY-18: the meter is answering without changing"
BLIND_FROZEN = "the meter is answering without changing"
# Where the ceiling came from. Only the second is a relaxation, and only an
# OBSERVED reading may produce it.
CEILING_CAP = "peak_cap_w"
CEILING_MONTH_PEAK = "the month's banked peak"
CEILING_MONTH_PEAK = "this month's peak"
# SAFETY-24. Why the forced discharge may not be sized. Reasons, not booleans,
# for BLIND_*'s reason: the status page, the action log and the operator
# notification all have to say WHICH, and "floor-limited" alone is unactionable.
FLOOR_SOC_UNREADABLE = ("the battery state of charge was not measured this "
"cycle, and an unreadable SoC is not a full battery")
# ⚠️ SAFETY-25. "the peak guard's SoC floor", not "the SoC floor", and the
# possessive is load-bearing: this string is what the status page, the action log
# and the operator notification all print, and `peak_soc_floor` bounds THIS GUARD
# ONLY. Widening it to "the SoC floor" would make the one sentence an operator
# reads at the moment the battery stops shaving into a claim about the pack that
# the grid-following loop is at that instant disproving.
FLOOR_AT_SOC_FLOOR = "state of charge is at or below the peak guard's SoC floor"
FLOOR_SOC_UNREADABLE = ("the battery level was not read this cycle, and "
"unread is not full")
# ⚠️ SAFETY-25. "the peak reserve", not "the SoC floor", and the name is
# load-bearing: this string is what the action log and the add-on log print,
# and `peak_soc_floor` (“Peak reserve”) bounds THIS GUARD ONLY. Widening it to
# "the SoC floor" would make the one sentence an operator reads at the moment
# the battery stops shaving into a claim about the pack that the
# grid-following loop is at that instant disproving.
FLOOR_AT_SOC_FLOOR = "the battery level is at or below the peak reserve"
SOURCE = "peak"
@@ -566,8 +566,9 @@ def blindness(projection, max_hold_s, frozen: bool) -> str | None:
return BLIND_NO_BLOCK
gap = uncovered_s(projection)
if max_hold_s is not None and gap > float(max_hold_s):
return (f"{BLIND_COVERAGE}: {gap:.0f} s of this quarter uncovered, past "
f"the {float(max_hold_s):.0f} s the averager will hold a sample")
return (f"{BLIND_COVERAGE}, {gap:.0f} s of this 15-minute period not "
f"covered, past the {float(max_hold_s):.0f} s a reading is "
f"held")
return None
@@ -743,9 +744,9 @@ def decide(projection, *, batt_w, cap_w, reading, achievable_w, soc, soc_floor,
return PeakDecision(
engaged=True, floor_w=0.0, ceiling_w=ceiling, ceiling_from=from_where,
blind=blind, projected_w=None,
reason=(f"PEAK GUARD BLIND ({blind}) - the battery may not import "
f"while the billed quarter cannot be measured; commanding no "
f"charging (floor 0 W)"))
reason=(f"PEAK_GUARD_BLIND: {blind}. The battery may not charge "
f"while this 15-minute period cannot be measured, so it "
f"is asked for no charging, floor 0 W"))
projected = float(projection.projected_w)
if batt_w is None:
@@ -807,17 +808,18 @@ def decide(projection, *, batt_w, cap_w, reading, achievable_w, soc, soc_floor,
ceiling_from=from_where, projected_w=projected, excess_w=ex,
wanted_w=wanted, floor_limited=True, soc=soc, soc_floor=soc_floor,
soc_floor_reason=denied,
# UX-10: plain sentences, every figure kept (test_messages.py
# part 6). The code is one token, so it is not read as shouting.
reason=(
f"PEAK GUARD FLOOR-LIMITED: the quarter projects "
f"{projected:.0f} W against a {ceiling:.0f} W ceiling "
f"({from_where}) and {wanted:+.0f} W of discharge would hold "
f"it, but {denied}"
+ ("" if soc is None else f" ({float(soc):.0f} %")
f"PEAK_GUARD_FLOOR_LIMITED: this 15-minute period heads for "
f"{projected:.0f} W against a {ceiling:.0f} W limit "
f"({from_where}), and {wanted:+.0f} W from the battery would "
f"hold it. But {denied}"
+ ("" if soc is None else f", at {float(soc):.0f} %")
+ ("" if soc is None or soc_floor is None
else f" vs {float(soc_floor):.0f} %")
+ ("" if soc is None else ")")
+ " - commanding no forced discharge, so THIS QUARTER WILL GO "
"OVER THE CEILING. Charging stays blocked (floor 0 W)"))
else f" against {float(soc_floor):.0f} %")
+ ", so no forced discharge and no charging, and this period "
"will go over the limit"))
floor = min(wanted, ceil_top)
saturated = floor < wanted
@@ -826,13 +828,15 @@ def decide(projection, *, batt_w, cap_w, reading, achievable_w, soc, soc_floor,
blind=None, projected_w=projected, excess_w=ex, wanted_w=wanted,
saturated=saturated, soc=soc, soc_floor=soc_floor,
reason=(
f"PEAK GUARD: quarter projects {projected:.0f} W against a "
f"{ceiling:.0f} W ceiling ({from_where}) with "
f"PEAK_GUARD: this 15-minute period heads for {projected:.0f} W "
f"against a {ceiling:.0f} W limit ({from_where}), with "
f"{QUARTER_S - projection.elapsed_s:.0f} s left, so {ex:.0f} W must "
f"come off the meter; battery measured {float(batt_w):+.0f} W, "
f"floor {floor:+.0f} W"
+ (f" - SATURATED, {wanted:+.0f} W was needed and the inverter can "
f"only give {ceil_top:.0f} W" if saturated else "")))
f"come off the meter. The battery measured {float(batt_w):+.0f} W "
f"and is asked for {floor:+.0f} W"
# Saturated means floor == ceil_top: the ask IS the most the
# inverters give, so one clause says both.
+ (f", the most the inverters give, but {wanted:+.0f} W was needed"
if saturated else "")))
def charge_headroom_w(decision) -> float | None:
+8 -7
View File
@@ -150,6 +150,7 @@ from enum import Enum
from textwrap import dedent
from urllib.parse import urlencode
from . import messages
from .custom_formula import (
EXPORT_FORMULA_OPTION, FormulaInvalid, PREVIEW_HOURS, parse_export_formula,
parse_price_formula, preview_lines, price_eur_kwh, to_resolution)
@@ -1738,11 +1739,11 @@ def _points_from_columnar_json(body, expect_unit, scale,
out.append(RawPoint(start=start, eur_per_kwh=float(v) * scale,
provisional=bool(provisional_default)))
if dropped:
_LOG.warning("The price feed gave no price for %d of %d times (index "
"%s). Those times are left out, not counted as free.",
len(dropped), len(times),
_LOG.warning("The price feed gave no price for %d of %s, at index "
"%s. Those are left out, not counted as free.",
len(dropped), messages.count(len(times), "time"),
", ".join(str(i) for i in dropped[:5])
+ (", ..." if len(dropped) > 5 else ""))
+ (" and more" if len(dropped) > 5 else ""))
if not out:
raise SourceUnavailable(
f"the feed carried {len(times)} instants and a price for none of "
@@ -2106,12 +2107,12 @@ async def load_prices(opts: dict, since: datetime, until: datetime,
pid = provider_id(opts)
if not provider_configured(opts):
return PriceRead.no_data(
"no price provider configured (price_provider is 'off'); "
"§11.4: static profile, plan provisional, no arbitrage")
"no price feed is set (price_provider is 'off'), so the fixed "
"tariff is used, the plan is estimated and there is no trading")
cls = PROVIDERS.get(pid)
if cls is None:
return PriceRead.no_data(
f"unknown price provider {pid!r}; shipped: "
f"unknown price provider {pid!r}. The known ones are "
f"{', '.join(sorted(PROVIDERS))}")
caps = cls.capabilities()
+27 -24
View File
@@ -164,6 +164,7 @@ from dataclasses import dataclass
from datetime import datetime, timedelta, timezone
from enum import Enum
from . import messages
from .maintenance import CHARGE_TIMEOUT_MIN, DRAIN_TIMEOUT_MIN
from .price import PricePoint, PriceRead, _Outcome, brussels
@@ -411,13 +412,14 @@ def fill_from_yesterday(read: PriceRead, *, yesterday: PriceRead,
if not out:
reason = read.match(
series=lambda r: (f"the {len(r.points)} published hours all fall "
f"outside {since.isoformat()}..{until.isoformat()}"),
series=lambda r: (f"all {messages.count(len(r.points), 'published price')} "
f"fall outside {messages.when(brussels(since))} to "
f"{messages.when(brussels(until))}"),
no_data=lambda r: r.reason)
return PriceRead.no_data(
f"§8.3 carry-forward produced no hours: {reason}, and yesterday's "
f"profile has nothing to fill them with either. §11.4 applies: "
f"static profile, plan provisional, no arbitrage")
f"no hours could be filled from yesterday's prices: {reason}. So "
f"the fixed tariff is used, the plan is estimated and there is no "
f"trading")
_audit(out, published)
carried = sum(1 for p in out if _utc_hour(p.start) not in published)
@@ -431,10 +433,11 @@ def fill_from_yesterday(read: PriceRead, *, yesterday: PriceRead,
# hours" about a 48-hour horizon. The fill's unit is the HOUR and the
# feed's is the POINT; nothing derived from one answers for the other.
total_h = len({_utc_hour(p.start) for p in out})
_LOG.info("§8.3: %d of %d hours carried forward from yesterday's "
"profile and flagged provisional; the feed published %d "
"points over the other %d hours",
carried, total_h, len(out) - carried, total_h - carried)
_LOG.info("%d of %s use yesterday's prices, marked as estimated. "
"The feed published %s over the other %s.",
carried, messages.count(total_h, "hour"),
messages.count(len(out) - carried, "price"),
messages.count(total_h - carried, "hour"))
product = read.match(series=lambda r: r.product,
no_data=lambda _r: yesterday.product)
@@ -525,8 +528,8 @@ class _Permitted(Gate):
"one rule this type has.")
self.action = action
self.hours = pts
self.words = (f"{action.name} permitted on {len(pts)} firm hours "
f"({pts[0].start.isoformat()} ..)")
self.words = (f"allowed on {messages.count(len(pts), 'published price')} "
f"from {messages.when(brussels(pts[0].start))}")
class _Blocked(Gate):
@@ -570,8 +573,8 @@ def price_permits(read: PriceRead, now: datetime,
return read.match(
series=lambda r: _walk(r, hours, action),
no_data=lambda r: Gate.block(
f"{action.name} is gated on a price and there is no price data: "
f"{r.reason}. §11.4 - and a missing price is not a cheap one"))
f"{action.name} needs a price and there is none: {r.reason}. A "
f"missing price is not a cheap one"))
def _walk(series, hours, action) -> Gate:
@@ -579,19 +582,18 @@ def _walk(series, hours, action) -> Gate:
for u in hours:
if not series.covers(u):
return Gate.block(
f"{action.name} commits {action.commits_h:g} h from "
f"{hours[0].isoformat()} and no price covers "
f"{u.isoformat()}. An hour outside the series is an hour with "
f"no price (§11.4 for that hour), not a free one")
f"{action.name} needs prices for {action.commits_h:g} hours "
f"from {messages.when(brussels(hours[0]))}, and no price "
f"covers {messages.when(brussels(u))}. An hour with no price "
f"is not a free one")
p = series.at(u)
if p.provisional:
return Gate.block(
f"{action.name} commits {action.commits_h:g} h from "
f"{hours[0].isoformat()} and {u.isoformat()} is PROVISIONAL - "
f"carried from yesterday's profile or standing in for a dead "
f"feed. §8.3: no irreversible action may be taken on a "
f"provisional price. It becomes available when the day-ahead "
f"print lands (~14-16 h CET, §5.4)")
f"{action.name} needs prices for {action.commits_h:g} hours "
f"from {messages.when(brussels(hours[0]))}, and the price for "
f"{messages.when(brussels(u))} is only estimated. It can start "
f"once the day-ahead prices are published, around 14:00 to "
f"16:00")
pts.append(p)
return Gate.permit(action, pts)
@@ -622,5 +624,6 @@ def _go(maint, now, gate) -> Gate:
def _no(gate) -> Gate:
_LOG.warning("irreversible action refused - %s", gate.reason)
_LOG.warning("An action that cannot be undone does not start: %s.",
gate.reason)
return gate
+54 -37
View File
@@ -186,8 +186,9 @@ import json
import logging
import os
import tempfile
from datetime import datetime, timedelta, timezone
from datetime import date, datetime, timedelta, timezone
from . import messages
from .price import PricePoint, PriceProduct, PriceRead, brussels
from .price_forecast import fill_from_yesterday
@@ -345,8 +346,19 @@ def _row_of(day: str, points: int, hours: int) -> str:
whole day to carry, and that is the HOUR figure; the point count says how
finely it is priced. Neither answers for the other.
"""
return (f"{day} ({points} price{'' if points == 1 else 's'} "
f"over {hours} hour{'' if hours == 1 else 's'})")
# UX-10: the day as the page writes dates ("26 Sep"), not ISO.
return (f"{points} price{'' if points == 1 else 's'} over {hours} "
f"hour{'' if hours == 1 else 's'} for {day_words(day)}")
def day_words(day) -> str:
"""`'2026-09-26'` -> `'26 Sep'`, as the page writes a date. A key that is
not a date is shown as it is, because this feeds a status row."""
try:
d = date.fromisoformat(str(day))
except ValueError:
return str(day)
return f"{d.day} {d:%b}"
def _bad_rows(rec) -> int:
@@ -393,9 +405,8 @@ class PriceHistory:
self.last_error = f"no durable volume at {parent}"
# INFO, not ERROR: on a dev host or in a test container there is no
# /data and nothing is wrong.
_LOG.info("no price history: %s - §8.3 carry-forward has nothing "
"to carry and the horizon stays as short as the feed",
self.last_error)
_LOG.info("No price history is kept (%s), so missing hours are "
"not filled from yesterday's prices.", self.last_error)
return
self.ok = True
self._load()
@@ -449,15 +460,15 @@ class PriceHistory:
# would not notice a writer this build has never met.
if not isinstance(blob, dict) or isinstance(found, bool) \
or not isinstance(found, int) or found != SCHEMA:
self.last_error = f"schema {found!r}, not {SCHEMA}"
_LOG.warning("price history at %s has %s - discarding it rather "
"than guessing what its points mean",
self.last_error = f"version {found!r}, not {SCHEMA}"
_LOG.warning("Price history at %s has %s, so it is not used.",
self.path, self.last_error)
return
days = blob.get("days")
if not isinstance(days, dict):
self.last_error = "no `days` object"
_LOG.warning("price history at %s has %s", self.path, self.last_error)
self.last_error = "no days in it"
_LOG.warning("Price history at %s has %s, so it is not used.",
self.path, self.last_error)
return
self._days = self._usable_days(days)
@@ -504,20 +515,22 @@ class PriceHistory:
kept[key] = rec
notes = []
if dropped:
notes.append(f"{len(dropped)} unusable day record(s) dropped "
f"({', '.join(sorted(dropped))})")
notes.append(f"{messages.count(len(dropped), 'unusable day')} "
f"dropped, " + ", ".join(day_words(d)
for d in sorted(dropped)))
if malformed:
notes.append(
f"{sum(malformed.values())} malformed point row(s) in "
+ ", ".join(f"{d} ({n})" for d, n in sorted(malformed.items())))
f"{messages.count(sum(malformed.values()), 'bad price')} in "
+ ", ".join(f"{day_words(d)} ({n})"
for d, n in sorted(malformed.items())))
if notes:
# Recorded, not silent: `yesterday()` and `words` both report
# `last_error`, and a cache that quietly discards half a file reads
# to an operator exactly like a normal first day.
self.last_error = "; ".join(notes)
_LOG.warning("price history at %s: %s - the controller starts "
"anyway and the horizon is as short as the feed makes "
"it", self.path, self.last_error)
self.last_error = " and ".join(notes)
_LOG.warning("Price history at %s: %s. The add-on starts anyway, "
"and fills in only what the rest holds.",
self.path, self.last_error)
return kept
def _save(self) -> bool:
@@ -680,10 +693,11 @@ class PriceHistory:
# undone with the rest of the merge, so those rows are still in the
# file and the next write that completes drops them again.
self.last_error = (
f"{sum(junked.values())} malformed point row(s) dropped from "
+ ", ".join(f"{d} ({n})" for d, n in sorted(junked.items())))
_LOG.warning("price history at %s: %s - the record is rewritten "
"without them and the refresh continues",
f"{messages.count(sum(junked.values()), 'bad price')} dropped "
f"from " + ", ".join(f"{day_words(d)} ({n})"
for d, n in sorted(junked.items())))
_LOG.warning("Price history at %s: %s. The file is saved without "
"them and the price update goes on.",
self.path, self.last_error)
self._prune(stamp)
if not self._save():
@@ -752,21 +766,23 @@ class PriceHistory:
if self.last_error and not self._days:
return PriceRead.no_data(
f"the price history at {self.path} is {self.last_error}, so "
f"§8.3 has no profile to carry forward for {want}; the plan "
f"covers only the hours the feed published")
f"there are no prices from yesterday to fill in for "
f"{day_words(want)}. The plan covers only the hours the feed "
f"published")
rec = self._days.get(want)
if rec is None:
have = ", ".join(sorted(self._days)) or "no days at all"
have = (", ".join(day_words(d) for d in sorted(self._days))
or "no days at all")
return PriceRead.no_data(
f"no published prices recorded for {want} (held: {have}), so "
f"§8.3 has no profile to carry forward. A record for another "
f"day is not a yesterday")
f"no published prices are kept for {day_words(want)}, only for "
f"{have}, so there are no prices from yesterday to fill in. A "
f"record for another day is not a yesterday")
points, bad = _parse_points(rec.get("points"))
if not points:
why = bad or "it is empty"
return PriceRead.no_data(
f"the {want} record holds no usable point ({why}), and an "
f"empty series is not a free day")
f"the {day_words(want)} record holds no usable price, {why}, "
f"and an empty series is not a free day")
try:
product = PriceProduct(rec.get("product"))
except ValueError:
@@ -775,8 +791,9 @@ class PriceHistory:
f"which is not a PriceProduct. The optimiser switches on that "
f"enum, so a record that cannot name one cannot be a series")
if bad:
_LOG.warning("Price history: %s in the %s record were dropped, "
"and %d points were kept.", bad, want, len(points))
_LOG.warning("Price history: %s dropped from the %s record, and "
"%s kept.", bad, day_words(want),
messages.count(len(points), "price"))
return PriceRead.series(points, product,
str(rec.get("provider") or "price_history"),
stamp)
@@ -805,7 +822,7 @@ class PriceHistory:
if not self._days:
why = f" - {self.last_error}" if self.last_error else ""
return f"empty{why} - nothing to carry forward yet"
held = "; ".join(_row_of(d, *_held(self._days[d]))
held = ", ".join(_row_of(d, *_held(self._days[d]))
for d in sorted(self._days, key=str))
# A file that PARTLY loaded says so, or the dropped days read as days
# that were simply never written.
@@ -833,7 +850,7 @@ def _parse_points(raw) -> tuple:
continue
out.append(pt)
out.sort(key=lambda p: p.start.astimezone(timezone.utc))
return tuple(out), (f"{dropped} malformed point(s)" if dropped else "")
return tuple(out), (messages.count(dropped, "bad price") if dropped else "")
class NoHistory:
@@ -861,5 +878,5 @@ class NoHistory:
def yesterday(self, stamp: datetime) -> PriceRead:
return PriceRead.no_data(
"this caller keeps no price history (NoHistory), so §8.3 has no "
"profile to carry forward")
"this caller keeps no price history, so there are no prices from "
"yesterday to fill in")
+4 -2
View File
@@ -82,6 +82,7 @@ import os
import aiohttp
from . import messages
from .configui import changed_keys
from .inverter import build_roster
from .validate import validate_startup_config, validate_unit_ranges
@@ -381,8 +382,9 @@ async def save(selfcfg: SelfConfig, proposed: dict, expect: str, *,
"""
problems = await problems_for(proposed, hass)
if problems:
_LOG.warning("The settings page did not save, because of %d "
"problems. The first: %s", len(problems), problems[0])
_LOG.warning("The settings page did not save, because of %s. The "
"first: %s", messages.count(len(problems), "problem"),
problems[0])
raise SaveRefused("invalid", problems=problems)
info = await selfcfg.info()
+30 -13
View File
@@ -1130,13 +1130,28 @@ class TariffPlan:
PriceProduct.STATIC: "day/night prices",
PriceProduct.FIXED: "a fixed price"}.get(self.product,
str(self.product))
# UX-10: the spacing in words, and no "not final yet": a plan is
# provisional exactly when it holds an estimated price, which the
# count already says.
gaps = self.spacings_s
return (f"{what} from {tag}, "
f"{self.n_points} prices over {self.hours} hours, "
f"{self.n_firm} published and {self.n_carried} estimated"
+ (f", {'+'.join(str(g) for g in gaps)} s apart"
if gaps else "")
+ (", not final yet" if self.provisional else ""))
+ (f", {spacing_words(gaps)}" if gaps else ""))
def spacing_words(gaps) -> str:
"""`(900, 3600)` -> `one every 15 minutes or every hour`."""
def one(s):
s = int(s)
if s == 3600:
return "every hour"
if s % 3600 == 0:
return f"every {s // 3600} hours"
if s % 60 == 0:
return f"every {s // 60} minutes"
return f"every {s} seconds"
return "one " + " or ".join(one(g) for g in gaps)
def _whole_hours(points) -> int:
@@ -1206,9 +1221,9 @@ def static_plan(opts: dict, since: datetime, until: datetime, *,
if profile is None:
return TariffPlan(
PriceRead.no_data(
"no static_profile configured; §11.4: plan provisional, no "
"arbitrage. Self-consumption, peak shaving and reserve "
"management are unaffected"),
"no fixed tariff is set, so the plan is estimated and there "
"is no trading. Self-consumption, peak limiting and the "
"reserve are not affected"),
None, "none")
points = profile.series(since, until, provisional=provisional)
return TariffPlan(
@@ -1338,16 +1353,18 @@ def _degrade(opts, read, since, until, stamp) -> TariffPlan:
try:
profile = parse_static_profile(price_option(opts, "static_profile"))
except ProfileInvalid as e:
_LOG.warning("the price feed is down AND static_profile is unusable "
"(%s), so there is no tariff at all", e)
_LOG.warning("The price feed is down and the fixed tariff "
"(static_profile) cannot be used either (%s), so there is "
"no tariff at all.", e)
profile = None
if profile is None:
_LOG.warning("%s, and no static_profile is set to fall back to, so "
"prices are provisional and trading is off. Peak "
"limiting and home use go on.", read.reason)
_LOG.warning("The price feed failed and no fixed tariff is set, so "
"trading is off, while peak limiting and home use go on. "
"%s.", read.reason)
return TariffPlan(read, None, "none")
_LOG.warning("%s, so the static_profile tariff is used instead, marked "
"provisional, and trading is off.", read.reason)
_LOG.warning("The price feed failed, so the fixed tariff is used "
"instead, marked as estimated, and trading is off. %s.",
read.reason)
points = profile.series(since, until, provisional=True)
return TariffPlan(
PriceRead.series(points, profile.product, "static_profile", stamp),
+31 -22
View File
@@ -222,6 +222,8 @@ class MigrationReport:
self.misdirected = []
# Why nothing ran, when nothing ran. Empty means "already at schema".
self.skipped = ""
# The inverter list the moves were graded against, for `explain()`.
self.roster = []
@property
def ok(self) -> bool:
@@ -237,19 +239,27 @@ class MigrationReport:
# the flat keys ARE its namespace - and an operator reading the
# startup log needs to be told which, because only one of them
# changes when a second inverter is declared.
return self.skipped or (f"store already at schema "
f"{self.from_version}; no "
f"per-inverter migration needed")
out = (f"migrated {len(self.moved)} flat key(s) to inverter "
f"namespaces: " + ", ".join(sorted(self.moved)))
return self.skipped or (f"the saved state is already at version "
f"{self.from_version}, so nothing moves")
# UX-10: plain sentences (test_messages.py part 6). Each problem is
# named by its key and what went wrong, and `problems`, `lost` and
# `misdirected` keep their full notes for the checks that read them.
n = len(self.moved)
out = (f"moved {n} saved {'value' if n == 1 else 'values'} to one part "
f"per inverter: " + ", ".join(sorted(self.moved)) if n
else "moved nothing")
if self.kept:
out += " (left alone, already namespaced: " + ", ".join(sorted(self.kept)) + ")"
if self.problems:
out += " - PROBLEMS: " + "; ".join(self.problems)
if self.lost:
out += " - STATE LOST: " + "; ".join(self.lost)
if self.misdirected:
out += " - WRONG NAMESPACE: " + "; ".join(self.misdirected)
out += ". Already in place: " + ", ".join(sorted(self.kept))
def keys(notes):
return ", ".join(note.split(" ", 1)[0] for note in notes)
other = [n for n in self.problems
if n not in self.lost and n not in self.misdirected]
parts = ([f"lost {keys(self.lost)}"] if self.lost else []) + (
[f"moved under an inverter not in the list {self.roster!r}: "
f"{keys(self.misdirected)}"] if self.misdirected else []) + (
[f"read back differently {keys(other)}"] if other else [])
if parts:
out += ". Problems: " + ", and ".join(parts)
return out
@@ -436,6 +446,7 @@ def _verify_moves(store, rep: MigrationReport, roster=None) -> None:
if roster is None:
return
names = [str(n) for n in roster]
rep.roster = names
# `unit_key()` builds `unit/<unit>/<key>`, so the unit is field 1. Split
# through the same spelling the writer used rather than re-deriving it.
#
@@ -469,8 +480,8 @@ def _verify_moves(store, rep: MigrationReport, roster=None) -> None:
if unit in names:
continue
rep.verified = False
note = (f"{target} was migrated into namespace {unit!r}, which is NOT "
f"on the roster {names!r} - nothing reads that key")
note = (f"{target} was moved under {unit!r}, which is not in the "
f"inverter list {names!r}, so nothing reads it")
rep.problems.append(note)
rep.misdirected.append(note)
@@ -536,14 +547,12 @@ def migrate_maint_keys(store, unit: str, roster) -> MigrationReport:
names = [str(n) for n in roster]
rep.from_version = int(data.get(MAINT_SCHEMA_KEY, 0) or 0)
if len(names) <= 1:
rep.skipped = ("one inverter: the flat maintenance keys ARE that pack's "
"history and are read in place, so there is nothing to "
"move and the store layout does not change")
rep.skipped = ("one inverter, so it is read where it is and nothing "
"moves")
return rep
if rep.from_version >= MAINT_SCHEMA_VERSION:
rep.skipped = (f"maintenance history already at schema "
f"{rep.from_version}; written by a multi-inverter "
f"version and not touched")
rep.skipped = (f"already at version {rep.from_version}, written for "
f"several inverters, so it is left as it is")
return rep
rep.ran = True
@@ -567,8 +576,8 @@ def migrate_maint_keys(store, unit: str, roster) -> MigrationReport:
# the re-run a no-op where the keys did land, so refusing the marker
# costs one repeated pass and buys the difference between a migration
# that can still be fixed and one the store says already happened.
_LOG.error("per-pack maintenance-history migration did NOT land and "
"has not been marked done: %s", rep.explain())
_LOG.error("Moving the maintenance history to one part per inverter "
"did not work, so it is not marked done: %s", rep.explain())
return rep
+22 -13
View File
@@ -114,6 +114,8 @@ import sqlite3
from dataclasses import dataclass
from datetime import datetime, timedelta, timezone, tzinfo
from . import messages
_LOG = logging.getLogger("goodwe.tariff")
QUARTER_S = 900
@@ -339,8 +341,8 @@ class PeakStore:
# INFO, not ERROR: on a dev host or in a test container there is no
# /data and nothing is wrong. A store that OPENED and then broke is
# the error case, and it is logged as one below.
_LOG.info("no peak store: %s - the monthly peak will read "
"NOT_OBSERVED", self.last_error)
_LOG.info("No peak store (%s), so the month peak cannot be read "
"and only the peak limit is used.", self.last_error)
return
try:
self._db = sqlite3.connect(self.path, timeout=5.0,
@@ -360,8 +362,9 @@ class PeakStore:
# fault must not stop a controller that is regulating a battery. The
# cost of continuing is a peak that reads NOT_OBSERVED, and every
# reader is built to treat that as "do not use me", not as 0 W.
_LOG.error("peak store unusable at %s (%s) - the monthly peak will "
"read NOT_OBSERVED, which is not a zero peak", self.path, err)
_LOG.error("The peak store at %s cannot be used (%s), so only the "
"peak limit is used. The month peak is unknown, not "
"zero.", self.path, err)
def close(self) -> None:
if self._db is not None:
@@ -672,12 +675,12 @@ class PeakTracker:
now = now or datetime.now(timezone.utc)
snap = self.store.load_partial()
if not snap:
self.restore_state = ("fresh: no checkpoint" if self.store.ok
else "fresh: store unreadable")
self.restore_state = ("fresh start, nothing saved" if self.store.ok
else "fresh start, the store cannot be read")
return self.restore_state
block = snap.get("block")
if block is None:
self.restore_state = "fresh: checkpoint had no open block"
self.restore_state = "fresh start, no open 15-minute period saved"
return self.restore_state
current = int(now.timestamp() // QUARTER_S) * QUARTER_S
@@ -686,11 +689,13 @@ class PeakTracker:
# A reshaped accumulator (meter_phases changed) is a different
# measurement, not a resumable one. Say so; do not half-resume.
self.store.clear_partial()
self.restore_state = "fresh: checkpoint does not fit this averager"
self.restore_state = ("fresh start, the saved period does not "
"fit the number of phases")
return self.restore_state
self.restore_state = (
f"resumed the open block at {snap.get('elapsed', 0.0):.0f} s "
f"of {QUARTER_S} s ({snap.get('acc', 0.0) / QUARTER_S:.0f} W banked)")
f"resumed the open 15-minute period at "
f"{snap.get('elapsed', 0.0):.0f} s of {QUARTER_S} s, with "
f"{snap.get('acc', 0.0) / QUARTER_S:.0f} W counted so far")
return self.restore_state
# The block ended while the add-on was down. Its measured part really
@@ -704,10 +709,14 @@ class PeakTracker:
if snap.get("pp_acc") and snap.get("last_pp") else None))
banked = self.store.record_block(closed, self.policy)
self.store.clear_partial()
# UX-10: plain words and the local time, not ISO and "banked".
self.restore_state = (
f"closed a stale block from {closed.start.isoformat()} at "
f"{closed.offtake_avg_w:.0f} W (partial coverage), "
+ ("banked" if banked else "NOT banked - store unwritable"))
f"closed the 15-minute period from "
f"{messages.when(closed.start.astimezone(BILLING_TZ))} at "
f"{closed.offtake_avg_w:.0f} W, partly measured, "
+ ("and saved it" if banked
else "but could not save it, because the store cannot be "
"written"))
return self.restore_state
# -- steady state -------------------------------------------------------
+32 -9
View File
@@ -343,6 +343,30 @@ from .watchdog import SIGN_OPTION_DEFAULTS
_LOG = logging.getLogger("goodwe.config")
class _WarnOnce(logging.Filter):
"""UX-10: a settings warning is said once per start. The validator runs
twice at start (before the first cycle and again once the inverter's range
is known), and a warning about options that have not changed is the same
news both times. Refusals are ERROR and pass untouched."""
def __init__(self):
super().__init__()
self.seen = set()
def filter(self, record):
if record.levelno != logging.WARNING:
return True
text = record.getMessage()
if text in self.seen:
return False
self.seen.add(text)
return True
WARN_ONCE = _WarnOnce()
_LOG.addFilter(WARN_ONCE)
# ⚠️ A MIRROR OF A FIRMWARE CONSTANT, AND IT CANNOT BE IMPORTED. The firmware
# threshold is a compile-time YAML substitution baked into the ESP32 image
# (`max_age_s: "30"`, master/goodwe-master-stage4-failsafe.yaml), so nothing at
@@ -1314,12 +1338,11 @@ def _price_problems(opts: dict) -> list[str]:
if profile is not None and profile.product is not None \
and len(set(profile.prices)) == 1:
_LOG.info(
"static_profile carries one distinct price (%.4f EUR/kWh "
"all-in), so this site is priced as FULLY FIXED. Arbitrage is "
"off by arithmetic - a flat series has no spread - and the "
"add-on runs self-consumption only, which is §9.2's handling "
"for this product. Peak shaving, reserve management and the "
"maintenance cycle are unaffected.", profile.prices[0])
"static_profile has one price (%.4f EUR/kWh all-in), so this "
"site has a fully fixed price. A flat price has no spread to "
"trade on, so the add-on uses the battery for self-consumption "
"only. Peak limiting, the reserve and battery maintenance are "
"not affected.", profile.prices[0])
# ⚠️ TARIFF-17: THE TAXES PERIOD TABLE, PARSED AT STARTUP RATHER THAN AT
# 03:00, FOR `static_profile`'s REASON ONE OPTION OVER. This table is read
@@ -1505,9 +1528,9 @@ def _price_problems(opts: dict) -> list[str]:
_LOG.info(
"%s is set: injection priced as (%g x index %+g) x "
"(1 + %g/100) %s, i.e. %.4g x the wholesale price with a "
"%+.5f EUR/kWh offset. ⚠️ NO STRATEGY IN THIS ADD-ON READS "
"IT: arbitrage.py prices the sell side as displaced IMPORT "
"and compares two all-in CONSUMPTION prices, so this option "
"%+.5f EUR/kWh offset. No part of the add-on reads it yet: "
"trading prices the sell side as displaced import and "
"compares two all-in consumption prices, so this setting "
"changes no decision the add-on takes today. It is what you "
"are shown, and the shape a future export-aware strategy "
"would read.",
+9 -1
View File
@@ -304,8 +304,16 @@ def build_app(controller, selfcfg=None) -> web.Application:
return app
def access_log():
"""UX-10: the page polls /status every few seconds, and aiohttp logs each
request at INFO. That access log is kept for a DEBUG log level only."""
return (logging.getLogger("aiohttp.access")
if _LOG.isEnabledFor(logging.DEBUG) else None)
async def start(controller, port: int = 8099, selfcfg=None):
runner = web.AppRunner(build_app(controller, selfcfg))
runner = web.AppRunner(build_app(controller, selfcfg),
access_log=access_log())
await runner.setup()
site = web.TCPSite(runner, "0.0.0.0", port)
await site.start()
+21 -18
View File
@@ -1037,7 +1037,8 @@ check("...and the operator is told WHICH bound bit, so a device-rating clamp "
and messages.LIMIT_WORDS["device"] in notes_w[0]["message"]
and messages.LIMIT_WORDS["max_w"] not in notes_w[0]["message"])
check("...and the action log carries the row, written by write_setpoint()",
any(REASON_CODE in e and "device bound" in e for e in ctl_w.events))
any(REASON_CODE in e and messages.LIMIT_WORDS["device"] in e
for e in ctl_w.events))
# The same stimulus, the same clamp, the two calls swapped. This is the ticket
# in one pair of runs.
@@ -1125,8 +1126,8 @@ check("⚠️ THE ORDERED PAIR IN THE §15 ACTION-LOG ROW (main.py:1366). The "
"the loop asked for +2000 W and the guard clamped it UP to +9999 W - "
"past the 2000 W rating printed four words later - which is the alarm "
"reading backwards on the one line an operator is woken by",
any(f"the computed setpoint {_asked_x:+.0f} W was clamped to "
f"{_sent_x:+.0f} W" in e for e in _rows_x))
any(f"asked {_asked_x:+.0f} W and sent {_sent_x:+.0f} W" in e
for e in _rows_x))
# UX-08: the notification is a SECOND surface off the same numbers, in its own
# words (messages.output_clamp): asked first, sent second.
def _asked_then_sent(msg, asked, sent):
@@ -1142,8 +1143,8 @@ check("⚠️ ...AND IN THE ClampWatchdog NOTIFICATION, which is a SECOND surfac
bool(notes_x) and _asked_then_sent(notes_x[0]["message"], _asked_x, _sent_x))
check("...and the TRANSPOSED sentence appears on NEITHER surface, so the two "
"checks above discriminate rather than decorate",
not any(f"the computed setpoint {_sent_x:+.0f} W was clamped to "
f"{_asked_x:+.0f} W" in e for e in _rows_x)
not any(f"asked {_sent_x:+.0f} W and sent {_asked_x:+.0f} W" in e
for e in _rows_x)
and not _asked_then_sent(nth(notes_x, 0)["message"], _sent_x, _asked_x)
and present(nth(notes_x, 0)))
# The DEVICE bound, off part 6c's controller: same sentence, other stage. The
@@ -1154,8 +1155,8 @@ check("...and the same ordered pair holds on the DEVICE-bound row, where the "
"loop asked for +3000 W and the device took +2500 W. PRECONDITION: those "
"two also render differently",
f"{_asked_w:+.0f}" != f"{_sent_w:+.0f}"
and any(f"the computed setpoint {_asked_w:+.0f} W was clamped to "
f"{_sent_w:+.0f} W" in e for e in ctl_w.events)
and any(f"asked {_asked_w:+.0f} W and sent {_sent_w:+.0f} W" in e
for e in ctl_w.events)
and _asked_then_sent(nth(notes_w, 0)["message"], _asked_w, _sent_w))
@@ -2028,16 +2029,17 @@ check("PRECONDITION: the integrator bound engaged, and on a tick where the "
"carried integrator AND the emitted command both differ from the bound",
any(d.i_w != _f(d, 'i_bound_w') and d.target_w != _f(d, 'i_bound_w')
for d, t, r in wind))
check("defect 1: the integrator bound is NOT reported as a BUG SIGNAL",
wind and all("BUG SIGNAL" not in r for d, t, r in wind))
check("defect 1: ...it names the anti-windup bound, from the same tick",
wind and all(f"its {_f(d, 'i_bound_w'):+.0f} W anti-windup bound" in r
check("defect 1: the integrator bound is NOT reported as an over-rating",
wind and all(" rating" not in r and "fault" not in r
for d, t, r in wind))
check("defect 1: ...it names the integrator's bound, from the same tick",
wind and all(f"reached its {_f(d, 'i_bound_w'):+.0f} W limit" in r
for d, t, r in wind))
check("defect 2: the integrator accumulator is not printed as a request",
wind and all(f"{d.i_w:+.0f} W" not in r and "asked for" not in r
for d, t, r in wind))
check("the command quoted is that tick's Decision, not a later read",
wind and all(f"command this cycle was {d.target_w:+.0f} W" in r
wind and all(f"command now {d.target_w:+.0f} W" in r
for d, t, r in wind))
check("at the bound nothing is described as 'above' or 'over' the rating",
wind and all(" above " not in r and " over " not in r
@@ -2050,7 +2052,7 @@ check("...under its OWN notification_id, so it cannot replace a BUG SIGNAL "
"notice still on screen",
notes_i and all(n["notification_id"] == BOUND_ID for n in notes_i))
check("...logged as a WARNING, not an ERROR",
any(x.levelno == logging.WARNING and "anti-windup" in x.getMessage()
any(x.levelno == logging.WARNING and "reached its" in x.getMessage()
for x in log_i)
and not any(x.levelno >= logging.ERROR and "OUTPUT_CLAMP" in x.getMessage()
for x in log_i))
@@ -2070,17 +2072,18 @@ for d, t, r in over[:2]:
check("PRECONDITION: the output clamp engaged on a tick where the slew limit "
"rewrote the command AND the integrator differs from the request",
any(t != _f(d, 'clamped_w') and d.i_w != _f(d, 'requested_w') for d, t, r in over))
check("the over-rating KEEPS the BUG SIGNAL",
over and all("BUG SIGNAL" in r for d, t, r in over))
check("the over-rating says it was cut to the rating",
over and all(" W rating, command now " in r for d, t, r in over))
check("defect 2: it quotes the requested COMMAND of that tick, not i_w",
over and all(f"computed {_f(d, 'requested_w'):+.0f} W" in r for d, t, r in over))
check("defect 3: 'clamped to' is the clamp's own result, not self.target",
over and all(f"clamped to {_f(d, 'clamped_w'):+.0f} W" in r for d, t, r in over))
check("defect 3: 'cut to' is the clamp's own result, not self.target",
over and all(f"cut to the {_f(d, 'clamped_w'):+.0f} W rating" in r
for d, t, r in over))
check("...and its ERROR says it is a software fault and that control keeps "
"running (UX-08 2d moved the 14 768 W rationale to a DEBUG line beside "
"it, which is still in main.py)",
any(x.levelno == logging.ERROR and "software fault" in x.getMessage()
and "Control is still running" in x.getMessage() for x in log_o)
and "control runs on" in x.getMessage() for x in log_o)
and "reached 14 768 W on this project" in
open(os.path.join(os.path.dirname(os.path.abspath(__file__)), "app",
"main.py"), encoding="utf-8").read())
+5 -6
View File
@@ -1644,9 +1644,8 @@ check("...and a re-trip's reason names the TWO durations separately, each "
[f.submit(A_FROZEN_W, 1300.0, float(t)) for t in range(80, 130)],
f.stale and f.releases == 1
and "unchanged for 92 s" in f.reason
and "the 35 s window this verdict rests on opened when the previous "
"one was withdrawn" in f.reason
and "graded 2 times" in f.reason)[-1])(
and "checked 2 times over a 35 s window since the last stop was "
"withdrawn" in f.reason)[-1])(
Freshness(BOUNDS["batt"])))
@@ -1799,8 +1798,8 @@ check("...and the two runs were driven at 50 % and 11 % SoC and the sentence "
# bytes, and "the register may be unable to comply / the source may have
# stopped reporting reality" is a different and wrong claim.
_S56_EXPLANATIONS = [
("DEAD", "the register may have stopped reporting reality"),
("REFUSED", "the source may be unable to comply with the command"),
("DEAD", "reading may have stopped"),
("REFUSED", "battery may be unable to follow the command"),
]
# ⚠️ WHAT THE THREE SENTENCES USED TO ASSERT. Each is a claim about the
# REGISTER or about the ENTITY, and 11a measured the register to be alive on
@@ -1868,7 +1867,7 @@ check(f"11c. BOTH EXPLANATIONS ARE NAMED, AND IN THAT ORDER: "
check("...and the sentence says in its own words that it CANNOT choose, rather "
"than leaving two explanations side by side for a reader to rank - an "
"operator who reads a list picks the first item",
"CANNOT TELL THEM APART" in _r56_ref)
"this check cannot tell which" in _r56_ref)
# ⚠️ THE POSITIVE CONTROL FOR THE `not any(...)` BELOW, AND IT IS NOT OPTIONAL:
# a quantifier over an empty list is True, and so is one over three literals
# with a typo in each. These are the three sentences as 0.10.1 SHIPPED them,
+5 -5
View File
@@ -497,7 +497,7 @@ check("a FORCED start is refused while another pack holds the slot, and the "
"phase machine does not move. The calendar is a preference an operator "
"may overrule; one pack at a time is a property of the grid connection "
"and a button does not add a second one",
_b8.phase == IDLE and len(_ev) == 1 and "REFUSED" in _ev[0]
_b8.phase == IDLE and len(_ev) == 1 and "cannot start now" in _ev[0]
and "inverter-a" in _ev[0])
check("...and an unblocked forced start still works, so the refusal is a "
"condition and not a disabled feature",
@@ -534,7 +534,7 @@ check("...and the deferred pack's PHASE does not move either, so "
_b9.phase == IDLE and _b9.store.get_time("phase_started") is None)
check("...and the words say WAITING, name the pack it waits for, and say it "
"will run next - none of which any failure path in this module says",
"WAITING" in _r9[1].events[0]
"waits its turn" in _r9[1].events[0]
and "inverter-a" in _r9[1].events[0]
and "not a stalled phase" in _r9[1].events[0]
and "ABORT" not in _r9[1].events[0] and "stuck" not in _r9[1].events[0])
@@ -687,7 +687,7 @@ print(f" a store already written by a multi-inverter version: {_rep3.explain(
check("a store already at the per-pack schema is NOT TOUCHED - not one key "
"written - and says so",
not _rep3.ran and _m3.data == _before3 and _m3.writes == []
and "not touched" in _rep3.explain())
and "left as it is" in _rep3.explain())
# ⚠️ AND BREAK IT. The read-back postcondition is the whole difference between
# this and a two-line copy, and it is inherited from `migrate_unit_keys()`
@@ -766,7 +766,7 @@ check("...and the refusal NAMES the namespace it used AND the roster it was "
"graded against, rather than merely saying something went wrong - the "
"operator's next question is 'which name, and which one should it have "
"been', and a bare `not ok` answers neither",
"WRONG NAMESPACE" in _rep5.explain()
"moved under an inverter not in the list" in _rep5.explain()
and unit_key(UNIT_A, "last_completed") in _rep5.explain()
and repr(ROSTER) in _rep5.explain())
check("⚠️ AND THE MARKER IS NOT STAMPED, WHICH IS THE WHOLE REMEDY. A stamped "
@@ -893,7 +893,7 @@ check("...and the counterfactual: the SAME two calls with the roster's own "
"`already at schema` early return, not a refusal. So 9c is about the "
"NAME surviving into the second start, not about second calls",
_rep7ok_a.ok and _m7ok.data[MAINT_SCHEMA_KEY] == MAINT_SCHEMA_VERSION
and _rep7ok_b.ran is False and "already at schema" in _rep7ok_b.explain())
and _rep7ok_b.ran is False and "already at version" in _rep7ok_b.explain())
# --------------------------------------------------------------------------- #
+754 -1
View File
@@ -580,7 +580,7 @@ check(f"every event the add-on records gives the page its plain words, from "
f"messages.hint() ({_calls} calls, without: {_bare})",
_calls >= 40 and not _bare)
_raw = ("OUTPUT_CLAMP", "BUG SIGNAL", "FAILSAFE", "SIGN_DISAGREEMENT",
"ALLOCATOR", "UNMET", "ARBITER", "PEAK GUARD")
"ALLOCATOR", "UNMET", "ARBITER", "PEAK GUARD", "PEAK_GUARD")
check("no hint carries the raw event codes the page used to show",
not [t for _k, t in messages.hint_samples()
if any(r in t for r in _raw)])
@@ -796,6 +796,759 @@ _bad = ast.parse("await self.hass.call('persistent_notification', 'create', "
check("a hand-written notification payload is seen by part 2",
any(not (isinstance(c.args[2], ast.Call)) for c in notification_calls(_bad)))
# ============================================================================== #
print("\n6. log lines as they are built at run time (UX-10)")
# Part 3 reads a WARNING+ line's own literal and counts each placeholder as one
# word. So a reason text built elsewhere and passed in as `%s` was never seen:
# the 2d test found "…clamped to +2000 W; … This is a BUG SIGNAL … Cut back 1
# times" in the log while part 3 was green, because `loop_clamp_note()` built
# it. This part closes that gap in two steps.
# a. Every dynamic part of every WARNING+ line in `app/` is classified here,
# as data (a number, a name, a path, an exception's own text) or as a text
# the add-on builds. A new dynamic part that is in neither list fails, so a
# new builder cannot slip past.
# b. Every built text is produced by the real code and checked. It is the
# evidence behind an alarm, so it gets the red-alarm shape: at most 3
# sentences of at most 30 words, 70 in all. It keeps its reason code. The
# whole line, as logged, may carry no semicolon, banned term, capitals,
# "1 times", "(s)" or a doubled full stop.
from datetime import datetime as _dt, timedelta as _td, timezone as _tz # noqa: E402
from app import clamp as _clamp, freshness as _fresh, peakguard as _pg # noqa: E402
from app import store as _store # noqa: E402
from app.circulation import CirculationConfig, CirculationWatchdog # noqa: E402
from app.control import Tuning, compute # noqa: E402
from app.delivery import (DeliveryConfig, DeliveryWatchdog, UnitDelivery, # noqa: E402
delinquent)
from app.freeze import FreezeWatchdog, FreezeWatchdogConfig # noqa: E402
from app.price import PricePoint, PriceProduct, PriceRead # noqa: E402
from app.static_tariff import TariffPlan # noqa: E402
from app.tariff import Projection # noqa: E402
from app.watchdog import (AGAINST_METER, AGAINST_OWN_POWER, SignWatchdog, # noqa: E402
SignWatchdogConfig)
_T0 = _dt(2026, 9, 27, 9, 0, tzinfo=_tz.utc)
PLURAL = re.compile(r"\b1 [a-z]{2,}s\b(?<!\b1 [a-z]ss)|\w\(s\)")
COUNT_PLURAL = re.compile(r"%d [a-z]{2,}s\b")
def dynamic_parts(tree, fname):
"""(key, call) for every dynamic part of a WARNING+ log call in `tree`."""
for node in ast.walk(tree):
if not isinstance(node, ast.Call):
continue
name = ast.unparse(node.func)
moan = name.endswith("._moan")
if not (LOG_CALL.search(name) or moan):
continue
i = 1 if moan else 0
if len(node.args) <= i:
continue
fmt = node.args[i]
parts = [ast.unparse(a) for a in node.args[i + 1:]]
if isinstance(fmt, ast.JoinedStr):
parts += [ast.unparse(v.value) for v in fmt.values
if isinstance(v, ast.FormattedValue)]
elif not (isinstance(fmt, ast.Constant) and isinstance(fmt.value, str)):
parts.append(ast.unparse(fmt))
for part in parts:
yield f"{fname}:{part}", node
# a. DATA: shown as it is, never worded by the add-on. An exception's text is
# the library's (hass.py words the Home Assistant ones, UX-10 item 3).
DATA = {
# hass.py: the _moan() wrapper and what its callers pass
"hass.py:msg", "hass.py:*args", "hass.py:entity_id", "hass.py:err",
"hass.py:obj", "hass.py:raw", "hass.py:domain", "hass.py:service",
"hass.py:resp.status", "hass.py:said", "hass.py:entity", "hass.py:what",
# main.py
"main.py:'cancelled' if task.cancelled() else repr(exc) if exc else 'returned'",
"main.py:EXIT_CONTROL_DIED", "main.py:first.name", "main.py:OPTIONS_PATH",
"main.py:err", "main.py:', '.join(sorted(stranded))",
"main.py:sorted(on_roster)", "main.py:inv.name",
"main.py:inv.batt_fresh.bound.release_s", "main.py:inv.batt_fresh.bound.move_w",
"main.py:inv.batt_fresh.bound.unchanged_s", "main.py:inv.batt_fresh.held",
"main.py:value", "main.py:float(value)",
"main.py:entity", "main.py:WRITE_BUDGET_S",
"main.py:_e",
"main.py:messages.times(self.clamp_wd.engagements)",
"main.py:messages.when(brussels(self.tariff_at))",
"main.py:messages.duration(TARIFF_MAX_AGE_S)",
"main.py:messages.count(len(targets), 'inverter')",
# maintenance.py, mqtt.py, p1.py
"maintenance.py:phase", "mqtt.py:err", "p1.py:err", "p1.py:self.host",
"p1.py:self.topic", "p1.py:poll_s", "p1.py:ingest.max_age_s",
"p1.py:backoff", "p1.py:self.url", "p1.py:str(err) or type(err).__name__",
"p1.py:self.poll_s",
# price.py
"price.py:doc.get('deprecated')", "price.py:len(dropped)",
"price.py:messages.count(len(times), 'time')", "price.py:plugin_id",
"price.py:override",
"price.py:', '.join((str(i) for i in dropped[:5])) + (' and more' if len(dropped) > 5 else '')",
"price.py:*(d.isoformat() for d in brussels_date_range(since, until))",
"price.py:pid",
"price.py:'/'.join(sorted((c.value for c in caps.sources - {Component.ENERGY})))",
"price.py:' and '.join(ignored) + (' is' if len(ignored) == 1 else ' are')",
"price.py:getattr(cls, 'id', cls)", "price.py:e", "price.py:type(e).__name__",
# price_history.py, selfconfig.py, static_tariff.py, store.py, tariff.py
"price_history.py:self.path", "price_history.py:day_words(want)",
"price_history.py:messages.count(len(points), 'price')",
"price_history.py:err",
"selfconfig.py:messages.count(len(problems), 'problem')",
"selfconfig.py:', '.join(changed) or 'none this page also edited'",
"static_tariff.py:e", "store.py:err", "store.py:key", "store.py:raw",
"tariff.py:self.path", "tariff.py:err", "tariff.py:start", "tariff.py:month",
# validate.py: option values and keys (the refusals are part 3's)
"validate.py:integ_w", "validate.py:max_w", "validate.py:disch_w",
"validate.py:maint_where", "validate.py:maint_cap", "validate.py:pid",
"validate.py:i", "validate.py:TAXES_PROFILE_OPTION", "validate.py:negative",
"validate.py:EXPORT_FORMULA_OPTION", "validate.py:xspec.passthrough",
"validate.py:xspec.offset_eur_kwh", "validate.py:'=' * 72",
"validate.py:'-' * 72",
"web.py:err",
}
# b. BUILT TEXT: each producer, run for real. A reason that is only ever
# stored and restored (a saved safety stop) is produced by the same builder.
def _sign(against, cmd=1500.0, got=-1400.0):
wd = SignWatchdog(SignWatchdogConfig(min_w=250.0, hold_s=60.0),
against=against)
for s in (0, 61):
wd.evaluate(cmd, got, True, _T0 + _td(seconds=s))
return wd.reason
def _sign_texts():
return [_sign(AGAINST_METER), _sign(AGAINST_OWN_POWER, -1100.0, 2000.0)]
def _circ_texts():
wd = CirculationWatchdog(CirculationConfig(min_w=250.0, hold_s=60.0))
for s, w in ((0, 5200.0), (30, 6000.0), (61, 5800.0)):
wd.evaluate(w, _T0 + _td(seconds=s))
return [wd.reason]
def _delivery_texts():
units = [UnitDelivery("inverter-a", 1000.0, 990.0),
UnitDelivery("inverter-b", 2000.0, 0.0)]
sentence = delinquent(units, 200.0)["inverter-b"]
wd = DeliveryWatchdog(DeliveryConfig(hold_s=120.0))
for s in (0, 121):
wd.evaluate(sentence, _T0 + _td(seconds=s))
return [wd.reason]
def _freeze_texts():
out = []
for dev in (None, 4700.0):
wd = FreezeWatchdog(FreezeWatchdogConfig(hold_s=600.0))
wd.evaluate(3600.0, 4480.0 if dev else 5000.0, 5000.0, _T0,
dev_min=-dev if dev else None, dev_max=dev)
out.append(wd.reason)
return out
def _stale_texts():
one = _fresh.Freshness(_fresh.BOUNDS["batt"])
for t in range(0, 40):
one.submit(-1200.0, -1200.0 if t < 1 else 1300.0, float(t))
two = _fresh.Freshness(_fresh.BOUNDS["batt"])
for t in range(0, 40):
two.submit(-1200.0, -1200.0 if t < 1 else 1300.0, float(t))
for t in range(40, 80):
two.submit(-1200.0, 0.0, float(t))
for t in range(80, 130):
two.submit(-1200.0, 1300.0, float(t))
return [one.reason, two.reason]
def _clamp_texts():
over = compute(prev_w=1000.0, grid_w=9000.0, actual_w=1000.0,
tuning=Tuning(max_w=5000.0, slew_w=1000.0, gain=0.6,
integrator_max_w=9000.0), i_w=8000.0)
at = compute(prev_w=1000.0, grid_w=9000.0, actual_w=1000.0,
tuning=Tuning(max_w=5000.0, slew_w=1000.0, gain=0.6),
i_w=4500.0)
write = [(n, _clamp.clamp_to_rating(w, 5000.0, -2500.0, 2500.0))
for n, w in (("inverter-a", 3000.0), ("inverter-b", -7412.0))]
# One inverter is not named (main.py passes None), several are.
return [_clamp.loop_clamp_note(over), _clamp.loop_clamp_note(at),
_clamp.write_clamp_note([(None, write[0][1])]),
_clamp.write_clamp_note(write[:1]), _clamp.write_clamp_note(write)]
def _peak_texts():
proj = Projection(projected_w=4338.0, elapsed_w=4338.0, elapsed_s=799.0,
covered_frac=1.0, complete=False, block_start=_T0,
held_w=0.0)
kw = dict(cap_w=3500.0, reading=None, soc_floor=30.0, max_hold_s=30.0)
sat = _pg.decide(proj, batt_w=1500.0, achievable_w=5000.0, soc=80.0, **kw)
low = _pg.decide(proj, batt_w=1500.0, achievable_w=5000.0, soc=20.0, **kw)
unread = _pg.decide(proj, batt_w=1500.0, achievable_w=5000.0, soc=None, **kw)
return [sat.reason, low.reason, unread.reason]
def _migration_texts():
out = []
for moved, kept, lost, wrong in (
(2, 0, 0, 0), (2, 1, 1, 0), (2, 0, 0, 1), (0, 2, 0, 0),
(0, 2, 1, 0)):
rep = _store.MigrationReport()
rep.ran = moved > 0 or lost > 0
rep.from_version = 1
rep.roster = ["inverter-a"]
rep.moved = {f"unit/inverter-a/k{i}": True for i in range(moved)}
rep.kept = [f"unit/inverter-a/old{i}" for i in range(kept)]
for i in range(lost):
note = f"unit/inverter-a/k{i} was written as True and reads back as None"
rep.problems.append(note)
rep.lost.append(note)
for i in range(wrong):
note = (f"unit/garage/k{i} was migrated into namespace 'garage', "
f"which is not in the inverter list")
rep.problems.append(note)
rep.misdirected.append(note)
out.append(rep.explain())
return out
def _tariff_texts():
hours = [_T0 + _td(minutes=15 * i) for i in range(8)]
pts = [PricePoint(h, 0.2, i >= 4) for i, h in enumerate(hours)]
read = PriceRead.series(pts, PriceProduct.DAY_AHEAD, "x", _T0)
return [TariffPlan(read, None, "provider").words,
TariffPlan(PriceRead.no_data("the price feed timed out"), None,
"none").words]
def _static(spec):
"""Templates for a family of builders that is not one function: the first
argument of every call to `spec`, or every value assigned to `spec`, in
the named file (placeholders count as one word, as in part 3)."""
fname, kind, name = spec
out = []
for f in ([APP / fname] if fname != "*" else sorted(APP.glob("*.py"))):
tree = ast.parse(f.read_text(encoding="utf-8"))
for node in ast.walk(tree):
if kind == "call" and isinstance(node, ast.Call) and node.args \
and ast.unparse(node.func).split(".")[-1] == name:
out += [t for _n, t in strings_in(node.args[0])]
elif kind == "assign" and isinstance(node, ast.Assign) \
and ast.unparse(node.targets[0]) == name:
out += [t for _n, t in strings_in(node.value)]
elif kind == "return" and isinstance(node, ast.FunctionDef) \
and node.name == name:
out += [t for r in ast.walk(node) if isinstance(r, ast.Return)
and r.value is not None for _n, t in strings_in(r.value)]
return [t for t in out if len(words(t)) > 1]
TEXT = {
"main.py:first.sign_wd.reason": _sign_texts,
"main.py:inv.sign_wd.reason": _sign_texts,
"main.py:inv.sign_wd.reason or '(reason not recorded)'": _sign_texts,
"main.py:self.site_sign_wd.reason": _sign_texts,
"main.py:self.site_sign_wd.reason or '(reason not recorded)'": _sign_texts,
"main.py:self.circ_wd.reason": _circ_texts,
"main.py:self.circ_wd.reason or '(reason not recorded)'": _circ_texts,
"main.py:inv.delivery_wd.reason": _delivery_texts,
"main.py:inv.delivery_wd.reason or '(reason not recorded)'": _delivery_texts,
"main.py:self.clamp_wd.reason": _clamp_texts,
"main.py:g.reason": _peak_texts,
"main.py:self.freeze_wd.reason": _freeze_texts,
"main.py:inv.batt_fresh.reason": _stale_texts,
"main.py:rep.explain()": _migration_texts,
"store.py:rep.explain()": _migration_texts,
"main.py:plan.words": _tariff_texts,
# Families: every builder of the text, as a template.
"main.py:refusal": lambda: (_static(("main.py", "return", "write_refusal"))
+ _static(("allocator.py", "return", "authorises"))),
"main.py:' / '.join(resolution.scope_errors)":
lambda: _static(("arbiter.py", "return", "scope_violations"))
+ _static(("arbiter.py", "call", "append")),
"price_forecast.py:gate.reason": lambda: _static(("*", "call", "block")),
"static_tariff.py:read.reason": lambda: _static(("*", "call", "no_data")),
"price_history.py:self.last_error":
lambda: _static(("price_history.py", "assign", "self.last_error")),
"price_history.py:bad": lambda: _static(("price_history.py", "return",
"_parse_points")),
"maintenance.py:msg": lambda: _static(("maintenance.py", "assign", "msg")),
"validate.py:aged": lambda: _static(("*", "return", "stale_card")),
"validate.py:xaged": lambda: _static(("*", "return", "stale_card")),
# Refusals: part 3 holds them to the refusal rule already.
"selfconfig.py:problems[0]": None,
"validate.py:problem": None,
"p1.py:problem": None,
}
def reason_problems(text):
"""STYLE.md's red-alarm shape, for a text a log line quotes."""
out = []
n_s, n_w = sentences(text), len(words(text))
if n_s > 3:
out.append(f"over 3 sentences ({n_s})")
if n_w > 70:
out.append(f"over 70 words ({n_w})")
long = [x for x in re.split(r"(?<=[.!?])\s+", text) if len(words(x)) > 30]
if long:
out.append(f"a sentence over 30 words ({len(words(long[0]))})")
return out + line_problems(text)
def logged_shape(line):
"""UX-10 review: the line as logged, wrapper and reason together, has the
red-alarm shape too. The reason alone passing is not enough: the 2d-style
"title: reason. tail. tail." line read as 4 sentences with a 3-sentence
reason inside it."""
out = []
if sentences(line) > 3:
out.append(f"over 3 sentences ({sentences(line)})")
long = [x for x in re.split(r"(?<=[.!?])\s+", line) if len(words(x)) > 30]
if long:
out.append(f"a sentence over 30 words ({len(words(long[0]))})")
return out
def line_problems(text):
"""What no WARNING+ line may carry, whatever its length."""
out = []
if ";" in text:
out.append("semicolon")
if re.search(r"(?<!\.)\.\.(?!\.)|\.{4,}|\.:|:\s*\.", text):
out.append("a doubled full stop")
if PLURAL.search(text):
out.append("plural: " + PLURAL.search(text).group(0))
return out + text_problems(text, keys=True, entities=True)
def _fill(template, fmt_node, key_part, sample):
"""The line as logged: `sample` in the text slot, `X` in the others."""
if isinstance(fmt_node, ast.JoinedStr):
return template.replace("{" + key_part + "}", sample)
return template # %-style: filled by the caller
def scan_log_lines(files, text=None, data=None):
"""-> (unclassified keys, stale keys, [(key, sample, problems)])."""
text = TEXT if text is None else text
data = DATA if data is None else data
seen, bad = set(), []
for fname, tree in files:
for key, call in dynamic_parts(tree, fname):
seen.add(key)
if key in data or key not in text:
continue
maker = text[key]
if maker is None:
continue
i = 1 if ast.unparse(call.func).endswith("._moan") else 0
fmt = call.args[i]
template = render(fmt) or ""
args = [ast.unparse(a) for a in call.args[i + 1:]]
part = key.split(":", 1)[1]
for sample in maker():
p = reason_problems(sample)
if isinstance(fmt, ast.JoinedStr):
line = template.replace("{" + part + "}", sample)
else:
slots = iter(["%s" if a != part else "\0" for a in args])
line = re.sub(r"%[-+ #0-9.]*[sdrfgx]",
lambda m: next(slots, m.group(0)), template)
line = PLACEHOLDER.sub("X", line).replace("\0", sample)
p += [f"as logged: {x}" for x in line_problems(line)
+ logged_shape(line) if x not in p]
if p:
bad.append((key, sample, p))
unknown = sorted(seen - set(data) - set(text))
stale = sorted((set(data) | set(text)) - seen)
return unknown, stale, bad
_FILES = [(f.name, ast.parse(f.read_text(encoding="utf-8")))
for f in sorted(APP.glob("*.py"))]
_unknown, _stale, _bad = scan_log_lines(_FILES)
for k, sample, p in _bad:
print(f" BAD {k}: {'; '.join(p)} :: {sample[:110]!r}")
check(f"every dynamic part of a WARNING+ line is classified as data or as a "
f"built text (unclassified: {_unknown})", not _unknown)
check(f"...and no classification is left over from a line that is gone "
f"(stale: {_stale})", not _stale)
_n_texts = sum(len(m()) for m in TEXT.values() if m is not None)
check(f"every built text, run for real, obeys the rule, and so does the line "
f"that quotes it ({_n_texts} texts, {len(_bad)} bad)", not _bad)
_counts = [f"{f}:{n.lineno}" for f, t in _FILES for n in ast.walk(t)
if isinstance(n, ast.Call) and (LOG_CALL.search(ast.unparse(n.func))
or ast.unparse(n.func).endswith("._moan"))
for a in n.args[:2] if isinstance(a, ast.Constant)
and isinstance(a.value, str) and COUNT_PLURAL.search(a.value)]
check(f"no WARNING+ line puts a plural noun after a bare count, which reads "
f"'1 times' (use messages.times() and friends; found: {_counts})",
not _counts)
# UX-10 review: the two clamp lines the owner quoted, as logged for one
# inverter, fit the red shape the tight way: at most 3 sentences and 30 words
# in all, code and numbers kept. The real literals from main.py, filled with
# the real notes.
def _clamp_line(opening):
for n in ast.walk(dict(_FILES)["main.py"]):
if isinstance(n, ast.Call) and LOG_CALL.search(ast.unparse(n.func)) \
and n.args and (render(n.args[0]) or "").startswith(opening):
return n.args[0].value
return None
_over, _at, _w1, _w1n, _w2 = _clamp_texts()
_clamp_lines = {
"error, loop": (_clamp_line("Power request too high"), _over),
"error, write": (_clamp_line("Power request too high"), _w1),
"warning, loop": (_clamp_line("The battery gives less than asked"), _at),
}
_clamp_shown = {k: (f % (r, messages.times(1)) if f else None)
for k, (f, r) in _clamp_lines.items()}
for k, v in _clamp_shown.items():
print(f" {k}: {v!r} ({len(words(v or ''))} words)")
check("the clamp lines for one inverter are at most 3 sentences and 30 words, "
"and keep OUTPUT_CLAMP and the numbers",
all(v and sentences(v) <= 3 and len(words(v)) <= 30
and "OUTPUT_CLAMP" in v and "1 time so far" in v
for v in _clamp_shown.values())
and all(x in _clamp_shown["error, loop"]
for x in ("+9000 W", "+5000 W", "+2000 W", "software fault")))
# Mutations: the scan catches what the 2d scan missed.
_OLD_CLAMP = ("OUTPUT_CLAMP: the loop computed +2148 W, over the 2000 W rating, "
"and it was clamped to +2000 W; the loop's command this cycle was "
"+440 W. This is a BUG SIGNAL, not a limit being used: something "
"upstream computed a setpoint the actuator cannot deliver.")
_mut_text = dict(TEXT, **{"main.py:self.clamp_wd.reason": lambda: [_OLD_CLAMP]})
_u, _s, _b = scan_log_lines([f for f in _FILES if f[0] == "main.py"],
text=_mut_text)
check("an injected bad reason (the 2d clamp text) is caught, on both clamp "
f"lines ({sorted({k for k, _t, _p in _b if 'clamp' in k})})",
[k for k, _t, _p in _b].count("main.py:self.clamp_wd.reason") == 2)
_new_site = ast.parse("_LOG.warning('Something broke: %s', self.new_wd.reason)")
_u, _s, _b = scan_log_lines([("main.py", _new_site)])
check(f"...and a new line quoting a text nobody classified is caught ({_u})",
_u == ["main.py:self.new_wd.reason"])
check("...and '1 times', '(s)', a semicolon and a doubled full stop in a "
"logged line are caught",
all(line_problems(t) for t in ("Cut back 1 times so far.",
"2 malformed point row(s) dropped.",
"It failed; retrying.",
"Cut back to +2000 W.. Only this.",
"index 0, 1, .... Those are left out.",
"moved to one part: . Problems")))
check("...and so is the 2d-style line, a 2-sentence reason inside a title and "
"two tails, which reads as 4 sentences although the reason passes",
logged_shape("Power request too high: OUTPUT_CLAMP: cut to +5000 W. The "
"command was +1000 W. Control is still running. Cut back "
"1 time so far.")
and not reason_problems("OUTPUT_CLAMP: cut to +5000 W. The command was "
"+1000 W"))
check("...while '1 s' and '1 time' are fine",
not line_problems("Held for 1 s, cut back 1 time so far."))
# INFO lines are not held to the length rule, but the 2d test found "§8.3",
# ISO timestamps and "keys ARE" in them. Their literals may carry none.
INFO_JARGON = re.compile(r"§\s?\d|isoformat|\b(?:ARE|NOT|AND)\b")
_info_bad = [f"{f}:{n.lineno}" for f, t in _FILES for n in ast.walk(t)
if isinstance(n, ast.Call) and n.args
and re.search(r"(?:^|\.)(?:_LOG|log|logger|LOG)\.info$",
ast.unparse(n.func))
for _n, s in strings_in(n.args[0])
if INFO_JARGON.search(ast.unparse(n.args[0])) or SHOUT.search(s)]
check(f"no INFO line carries a section number, an ISO timestamp or capitals "
f"(found: {_info_bad})", not _info_bad)
check("...and one that did is caught",
bool(INFO_JARGON.search('"§8.3 price history: %s"'))
and bool(SHOUT.search("the flat keys ARE NOT that pack's history")))
# ============================================================================== #
print("\n7. log levels, log noise and the display bugs (UX-10)")
import logging # noqa: E402
from app import hass as _hass, p1 as _p1, validate as _validate, web as _web # noqa: E402
from app.arbiter import Claim # noqa: E402
from app.main import Controller, why_key # noqa: E402
class _Rec(logging.Handler):
def __init__(self):
super().__init__(logging.DEBUG)
self.records = []
def emit(self, record):
self.records.append(record)
def _captured(logger_name, fn):
rec, lg = _Rec(), logging.getLogger(logger_name)
old = lg.level
lg.addHandler(rec)
lg.setLevel(logging.DEBUG)
try:
fn()
finally:
lg.removeHandler(rec)
lg.setLevel(old)
return rec.records
def _level_of(fname, words_in_line):
"""The level of the log call in `fname` whose literal holds the words."""
tree = ast.parse((APP / fname).read_text(encoding="utf-8"))
for node in ast.walk(tree):
if isinstance(node, ast.Call) and node.args \
and re.search(r"_LOG\.\w+$", ast.unparse(node.func)):
text = render(node.args[0]) or ""
if words_in_line in text:
return ast.unparse(node.func).rsplit(".", 1)[-1]
return None
check("the shadow line of every cycle is DEBUG, not INFO in capitals "
f"({_level_of('main.py', 'Shadow mode: would send')})",
_level_of("main.py", "Shadow mode: would send") == "debug"
and _level_of("main.py", "SHADOW MODE: not commanding") is None)
check("'Shadow mode is on' and 'is off', which follow a setting or a button, "
f"are INFO ({_level_of('main.py', 'Shadow mode is on')}, "
f"{_level_of('main.py', 'Shadow mode is off')})",
_level_of("main.py", "Shadow mode is on") == "info"
and _level_of("main.py", "Shadow mode is off") == "info")
_access = {}
for _lvl in (logging.INFO, logging.DEBUG):
logging.getLogger("goodwe.web").setLevel(_lvl)
_access[logging.getLevelName(_lvl)] = _web.access_log()
logging.getLogger("goodwe.web").setLevel(logging.NOTSET)
_start_src = " ".join(
ast.unparse(n) for n in ast.walk(ast.parse(
(APP / "web.py").read_text(encoding="utf-8")))
if isinstance(n, ast.AsyncFunctionDef) and n.name == "start")
check(f"the page's own polls are not logged at INFO: aiohttp's access log is "
f"off unless the log level is debug ({_access})",
_access["INFO"] is None
and isinstance(_access["DEBUG"], logging.Logger)
and "access_log=access_log()" in _start_src)
_validate.WARN_ONCE.seen.clear() # part 3 ran the validator already
_twice = _captured("goodwe.config", lambda: [
_validate.validate_startup_config(
dict(_BASE, price_provider="generic_dayahead", static_profile=""),
-5000, 5000) for _ in range(2)])
_sp = [r for r in _twice if "static_profile is empty" in r.getMessage()]
check(f"a settings warning is logged once per start, though the check runs "
f"twice ({len(_sp)} line(s))", len(_sp) == 1
and _sp[0].levelno == logging.WARNING)
def _outage():
o = _hass.Outage()
o.down("api", "error 502", "read sensor.x: 502, message='Bad Gateway'")
o.down("api", "error 502", "read sensor.y: 502")
o.down("websocket", "the meter connection closed",
"Received message 8:1000 is not str")
o.up("api")
o.up("websocket")
o.down("api", "no connection", "Cannot connect to host supervisor:80")
_out = _captured("goodwe.hass", _outage)
_warn = [r.getMessage() for r in _out if r.levelno == logging.WARNING]
_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)
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)
and not any("8:1000" in m or "Bad Gateway" in m for m in _warn + _info))
class _Resp400:
def __init__(self, body):
self.status, self.reason, self._body = 400, "Bad Request", body
async def __aenter__(self):
return self
async def __aexit__(self, *a):
return False
async def text(self):
return self._body
class _Session400:
def __init__(self, body):
self.body = body
def post(self, *a, **k):
return _Resp400(self.body)
def _refused(body):
ha = _hass.HomeAssistant(_Session400(body), token="t")
ok = []
recs = _captured("goodwe.hass", lambda: ok.append(asyncio.run(
ha.call("number", "set_value", {"entity_id": "number.sp", "value": 1}))))
return (ok[0] if ok else None), [r.getMessage() for r in recs
if r.levelno == logging.WARNING]
def _one(res):
"""(write result, the one WARNING line) or a named absence that fails."""
ok, lines = res
return ok, (lines[0] if len(lines) == 1 else f"<{len(lines)} lines>")
_bare_ok, _bare = _one(_refused("400: Bad Request"))
_full_ok, _full = _one(_refused(
'{"message": "Value 6000 for number.sp is outside valid range"}'))
check(f"a write Home Assistant refuses while it loads is one plain WARNING, "
f"still a failed write, without the empty '400: Bad Request' ({_bare!r})",
_bare_ok is False
and _bare.startswith("Home Assistant refused number.set_value for "
"number.sp (error 400, no details).")
and "Bad Request" not in _bare)
check(f"...while a body that says more is still quoted ({_full!r})",
_full_ok is False and "outside valid range" in _full)
class _WS:
def __init__(self, kind):
self.kind = kind
async def receive(self):
return type("M", (), {"type": self.kind, "data": "{}"})()
def _closed_ws():
try:
asyncio.run(_p1._receive_json(_WS(_p1.aiohttp.WSMsgType.CLOSE)))
except ConnectionResetError as e:
return str(e)
return None
check(f"a socket Home Assistant closed is a plain ConnectionResetError, which "
f"the reconnect loop reports through that one line ({_closed_ws()!r})",
(_closed_ws() or "").startswith("Home Assistant closed the connection"))
# "Why: Other". Every winner and every safety reason the code can produce has
# words. The keys are found in the code: each `Claim.set(source, ..., reason)`
# through main.why_key(), plus main.py's own refusal to split ("unsplit").
_SOURCES = {}
for _f in sorted(APP.glob("*.py")):
_tree = ast.parse(_f.read_text(encoding="utf-8"))
_consts = _module_constants(_tree)
for _n in ast.walk(_tree):
if isinstance(_n, ast.Call) and ast.unparse(_n.func) == "Claim.set" \
and _n.args:
_src = _n.args[0]
_src = (_src.value if isinstance(_src, ast.Constant)
else _consts.get(getattr(_src, "id", ""), None))
_rsn = next((k.value for k in _n.keywords if k.arg == "reason"),
_n.args[3] if len(_n.args) > 3 else None)
_rsn = _rsn.value if isinstance(_rsn, ast.Constant) else ""
_SOURCES.setdefault((_src, _rsn), f"{_f.name}:{_n.lineno}")
_keys = {why_key(s, [Claim.set(s, 0, 0.0, r)]) for s, r in _SOURCES}
_keys |= {why_key("failsafe", []),
why_key("failsafe", [Claim.set("loop", 0, 1.0, "tracking")])}
check(f"the scan found the claims ({len(_SOURCES)}), including the latched "
f"per-inverter stop the 2d test saw as 'Other'",
("failsafe", "sign disagreement") in _SOURCES and len(_SOURCES) >= 8)
_missing_why = sorted(k for k in _keys if k not in messages.WHY_WINNER)
check(f"every winner and safety reason has words in messages.WHY_WINNER "
f"(missing: {_missing_why}, keys: {sorted(_keys)})", not _missing_why)
check("...so the latched stop reads as a safety stop, not 'Other' "
f"({messages.why(why_key('failsafe', [Claim.set('failsafe', 0, 0.0, 'sign disagreement')]), 0)!r})",
messages.why(why_key("failsafe", [Claim.set("failsafe", 0, 0.0,
"sign disagreement")]), 0)
== "Safety stop, power went the wrong way: 0 W")
_without = {k: v for k, v in messages.WHY_WINNER.items()
if k != "sign disagreement"}
check("...and a table that lost that entry is caught",
any(k not in _without for k in _keys))
class _H:
async def number(self, *a, **k):
return None
async def limits(self, *a):
return (-2000.0, 2000.0, 1.0)
async def call(self, *a, **k):
return True
class _S:
data = {}
def set(self, *a):
pass
def get_time(self, *a):
return None
class _P:
enabled = False
def publish(self, *a, **k):
pass
_c = Controller({"setpoint_entity": "number.sp", "meter_source": "off",
"max_w": 2000, "stale_input_s": 15}, _H(), _S(), _P(),
stop=asyncio.Event())
_c.p1_enabled = True
_c.p1 = _p1.P1Ingest(max_age_s=30.0)
def _meter_row():
"""The meter row, or a named absence that fails every check below."""
rows = [r for r in _c.checks() if r.get("id") == "meter"]
return rows[0] if len(rows) == 1 else {
"ok": None, "warn": None, "text": f"<{len(rows)} meter rows>"}
_r0 = _meter_row()
_c.p1.started_mono -= 31.0
_r1 = _meter_row()
_c.p1.submit(_p1.make_sample(_p1.SOURCE_HA, 500.0, 0.0, phases=1))
_r2 = _meter_row()
check(f"right after a start, before the first meter reading and inside its "
f"limit, the meter row is amber and waits, not red at 0 s ({_r0})",
_r0["warn"] and not _r0["ok"]
and _r0["text"] == "Meter: waiting for the first reading, limit 30 "
"seconds")
check(f"...past the limit with still no reading it is red, as before ({_r1})",
not _r1["ok"] and not _r1["warn"]
and _r1["text"].startswith("Meter: no reading for 31 seconds"))
check(f"...and a reading makes it green ({_r2['text']!r})",
_r2["ok"] and _r2["text"].startswith("Meter: 500 W"))
_c.auto = True
_c.p1_enabled = False
asyncio.run(_c.cycle())
_w0 = _c.why_words
_c._why_waiting_since -= _td(seconds=7)
_w7 = _c.why_words
check(f"'A reading is missing for N seconds' counts while control waits, "
f"instead of the age the last cycle saw ({_w0!r} -> {_w7!r})",
_w0 == "A reading is missing for 0 seconds, control waits"
and _w7 == "A reading is missing for 7 seconds, control waits")
_c.why_words = "Keeping the grid near zero: 0 W"
check("...and once a cycle decides again, the line is that decision",
_c.why_words == "Keeping the grid near zero: 0 W")
print()
if fails:
print(f"{len(fails)} FAILED")
+6 -6
View File
@@ -1240,13 +1240,13 @@ check("an engagement that is not saturated raises NO notification - §10.3's "
"goodwe_peak_saturated" not in hass.notifications)
check("...but it does reach the action log, which is where a control action "
"that moves energy belongs",
any("PEAK GUARD" in e for e in c.events))
n_events = sum(1 for e in c.events if "PEAK GUARD" in e)
any("PEAK_GUARD" in e for e in c.events))
n_events = sum(1 for e in c.events if "PEAK_GUARD" in e)
asyncio.get_event_loop_policy().new_event_loop().run_until_complete(c.cycle())
check("...and it is edge-logged, not level-logged: a second engaged cycle adds "
"no second line, so a quarter of engagement cannot push the cause of the "
"event off a 40-line log",
sum(1 for e in c.events if "PEAK GUARD" in e) == n_events)
sum(1 for e in c.events if "PEAK_GUARD" in e) == n_events)
# The saturated case, through the same real cycle.
# A floor of 1.5x what the inverter can give: it saturates wherever in the
@@ -1661,8 +1661,8 @@ check("...and it still says what it WOULD have taken, so the under-shave is a "
near(d_lim.wanted_w, WANTED, 1e-6) and d_lim.wanted_w > d_lim.floor_w)
check("...and its one-line explanation tells the operator the consequence in "
"the words that matter - the quarter is going over the ceiling",
"FLOOR-LIMITED" in d_lim.explain()
and "WILL GO OVER THE CEILING" in d_lim.explain()
"FLOOR_LIMITED" in d_lim.explain()
and "will go over the limit" in d_lim.explain()
and f"{CEIL:.0f} W" in d_lim.explain())
check("an unreadable SoC lands in the same branch, with the OTHER reason - so "
"an operator reading one line can tell a flat battery from a dead sensor",
@@ -1944,7 +1944,7 @@ check("the status page carries exactly one peak-guard row and it is NOT ok - "
"the money is going to be spent and a human is the only actuator left",
len(rows24) == 1 and not rows24[0]["ok"] and not rows24[0]["warn"]
and "peak limit will be passed" in rows24[0]["text"])
check("...and it reaches the action log too", any("FLOOR-LIMITED" in e
check("...and it reaches the action log too", any("FLOOR_LIMITED" in e
for e in c24.events))
# A missing SoC sensor, through the same real cycle. `inputs_ok` stops the loop
# at 0 W in that state, so the guard's own answer is what is graded here.
+19 -6
View File
@@ -4107,7 +4107,8 @@ _T11_SLOTS = {
"carried": r"\d+ published and (\d+) estimated",
"horizon": r"for (\d+) hours ahead",
"age_s": r"Price plan from (\d+) s ago",
"spacings": r"([\d+]+) s apart",
# UX-10: the spacing is in words ("one every 15 minutes or every hour").
"spacings": r"one (every [a-z0-9 ]+?)(?:,|\.|$)",
# ⚠️ THE *Arbitrage* ROW'S OWN AGE SLOT, and it is deliberately the same
# pattern for "decided N s ago" and "the last one was taken N s ago" -
# WHICH of the two sentences was rendered is graded by inequality below,
@@ -4125,6 +4126,18 @@ _T11_SLOTS = {
}
def _spacing_s(raw):
"""`every 15 minutes or every hour` -> `[900, 3600]`; raises otherwise."""
unit = {"second": 1, "minute": 60, "hour": 3600}
out = []
for part in raw.split(" or "):
m = re.fullmatch(r"every (?:(\d+) )?(second|minute|hour)s?", part.strip())
if m is None:
raise ValueError(f"no spacing in {part!r}")
out.append(int(m.group(1) or 1) * unit[m.group(2)])
return out
def _slot(row, name):
"""The number in ONE NAMED SLOT of a rendered row, or `_Raised`.
@@ -4140,18 +4153,18 @@ def _slot(row, name):
if m is None:
raise ValueError(f"no {name!r} slot in {row[:90]!r}")
raw = m.group(1)
return ([int(x) for x in raw.split("+")] if name == "spacings"
else int(raw))
return (_spacing_s(raw) if name == "spacings" else int(raw))
return derived(_get)
_T11_GOOD = ("x. Price plan from 7 s ago, for 48 hours ahead: day-ahead "
"prices from the price feed, 132 prices over 33 hours, "
"36 published and 96 estimated, 900+3600 s apart")
"36 published and 96 estimated, one every 15 minutes or every "
"hour")
_T11_SHIPPED_DEFECT = ("x. Price plan from 7 s ago, for 48 hours ahead: "
"day-ahead prices from the price feed, 132 prices over "
"132 hours, 96 published and 36 estimated, 900+3600 s "
"apart")
"132 hours, 96 published and 36 estimated, one every "
"15 minutes or every hour")
# The slots divide into the ones a *Tariff*/​*Arbitrage* ROW carries and the
# ones a REFUSAL sentence carries; each group is calibrated against its own
# well-formed example, because a slot asked of the wrong kind of sentence is
+11 -6
View File
@@ -66,6 +66,7 @@ import sys
from named_absence import first, nth
from datetime import datetime, timedelta, timezone
from app import messages as _msg_fc
from app import price as _price
from app import price_forecast as _fc
from app import static_tariff as _st
@@ -668,8 +669,10 @@ check("with neither a published hour nor a yesterday, the result is no_data - "
check("...so it has no .points to iterate and no .get() to default out of",
raises(lambda: _nothing.points, Absence)
and raises(lambda: _nothing.get("points", []), Absence))
check("...and its reason names §11.4 for an operator",
"§11.4" in _nothing.reason)
check("...and its reason says the fixed tariff is used and there is no "
"trading (§11.4), in words an operator reads",
"fixed tariff is used" in _nothing.reason
and "no trading" in _nothing.reason)
check("a naive `since` is refused rather than silently interpreted as UTC",
raises(lambda: fill_from_yesterday(TODAY_PART, yesterday=YESTERDAY,
since=datetime(2026, 1, 15),
@@ -745,9 +748,10 @@ check("...and the phase machine did not move: it is still idle, so the "
_m.phase == IDLE)
check("...and the reason names §8.3, the offending hour, and when the real "
"price is expected",
"§8.3" in _gate_bad.reason
and bool(_first_prov) and _first_prov.isoformat() in _gate_bad.reason
and "14-16" in _gate_bad.reason)
"is only estimated" in _gate_bad.reason
and bool(_first_prov)
and _msg_fc.when(brussels(_first_prov)) in _gate_bad.reason
and "14:00 to 16:00" in _gate_bad.reason)
# The positive arm, so the block above is discriminating rather than universal.
_firm_long = series_of(hours_between(START,
@@ -772,7 +776,8 @@ _gate_none = begin_phase(_m3, START, PriceRead.no_data("the feed timed out"),
MAINTENANCE_DRAIN)
check("no price data at all BLOCKS an irreversible action too - a missing "
"price is not a cheap one (§11.4)",
_gate_none.kind == "blocked" and "§11.4" in _gate_none.reason
_gate_none.kind == "blocked"
and "missing price is not a cheap one" in _gate_none.reason
and _m3.phase == IDLE)
_short = series_of(DAY[:4], lambda u: t_price(brussels(u).hour),
PriceProduct.DAY_AHEAD, "generic_dayahead",
+19 -19
View File
@@ -1020,7 +1020,7 @@ check("a store holding only the day before LAST answers no_data, not those "
_y3.kind == "no_data")
check(f"...and the reason names BOTH the date wanted and the dates held, so an "
f"operator can see which it is: {why(_y3)!r}",
"2026-01-14" in why(_y3) and "2026-01-12" in why(_y3))
"14 Jan" in why(_y3) and "12 Jan" in why(_y3))
_h4 = store()
_ph.PriceHistory._remember(
@@ -1217,7 +1217,7 @@ json.dump({"version": SCHEMA + 99, "days": {}}, open(_p7, "w", encoding="utf-8")
_h7 = PriceHistory(_p7)
check("a file from a schema this build does not know is discarded rather than "
"guessed at - its points might mean something else",
"schema" in (_h7.last_error or "")
"version" in (_h7.last_error or "")
and _h7.yesterday(NOW).kind == "no_data")
# A record whose points are malformed. THE DEFECT IS A DEFAULTED PRICE.
@@ -1270,7 +1270,7 @@ json.dump({"version": SCHEMA, "days": {
_h14 = PriceHistory(_p14)
check("a day record that is not a dict is DROPPED and REPORTED, and the rest "
"of the file still loads - one bad record is not a bad file",
_h14.ok and "unusable day record" in (_h14.last_error or "")
_h14.ok and "unusable day" in (_h14.last_error or "")
and sorted(_h14._days) == ["2026-01-13"])
_w14 = derived(lambda: _h14.words)
_y14 = derived(lambda: _h14.yesterday(NOW).kind)
@@ -1291,7 +1291,7 @@ for _shape in ("oops", [1, 2, 3], 7, None, {"points": "not a list"}):
check(f"...and the same holds for a day record of {type(_shape).__name__} "
f"{_shape!r}: dropped, reported, and every accessor answers "
f"({_wX!r}, {_yX!r})",
_hX._days == {} and "unusable day record" in (_hX.last_error or "")
_hX._days == {} and "unusable day" in (_hX.last_error or "")
and isinstance(_wX, str) and _yX == "no_data")
_pF = os.path.join(tmpdir(), "price_history.json")
@@ -1300,7 +1300,7 @@ json.dump({"version": float(SCHEMA), "days": {}},
check(f"a `version` of {float(SCHEMA)!r} is refused although it EQUALS "
f"{SCHEMA} - a schema check that cannot tell 1 from 1.0 is one that "
f"would not notice a writer this build has never met",
"schema" in (PriceHistory(_pF).last_error or ""))
"version" in (PriceHistory(_pF).last_error or ""))
# --------------------------------------------------------------------------- #
@@ -1328,7 +1328,7 @@ check(f"...and a store holding a day names the DATE, the POINT COUNT and the "
f"HOUR COUNT {words_of(_h_words)!r} - 'a cache exists' and 'the cache "
f"holds yesterday, all 24 hours of it' are different facts, and only "
f"the second says the horizon will be full tomorrow morning",
words_of(_h_words) == f"{YDAY_D} (24 prices over 24 hours)")
words_of(_h_words) == "24 prices over 24 hours for 14 Jan")
# ⚠️ AND THE TWO NUMBERS ARE NOT THE SAME NUMBER - FCST-05's LOW. The row
# shipped as `f"{d} ({_n_points(rec)} h)"`, which counts POINTS and prints them
@@ -1362,15 +1362,15 @@ check(f"...and the row reports BOTH, each under its own unit: {_qw!r}. "
f"A day of 96 quarter-hourly prints is 96 points over 24 h, and the "
f"figure that says whether tomorrow's fill has a whole day to carry is "
f"the HOUR one",
_qw == f"{YDAY_D} (96 prices over 24 hours)")
_qw == "96 prices over 24 hours for 14 Jan")
check(f"...and specifically the row does NOT say '96 h' {_qw!r} - a point "
f"count wearing the hour's name is H1's defect, and this row is where "
f"an operator would have read it",
isinstance(_qw, str) and "(96 h)" not in _qw and " (96 prices " in _qw)
isinstance(_qw, str) and "(96 h)" not in _qw and _qw.startswith("96 prices "))
check(f"a file that only PARTLY loaded says so in the row {_w14!r}, or the "
f"days it dropped read as days that were simply never written",
isinstance(_w14, str) and (_h14.last_error or "") in _w14
and "2026-01-13" in _w14)
and "13 Jan" in _w14)
check("NoHistory() has a sentence of its own rather than an empty cell",
NoHistory().words == "not kept")
check("...and `words` never raises, whatever the file holds. It is read once "
@@ -1546,8 +1546,8 @@ for _shape, _bad in _BAD_STARTS:
f"{_wload!r}: ONE point held, and the row that is not a point named "
f"rather than counted",
isinstance(_wload, str)
and _wload.startswith(f"{TODAY_D} (1 price over 1 hour) [")
and "1 malformed point row(s) in" in _wload)
and _wload.startswith("1 price over 1 hour for 15 Jan [")
and "1 bad price in" in _wload)
# ⚠️ AND THE TWO NOTES ARE GRADED APART, BECAUSE THEY MASK EACH OTHER
# OTHERWISE (MUTATION.md TEST-16). `_usable_days()` records what it FOUND
# at open and `_remember()` records what it DROPPED on the refresh; both
@@ -1562,22 +1562,22 @@ for _shape, _bad in _BAD_STARTS:
f"'{TODAY_D} (1 h)' - the status row reporting a full cache while "
f"every tariff refresh was dying on it",
isinstance(_wafter, str)
and "malformed point row(s) dropped from" in _wafter
and TODAY_D in _wafter)
and "bad price dropped from" in _wafter
and "15 Jan" in _wafter)
check(f"...and the row MOVED from what was found to what was dropped "
f"{_wload.split('[')[-1]!r} -> {_wafter.split('[')[-1]!r}, so the "
f"two notes are not one note read twice",
isinstance(_wload, str) and isinstance(_wafter, str)
and "malformed point row(s) in" in _wload
and "malformed point row(s) in" not in _wafter
and "malformed point row(s) dropped from" not in _wload)
and "bad price in" in _wload
and "bad price in" not in _wafter
and "bad price dropped from" not in _wload)
# ...and a SECOND refresh over the same store is clean, which is the state
# a restarted add-on comes up in.
_hM2 = PriceHistory(_pM)
check(f"...and the store reopened from that file is CLEAN: the whole day "
f"held and nothing to report {words_of(_hM2)!r}, so the note clears "
f"itself rather than becoming permanent furniture",
words_of(_hM2) == f"{TODAY_D} ({_want} prices over {_want} hours)"
words_of(_hM2) == f"{_want} prices over {_want} hours for 15 Jan"
and _hM2.last_error is None)
# ...and the shipped path, end to end, through the caller that catches
@@ -1641,7 +1641,7 @@ print("5d. FCST-06 - the OTHER way to be a store that cannot persist")
# read-only and again on a full tmpfs:
#
# last_error = 'could not write ([Errno 30] Read-only file system)'
# words = '2026-01-14 (24 prices over 24 hours); 2026-01-15 (24 points
# words = '2026-01-14 (24 points over 24 h); 2026-01-15 (24 points
# over 24 h) [could not write (...)]'
# yesterday()= series, 24 points
# ON DISK = {} <- and gone on the next restart
@@ -1701,7 +1701,7 @@ check(f"...and `words` and `yesterday()` AGREE about that store "
f"{_h16.words[:44]!r}: neither names a day the file does not hold, and "
f"both name the write failure. They disagreed - `words` printed two "
f"full days BESIDE the error while `yesterday()` answered 24 points",
YDAY_D not in _h16.words and TODAY_D not in _h16.words
"14 Jan" not in _h16.words and "15 Jan" not in _h16.words
and "could not write" in _h16.words
and _y16.kind == "no_data" and "could not write" in why(_y16))
check(f"...and it DEGRADES rather than raising: the carry still returned a "
+2 -2
View File
@@ -448,7 +448,7 @@ print(f" restore() across the boundary said: {said}")
aug7, sep7 = st7.peak(month="2026-08"), st7.peak(month="2026-09")
check("a restart that straddles the month boundary BANKS the dead August "
"quarter rather than dropping measured energy",
said.startswith("closed a stale block") and aug7.is_observed)
said.startswith("closed the 15-minute period") and aug7.is_observed)
check(f"...at its partial-coverage figure ({aug7.peak_w:.2f} W = "
f"{RUN_W * 399 / QUARTER_S:.2f} W, the seconds it actually covered)",
near(aug7.peak_w, RUN_W * 399 / QUARTER_S, 1e-6))
@@ -1325,7 +1325,7 @@ print(f" quarters banked in {month_key(_sb)}: {_before_stale} -> "
check("a block closed by restore() rather than by sync() is counted too - the "
"old counter incremented only in sync() and missed it entirely",
_before_stale == 0 and _tr13.recorded_in(_sb) == 1
and "banked" in _state)
and "and saved it" in _state)
# --- the count is scoped to the MONTH it is printed beside --------------------
# ⚠️ TWO MONTHS AT DIFFERENT COUNTS. Equal counts would be satisfied by a
+2 -2
View File
@@ -1693,11 +1693,11 @@ check("...and a card ON THIS LEG that the coefficients do not reproduce is "
# ⚠️ THE SENTENCE DOCS.md RESTS ON, AND IT IS THE ONE MOST LIKELY TO ROT.
_T16_INFO = [m for lvl, m in _T16_OK_LOG if lvl == "INFO"
and "NO STRATEGY IN THIS ADD-ON READS IT" in m]
and "No part of the add-on reads it yet" in m]
check("the startup line says, in so many words, that NO STRATEGY IN THIS "
"ADD-ON READS IT - the operator is told what the option does not do in "
"the same breath as it being accepted",
len(_T16_INFO) == 1 and "displaced IMPORT" in _T16_INFO[0])
len(_T16_INFO) == 1 and "displaced import" in _T16_INFO[0])
# ⚠️ THE ASYMMETRY IS ASSERTED AS AN ORDERED PAIR, NOT AS TWO NUMBERS IN ONE
# SENTENCE (MUTATION.md habit 14). "6 and 0 appear somewhere" is satisfied by
# the two legs TRANSPOSED - which is the sentence telling an operator that the