OPT-11 P2 review: refusals stay counted, removals survive a start with no broker

- A refusal past the log-once set or the 32 cap is counted in the log at
  1, 10, 100 and so on, so a repeated attack stays visible.
- The logged topic is printable only (no forged log lines).
- mode_announcement(): the start-up store logic, now tested with a real
  Store. A removed config topic stays stored, so a start with no broker
  cannot forget it (rename case tested).
- A test ties each HA mode option to the page's English name.
- packmode.enabled() is tested for "true", 1 and "false".
- Retained-command text, DOCS and DECISIONS updated to match.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

goodwe_controller/DECISIONS/OPT-11-battery-modes.md

@@ -23,6 +23,10 @@ P1 is its section 6 P1, and the pull request lists what was measured.
   and a replay after a restart could otherwise undo a newer one. The config
   topics announced are kept in the store (`mqtt_mode_configs`), so turning
   modes off removes exactly those, and an install that never turned them on
-  publishes what ed739d4 did (`test_mqtt.py` part 10).
+  publishes what ed739d4 did (`test_mqtt.py` part 10). A removed topic stays
+  in that list and its empty config is re-sent on each start, so a start with
+  no broker cannot lose it; re-sending is harmless. The HA options are the
+  page's English names, pinned by a test, and are not renamed with the page:
+  automations send them.
 - In P1 only Off closes a direction; Leftover solar differs by charging last.
   Price runs, selling (`pack_sell`, reserved) and the forecast are P3/P4.

goodwe_controller/DOCS.md

@@ -524,7 +524,7 @@ The peak limit, the safety stops and the monthly cycle always come before a batt
 
 **In Home Assistant.** With MQTT set up, each battery also gets a *Mode* list and a *Use* switch, for example `select.goodwe_inverter_a_mode` and `switch.goodwe_inverter_a_use`. They do the same as the Batteries screen. Turn battery modes off and restart, and they are removed.
 
-*For installers:* commands arrive on `goodwe_ctl/unit/<battery>/mode/set` (a *Mode* option, such as `Solar first`) and `.../use/set` (`ON` or `OFF`). They go through the same checks as the Batteries screen, and a refusal is logged once. A retained command is never applied, so the broker cannot replay an old choice after a restart; the add-on keeps the last choice itself.
+*For installers:* commands arrive on `goodwe_ctl/unit/<battery>/mode/set` (a *Mode* option, such as `Solar first`) and `.../use/set` (`ON` or `OFF`). They go through the same checks as the Batteries screen. A refusal is logged once, and later refusals are counted in the log. A retained command is never applied, so the broker cannot replay an old choice after a restart; the add-on keeps the last choice itself.
 
 *For installers:* a mode is a limit at priority 35, kept apart from the hard limits. It gives way only as far as a limit above it (the peak guard) needs. A mode range always holds 0 W, so a mode can forbid a direction and never force one. With one inverter the mode also bounds the loop. The record is `DECISIONS/OPT-11-battery-modes.md`.
 

goodwe_controller/app/main.py

@@ -73,9 +73,8 @@ from .maintenance import (
     arbitrate as maint_arbitrate,
 )
 from .mqtt import (MODE_CONFIGS_KEY, MODE_LABELS, USE_OFF, USE_ON,
-                   MqttPublisher, announced_units, mode_payloads,
+                   MqttPublisher, announced_units, mode_configs,
-                   mode_retractions, optional_keys, parse_command, unit_slugs,
+                   optional_keys, parse_command, unit_slugs, unit_state_key)
-                   unit_state_key)
 from . import peakguard
 from . import packshare
 from . import pv as pv_read
@@ -908,6 +907,7 @@ class Controller:
         self._mode_faults = set()
         # OPT-11 P2: (topic, reason) of MQTT commands refused and logged once.
         self._mqtt_refused = set()
+        self._mqtt_refused_more = 0
         # [(pack name, why)] for packs that are due and waiting their turn.
         # Empty at a roster of one, where nothing can defer anything.
         self._maint_deferred = []
@@ -2079,7 +2079,8 @@ class Controller:
         checks and the store write are the same. A retained command (one the
         broker replays on subscribe, e.g. after a restart) is never applied:
         the store already holds the last choice. A refusal is logged once per
-        topic and reason. Never raises: MQTT must not reach control.
+        topic and reason, at most 32, and further refusals are counted in the
+        log at 1, 10, 100 and so on. Never raises: MQTT must not reach control.
         """
         try:
             slug, action, value, why = parse_command(
@@ -2095,11 +2096,19 @@ class Controller:
                 why = result["error"]
             else:
                 why = messages.pack_refused(why)
-            topic_s = str(topic)[:128]
+            # Printable only: a topic is sender-chosen, so no log injection.
+            topic_s = "".join(c if c.isprintable() else "?"
+                              for c in str(topic)[:128])
             _LOG.debug("Home Assistant command %s %s refused: %s", topic_s,
                        repr(payload)[:48], why)
             if (topic_s, why) in self._mqtt_refused \
                     or len(self._mqtt_refused) >= 32:
+                # Not logged again, but counted: 1, 10, 100... stay visible.
+                self._mqtt_refused_more += 1
+                more = self._mqtt_refused_more
+                if str(more).rstrip("0") == "1":
+                    _LOG.warning("Home Assistant commands still ignored: %d "
+                                 "more so far.", more)
                 return
             self._mqtt_refused.add((topic_s, why))
             _LOG.warning("Home Assistant command on %s ignored: %s", topic_s,
@@ -6115,6 +6124,21 @@ class ControlTaskDied(RuntimeError):
     """The control task ended while nothing had asked it to stop."""
 
 
+def mode_announcement(opts, store) -> tuple:
+    """OPT-11 P2: `(modes, retract)` for the MQTT publisher at start-up.
+
+    The config topics announced are kept in the store, so turning modes off
+    removes exactly those (`mqtt.mode_configs()`). An install that never
+    turned modes on gets nothing, and its store is not written.
+    """
+    modes = packmode.MODES if packmode.enabled(opts) else ()
+    stored = store.data.get(MODE_CONFIGS_KEY)
+    keep, retract = mode_configs(roster_names(opts), modes, stored)
+    if keep and keep != stored:
+        store.set(MODE_CONFIGS_KEY, keep)
+    return modes, retract
+
+
 def control_task_done(task: asyncio.Task, *, controller, stop: asyncio.Event,
                       died: list) -> None:
     """Done-callback on the control task: log its death now and wake amain()
@@ -6246,15 +6270,8 @@ async def amain() -> None:
         broker = None
         try:
             # OPT-11 P2: each battery's switch and mode list, only while
-            # battery modes are on. The config topics are kept in the store,
+            # battery modes are on (`mode_announcement()`).
-            # so turning modes off removes exactly the ones announced.
+            _modes, _retract = mode_announcement(opts, store)
-            _modes = packmode.MODES if packmode.enabled(opts) else ()
-            _mode_cfgs = [t for t, _ in mode_payloads(roster_names(opts),
-                                                      _modes)]
-            _retract = mode_retractions(store.data.get(MODE_CONFIGS_KEY),
-                                        _mode_cfgs)
-            if _modes:
-                store.set(MODE_CONFIGS_KEY, _mode_cfgs)
             broker = await hass.mqtt_service()
             pub = MqttPublisher(
                 broker.get("host") if broker else None,

goodwe_controller/app/messages.py

@@ -933,7 +933,7 @@ PACK_REFUSED = {
     "unit": "There is no battery with that name.",
     "value": "That choice is not possible for this battery.",
     # OPT-11 P2: a Home Assistant command dropped before it reaches a battery.
-    "retained": "A saved command is not used after a restart.",
+    "retained": "An old saved command is not used.",
     "size": "That command is too long.",
     "encoding": "That command is not plain text.",
     "topic": "That is not a battery command.",

goodwe_controller/app/mqtt.py

@@ -515,8 +515,18 @@ def mode_retractions(stored, current) -> list:
     if not isinstance(stored, list):
         return []
     keep = set(current)
-    return [t for t in stored if isinstance(t, str)
+    return list(dict.fromkeys(t for t in stored if isinstance(t, str)
-            and _MODE_CONFIG_RE.fullmatch(t) and t not in keep]
+                              and _MODE_CONFIG_RE.fullmatch(t)
+                              and t not in keep))
+
+
+def mode_configs(units, modes, stored) -> tuple:
+    """`(keep, retract)` at start-up: the mode config topics to store, and the
+    ones to remove now. A removal stays in `keep`, so a start with no broker
+    does not forget it; resending an empty config is harmless."""
+    current = [t for t, _ in mode_payloads(units, modes)]
+    retract = mode_retractions(stored, current)
+    return current + retract, retract
 
 
 def parse_command(topic, payload, retained, modes):

goodwe_controller/test_messages.py

@@ -846,6 +846,7 @@ DATA = {
     "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:topic_s",
+    "main.py:more",
     "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)",

goodwe_controller/test_mqtt.py

@@ -1053,6 +1053,15 @@ check("every mode has a plain label, in MODES order, and a later mode only "
       and len(set(mqtt.MODE_LABELS.values())) == len(mqtt.MODE_LABELS)
       and json.loads(MODE_N1[0][1])["options"]
       == [mqtt.MODE_LABELS[k] for k in MODES])
+# Review of #152: the HA options are what automations send, so they are kept
+# apart from the page's words on purpose. They start equal; if the page's
+# English changes, this goes red and the author decides: keep the HA option
+# (and change this pin) or rename it (a breaking change, in DECISIONS).
+_en = json.loads((HERE / "app" / "ui_text" / "en.json").read_text())
+check("each HA mode option is the page's English name for that mode, in "
+      "both places the page names it",
+      all(mqtt.MODE_LABELS[k] == _en["home_words"]["modes"][k]
+          == _en["home"]["batteries"]["choice"][k]["name"] for k in MODES))
 _later = dict(mqtt.MODE_LABELS, cheap_hours="Cheap hours only")
 _orig = mqtt.MODE_LABELS
 mqtt.MODE_LABELS = _later
@@ -1094,6 +1103,59 @@ check("...and nothing from the store is removed that is not one of our mode "
       == ["homeassistant/select/goodwe_ctl_unit_a_mode/config"])
 
 
+_on1 = [t for t, _ in mqtt.mode_payloads(["inverter-a"], MODES)]
+_k, _r = mqtt.mode_configs(["inverter-a"], MODES, _cur2)
+check("start-up (`mode_configs`): a battery that left is removed, and stays "
+      "in the store, so a start with no broker does not forget it",
+      _r == _cur2[2:] and _k == _on1 + _cur2[2:])
+_k, _r = mqtt.mode_configs(NAMES2, (), _cur2 + _cur2[:1])
+check("...modes turned off: all four are removed, once each, and kept",
+      _r == _cur2 and _k == _cur2)
+check("...never turned on: nothing to store and nothing to remove, so the "
+      "store is not written",
+      mqtt.mode_configs(NAMES2, (), None) == ([], []))
+_k, _r = mqtt.mode_configs(NAMES2, MODES, _cur2)
+check("...turned on again: nothing removed, and the list does not grow",
+      _r == [] and _k == _cur2)
+
+
+from app.main import mode_announcement  # noqa: E402
+_st = Store(os.path.join(tempfile.mkdtemp(), "ann.json"))
+_OPTS1M = dict(OPTS2, battery_modes_enabled=True,
+               inverters=OPTS2["inverters"][:1])
+_seen = [mode_announcement(dict(OPTS2), _st),
+         dict(_st.data)]
+_seen += [mode_announcement(dict(OPTS2, battery_modes_enabled=True), _st),
+          list(_st.data.get(mqtt.MODE_CONFIGS_KEY) or [])]
+_seen += [mode_announcement(_OPTS1M, _st),
+          list(_st.data.get(mqtt.MODE_CONFIGS_KEY) or [])]
+_seen += [mode_announcement(dict(OPTS2, battery_modes_enabled=False), _st),
+          list(_st.data.get(mqtt.MODE_CONFIGS_KEY) or [])]
+check("main's start-up, through a real Store: never on announces and stores "
+      "nothing; on stores the four; a roster of one removes B's two and keeps "
+      "them; off removes all four and the store keeps them",
+      _seen[0] == ((), []) and mqtt.MODE_CONFIGS_KEY not in _seen[1]
+      and _seen[2] == (MODES, []) and _seen[3] == _cur2
+      and _seen[4] == (MODES, _cur2[2:]) and sorted(_seen[5]) == sorted(_cur2)
+      and _seen[6] == ((), _seen[5])
+      and sorted(_seen[7]) == sorted(_cur2))
+_st = Store(os.path.join(tempfile.mkdtemp(), "ren.json"))
+mode_announcement(dict(OPTS2, battery_modes_enabled=True), _st)
+_ren = dict(OPTS2, battery_modes_enabled=True, inverters=[
+    OPTS2["inverters"][0], dict(OPTS2["inverters"][1], name="inverter-c")])
+_r = mode_announcement(_ren, _st)[1]
+_kept = list(_st.data.get(mqtt.MODE_CONFIGS_KEY) or [])
+check("...B renamed C while on: B's two are removed and stay stored beside "
+      "A's and C's, so a start with no broker does not forget them",
+      _r == _cur2[2:] and _kept[-2:] == _cur2[2:] and len(_kept) == 6
+      and mode_announcement(_ren, _st)[1] == _cur2[2:])
+check("battery modes are on only for exactly `true`: not \"true\", 1 or "
+      "\"false\"",
+      [packmode.enabled({"battery_modes_enabled": v})
+       for v in (True, "true", 1, "false", None)]
+      == [True, False, False, False, False])
+
+
 # --- 10d. state topics, from the store ----------------------------------------
 _tmp = tempfile.mkdtemp()
 OPTS2M = dict(OPTS2, battery_modes_enabled=True)
@@ -1237,8 +1299,30 @@ _logs.rows.clear()
 _flood, _ = ctl_for(OPTS2M, os.path.join(_tmp, "flood.json"))
 for _i in range(100):
     cmd(f"goodwe_ctl/unit/x{_i}/use/set", b"OFF", ctl=_flood)
-check("...and a flood of 100 different bad topics logs 32 WARNINGs, no more",
+_w = [r[1] for r in _logs.rows if r[0] >= logging.WARNING]
-      len([r for r in _logs.rows if r[0] >= logging.WARNING]) == 32)
+_per = [w for w in _w if "still ignored" not in w]
+_more = [w for w in _w if "still ignored" in w]
+print(f"    flood: {len(_per)} per-topic WARNINGs, then {_more}")
+check("...and a flood of 100 different bad topics logs 32 WARNINGs, then the "
+      "rest only as a count, at 1 and 10 more (review of #152)",
+      len(_per) == 32 and len(_more) == 2
+      and "1 more so far" in _more[0] and "10 more so far" in _more[1])
+_logs.rows.clear()
+for _ in range(100):
+    cmd(f"{T_B}/use/set", b"maybe", ctl=_flood)
+_more = [r[1] for r in _logs.rows
+         if r[0] >= logging.WARNING and "still ignored" in r[1]]
+check("...so a repeated attack on ONE topic still shows it goes on: the count "
+      "reaches 100 in 3 lines, not 100",
+      len(_more) == 1 and "100 more so far" in _more[0])
+_logs.rows.clear()
+_inj, _ = ctl_for(OPTS2M, os.path.join(_tmp, "inj.json"))
+cmd("goodwe_ctl/unit/a\nERROR forged line\x1b[31m/use/set", b"OFF", ctl=_inj)
+_w = [r[1] for r in _logs.rows if r[0] >= logging.WARNING]
+check("...and a topic with a newline or an escape code cannot forge a log "
+      "line: it is logged printable only",
+      len(_w) == 1 and "\n" not in _w[0] and "\x1b" not in _w[0]
+      and "a?ERROR forged line?[31m" in _w[0])
 
 # Modes off: refused on the same path, even if a message arrives.
 cmd(f"{T_A}/use/set", b"OFF", ctl=_c_off)
@@ -1299,7 +1383,8 @@ check("(source read) main() passes modes and retractions to the publisher, "
       "and binds its commands to the controller",
       _kws.get("modes") == "_modes" and _kws.get("retract") == "_retract"
       and "pub.bind(asyncio.get_running_loop(), controller.mqtt_command)"
-      in _main_src)
+      in _main_src
+      and "_modes, _retract = mode_announcement(opts, store)" in _main_src)
 
 
 # --- 10h. the guards, broken one at a time --------------------------------------
@@ -1370,8 +1455,8 @@ P2_MUTATIONS = [
     ("command topic matched as a prefix",
      [("_COMMAND_RE.fullmatch(topic)", "_COMMAND_RE.search(topic)")]),
     ("store list not filtered",
-     [("and _MODE_CONFIG_RE.fullmatch(t) and t not in keep", "and t not in keep")]),
+     [("and _MODE_CONFIG_RE.fullmatch(t)\n", "and True\n")]),
-    ("current configs also removed", [("_MODE_CONFIG_RE.fullmatch(t) and t not in keep", "_MODE_CONFIG_RE.fullmatch(t)")]),
+    ("current configs also removed", [("and t not in keep))", "))")]),
     ("commands published retained by HA", [('cfg["retain"] = False', 'cfg["retain"] = True')]),
     ("retractions not published",
      [('            self.client.publish(topic, "", retain=True)\n', "            pass\n")]),