Skip to content

Commit 39eb2c8

Browse files
0xAHAclaude
andcommitted
Bump version to v1.1.4 — fix false "Write reversion detected" warnings (#358)
Root-caused in detail by alanmk (SPH 3600 driven by Predbat, which writes every 5 min). Any controller writing on a fixed cadence eventually collides with an in-flight poll and trips this. _fetch_data() assembles its snapshot over several seconds. A write landing in that window is not reflected in the snapshot, so _check_for_cloud_overrides() compared the tracked value against registers read BEFORE the write and reported the pre-write value as a reversion. The entry was then popped on that first mismatch, so the write was never re-checked and could never be vindicated — a guaranteed false alarm plus the once-per-session persistent notification. Signature was distinctive: every false warning reported an age of 0-2s, and the "reverted to" value was always the previous locally-written value. Recorder history confirmed the writes had held. Changes: - Poll timestamping. _async_update_data() records poll_start before the reads begin and passes it through. Any tracked write with write_time >= poll_start is left pending and evaluated on the next poll, which genuinely post-dates it. - Debounce. _pending_write_checks entries carry a mismatch_count; a write must mismatch on two consecutive polls before being reported. A real revert persists, a timing artefact does not. - Expiry raised and scaled. The old flat 120s could not confirm a genuine reversion even at the 60s default now that confirmation can need three cycles. Now max(240s, 4 * scan_interval), based on the normal interval rather than the temporary offline slow-poll interval so the latter cannot inflate it. track_write()'s public 3-arg signature is unchanged; all 13 call sites across number.py, select.py and time.py are unaffected. The 4-tuple is constructed in one place and unpacked in one place. Co-Authored-By: Claude <noreply@anthropic.com>
1 parent 55741e6 commit 39eb2c8

4 files changed

Lines changed: 107 additions & 12 deletions

File tree

README.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
# Growatt Modbus Integration for Home Assistant ☀️
44

55
![HACS Badge](https://img.shields.io/badge/HACS-Custom-orange.svg)
6-
![Version](https://img.shields.io/badge/Version-1.1.3-blue.svg)
6+
![Version](https://img.shields.io/badge/Version-1.1.4-blue.svg)
77
[![GitHub Issues](https://img.shields.io/github/issues/0xAHA/Growatt_ModbusTCP.svg)](https://github.com/0xAHA/Growatt_ModbusTCP/issues)
88
[![GitHub Stars](https://img.shields.io/github/stars/0xAHA/Growatt_ModbusTCP.svg?style=social)](https://github.com/0xAHA/Growatt_ModbusTCP)
99

RELEASENOTES.md

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,43 @@
44

55
---
66

7+
## v1.1.4
8+
9+
Issues: #358
10+
11+
- **Fix: false "Write reversion detected" warnings when a write lands mid-poll:**
12+
Reported with a full root-cause analysis by @alanmk (SPH 3600 driven by Predbat, which
13+
writes every 5 minutes). Any controller that writes on a fixed cadence eventually collides
14+
with an in-flight poll and trips this.
15+
16+
`_fetch_data()` assembles its snapshot over several seconds. A write landing during that
17+
window is not reflected in the snapshot, so the detector compared the tracked value
18+
against registers read *before* the write and reported the pre-write value as a
19+
"reversion". Worse, the entry was popped on that first mismatch, so the write was never
20+
re-checked and could never be vindicated — a guaranteed false alarm, plus the
21+
once-per-session persistent notification.
22+
23+
The signature was distinctive: every false warning reported an age of 0–2 seconds, and the
24+
"reverted to" value was always the previous locally-written value. HA recorder history
25+
confirmed the writes had actually held.
26+
27+
Three changes:
28+
- **Poll timestamping.** `_async_update_data()` now records `poll_start` before the reads
29+
begin. Any tracked write newer than that is left pending and evaluated on the next poll,
30+
which genuinely post-dates it.
31+
- **Debounce.** A write must mismatch on two consecutive polls before being reported. A
32+
real cloud or firmware revert persists; a timing artefact vanishes on the next poll.
33+
- **Expiry raised and scaled.** The old flat 120 s could not confirm a genuine reversion
34+
even at the 60 s default, since confirmation can now need three cycles. It is now
35+
`max(240 s, 4 × scan interval)`, so slow-polling setups get their reversions confirmed
36+
rather than silently expired. Based on the configured interval, not the temporary
37+
offline slow-poll interval.
38+
39+
Genuine cloud overrides are still detected — they persist across polls and are reported on
40+
the second mismatch, with an accurate age.
41+
42+
---
43+
744
## v1.1.3
845

946
Issues: #348

custom_components/growatt_modbus/coordinator.py

Lines changed: 68 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,12 @@
4040

4141
_LOGGER = logging.getLogger(__name__)
4242

43+
# Floor for how long a tracked write stays pending verification (Issue #358).
44+
# Must cover: one poll skipped for pre-dating the write, plus two consecutive mismatching
45+
# polls to satisfy the debounce — three cycles at the default 60 s scan interval.
46+
# The effective value scales with the configured interval; see _check_for_cloud_overrides.
47+
_WRITE_CHECK_EXPIRY_S = 240
48+
4349
def test_connection(config: dict) -> dict:
4450
"""Test the connection to the Growatt inverter (TCP or Serial)."""
4551
try:
@@ -186,8 +192,9 @@ def __init__(self, hass: HomeAssistant, entry: ConfigEntry,
186192
self._midnight_grace_expires: datetime | None = None
187193

188194
# Cloud override detection: tracks recently written register values
189-
# Format: {register_address: (expected_value, write_timestamp, control_name)}
190-
self._pending_write_checks: dict[int, tuple[int, float, str]] = {}
195+
# Format: {register_address: (expected_value, write_timestamp, control_name, mismatch_count)}
196+
# mismatch_count debounces the check — see _check_for_cloud_overrides (Issue #358).
197+
self._pending_write_checks: dict[int, tuple[int, float, str, int]] = {}
191198
self._cloud_override_notified: bool = False # Only notify once per session
192199

193200
# WIT: saves register 122 (export_limit_mode) before disabling control authority (30100=0).
@@ -220,26 +227,62 @@ def track_write(self, register: int, expected_value: int, control_name: str) ->
220227
_check_for_cloud_overrides() compares the tracked value against the fresh data.
221228
"""
222229
import time as _time
223-
self._pending_write_checks[register] = (expected_value, _time.time(), control_name)
230+
self._pending_write_checks[register] = (expected_value, _time.time(), control_name, 0)
231+
232+
async def _check_for_cloud_overrides(self, data, poll_start: float | None = None) -> None:
233+
"""Check if any recently written register values have been overridden by the cloud.
234+
235+
Two guards prevent false positives (Issue #358):
236+
237+
1. Snapshot staleness. `data` is assembled over several seconds by _fetch_data().
238+
A write that lands mid-poll is not reflected in that snapshot, so comparing
239+
against it reports the *pre-write* value as a "reversion". Any write newer than
240+
poll_start is therefore left pending and evaluated on the next poll, which
241+
genuinely post-dates it.
224242
225-
async def _check_for_cloud_overrides(self, data) -> None:
226-
"""Check if any recently written register values have been overridden by the cloud."""
243+
2. Debounce. A real cloud/firmware revert persists; a timing artefact does not.
244+
An entry must mismatch on two consecutive polls before it is reported.
245+
246+
Without these, a controller writing on a fixed cadence (e.g. Predbat every 5 min)
247+
eventually collides with an in-flight poll and produces a spurious warning whose
248+
reported age is ~0 s — and because the entry was popped on first mismatch, the
249+
write was never re-checked and never vindicated.
250+
"""
227251
if not self._pending_write_checks:
228252
return
229253

230254
import time as _time
231255
current_time = _time.time()
232256
to_remove = []
257+
to_update = {}
233258
overridden_controls = []
234259

235-
for register, (expected_value, write_time, control_name) in self._pending_write_checks.items():
260+
for register, entry in self._pending_write_checks.items():
261+
expected_value, write_time, control_name, mismatch_count = entry
236262
age = current_time - write_time
237263

238-
# Expire entries older than 120 seconds (roughly 2 poll cycles)
239-
if age > 120:
264+
# Expire stale entries. Must allow for: one poll skipped as pre-dating the
265+
# write, then two consecutive mismatching polls to satisfy the debounce —
266+
# three cycles. Scaled to the configured interval so slow pollers still get
267+
# their reversions confirmed rather than silently expired; the old flat 120 s
268+
# could not confirm a genuine reversion even at the 60 s default.
269+
# Uses the *normal* interval, not self.update_interval, so the temporary
270+
# offline slow-poll interval doesn't inflate this.
271+
if age > max(_WRITE_CHECK_EXPIRY_S,
272+
4 * self._normal_update_interval.total_seconds()):
240273
to_remove.append(register)
241274
continue
242275

276+
# Guard 1: this snapshot's registers were read before the write landed.
277+
# Leave the entry pending; the next poll will evaluate it fairly.
278+
if poll_start is not None and write_time >= poll_start:
279+
_LOGGER.debug(
280+
"Write check for '%s' deferred — write landed mid-poll "
281+
"(write_time %.3f >= poll_start %.3f); will verify on next poll",
282+
control_name, write_time, poll_start,
283+
)
284+
continue
285+
243286
# Get current value from the freshly polled data
244287
current_value = getattr(data, control_name, None)
245288
if current_value is None:
@@ -248,14 +291,24 @@ async def _check_for_cloud_overrides(self, data) -> None:
248291
if int(current_value) == expected_value:
249292
# Write stuck — remove from tracking
250293
to_remove.append(register)
294+
elif mismatch_count == 0:
295+
# Guard 2: first mismatch. Could still be a timing artefact — keep the
296+
# entry and require the next poll to agree before reporting.
297+
_LOGGER.debug(
298+
"Write check for '%s': expected %d but read %d (%.0fs after write) — "
299+
"awaiting confirmation on next poll before reporting",
300+
control_name, expected_value, int(current_value), age,
301+
)
302+
to_update[register] = (expected_value, write_time, control_name, 1)
251303
else:
252-
# Value reverted — cloud override detected
304+
# Mismatched on two consecutive polls — treat as a genuine reversion.
253305
overridden_controls.append((control_name, expected_value, int(current_value), age))
254306
to_remove.append(register)
255307

256308
# Clean up tracked entries
257309
for reg in to_remove:
258310
self._pending_write_checks.pop(reg, None)
311+
self._pending_write_checks.update(to_update)
259312

260313
# Report overrides
261314
if overridden_controls:
@@ -643,6 +696,11 @@ async def _async_update_data(self) -> GrowattData:
643696
raise UpdateFailed("Growatt client not initialized")
644697

645698
try:
699+
# Timestamp taken BEFORE the reads begin. _check_for_cloud_overrides() uses it
700+
# to tell "this snapshot pre-dates the write" apart from "the value genuinely
701+
# reverted" — see Issue #358.
702+
poll_start = time.time()
703+
646704
# Run the blocking operations in executor
647705
data = await self.hass.async_add_executor_job(self._fetch_data)
648706

@@ -850,7 +908,7 @@ async def _async_update_data(self) -> GrowattData:
850908
self._just_came_online_time = None
851909

852910
# Check for cloud overrides on recently written registers
853-
await self._check_for_cloud_overrides(data)
911+
await self._check_for_cloud_overrides(data, poll_start)
854912

855913
# Deliver pending clock-drift notification (populated by _check_inverter_clock
856914
# on the first successful poll; cleared immediately so it only fires once).

custom_components/growatt_modbus/manifest.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,5 +12,5 @@
1212
"pymodbus>=3.0.0",
1313
"pyserial>=3.4"
1414
],
15-
"version": "1.1.3"
15+
"version": "1.1.4"
1616
}

0 commit comments

Comments
 (0)