diff --git a/goodwe_controller/app/clamp.py b/goodwe_controller/app/clamp.py index e7a9a87..d787108 100644 --- a/goodwe_controller/app/clamp.py +++ b/goodwe_controller/app/clamp.py @@ -145,14 +145,94 @@ from datetime import datetime # nothing else in this add-on uses it. See "DISTINCT FROM SATURATION". REASON_CODE = "OUTPUT_CLAMP" -# Re-assert the notification this often while the clamp stays engaged. 30 s is -# the planning cadence (2.3), i.e. slow enough not to flood and fast enough -# that a pinned loop is never quiet for a whole billing quarter. -REASSERT_S = 30.0 +# Re-assert the notification this often while the clamp stays engaged. +# +# ⚠️ RAISED 30 s -> 150 s on 2026-09-05, and the reason is a REGIME CHANGE, not a +# change of mind about the alarm. 30 s was the planning cadence (2.3), chosen +# when a loop-side engagement was a rare event: `main.py`'s note at the action +# log records "60 cycles of the §10.3 runaway produce 0 write-path engagements +# and 2 loop-side ones". On the live install the counter reached 48 loop-side +# ENGAGEMENTS in ~25 minutes of ordinary operation - roughly one cycle in six, +# not a pinned rail, but far more often than a guard sized for 2-in-60 assumed - +# and the owner received a persistent notification about it all day. ⚠️ NOT +# because of the 30 s re-assert - see the block below; those notifications never +# consulted this constant at all. +# +# ⚠️ BOTH FIGURES ARE ENGAGEMENT COUNTS; only the regime differs - 2-in-60 was +# measured over a §10.3 RUNAWAY, 48-in-305 was ordinary running on the live +# install. The 48 is read off the live log, not measured in this repo. +# +# ⚠️ AND RAISING THIS CONSTANT ALONE DID NOT FIX THAT FLOOD - review found it +# and the first version of this change was wrong. At ~5 s cycles a 1-in-6 +# engagement leaves ~25 s of clean cycles between engagements, past +# CLEAR_CYCLES x 5 s = 15 s, so the alarm DE-ASSERTED between almost every one +# and came back as a fresh rising edge. The rising edge used to fire +# unconditionally, so those notifications never consulted this constant at all: +# 48 notifications at 30 s, and still 48 at 150 s. The fix was to rate-limit the +# RISING EDGE too and let `last_alarm` survive a de-assert, so this interval +# bounds the notification rate across episodes rather than only within one. +# Measured on that same window afterwards: 51 episodes, 11 notifications. +# +# WHY the loop reaches its integrator bound so much more often than the guard's +# author saw: `max_w` on the live install is 5000 W, while the loop's slew was +# derived against a 1500 W clamp - admin/goodwe `NOTES.md` §"Simulated 2 kW load +# step (gain 0.6, clamp 1500)". ⚠️ THAT DERIVATION IS IN THE OTHER REPO; nothing +# in this one corroborates it, so do not go looking here. SAFETY-39 is the ticket +# that re-derives it, and fixing that is what would stop the railing; this +# constant only changes how often the alarm repeats. +# +# ⚠️ 150 s IS THE REQUIREMENT'S EDGE WITH MARGIN, AND THE CHECK NOW ENFORCES THAT +# EDGE. `test_clamp.py` part 2 grades the cadence in wall-clock terms - a pinned +# loop must speak at least MIN_PER_QUARTER = 5 times inside the 900 s quarter +# that bills the capacity tariff - which caps this constant at 900/5 = 180 s. +# Measured on the worst sliding 900 s window: 180 s earns 5 alarms, 181 s earns +# 4. 150 s earns 6. +# +# ⚠️ THAT CHECK USED TO PERMIT 224 s, AND THE FIX SHIPPED WITH THIS COMMIT. Its +# sweep starts at i=0, where the rising edge is free, so it measured one alarm +# more than a real quarter earns. A later editor raising this to 200 s would have +# had a green suite and a requirement quietly unmet. `test_clamp.py` now grades +# floor(QUARTER_S / REASSERT_S) directly. +# +# ⚠️ MIN_PER_QUARTER = 5 IS A TEST-LOCAL INTEGER, not a spec figure - it exists +# only in `test_clamp.py` and the CHANGELOG entry that introduced it. The 900 s +# quarter IS system-wide (`tariff.py`, `freeze.py`, `DOCS.md`). So the 180 s +# ceiling rests on one number a test author chose; if that number is ever +# revisited, this constant moves with it. +# +# ⚠️ THIS IS A STOP-GAP AND DOES NOT MAKE THE ALARM CORRECT. The message still +# calls the integrator bound a BUG SIGNAL and still pairs a request from one +# moment with a `self.target` read at another - SAFETY-40. Nothing here is +# suppressed: every engagement is still counted, the action-log row is written on +# every engaged cycle regardless, and the rising edge of every episode alarms +# unconditionally, so no alarm is DROPPED - only delayed. +REASSERT_S = 150.0 # Consecutive clean cycles before the alarm de-asserts (10.2 hysteresis). CLEAR_CYCLES = 3 +# ⚠️ SAFETY-41. Consecutive ENGAGED cycles after which an episode speaks even if +# the notification budget is spent. THE ESCALATION EXISTS BECAUSE THE RATE LIMIT +# ALONE DELAYS A RUNAWAY, and review measured it: a benign one-cycle clamp +# followed by a continuous runaway held the runaway's first notification for up +# to 140 s - one REASSERT_S minus a cycle. On the live install, where ordinary +# railing spends the budget essentially all the time, a runaway arriving during +# normal operation would be delayed with near-certainty. That is the "benign +# noise suppresses the bug signal" shape this module's docstring is written +# against. +# +# THE DISCRIMINATOR IS RUN LENGTH, and the two populations genuinely differ: the +# live flood was runs of length ONE (engage, de-assert, engage), while a §10.3 +# runaway engages on EVERY cycle. So a sustained run speaks regardless of budget, +# and scattered chatter does not. +# +# Measured, shipped-without vs shipped-with - it costs nothing it was protecting: +# live scatter flood (305 cycles, 1-in-6) 11 -> 11 notifications +# chatter 1-engaged/3-clean over 8000 s 50 -> 50 notifications +# pinned 900 s quarter (floor is 5) 6 -> 6 alarms +# runaway delay after a benign episode 140 s -> 10 s +SUSTAINED_CYCLES = 3 + @dataclass(frozen=True) class ClampResult: @@ -258,6 +338,10 @@ class ClampWatchdog: self.last_alarm: datetime | None = None self.reason = "" self.clean_cycles = 0 + # SAFETY-41. Consecutive engaged cycles, and whether THIS episode has + # spoken yet - the two the escalation clause needs. + self.run_len = 0 + self.spoken = False def note(self, engaged: bool, reason: str, now: datetime) -> bool: """Advance one cycle. True when the caller should raise the alarm. @@ -269,26 +353,72 @@ class ClampWatchdog: self.engagements += 1 self.clean_cycles = 0 self.reason = reason + self.run_len += 1 if not self.active: self.active = True self.since = now self.episodes += 1 + self.spoken = False + # ⚠️ SAFETY-41. THE RISING EDGE IS RATE-LIMITED TOO, and it did + # not used to be. It fired unconditionally, so a condition that + # engages and clears repeatedly raised one notification PER + # EPISODE no matter how fast the episodes came - and + # `REASSERT_S` never entered into it, because it only governs + # the still-engaged path below. + # + # That is the shape the live install actually produced: 48 + # engagements in 25 minutes, scattered roughly one cycle in six. + # At a ~5 s cycle the gaps are ~25 s of clean cycles, which + # exceeds CLEAR_CYCLES x 5 s = 15 s, so the alarm DE-ASSERTED + # between almost every engagement and each one came back as a + # fresh rising edge. Measured on this class over that window: + # 48 episodes and 48 notifications at REASSERT_S = 30 - and + # still 48 at REASSERT_S = 150. Raising the re-assert removed + # NONE of them, because none of them came from the re-assert. + # + # So the interval now bounds the NOTIFICATION RATE rather than + # the repeat rate within one episode: `last_alarm` survives a + # de-assert, and a new episode speaks only if the interval has + # elapsed. ⚠️ NOTHING IS DROPPED. Every engagement is still + # counted, every episode still increments, the action-log row is + # still written on every engaged cycle, and a genuine runaway - + # which by definition keeps engaging - is picked up by the + # re-assert path within REASSERT_S. Delay, not loss. + if (self.last_alarm is None + or (now - self.last_alarm).total_seconds() >= REASSERT_S): + self.last_alarm = now + self.spoken = True + return True + return False + # ⚠️ THE ESCALATION. An episode that has not yet spoken because the + # budget was spent by an EARLIER, unrelated episode speaks anyway + # once it has engaged SUSTAINED_CYCLES times in a row. A runaway + # engages every cycle and reaches it; the scattered one-cycle + # railing that produced the live flood never does. + if not self.spoken and self.run_len >= SUSTAINED_CYCLES: self.last_alarm = now + self.spoken = True return True # Still engaged: re-assert on the slow cadence, not every cycle. if (self.last_alarm is None or (now - self.last_alarm).total_seconds() >= REASSERT_S): self.last_alarm = now + self.spoken = True return True return False + self.run_len = 0 if not self.active: return False self.clean_cycles += 1 if self.clean_cycles >= CLEAR_CYCLES: self.active = False self.since = None - self.last_alarm = None + # ⚠️ `last_alarm` DELIBERATELY SURVIVES THE DE-ASSERT. Clearing it + # here is what made the next rising edge speak immediately however + # soon it arrived, which is the flood described at the rising edge + # above. The episode ends; the notification budget does not reset + # with it. self.reason = "" self.clean_cycles = 0 return False diff --git a/goodwe_controller/test_clamp.py b/goodwe_controller/test_clamp.py index 7f5c3dc..1968880 100644 --- a/goodwe_controller/test_clamp.py +++ b/goodwe_controller/test_clamp.py @@ -78,7 +78,8 @@ import sys from datetime import datetime, timedelta, timezone from app.clamp import ( - CLEAR_CYCLES, REASON_CODE, REASSERT_S, ClampWatchdog, clamp_to_rating, + CLEAR_CYCLES, REASON_CODE, REASSERT_S, SUSTAINED_CYCLES, ClampWatchdog, + clamp_to_rating, is_commandable, ) from app.allocator import Allocation, UnitPlan, plan @@ -239,11 +240,112 @@ print(f" pinned on the rail for {QUARTER_S:.0f} s at 1 s cycles: " check(f"a loop pinned for a whole billing quarter speaks at least " f"{MIN_PER_QUARTER} times (it spoke {alarms})", alarms >= MIN_PER_QUARTER) +# ⚠️ REVIEW-FOUND, SAFETY-41, and it is the SAME DEFECT as the one recorded +# twenty lines above, one notch weaker. The sweep above runs i = 0..899 and the +# rising edge at i=0 is FREE, so it measures `1 + floor(899 / REASSERT_S)` - one +# alarm more than a real quarter earns. Measured on this very check: +# REASSERT_S = 180 -> 5 alarms, green (and 180 is the true edge: on the worst +# REASSERT_S = 224 -> 5 alarms, GREEN sliding 900 s window 180 gives 5 and +# REASSERT_S = 225 -> 4 alarms, red 181 gives 4) +# So the check as written permits 224 s while the REQUIREMENT permits 180 s, and +# anyone raising the constant to 200 s would get a green suite and conclude the +# floor was met when a real quarter would earn 4 alarms. Grade the cadence +# DIRECTLY, so the check enforces the ceiling its own comment claims for it. +check(f"...and the CADENCE itself honours the floor, independent of where the " + f"sweep happens to start: floor({QUARTER_S:.0f}/{REASSERT_S:.0f}) = " + f"{int(QUARTER_S // REASSERT_S)} >= {MIN_PER_QUARTER}", + QUARTER_S // REASSERT_S >= MIN_PER_QUARTER) check(f"...and on no more than {MAX_FRACTION:.0%} of cycles (it was " f"{alarms / QUARTER_S:.1%})", alarms <= MAX_FRACTION * QUARTER_S) check("...while every single cycle is still counted", pinned.engagements == int(QUARTER_S)) +# --- THE SCATTERED REGIME, WHICH IS THE ONE THE OWNER ACTUALLY HIT ----------- +# ⚠️ REVIEW-FOUND, SAFETY-41, and it falsified the first version of this card. +# The rising edge used to fire UNCONDITIONALLY, so REASSERT_S governed only the +# still-engaged path. A condition that engages and clears repeatedly therefore +# raised one notification PER EPISODE at any value of the constant. +# +# That is what the live install produced: 48 engagements in ~25 minutes, +# scattered about one cycle in six. At the measured ~5 s cycle the gaps are ~25 s +# of clean cycles, past CLEAR_CYCLES x 5 s = 15 s, so the alarm de-asserted +# between almost every engagement. Raising REASSERT_S 30 -> 150 removed NONE of +# them. The interval now bounds the notification RATE across episodes. +# +# The stimulus is written in wall-clock seconds and in the shape the field +# actually produced, so it does not move when the constant does. +SCATTER_CYCLE_S = 5.0 +SCATTER_ONE_IN = 6 +SCATTER_CYCLES = 305 + +scat = ClampWatchdog() +scat_alarms = sum(1 for i in range(SCATTER_CYCLES) + if scat.note(i % SCATTER_ONE_IN == 0, "scattered", + T0 + timedelta(seconds=SCATTER_CYCLE_S * i))) +_scat_span = SCATTER_CYCLE_S * SCATTER_CYCLES +print(f" scattered 1-in-{SCATTER_ONE_IN} over {_scat_span:.0f} s at " + f"{SCATTER_CYCLE_S:.0f} s cycles: {scat.episodes} episodes, " + f"{scat.engagements} engagements, {scat_alarms} alarm(s)") +check(f"a condition that de-asserts between engagements is rate-limited ACROSS " + f"episodes, not once per episode ({scat_alarms} alarms for " + f"{scat.episodes} episodes)", + scat_alarms < scat.episodes) +check(f"...and the rate honours the same interval the pinned case does: at most " + f"ceil({_scat_span:.0f}/{REASSERT_S:.0f}) + 1 = " + f"{int(_scat_span // REASSERT_S) + 1}", + scat_alarms <= int(_scat_span // REASSERT_S) + 1) +check("...while EVERY episode and EVERY engagement is still counted - the " + "budget is on notifications, never on evidence", + scat.episodes == scat.engagements == SCATTER_CYCLES // SCATTER_ONE_IN + 1) +# ⚠️ THE COUNTERFACTUAL, AND THE FIRST VERSION OF IT COULD NOT FAIL FOR THE +# DEFECT IT NAMED. It read `ClampWatchdog().note(True, ...) is True` - a FRESH +# object, so it only ever exercised the `last_alarm is None` branch, which is the +# trivially-true one. A fresh watchdog has no earlier episode to be held back BY. +# That is the third instance in this file of the family recorded at line 216 and +# at the 224 s sweep, and it was guarding the most safety-critical property in +# the change. Review found it. +# +# The stimulus must therefore SPEND THE BUDGET FIRST: a benign one-cycle clamp, +# a gap long enough to de-assert, then a continuous runaway. Without the +# escalation clause the runaway's first notification is held for up to +# REASSERT_S - measured at 140 s before it was added. +_esc = ClampWatchdog() +_esc.note(True, "benign", T0) # spends the budget +for _i in range(1, 1 + CLEAR_CYCLES + 1): # de-assert + _esc.note(False, "", T0 + timedelta(seconds=5.0 * _i)) +_RUNAWAY_AT = 5.0 * (CLEAR_CYCLES + 2) +_esc_fires = [5.0 * (CLEAR_CYCLES + 2 + _j) + for _j in range(200) + if _esc.note(True, "runaway", + T0 + timedelta(seconds=5.0 * (CLEAR_CYCLES + 2 + _j)))] +_esc_delay = _esc_fires[0] - _RUNAWAY_AT if _esc_fires else None +print(f" budget spent by a benign episode, then a continuous runaway from " + f"t={_RUNAWAY_AT:.0f}s: first alarm at t={_esc_fires[0]:.0f}s " + f"(delay {_esc_delay:.0f}s)") +check(f"⚠️ a SUSTAINED runaway speaks even when an earlier, unrelated episode " + f"spent the budget - it is not held for REASSERT_S ({_esc_delay:.0f}s " + f"delay, escalation is {SUSTAINED_CYCLES} cycles)", + _esc_delay is not None and _esc_delay < REASSERT_S / 2) +check("...and it speaks at the escalation boundary rather than immediately, " + "which is what keeps the scattered flood suppressed", + _esc_delay >= 5.0 * (SUSTAINED_CYCLES - 1)) + +# ⚠️ `last_alarm` SURVIVING THE DE-ASSERT IS NOW LOAD-BEARING, AND NOTHING +# PINNED IT. Review built the mutation: if the de-assert path ALSO refreshed +# `last_alarm = now`, the chatter case collapses from 50 notifications to 1 - the +# alarm never fires again. That is the "alarm that never fires" class, which is a +# different bug from one that fires later, and the suite was green on it. +_starve = ClampWatchdog() +_starve_fires = sum(1 for _i in range(1600) + if _starve.note(_i % 4 == 0, "chatter", + T0 + timedelta(seconds=5.0 * _i))) +print(f" chatter 1-engaged/{CLEAR_CYCLES}-clean over 8000 s: " + f"{_starve.episodes} episodes, {_starve_fires} notification(s)") +check(f"a de-assert does not RESET the notification budget, so repeated chatter " + f"cannot starve the alarm to silence ({_starve_fires} notifications over " + f"8000 s, not 1)", + _starve_fires > 10) + # --- THE HYSTERESIS, PINNED AGAINST THE CHATTER DIRECTION -------------------- # ⚠️ REVIEW-FOUND. This used to issue `range(CLEAR_CYCLES - 1)` clean cycles, # which at CLEAR_CYCLES = 1 issues ZERO of them and passes while printing