Skip to content

Commit b02cd6d

Browse files
CIclaude
andcommitted
fix(sungrow): release a command nobody is re-deciding; keep the device read through a brief failure
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
1 parent 6f28fb3 commit b02cd6d

5 files changed

Lines changed: 194 additions & 17 deletions

File tree

‎apps/predbat/sungrow.py‎

Lines changed: 53 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -141,6 +141,7 @@
141141
SUNGROW_FORCED_EVERYDAY,
142142
SUNGROW_HEARTBEAT_DEFAULT_SECONDS,
143143
SUNGROW_HEARTBEAT_MAX_MISSES,
144+
SUNGROW_DECISION_STALE_SECONDS,
144145
SUNGROW_ESS_POINTS,
145146
SUNGROW_ESS_ENERGY,
146147
SUNGROW_ERROR_CODES,
@@ -296,6 +297,8 @@ def initialize(
296297
# Inverters whose own realtime read is currently failing, so the fallback to plant
297298
# figures is logged once per episode rather than once a minute.
298299
self._device_read_failing = set()
300+
# When each inverter's own telemetry was last read successfully.
301+
self._device_read_time = {}
299302
# What was read back of each inverter's own feed-in limitation (10012-10014).
300303
self.device_limits = {}
301304
self.local_schedule = {}
@@ -316,6 +319,8 @@ def initialize(
316319
self._heartbeat_task = None
317320
self._heartbeat_stop = False
318321
self._beat_failures = {}
322+
# When each inverter's command was last decided; the heartbeat will not hold one open past it.
323+
self._decision_time = {}
319324
# Per-device "does this device accept parameter configuration" verdict from
320325
# paramSettingCheck. Cached because it is a property of the hardware and the account
321326
# tier, not a transient error, and re-probing it every cycle spends a call to be told
@@ -716,7 +721,8 @@ async def refresh_power(self):
716721
"""Refresh the telemetry tier. True when at least one plant answered.
717722
718723
The device read is optional - not every account and model serves it - so its failure
719-
does not fail the tier. It does discard that inverter's previous device values.
724+
does not fail the tier. That inverter's previous device values are kept through a brief
725+
failure and discarded once the last good read is SUNGROW_TELEMETRY_STALE_MINUTES old.
720726
"""
721727
any_ok = False
722728
for ps_id in list(self.plant_list):
@@ -726,18 +732,28 @@ async def refresh_power(self):
726732
await asyncio.sleep(self.api_delay)
727733
for uuid in list(self.device_list):
728734
if await self.fetch_device_realtime(uuid):
735+
self._device_read_time[uuid] = time.time()
729736
self._device_read_failing.discard(uuid)
730737
else:
731-
# Drop what the last good read left behind. telemetry() and energy() prefer
732-
# the device read, and the plant read above still marks this tier fresh, so
733-
# keeping it would freeze SoC at its last value with the component reporting
734-
# healthy. Without it they fall back to the plant read - which, for a plant
735-
# with more than one inverter, deliberately gives None for power and energy.
736-
self.device_values.pop(uuid, None)
737-
self.device_energy.pop(uuid, None)
738-
if uuid not in self._device_read_failing:
739-
self._device_read_failing.add(uuid)
740-
self.log("Info: Sungrow {} own telemetry could not be read; plant-level figures are being used until it answers again".format(self._serial(uuid)))
738+
# A brief failure KEEPS what the last good read left behind. telemetry() and
739+
# energy() prefer the device read, so dropping it for one poll publishes the
740+
# plant's daily counters and the next poll publishes the device's again. The
741+
# two sources never agree exactly, and Predbat's history cleaner counts every
742+
# rise in an incrementing sensor as energy and ignores every fall - so each
743+
# flip there and back adds the difference to load, import, export and PV.
744+
#
745+
# A long failure DISCARDS it. The plant read above still marks this tier fresh,
746+
# so keeping the values for ever would freeze SoC at its last value with the
747+
# component reporting healthy. Without them telemetry() and energy() fall back
748+
# to the plant read - which, for a plant with more than one inverter,
749+
# deliberately gives None for power and energy.
750+
last = self._device_read_time.get(uuid)
751+
if last is None or (time.time() - last) > SUNGROW_TELEMETRY_STALE_MINUTES * 60:
752+
self.device_values.pop(uuid, None)
753+
self.device_energy.pop(uuid, None)
754+
if uuid not in self._device_read_failing:
755+
self._device_read_failing.add(uuid)
756+
self.log("Info: Sungrow {} own telemetry could not be read; plant-level figures are being used until it answers again".format(self._serial(uuid)))
741757
if self.api_delay:
742758
await asyncio.sleep(self.api_delay)
743759
if any_ok:
@@ -1543,6 +1559,8 @@ async def _write_params(self, uuid, decision, force=False):
15431559
# Control is only marked as HELD once the task has actually completed. Starting the
15441560
# heartbeat for a task that never landed would beat for a mode the inverter is not in.
15451561
self.control_held.add(uuid)
1562+
# Control has just been taken on a fresh decision, whoever called.
1563+
self._decision_time[uuid] = time.time()
15461564
# A fresh hold starts with a clean count; a miss from an earlier hold is not this one's.
15471565
self._beat_failures.pop(uuid, None)
15481566
self._ensure_heartbeat()
@@ -1577,6 +1595,7 @@ async def release_control(self, uuid, reserve=0):
15771595
written, paced by sungrow_min_write_interval like any other change of plan.
15781596
"""
15791597
self._beat_failures.pop(uuid, None)
1598+
self._decision_time.pop(uuid, None)
15801599
was_held = uuid in self.control_held
15811600
self.control_held.discard(uuid)
15821601
release = {"command": SUNGROW_CMD_RELEASE, "soc_lower": int(clamp_range(SUNGROW_PARAM_SOC_LOWER, as_float(reserve, 0.0)))}
@@ -1634,6 +1653,9 @@ async def _reconcile_control(self, uuid):
16341653
"""
16351654
if uuid not in self.control_active or self._is_read_only() or not self.control_enable:
16361655
return
1656+
# Stamped past the gate only: a reconcile stopped there decided nothing. This is what
1657+
# the heartbeat reads to tell a command that is still supervised from one that is not.
1658+
self._decision_time[uuid] = time.time()
16371659
try:
16381660
await self.apply_schedule(uuid)
16391661
except Exception as error:
@@ -1654,6 +1676,7 @@ def _drop_control(self, uuids, reason):
16541676
self.control_held.discard(uuid)
16551677
self.applied_command.pop(uuid, None)
16561678
self._beat_failures.pop(uuid, None)
1679+
self._decision_time.pop(uuid, None)
16571680
# The inverter's state is now unknown, so the write that re-establishes control
16581681
# must not wait out sungrow_min_write_interval. This cannot become a retry storm:
16591682
# a re-establishing write that fails stamps the clock again in _write_params.
@@ -1691,6 +1714,13 @@ async def _heartbeat_loop(self):
16911714
Control is dropped there and then, and the next run() cycle writes the full command
16921715
again. Nothing else is escalated: the inverter's own response to missing beats is a
16931716
revert to self-consumption, which is the safe state.
1717+
1718+
A beat only goes out for a command that has been decided recently. run() is the only
1719+
place a command is decided, and it is not always running once a minute: in
1720+
ComponentBase's start-up backoff it is called at gaps of up to two hours. If no decision
1721+
has been made for an inverter within SUNGROW_DECISION_STALE_SECONDS, nobody is checking
1722+
that its command is still wanted, so it is handed back here instead of being kept alive
1723+
past the end of its window.
16941724
"""
16951725
interval = heartbeat_send_interval(self.heartbeat_interval)
16961726
self.log("Info: Sungrow heartbeat loop started, beating every {:.0f}s for a declared interval of {}s".format(interval, self.heartbeat_interval))
@@ -1713,6 +1743,17 @@ async def _heartbeat_loop(self):
17131743
self._drop_control(list(self.control_held), "heartbeat paused")
17141744
break
17151745
for uuid in list(self.control_held):
1746+
decided = self._decision_time.get(uuid)
1747+
if decided is None or (time.time() - decided) > SUNGROW_DECISION_STALE_SECONDS:
1748+
# Nobody has decided this command recently, so nobody is checking that it
1749+
# is still wanted. Hand the inverter back rather than hold it open.
1750+
self.log("Warn: Sungrow {} command has not been re-decided for over {}s (the component cycle is not running); handing the inverter back to self-consumption".format(self._serial(uuid), SUNGROW_DECISION_STALE_SECONDS))
1751+
try:
1752+
await self.release_control(uuid, int(as_float(self.local_schedule.get(uuid, {}).get("reserve"), 0)))
1753+
except Exception as error:
1754+
self.log("Warn: Sungrow could not release {}: {}; it will revert when the heartbeat lapses".format(self._serial(uuid), error))
1755+
self._drop_control([uuid] if uuid in self.control_held else [], "its command was no longer being decided")
1756+
continue
17161757
try:
17171758
confirmed = await self.send_heartbeat(uuid)
17181759
except asyncio.CancelledError:
@@ -1739,7 +1780,7 @@ async def send_heartbeat(self, uuid):
17391780
"""
17401781
results = await self.dispatch_params(uuid, [param_entry(SUNGROW_PARAM_HEARTBEAT, scale_for_write(SUNGROW_PARAM_HEARTBEAT, heartbeat_declared_interval(self.heartbeat_interval)))], task_name="Predbat heartbeat")
17411782
if results is None:
1742-
self.log("Warn: Sungrow heartbeat for {} was not confirmed; if the beats keep failing the inverter will revert to self-consumption".format(self._serial(uuid)))
1783+
self.log("Warn: Sungrow heartbeat for {} was not confirmed; the inverter may revert to self-consumption, so control will be re-established on the next cycle".format(self._serial(uuid)))
17431784
return False
17441785
return True
17451786

‎apps/predbat/sungrow_const.py‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -442,6 +442,11 @@
442442
# success resets the count while the inverter has already reverted, and the command is never
443443
# sent again.
444444
SUNGROW_HEARTBEAT_MAX_MISSES = 1
445+
# How long a held command stays valid without being decided again. run() re-decides every
446+
# minute in normal running, so five minutes without a decision means run() is not being
447+
# called - the start-up backoff, or a stalled component - and the heartbeat must stop holding
448+
# a command nobody is supervising. Deliberately longer than any single run() cycle can take.
449+
SUNGROW_DECISION_STALE_SECONDS = 300
445450

446451
# -----------------------------------------------------------------------------
447452
# Measuring points

‎apps/predbat/tests/test_sungrow_api.py‎

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010

1111
import predbat # noqa: F401 (import first - avoids circular import: config.py does `from predbat import THIS_VERSION`)
1212
import copy
13+
import time
1314
import pytz
1415
from datetime import datetime, timedelta
1516
from unittest.mock import MagicMock, patch
@@ -665,6 +666,8 @@ def test_sungrow_failed_device_read_falls_back_instead_of_freezing():
665666
failed = True
666667
plant = copy.deepcopy(PLANT_REALTIME)
667668
plant["device_point_list"][0]["p83252"] = "50"
669+
# Long enough since the last good read that this is a dead endpoint, not a blip.
670+
client._device_read_time[uuid] = time.time() - 16 * 60
668671
for _ in range(2):
669672
with _mock_post([_envelope(plant), _envelope(None, code="E00000")]):
670673
run_async_local(client.refresh_power())
@@ -685,6 +688,10 @@ def test_sungrow_failed_device_read_falls_back_instead_of_freezing():
685688
# Answering again clears the episode, so the next failure is reported afresh.
686689
with _mock_post([_envelope(plant), _envelope(DEVICE_REALTIME)]):
687690
run_async_local(client.refresh_power())
691+
if abs(time.time() - client._device_read_time.get(uuid, 0)) > 1:
692+
print(f"ERROR: a good device read stamped {client._device_read_time.get(uuid)}, expected now")
693+
failed = True
694+
client._device_read_time[uuid] = time.time() - 16 * 60
688695
with _mock_post([_envelope(plant), _envelope(None, code="E00000")]):
689696
run_async_local(client.refresh_power())
690697
if len([message for message in client.log_messages if "own telemetry could not be read" in message]) != 2:
@@ -693,6 +700,27 @@ def test_sungrow_failed_device_read_falls_back_instead_of_freezing():
693700
assert not failed, "test_sungrow_failed_device_read_falls_back_instead_of_freezing"
694701

695702

703+
def test_sungrow_one_failed_device_read_keeps_the_same_source():
704+
"""A single failed read must not flip the daily counters to the plant's figures and back."""
705+
failed = False
706+
client = _polled_client()
707+
uuid = client.device_list[0]
708+
if abs(time.time() - client._device_read_time.get(uuid, 0)) > 1:
709+
print(f"ERROR: the fixture's own poll stamped {client._device_read_time.get(uuid)}, expected now")
710+
failed = True
711+
before = {leaf: client.energy(uuid, leaf) for leaf in ("load_today", "import_today", "export_today", "pv_today")}
712+
with _mock_post([_envelope(PLANT_REALTIME), _envelope(None, code="E00000")]):
713+
run_async_local(client.refresh_power())
714+
after = {leaf: client.energy(uuid, leaf) for leaf in before}
715+
if after != before:
716+
print(f"ERROR: one failed device read changed the counters from {before} to {after}")
717+
failed = True
718+
if uuid not in client.device_values:
719+
print("ERROR: the last good device read was discarded after a single failure")
720+
failed = True
721+
assert not failed, "test_sungrow_one_failed_device_read_keeps_the_same_source"
722+
723+
696724
def test_sungrow_energy_counters_convert_watt_hours_to_kilowatt_hours():
697725
"""The OpenAPI reports energy in Wh throughout; Predbat works in kWh.
698726
@@ -1455,6 +1483,7 @@ def run_sungrow_api_tests(my_predbat):
14551483
("telemetry_prefers_device", test_sungrow_telemetry_prefers_the_device_read_over_the_plant_read),
14561484
("telemetry_falls_back", test_sungrow_telemetry_falls_back_when_the_device_read_fails),
14571485
("device_read_failure_not_frozen", test_sungrow_failed_device_read_falls_back_instead_of_freezing),
1486+
("device_read_blip_keeps_source", test_sungrow_one_failed_device_read_keeps_the_same_source),
14581487
("energy_units", test_sungrow_energy_counters_convert_watt_hours_to_kilowatt_hours),
14591488
("battery_capacity", test_sungrow_battery_capacity_sums_the_two_halves),
14601489
("battery_rate_max", test_sungrow_battery_rate_max_prefers_the_override),

‎apps/predbat/tests/test_sungrow_control.py‎

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@
99
"""Tests for the Sungrow control decision and the dispatch-then-poll write path."""
1010

1111
import json
12+
import time
1213
import predbat # noqa: F401 (import first - avoids circular import: config.py does `from predbat import THIS_VERSION`)
1314
from unittest.mock import patch
1415
from sungrow_const import (
@@ -998,6 +999,34 @@ def test_forced_charge_window_is_cleared_on_release_and_tracked_for_change():
998999
assert not failed, "test_forced_charge_window_is_cleared_on_release_and_tracked_for_change"
9991000

10001001

1002+
def test_reconcile_stamps_the_decision_only_when_it_decides():
1003+
"""The heartbeat only holds a command decided recently, so each real decision is stamped.
1004+
1005+
A reconcile stopped at its gate decided nothing, and must not make a command look supervised.
1006+
"""
1007+
failed = False
1008+
client = _controlled_client()
1009+
client.set_mock_clock(3 * 60)
1010+
_capture_dispatch(client)
1011+
schedule = _schedule(charge={"enable": True, "soc": 90, "power": 3000, "start": "02:00:00", "end": "05:00:00"}, export={"power": 5000})
1012+
client.local_schedule[UUID] = schedule
1013+
run_async_local(client.publish_schedule_settings_ha(UUID))
1014+
run_async_local(client.get_schedule_settings_ha(UUID))
1015+
client.control_active.add(UUID)
1016+
run_async_local(client._reconcile_control(UUID))
1017+
stamp = client._decision_time.get(UUID)
1018+
if stamp is None or abs(time.time() - stamp) > 1:
1019+
print(f"ERROR: the reconcile stamped the decision as {stamp}, expected now")
1020+
failed = True
1021+
client.state["switch.predbat_set_read_only"] = "on"
1022+
client._decision_time.pop(UUID, None)
1023+
run_async_local(client._reconcile_control(UUID))
1024+
if UUID in client._decision_time:
1025+
print("ERROR: a reconcile stopped by read-only was stamped as a decision")
1026+
failed = True
1027+
assert not failed, "test_reconcile_stamps_the_decision_only_when_it_decides"
1028+
1029+
10011030
def run_sungrow_control_tests(my_predbat):
10021031
"""Run all Sungrow control-logic tests."""
10031032
failed = False
@@ -1048,6 +1077,7 @@ def run_sungrow_control_tests(my_predbat):
10481077
("read_only_button", test_the_write_button_sends_nothing_in_read_only),
10491078
("read_only_release", test_read_only_releases_a_held_inverter_but_changes_nothing_else),
10501079
("forced_window_cleared", test_forced_charge_window_is_cleared_on_release_and_tracked_for_change),
1080+
("decision_stamped", test_reconcile_stamps_the_decision_only_when_it_decides),
10511081
]:
10521082
try:
10531083
if fn():

0 commit comments

Comments
 (0)