Skip to content

Commit 3cb4213

Browse files
author
CI
committed
Merge remote-tracking branch 'origin/main' into fix/iog-slot-io-adjusted
2 parents 6b8718e + 00f388b commit 3cb4213

34 files changed

Lines changed: 3799 additions & 1257 deletions

‎.cspell/custom-dictionary-workspace.txt‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -499,6 +499,7 @@ preclip
499499
pred
500500
predai
501501
predbat
502+
predbatsolcast
502503
predbatt
503504
predheat
504505
preseed

‎apps/predbat/config.py‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2530,7 +2530,15 @@
25302530
"has_ge_inverter_mode": False,
25312531
"time_button_press": False,
25322532
"clock_time_format": "%H:%M:%S",
2533-
"write_and_poll_sleep": 2,
2533+
# The hub applies register writes one at a time and a single write can take 10-20s (longer
2534+
# under an EMS), so re-sending every couple of seconds only queues more work ahead of the
2535+
# read-back. Allow each attempt 10s to verify, give up after 3, and when a control keeps
2536+
# failing from one cycle to the next send it once, at most every few minutes (see
2537+
# INVERTER_WRITE_BACKOFF_FAILURES and INVERTER_WRITE_DEGRADED_INTERVAL). Only this row sets
2538+
# write_max_retry/write_backoff.
2539+
"write_and_poll_sleep": 10,
2540+
"write_max_retry": 3,
2541+
"write_backoff": True,
25342542
"has_time_window": True,
25352543
"support_charge_freeze": True,
25362544
"support_discharge_freeze": True,

‎apps/predbat/config/apps.yaml‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -635,7 +635,6 @@ pred_bat:
635635
# - '{octopus_saving_session}'
636636
# - '+[car_charging_planned]'
637637
# - '+[car_charging_soc]'
638-
# - '{car_charging_now}'
639638

640639
# Redact additional values from predbat.log and debug dumps that Predbat cannot otherwise
641640
# recognise as sensitive (an MPAN or similar identifier surfaced by a third-party HA

‎apps/predbat/const.py‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -70,6 +70,13 @@
7070
INVERTER_WRITE_POLL_INTERVAL = 0.25 # Seconds before the second look, doubling after each miss
7171
INVERTER_WRITE_POLL_MAX_INTERVAL = 2.0 # Ceiling for that backoff
7272
INVERTER_MAX_RETRY_REST = 5 # Maximum number of retries for inverter REST commands
73+
# Per-control write backoff, for inverter types that opt in with write_backoff in INVERTER_DEF (only
74+
# GWMQTT). A control whose write of the same target has failed to verify this many times in a row
75+
# (one write per plan cycle) is degraded: it is sent once rather than retried in a burst, and at most
76+
# once per INVERTER_WRITE_DEGRADED_INTERVAL seconds, until a write verifies, it reads back as wanted,
77+
# or the target changes. Every call still checks the read-back and reports a mismatch as a failure.
78+
INVERTER_WRITE_BACKOFF_FAILURES = 2
79+
INVERTER_WRITE_DEGRADED_INTERVAL = 300
7380
# Inverter clock skew bands, measured as (inverter time - Predbat computer time) in minutes.
7481
# At or above the restart threshold Predbat warns loudly and triggers auto_restart. Between the warn
7582
# and restart thresholds nothing used to be said at all, yet the drift still shifts every charge and

‎apps/predbat/gateway.py‎

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -57,8 +57,9 @@
5757
_TELEMETRY_STALE_THRESHOLD = 120
5858

5959
# How long an identical control command waits for the hub's ack (or, after an ack,
60-
# for telemetry to catch up) before it may be published again (seconds). Longer than
61-
# the generic write_and_poll loop (10 x 2 s), so one write sends the command once.
60+
# for telemetry to catch up) before it may be published again (seconds). Covers the
61+
# GWMQTT write_and_poll loop (3 attempts of up to 10 s each, see INVERTER_DEF), so one
62+
# write sends the command once.
6263
_COMMAND_ACK_WINDOW = 30
6364

6465
# Ids kept per tracked command, so an ack for an earlier send of the same value still
@@ -1989,8 +1990,8 @@ async def switch_event(self, entity_id, service):
19891990
async def _send_control(self, entity_id, command, **kwargs):
19901991
"""Publish a control write once and let the hub's ack confirm it.
19911992
1992-
The generic write_and_poll loop calls the event handlers again every couple of
1993-
seconds until the read-back matches. Publishing on every call queued a fresh
1993+
The generic write_and_poll loop calls the event handlers again on every retry
1994+
until the read-back matches. Publishing on every call queued a fresh
19941995
Modbus write on the hub each time, so a slow dongle write turned into a storm.
19951996
Once the hub has shown it acks commands on this connection, an identical command
19961997
(same entity, command and payload) is published only once per _COMMAND_ACK_WINDOW:

‎apps/predbat/gecloud.py‎

Lines changed: 163 additions & 43 deletions
Large diffs are not rendered by default.

‎apps/predbat/inverter.py‎

Lines changed: 86 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,8 @@
3131
INVERTER_TEST,
3232
TIME_FORMAT_SECONDS,
3333
INVERTER_MAX_RETRY,
34+
INVERTER_WRITE_BACKOFF_FAILURES,
35+
INVERTER_WRITE_DEGRADED_INTERVAL,
3436
EXPORT_MODE_TARGET,
3537
EXPORT_MODE_IDLE,
3638
FULL_EXPORT_POWER,
@@ -62,6 +64,12 @@ class Inverter:
6264
REST API and Home Assistant entity writes with polling validation.
6365
"""
6466

67+
# Write retry policy, set per type from INVERTER_DEF by refresh_config(). Declared here too so an
68+
# Inverter built without __init__ (the test stubs) gets the default policy: INVERTER_MAX_RETRY
69+
# attempts per write and no per-control backoff. Only GWMQTT sets anything else.
70+
inv_write_max_retry = INVERTER_MAX_RETRY
71+
inv_write_backoff = False
72+
6573
def self_test(self, minutes_now):
6674
self.base.log("======= INVERTER CONTROL SELF TEST START ========")
6775
self.adjust_battery_target(99, False)
@@ -348,6 +356,8 @@ def __init__(self, base, id=0, quiet=False):
348356
# the new value back afterwards. Callers take the difference across their own writes to
349357
# learn whether something outside Predbat had changed what they manage - see commit_needed().
350358
self.registers_moved = 0
359+
# Per-control write backoff state, keyed by entity_id - see _write_attempts().
360+
self.write_backoff = {}
351361

352362
self._init_attribute_defaults()
353363

@@ -505,6 +515,9 @@ def refresh_config(self, quiet=False):
505515
self.inv_has_ge_eco_toggle = INVERTER_DEF[self.inverter_type].get("has_ge_eco_toggle", False)
506516
self.inv_num_load_entities = INVERTER_DEF[self.inverter_type]["num_load_entities"]
507517
self.inv_write_and_poll_sleep = INVERTER_DEF[self.inverter_type]["write_and_poll_sleep"]
518+
# Only take effect when a row sets them explicitly - currently only GWMQTT does
519+
self.inv_write_max_retry = INVERTER_DEF[self.inverter_type].get("write_max_retry", INVERTER_MAX_RETRY)
520+
self.inv_write_backoff = INVERTER_DEF[self.inverter_type].get("write_backoff", False)
508521
self.inv_has_idle_time = INVERTER_DEF[self.inverter_type]["has_idle_time"]
509522
self.inv_can_span_midnight = INVERTER_DEF[self.inverter_type]["can_span_midnight"]
510523
self.inv_charge_discharge_with_rate = INVERTER_DEF[self.inverter_type].get("charge_discharge_with_rate", False)
@@ -2256,6 +2269,57 @@ def check_write_entity(self, caller, name, entity_id, new_value):
22562269
self.base.record_status(message, had_errors=True)
22572270
return False
22582271

2272+
def _write_attempts(self, name, entity_id, new_value):
2273+
"""
2274+
How many times to send a write of new_value to this control before giving up on it.
2275+
2276+
Normally inv_write_max_retry. For inverter types with write_backoff set, a control whose
2277+
write of this same target has failed INVERTER_WRITE_BACKOFF_FAILURES times in a row is
2278+
degraded: re-sending a burst every cycle can swamp a device that applies writes slowly and
2279+
one at a time, which only makes the read-back lag further behind. A degraded control gets a
2280+
single attempt, at most once per INVERTER_WRITE_DEGRADED_INTERVAL seconds; in between it
2281+
gets 0, so the caller only checks the read it already took and, if that still differs,
2282+
reports the failure as usual. A different target is new work and gets the full ladder at once.
2283+
"""
2284+
if not self.inv_write_backoff:
2285+
return self.inv_write_max_retry
2286+
state = self.write_backoff.get(entity_id)
2287+
if state is not None and state["value"] != new_value:
2288+
if state["failures"] >= INVERTER_WRITE_BACKOFF_FAILURES:
2289+
self.base.log(f"Inverter {self.id} {name} target changed to {new_value}, retrying writes normally again")
2290+
del self.write_backoff[entity_id]
2291+
state = None
2292+
if state is None or state["failures"] < INVERTER_WRITE_BACKOFF_FAILURES:
2293+
return self.inv_write_max_retry
2294+
now = time.monotonic()
2295+
if state.get("published_at") is not None and now - state["published_at"] < INVERTER_WRITE_DEGRADED_INTERVAL:
2296+
return 0
2297+
state["published_at"] = now
2298+
return 1
2299+
2300+
def _write_backoff_result(self, name, entity_id, new_value, verified):
2301+
"""
2302+
Record whether a write to this control verified, for _write_attempts().
2303+
2304+
Logged once when a control drops to a single attempt per write and once when it recovers.
2305+
"""
2306+
if not self.inv_write_backoff:
2307+
return
2308+
state = self.write_backoff.get(entity_id)
2309+
if verified:
2310+
if state is not None and state["failures"] >= INVERTER_WRITE_BACKOFF_FAILURES:
2311+
self.base.log(f"Inverter {self.id} {name} write verified, retrying writes normally again")
2312+
self.write_backoff.pop(entity_id, None)
2313+
return
2314+
if state is None or state["value"] != new_value:
2315+
state = {"value": new_value, "failures": 0}
2316+
self.write_backoff[entity_id] = state
2317+
state["failures"] += 1
2318+
if state["failures"] == INVERTER_WRITE_BACKOFF_FAILURES:
2319+
# This failing call has just published, so the degraded interval runs from now
2320+
state["published_at"] = time.monotonic()
2321+
self.base.log(f"Warn: Inverter {self.id} write of {new_value} to {name} has failed {state['failures']} times in a row, sending it at most once every {INVERTER_WRITE_DEGRADED_INTERVAL} seconds until it verifies")
2322+
22592323
def write_and_poll_switch(self, name, entity_id, new_value):
22602324
"""
22612325
GivTCP Workaround, keep writing until correct
@@ -2300,10 +2364,12 @@ def switch_matched(state):
23002364
# weaker but sufficient evidence.
23012365
if ledger is not None:
23022366
ledger.record_ownership_from_read(entity_id, name, raw_state, now=time.time(), generation=self._ledger_generation(entity_id))
2367+
self._write_backoff_result(name, entity_id, new_value, True)
23032368
return True
23042369

2370+
attempts = self._write_attempts(name, entity_id, new_value)
23052371
retry = 0
2306-
while not switch_matched(raw_state) and retry < INVERTER_MAX_RETRY:
2372+
while not switch_matched(raw_state) and retry < attempts:
23072373
retry += 1
23082374
if domain == "sensor":
23092375
if new_value:
@@ -2328,6 +2394,7 @@ def switch_matched(state):
23282394
# like a change - PredBat accusing somebody else of its own successful write.
23292395
if ledger is not None:
23302396
ledger.record_write(entity_id, name, raw_state, now=time.time(), generation=self._ledger_generation(entity_id))
2397+
self._write_backoff_result(name, entity_id, new_value, True)
23312398
return True
23322399
else:
23332400
self.base.log("Warn: Inverter {} Trying to write {} to {} didn't complete got {}".format(self.id, name, new_value, self.base.get_state_wrapper(entity_id=entity_id)))
@@ -2336,6 +2403,7 @@ def switch_matched(state):
23362403
# confirmation would report the next read of a control we have just failed to set.
23372404
if ledger is not None:
23382405
ledger.clear(entity_id)
2406+
self._write_backoff_result(name, entity_id, new_value, False)
23392407
return False
23402408

23412409
def write_and_poll_value(self, name, entity_id, new_value, fuzzy=0, ignore_fail=False, required_unit=None):
@@ -2382,8 +2450,9 @@ def value_matched(state):
23822450
if not matched:
23832451
ledger.note_write_attempt(entity_id)
23842452

2453+
attempts = self._write_attempts(name, entity_id, new_value) if not matched else 0
23852454
retry = 0
2386-
while (not matched) and (retry < INVERTER_MAX_RETRY):
2455+
while (not matched) and (retry < attempts):
23872456
retry += 1
23882457
if domain == "sensor":
23892458
self.base.set_state_wrapper(entity_id, state=new_value, attributes=self.created_attributes.get(entity_id, {}), required_unit=required_unit)
@@ -2404,12 +2473,13 @@ def value_matched(state):
24042473
current_state = value_state(raw_state)
24052474
matched = value_matched(raw_state)
24062475

2407-
if retry == 0:
2476+
if retry == 0 and matched:
24082477
self.base.log(f"Inverter {self.id} write_and_poll_value: No write needed for {name}: {new_value} == {current_state} fuzzy {fuzzy}")
24092478
# Re-arm - see write_and_poll_switch() for why this early return would otherwise leave
24102479
# the control unwatched for good once ownership had been dropped.
24112480
if ledger is not None:
24122481
ledger.record_ownership_from_read(entity_id, name, raw_state, fuzzy=fuzzy, now=time.time(), generation=self._ledger_generation(entity_id))
2482+
self._write_backoff_result(name, entity_id, new_value, True)
24132483
return True
24142484
elif matched:
24152485
self.base.log(f"Inverter {self.id} write_and_poll_value: Wrote {new_value} to {name}, successfully now {current_state}")
@@ -2421,12 +2491,14 @@ def value_matched(state):
24212491
# 0.0 read-back would otherwise be stored as a confirmed owned value.
24222492
if ledger is not None:
24232493
ledger.record_write(entity_id, name, raw_state, fuzzy=fuzzy, now=time.time(), generation=self._ledger_generation(entity_id))
2494+
self._write_backoff_result(name, entity_id, new_value, True)
24242495
return True
24252496
else:
24262497
self.base.log(f"Warn: Inverter {self.id} Trying to write {new_value} to {name} didn't complete got {current_state}")
24272498
self.base.record_status(f"Warn: Inverter {self.id} write to {name} failed", had_errors=True)
24282499
if ledger is not None:
24292500
ledger.clear(entity_id)
2501+
self._write_backoff_result(name, entity_id, new_value, False)
24302502
return False
24312503

24322504
def write_and_poll_option(self, name, entity_id, new_value, ignore_fail=False):
@@ -2459,7 +2531,15 @@ def write_and_poll_option(self, name, entity_id, new_value, ignore_fail=False):
24592531
if old_value != new_value:
24602532
ledger.note_write_attempt(entity_id)
24612533

2462-
for _retry in range(INVERTER_MAX_RETRY):
2534+
attempts = self._write_attempts(name, entity_id, new_value)
2535+
if attempts == 0 and old_value == new_value:
2536+
# A degraded control between publishes that already reads back as wanted
2537+
self.base.log("Inverter {} {} already reads {}".format(self.id, name, new_value))
2538+
if ledger is not None:
2539+
ledger.record_ownership_from_read(entity_id, name, old_value, now=time.time(), generation=self._ledger_generation(entity_id))
2540+
self._write_backoff_result(name, entity_id, new_value, True)
2541+
return True
2542+
for _retry in range(attempts):
24632543
if entity_base == "time":
24642544
service = entity_base + "/set_value"
24652545
self.base.call_service_wrapper(service, time=new_value, entity_id=entity_id)
@@ -2482,11 +2562,13 @@ def write_and_poll_option(self, name, entity_id, new_value, ignore_fail=False):
24822562
self.registers_moved += 1
24832563
if ledger is not None:
24842564
ledger.record_write(entity_id, name, old_value, now=time.time(), generation=self._ledger_generation(entity_id))
2565+
self._write_backoff_result(name, entity_id, new_value, True)
24852566
return True
24862567
self.base.log("Warn: Inverter {} Trying to write {} to {} didn't complete got {}".format(self.id, name, new_value, self.base.get_state_wrapper(entity_id, refresh=True)))
24872568
self.base.record_status("Warn: Inverter {} write to {} failed".format(self.id, name), had_errors=True)
24882569
if ledger is not None:
24892570
ledger.clear(entity_id)
2571+
self._write_backoff_result(name, entity_id, new_value, False)
24902572
return False
24912573

24922574
def write_hm_time_part(self, name, new_time):

‎apps/predbat/predbat.py‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@
3434
import pytz
3535
import asyncio
3636

37-
THIS_VERSION = "v9.3.2"
37+
THIS_VERSION = "v9.3.3"
3838
THIS_VERSION_DISPLAY = THIS_VERSION
3939

4040
from download import predbat_update_move, predbat_update_download, check_install, read_deploy_git_version, DEFAULT_PREDBAT_REPOSITORY

0 commit comments

Comments
 (0)