diff --git a/goodwe_controller/CHANGELOG.md b/goodwe_controller/CHANGELOG.md index 0988b6b..51f0ca6 100644 --- a/goodwe_controller/CHANGELOG.md +++ b/goodwe_controller/CHANGELOG.md @@ -31,6 +31,54 @@ guessing a boundary; saying so is more useful than a guess. ## Unreleased +**`test_peakguard.py` answered two of its own checks with the wall clock +(CI-06).** The file sits on the required `checks / unit (pull_request)` context +and had a measured ~20 % flake rate. It cost a wrong merge diagnosis (parents +green, merge red — read as a semantic merge conflict, it was the flake), a false +red on two reviewers' CONTROL runs, and a false "mutation caught" that reached a +merged card in four places. **A flaky check does not waste a re-run; it +manufactures evidence for whichever hypothesis the reader already holds.** + +Both causes are the control law's own gain `900 / remaining` applied to a +wall-clock gap the file never intended to have. Neither fix widens anything. + +* **The cross-time projection.** The "one cycle of the intent form is exactly + the delivered form plus the command standing on the wire" check decided the + intent form from a **second** `PeakTracker.project(..., datetime.now())` taken + after the real cycle had returned, and compared it against a floor decided + from the **first** projection — three lines under a comment saying both run + "against the same frozen projection". `excess = 900 × (projected − ceiling) / + remaining` moves at `excess / remaining` W/s, so at a 1500 W floor the 1.5 W + tolerance bought exactly **`remaining / 1000` seconds**: 333 ms with 880 s + left in the quarter, **6 ms with 10 s left**. The gap between the two + statements measured **12.7–39.5 ms** over 26 instrumented runs. The check was + decided by *where in the quarter it ran*. It now keeps the `Projection` + **object** the real cycle graded and decides both forms from it — the clock is + out of the comparison and the tolerance is **exact**, not widened. Measured on + a real cycle: re-deciding the delivered form from that object reproduces the + controller's own floor to **0.000000000000 W**. +* **The fixture's own room.** `wired_over_limit()` laid telegrams with + `range(0, span + 1, 5)`, leaving **0–5 s of the open block uncovered by + construction**, and `excess` multiplies an uncovered second back up by + `900 / remaining`. Measured on the shipped file: at **12 s of remaining a + fixture that asked for a 1500 W floor delivered 613 W (−59 %)**, and at 2 s + the guard **did not engage at all** — which fails "the real cycle files the + peak claim", "…and the number written to the inverter is the guard's floor" + and "the STATUS PAGE row for a floor-limited guard" **together**. The + four-attempt retry could not help: four attempts take ~40 ms and all land in + the same dying quarter. Fixed with one telegram stamped at `now` (what a real + meter does, and what the docstring already claimed) plus `FIXTURE_ROOM_S`, + **derived** from the 1 % accuracy the helper promises rather than picked: + `net_w × lag / (remaining × want) ≤ 0.01 − lag/900` → **23.6 s → 24 s**, at + the measured 0.1 s worst-case lag. + +**Nothing was skipped, disabled or marked xfail** — the file still carries all +of SAFETY-07 and SAFETY-25's forced-discharge SoC floor, and it gains a check: +the delivered form re-decided from the cycle's own projection must reproduce the +real controller's number to the bit, which pins the test's `decide()` kwargs as +main.py's actual call rather than an approximation of it. **One tolerance got +stricter** (1.5 W → exact), because removing the clock made exactness possible. + **Inverter B gets its own MQTT device, and inverter A keeps the one it has (TEL-07).** MQTT discovery announced **one** device, and every entity hung off one `unique_id` prefix, so at two inverters B's per-unit telemetry had nowhere diff --git a/goodwe_controller/test_peakguard.py b/goodwe_controller/test_peakguard.py index 2577647..51cb72a 100644 --- a/goodwe_controller/test_peakguard.py +++ b/goodwe_controller/test_peakguard.py @@ -109,6 +109,7 @@ import re import shutil import sys import tempfile +import time from datetime import datetime, timedelta, timezone from math import inf, isinf from pathlib import Path @@ -1062,6 +1063,58 @@ check("...and the status page says NOT COVERED rather than 'idle' or a green " # block with no seconds remaining - so the whole setup is retried on a fresh # Controller rather than left to flake. It is bounded at three attempts: a fourth # would mean something is wrong that is not a boundary. +# +# ⚠️⚠️ CI-06. AND THE QUARTER MUST HAVE ROOM LEFT TO SIZE A FIXTURE IN, WHICH IS +# A SECOND AND MUCH WIDER RACE THAN THE BOUNDARY ONE ABOVE. It is where three of +# this file's four known-flaky checks came from, and it is not a boundary +# effect - it is the control law's own gain applied to this helper's arithmetic. +# +# Every second of the open block the telegrams do NOT cover is credited at the +# HELD value instead of the measured one, so the projection loses `net_w x +# uncovered / 900` W - and `excess = 900 x (projected - ceiling) / remaining` +# multiplies that back up by `900 / remaining`. The floor this helper delivers +# is therefore +# +# floor ~ want x (1 - uncovered/900) - net_w x uncovered / remaining +# +# and the second term is the whole story: at 600 s left one uncovered second +# costs 6 W of a 1500 W floor, at 12 s left it costs 292 W, and at 3 s left it +# takes the projection under the ceiling and THE GUARD DOES NOT ENGAGE AT ALL - +# which fails "the real cycle files the peak claim", "...and the number written +# to the inverter is the guard's floor" and "the STATUS PAGE row for a +# floor-limited guard" together, for no reason except the minute the suite ran. +# Measured on this tree as shipped: at 12 s left the fixture asked for 1500 W +# and delivered 613 W, a -59 % fixture that stayed green and graded a different +# site than the one its text names. +# +# TWO uncovered stretches produced it and both are closed here: +# +# 1. THE TAIL. `range(0, span + 1, 5)` stops at the last 5 s mark at or before +# `now`, so 0-5 s of the block were never covered by construction. One +# final telegram stamped at `now` closes it - which is also what a real +# meter does, and what this helper's own docstring already claims it does. +# 2. THE LAG between that last telegram and `cycle()`'s own `datetime.now()`. +# That one is real work and cannot be removed, only bounded: measured at +# 12-96 ms over 23 fixtures on this tree under contention. +# +# So the ROOM the helper needs is derived from what it promises rather than +# picked. Requiring the delivered floor to be within 1 % of the floor asked for, +# at the shipped ceiling and this file's smallest fixture (`net_w` ~ 3500 W, +# `want` 1500 W), and taking the lag at 0.1 s - past every one of the 23 +# measurements: +# +# net_w x lag / (remaining x want) <= 0.01 - lag/900 +# remaining >= 3500 x 0.1 / (1500 x 0.00989) = 23.6 s -> FIXTURE_ROOM_S +# +# Below that the helper WAITS OUT THE REST OF THE QUARTER rather than grading a +# fixture the arithmetic cannot deliver. The wait is at most FIXTURE_ROOM_S and +# is taken on about 2.6 % of runs; a suite that silently graded a -59 % fixture +# instead was the alternative. ⚠️ This is not a widened tolerance - the checks +# downstream are unchanged and the 1 % is a requirement on the FIXTURE, not on +# any assertion. +FIXTURE_ROOM_S = 24.0 + + def wired_over_limit(db, want_floor_w, opts=None, store=None, batt_w=0.0, standing_w=None, soc=55.0, prepare=None): """A real Controller driven one real cycle over a real over-limit quarter. @@ -1081,6 +1134,13 @@ def wired_over_limit(db, want_floor_w, opts=None, store=None, batt_w=0.0, computed backwards from `remaining` at the moment of the run. """ for attempt in range(4): + # ⚠️ ROOM FIRST, AND BEFORE THE CONTROLLER IS BUILT. See FIXTURE_ROOM_S. + # Retrying does not help here - four attempts take ~40 ms each and all + # four would land in the same dying quarter - so the tail of the block + # is waited out once, which puts the next attempt at ~900 s of room. + _room = QUARTER_S - (datetime.now(timezone.utc).timestamp() % QUARTER_S) + if _room < FIXTURE_ROOM_S: + time.sleep(_room + 0.05) ctl, hs = built(db if attempt == 0 else Path(f"{db}.{attempt}"), opts, store=_Store(store) if store is not None else None) ctl.auto, ctl.soc, ctl.batt = True, soc, batt_w @@ -1099,6 +1159,13 @@ def wired_over_limit(db, want_floor_w, opts=None, store=None, batt_w=0.0, net_w = CAP_W + want_floor_w * remaining / QUARTER_S for i in range(0, span + 1, 5): ctl.p1.submit(sample(blk + timedelta(seconds=i), net_w)) + # ⚠️ AND ONE TELEGRAM AT `now` ITSELF. The averager credits a sample's + # value over the interval to the NEXT sample, so without this the block + # is covered only to the last 5 s mark and 0-5 s of it are extrapolated + # from the held value. See the header: at 12 s of remaining that alone + # turned a 1500 W fixture into a 613 W one. A real meter does not stop + # sending at the last multiple of five either. + ctl.p1.submit(sample(now, net_w)) # ⚠️ ASSIGNED, not read back from `p1.net_w`. This helper stamps # `ingest_mono` with an epoch second so the averager (which keys on # `ingest_ts`) replays correctly, while `net_w` keys on a MONOTONIC age @@ -1273,6 +1340,23 @@ _shipped_decide = peakguard.decide def _recording_decide(projection, **kw): _seen.update(kw) + # ⚠️ CI-06. THE PROJECTION OBJECT ITSELF IS KEPT, AND THAT IS WHAT MAKES THE + # COMPARISON BELOW A COMPARISON RATHER THAN A RACE. The check under + # "THE CONSEQUENCE, ITERATED" says both forms are run "against the same + # frozen projection", and until this line existed that sentence was FALSE: + # the intent form was decided against a SECOND `PeakTracker.project( + # b3.p1.averager, datetime.now())` taken after the cycle had returned, so + # the two numbers came from two different instants of the wall clock. The + # control law is `excess = 900 x (projected - ceiling) / remaining`, whose + # derivative in time is `excess / remaining`, so at a 1500 W floor the two + # instants separated at 1500 / remaining W per second and the check's 1.5 W + # tolerance bought exactly `remaining / 1000` SECONDS - 900 ms at the top of + # a quarter and 6 ms with ten seconds left of it. Measured on this tree, the + # gap between the two statements is 13-40 ms idle and larger under load, so + # the check was answered by WHERE IN THE QUARTER IT RAN about `gap_ms / 900` + # of the time. Keeping the object removes the clock from the comparison + # altogether: the tolerance below is EXACT, not widened. + _seen["projection"] = projection return _shipped_decide(projection, **kw) @@ -1294,15 +1378,36 @@ check("B3: main.py sizes the floor from the MEASURED battery power, not from " # against the same frozen projection - the inverter never follows, so the meter # never moves - and the two are allowed to separate over time rather than being # judged at a single point where they need not differ. -_proj3 = PeakTracker.project(b3.p1.averager, datetime.now(timezone.utc)) +# +# ⚠️ CI-06. "THE SAME FROZEN PROJECTION" IS NOW THE SAME OBJECT. `_proj3` is the +# `Projection` the real cycle actually graded, captured by `_recording_decide` +# above, and not a second projection of the same averager taken at a later +# `datetime.now()`. Every number below therefore comes from ONE instant, and the +# tolerances that used to absorb the wall clock are gone. +_proj3 = _seen["projection"] _kw = dict(cap_w=CAP_W, reading=b3.peak.peak(), achievable_w=LIVE_MAX_W, max_hold_s=b3.p1.averager.max_hold_s, soc=SOC_OK, soc_floor=SOC_FLOOR) _intent = _shipped_decide(_proj3, batt_w=STANDING, **_kw) +# The delivered form, re-decided from the SAME projection. It has to reproduce +# the real controller's own floor EXACTLY or `_kw` is not the call main.py +# makes - which is a second thing this now grades and did not before, and the +# one that keeps the identity below honest rather than self-referential. +_delivered = _shipped_decide(_proj3, batt_w=0.0, **_kw) +check("the delivered form re-decided from the cycle's OWN projection is the " + "number the real Controller wrote, to the bit. The kwargs below are " + "main.py's call and not an approximation of it, so the identity that " + "follows is a statement about `decide()` and not about this fixture", + near(_delivered.floor_w, b3.peak_guard.floor_w)) check("one cycle of the intent form is exactly the delivered form plus the " "command standing on the wire - which is the whole defect in one line: " - "watts that were asked for and never arrived, counted as if they had", - near(_intent.floor_w - b3.peak_guard.floor_w, STANDING, 1.5)) + "watts that were asked for and never arrived, counted as if they had. " + "⚠️ EXACT, not within 1.5 W: both forms are decided from one Projection " + "object, so a tolerance here would only be hiding a clock. CI-06 - the " + "1.5 W it used to carry bought `remaining / 1000` seconds and made this " + "line answer by where in the quarter the suite happened to run", + near(_intent.floor_w - _delivered.floor_w, STANDING) + and not _intent.saturated and not _delivered.saturated) _i_cmd, _d_batt = STANDING, 0.0 _i_track, _d_track, _i_sat_at = [], [], None