Skip to content

Commit 51eaca8

Browse files
mgazzaclaude
andcommitted
fix(gecloud): time-based settings read backoff capped at an hour; an outage clears it
The backoff was counted in refreshes, so on an EMS member inverter (read once an hour) the 6-refresh cap left a register unread for six hours. It is now time-based: not read for 15, then 30, then at most 60 minutes, whatever the device's refresh cadence. A refresh in which no register answers (the inverter or GE Cloud is down) now clears the device's backoff, so every register is read again the moment the device is back. Such a refresh already did not count towards backing a register off. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_018BaJjLpuMEtQYfvmTRcFJf
1 parent 9df6f46 commit 51eaca8

2 files changed

Lines changed: 38 additions & 19 deletions

File tree

‎apps/predbat/gecloud.py‎

Lines changed: 18 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -77,11 +77,14 @@
7777
# burns its whole retry budget, so a refresh can run for many minutes. It runs as its own task and the
7878
# cycle waits this long for it before carrying on, so live status and meter data keep being published.
7979
SETTINGS_REFRESH_WAIT_SECONDS = 20
80-
# A setting whose read has failed this many periodic refreshes in a row is backed off: skipped for the
81-
# next refresh, then 2, 4... up to SETTING_READ_BACKOFF_MAX_SKIP refreshes, and tried again after that.
82-
# Its last known value is kept and published as a failed readback.
80+
# A setting whose read has failed this many periodic refreshes in a row, while the device answered its
81+
# other reads, is backed off: not read for SETTING_READ_BACKOFF_MINUTES, doubling with each further
82+
# failure up to SETTING_READ_BACKOFF_MAX_MINUTES, then tried again. Its last known value is kept and
83+
# published as a failed readback. Time-based, so no register goes unread for more than the cap whatever
84+
# the device's refresh cadence.
8385
SETTING_READ_BACKOFF_FAILURES = 3
84-
SETTING_READ_BACKOFF_MAX_SKIP = 6
86+
SETTING_READ_BACKOFF_MINUTES = 15
87+
SETTING_READ_BACKOFF_MAX_MINUTES = 60
8588

8689
# An inverter under EMS control is expected to leave its own slot 1 windows spanning the whole day so
8790
# that they never override a command from the EMS (see #3781). Anything else is reported.
@@ -653,7 +656,7 @@ def initialize(self, ge_cloud_direct, api_key, automatic, automatic_evc=False, e
653656
# a settings read can tell whether a write landed after it was issued
654657
self.write_seq = 0
655658
self.recent_writes = {}
656-
# serial -> setting id -> {"failures": consecutive failed reads, "skip": refreshes left to skip}
659+
# serial -> setting id -> {"failures": consecutive failed reads, "until": not read again before this time}
657660
self.setting_read_backoff = {}
658661
self.default_options_stamp = None
659662
# Devices found by the periodic device check still waiting for their default options, kept across
@@ -2784,8 +2787,7 @@ async def async_get_inverter_settings(self, serial, first=False, previous=None,
27842787
future["skipped"] = False
27852788
future["issue_seq"] = refresh_seq
27862789
state = device_backoff.get(sid, None)
2787-
if backoff and not first and state and state["skip"] > 0:
2788-
state["skip"] -= 1
2790+
if backoff and not first and state and state.get("until") and self.now_utc_exact < state["until"]:
27892791
future["skipped"] = True
27902792
future["data"] = None
27912793
complete.append(future)
@@ -2824,6 +2826,9 @@ async def async_get_inverter_settings(self, serial, first=False, previous=None,
28242826
# A failure only counts towards backing a register off when the device answered other reads in the
28252827
# same refresh: when nothing reads at all the device or GE Cloud is down, not that one register
28262828
device_answered = any(future["data"] and ("value" in future["data"]) for future in complete)
2829+
if not first and not device_answered and any(not future["skipped"] for future in complete):
2830+
# Nothing answered: start every register afresh, so all are read as soon as the device is back
2831+
device_backoff.clear()
28272832

28282833
# Wait for all the futures to complete and store results
28292834
for future in complete:
@@ -2874,8 +2879,8 @@ def record_setting_read(self, device_backoff, serial, sid, name, success):
28742879
Track consecutive failed reads of a setting and back it off once it keeps failing
28752880
28762881
An inverter can list a register it cannot serve (for example AC charge slots 8 and 9), and every
2877-
read of it times out through the whole retry budget. Backed off, it is skipped for 1, 2, 4... up
2878-
to SETTING_READ_BACKOFF_MAX_SKIP refreshes and then tried again, so it is never hidden for good.
2882+
read of it times out through the whole retry budget. Backed off, it is not read for 15, 30, then
2883+
at most 60 minutes before it is tried again, so it is never hidden for good.
28792884
device_backoff is the device's entry in setting_read_backoff taken when the reads started, so a
28802885
device dropped by a device list refresh meanwhile is not added back.
28812886
"""
@@ -2884,11 +2889,12 @@ def record_setting_read(self, device_backoff, serial, sid, name, success):
28842889
if state and state["failures"] >= SETTING_READ_BACKOFF_FAILURES:
28852890
self.log("GECloud: Device {} setting id {} ({}) read again after {} failed refreshes".format(serial, sid, name, state["failures"]))
28862891
return
2887-
state = device_backoff.setdefault(sid, {"failures": 0, "skip": 0})
2892+
state = device_backoff.setdefault(sid, {"failures": 0, "until": None})
28882893
state["failures"] += 1
28892894
if state["failures"] >= SETTING_READ_BACKOFF_FAILURES:
2890-
state["skip"] = min(2 ** (state["failures"] - SETTING_READ_BACKOFF_FAILURES), SETTING_READ_BACKOFF_MAX_SKIP)
2891-
self.log("GECloud: Warn: Device {} setting id {} ({}) has failed {} refreshes in a row, skipping it for the next {} refreshes and keeping its last known value".format(serial, sid, name, state["failures"], state["skip"]))
2895+
minutes = min(SETTING_READ_BACKOFF_MINUTES * 2 ** (state["failures"] - SETTING_READ_BACKOFF_FAILURES), SETTING_READ_BACKOFF_MAX_MINUTES)
2896+
state["until"] = self.now_utc_exact + timedelta(minutes=minutes)
2897+
self.log("GECloud: Warn: Device {} setting id {} ({}) has failed {} refreshes in a row, not reading it for {} minutes and keeping its last known value".format(serial, sid, name, state["failures"], minutes))
28922898

28932899
async def async_get_smart_device_data(self, uuid):
28942900
"""

‎apps/predbat/tests/test_ge_cloud.py‎

Lines changed: 20 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@
1111

1212
from gecloud import GECloudDirect, GECloudData, regname_to_ha
1313
from gecloud import GE_API_ACCOUNT, GE_API_DEVICES, GE_API_EVC_SEND_COMMAND, GE_API_INVERTER_WRITE_SETTING, GE_API_SITE
14-
from gecloud import GE_API_INVERTER_READ_SETTING, GE_API_INVERTER_SETTINGS, SETTING_READ_BACKOFF_MAX_SKIP
14+
from gecloud import GE_API_INVERTER_READ_SETTING, GE_API_INVERTER_SETTINGS, SETTING_READ_BACKOFF_MAX_MINUTES
1515
from gecloud import EVCCommandFailed, GECloudTerminalError, SITE_MAX_AGE_MINUTES, parse_site_export_limit
1616
from gecloud import DEVICE_REFRESH_SECONDS, SETTINGS_SLOW_REFRESH_SECONDS, find_ems_slot_overrides, normalise_register_time
1717
from utils import dp4
@@ -8839,12 +8839,15 @@ async def test():
88398839
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous={})
88408840
ge.read_values[120] = None
88418841
read_pattern = []
8842-
for _ in range(9):
8842+
for _ in range(17):
8843+
# A refresh every 10 minutes, as in polling mode
8844+
ge._now_utc_exact += timedelta(minutes=10)
88438845
before = len(ge.read_calls)
88448846
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous=ge.settings["inv001"], backoff=True)
88458847
read_pattern.append(any(call[1] == 120 for call in ge.read_calls[before:]))
8846-
# Fails 1, 2, 3 (back off 1), skip, fails 4 (back off 2), skip, skip, fails 5 (back off 4), skip
8847-
expected = [True, True, True, False, True, False, False, True, False]
8848+
# Fails 1, 2, 3 (15 min off: skip 1), fails 4 (30 min: skip 2), fails 5 (60 min: skip 5),
8849+
# fails 6 (capped at 60 min: skip 5), read again
8850+
expected = [True, True, True, False, True, False, False, True, False, False, False, False, False, True, False, False, False]
88488851
if read_pattern != expected:
88498852
print("ERROR: Backoff read pattern {} expected {}".format(read_pattern, expected))
88508853
failed += 1
@@ -8867,7 +8870,8 @@ async def test():
88678870

88688871
# Good again: read on the next try after the backoff, and the flag and backoff are cleared
88698872
ge.read_values[120] = "03:00"
8870-
for _ in range(SETTING_READ_BACKOFF_MAX_SKIP + 1):
8873+
for _ in range(SETTING_READ_BACKOFF_MAX_MINUTES // 10 + 1):
8874+
ge._now_utc_exact += timedelta(minutes=10)
88718875
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous=ge.settings["inv001"], backoff=True)
88728876
register = ge.settings["inv001"][120]
88738877
if register.get("value") != "03:00" or register.get("read_failed") or 120 in ge.setting_read_backoff.get("inv001", {}):
@@ -8878,15 +8882,24 @@ async def test():
88788882
failed += 1
88798883

88808884
# The device or GE Cloud being down fails every read: that is not a register it cannot serve, so
8881-
# nothing is backed off and every register is read again as soon as it is back
8885+
# nothing is backed off - even a register already backed off is read the moment the device is back
8886+
ge.read_values = {17: True, 120: None}
8887+
for _ in range(3):
8888+
ge._now_utc_exact += timedelta(minutes=10)
8889+
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous=ge.settings["inv001"], backoff=True)
8890+
if not ge.setting_read_backoff.get("inv001", {}).get(120, {}).get("until"):
8891+
print("ERROR: Expected id 120 backed off before the outage: {}".format(ge.setting_read_backoff))
8892+
failed += 1
88828893
ge.read_values = {17: None, 120: None}
8883-
for _ in range(SETTING_READ_BACKOFF_MAX_SKIP + 2):
8894+
for _ in range(8):
8895+
ge._now_utc_exact += timedelta(minutes=1)
88848896
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous=ge.settings["inv001"], backoff=True)
88858897
if ge.setting_read_backoff.get("inv001"):
88868898
print("ERROR: An outage backed registers off: {}".format(ge.setting_read_backoff))
88878899
failed += 1
88888900
ge.read_values = {17: True, 120: "04:00"}
88898901
before = len(ge.read_calls)
8902+
ge._now_utc_exact += timedelta(minutes=1)
88908903
ge.settings["inv001"] = await ge.async_get_inverter_settings("inv001", previous=ge.settings["inv001"], backoff=True)
88918904
if sorted(call[1] for call in ge.read_calls[before:]) != [17, 120] or ge.settings["inv001"][120]["value"] != "04:00":
88928905
print("ERROR: Registers not read on the first refresh after an outage: {}".format(ge.read_calls[before:]))

0 commit comments

Comments
 (0)