diff --git a/custom_components/localthings/coordinator.py b/custom_components/localthings/coordinator.py index 71f1dd4..db8ff6c 100644 --- a/custom_components/localthings/coordinator.py +++ b/custom_components/localthings/coordinator.py @@ -77,6 +77,14 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): # fine session shouldn't tear down a working OBSERVE subscription. _POLL_TIMEOUT_LIMIT: int = 3 + # Timeouts for the two network round trips a write triggers: the PUT + # itself (_do_put), then the confirming full /device/0 summary poll + # async_send_command requests right after (_poll_once). Named here + # (rather than left as inline literals) so the write-settle window + # below can be sized to always outlast both — see async_send_command. + _POST_TIMEOUT_S: float = 8.0 + _POLL_TIMEOUT_S: float = 35.0 + def __init__(self, hass: HomeAssistant, entry: ConfigEntry) -> None: # Per-device logger (module logger scoped to this device's host) so # every log line — including the base DataUpdateCoordinator's own @@ -211,7 +219,7 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): # would have succeeded, not a dead session. 35s gives a slow # blockwise transfer room to actually finish instead of # generating a TimeoutError every cycle. - code, payload = sess.get(_SEED_PATH, timeout=35.0) + code, payload = sess.get(_SEED_PATH, timeout=self._POLL_TIMEOUT_S) except TimeoutError: raise except Exception as e: @@ -571,14 +579,44 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): # onto, the settle window was just delaying the real device # confirmation for a few seconds on every write, which read exactly # like the write being silently reverted (issue #27). + # + # settle_s must outlast the PUT and the async_request_refresh() + # below combined, not just DEFAULT_SETTLE_S's fixed few seconds -- + # that refresh is a full /device/0 summary poll, which + # _POLL_TIMEOUT_S itself admits can legitimately take tens of + # seconds on these devices (see _poll_once), and some writes settle + # on the device itself well after that: issue #9's washer packs + # cycle/detergent/softener selection into the same /course/vs/0 + # options[] array, and picking a new value there visibly needs a + # few seconds of internal validation/dispenser movement before the + # device's own state agrees -- while /washer/vs/0's temperature/ + # spin fields (plain flags, no device-side settling) confirm + # instantly on the same device. A short fixed window expired while + # the confirm poll was still in flight (or before the device had + # caught up internally), so that stale read landed unprotected and + # reverted the optimistic value, self-correcting again only once a + # later poll finally saw the real change -- read by the user as the + # write "reverting, then re-applying itself" a few seconds later. + # + # An earlier attempt at this also released the guard early, right + # after the confirming refresh completed, to avoid shutting out + # unrelated real updates (another automation, the physical remote) + # for the rest of settle_s. That was reverted: releasing the guard + # the moment one round trip finishes doesn't mean the device has + # actually caught up (exactly the slow-settling case above), and it + # introduced its own races around overlapping writes to the same + # href. Simpler and safer to just hold the guard for the full, + # generously-sized window and let it expire on its own. self._observe.apply(write_href, body, source='optimistic') - self._observe.mark_write_pending(write_href) + self._observe.mark_write_pending( + write_href, settle_s=self._POST_TIMEOUT_S + self._POLL_TIMEOUT_S + ) def _do_put(): sess = self._session if sess is None: raise RuntimeError("no session") - code, _ = sess.post(path_segs, cbor2.dumps(body), timeout=8.0) + code, _ = sess.post(path_segs, cbor2.dumps(body), timeout=self._POST_TIMEOUT_S) self._log.info("PUT %s → code %#04x", write_href, code) try: diff --git a/tests/localthings/test_coordinator.py b/tests/localthings/test_coordinator.py index ce4772d..72a406e 100644 --- a/tests/localthings/test_coordinator.py +++ b/tests/localthings/test_coordinator.py @@ -749,6 +749,65 @@ async def test_climate_power_write_applies_to_its_own_href_not_bound_href( assert coordinator._observe._settle_until.get('/power/0') is not None +async def test_send_command_survives_stale_confirm_poll( + hass: HomeAssistant, mock_entry, mock_coordinator_observe_session, fridge_resources, +) -> None: + """The settle window must outlast the confirm poll async_send_command + triggers via async_request_refresh(), not just DEFAULT_SETTLE_S's fixed + few seconds (issue #9). Some devices settle a write internally slower + than that refresh's own round trip -- issue #9's washer packs cycle/ + detergent/softener selection into /course/vs/0's shared options[] + array, which visibly takes a few seconds of validation/dispenser + movement to catch up, unlike /washer/vs/0's plain temperature/spin + fields on the same device, which confirm instantly. A confirm poll that + lands before the device has caught up is stale, and a settle window + sized only to the fixed default (rather than the PUT+poll round trip) + expires before that poll even returns, so the stale read lands + unprotected and reverts the optimistic value -- self-correcting again + only once a later poll finally sees the real change. That reads to a + user as the write reverting, then reapplying itself, a few seconds + later.""" + from custom_components.localthings.registry.discovery import BoundEntity + from custom_components.localthings.registry.entities import NumberDesc + + fake = mock_coordinator_observe_session + await hass.config_entries.async_setup(mock_entry.entry_id) + await hass.async_block_till_done() + coordinator: LocalThingsCoordinator = hass.data[DOMAIN][mock_entry.entry_id] + + def _write_fn(payload, rep, href): + return (['test', 'vs', '0'], {'value': payload}) + + desc = NumberDesc(key='test', field='value', write_fn=_write_fn) + bound = BoundEntity(href='/test/vs/0', capability=coordinator.bound[0].capability, desc=desc) + + def _stale_confirm_poll(): + # Stand-in for the write's own confirming /device/0 poll racing + # against a stale read for the same href -- the device's internal + # state hasn't caught up to the write yet, even though it will a + # little later. + coordinator._observe.apply('/test/vs/0', {'value': 0}, source='poll') + return fridge_resources + + with ( + patch.object(fake, 'subscribe'), + patch.object(LocalThingsCoordinator, '_poll_once', side_effect=_stale_confirm_poll), + ): + fake.post = lambda *a, **k: (0x44, b'') + await coordinator.async_send_command(bound, 5) + + # The optimistic value is visible right away and survived the stale + # confirm-poll race triggered by the refresh above. + assert coordinator._cache.get('/test/vs/0') == {'value': 5} + + # The settle window is still open afterward -- sized to outlast the + # whole PUT + confirm-poll round trip, not released the moment that + # round trip happens to finish. + applied = coordinator._observe.apply('/test/vs/0', {'value': 0}, source='observe') + assert applied is False + assert coordinator._cache.get('/test/vs/0') == {'value': 5} + + class TestRemoteControlEnabled: """remote_control_enabled (registry/capabilities/common.py) is the single source of truth for the /remotectrl on/off signal, shared by