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

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