An independent review turned up the real bug behind the climate lag: async_send_command applied the optimistic value and settle guard to bound_entity.href, but write_fn's path_segs -- the resource actually POSTed to -- can point somewhere else entirely. The AC's composite climate entity is bound to /mode/vs/0, yet a power/temperature/fan/ swing/preset command writes to its own sibling resource (/power/0, /temperature/desired/0, ...), which is also what climate.py reads the displayed state from. The optimistic value landed on /mode/vs/0 instead, so the resource the entity actually shows stayed stale until the next unrelated read of it -- surviving the earlier optimistic-apply fix (issue #27), which applied to the same wrong href. Derive the write's target from path_segs and apply/guard/log against that instead. Reverts the previous commit's settle-window-sizing change on this branch: that was chasing a real but speculative edge case (a confirm poll slower than the settle window) that a follow-up review couldn't confirm matches the reported symptom, and its early-release mechanism had its own races (a debounced refresh that hadn't actually run yet, overlapping writes to the same href) for marginal benefit once this fix lands. Simpler to drop it than carry that risk for a case not in evidence. Added a coordinator-level regression test against the real AC CLIMATE capability (not just a synthetic mismatched-path descriptor) sending a power command and asserting the optimistic value lands on /power/0, not /mode/vs/0.
This commit is contained in:
@@ -13,9 +13,10 @@ snapshot via `coordinator.resource(href)` -- the same cross-resource read that
|
||||
|
||||
Writes go through `coordinator.async_send_command(bound, (kind, value))`: the
|
||||
CLIMATE capability's `write_fn` maps each `(kind, value)` payload to the right
|
||||
`(path_segs, body)`, and `async_send_command` POSTs to those path_segs (the
|
||||
bound href is only used for logging), so one descriptor drives writes to power,
|
||||
mode, temperature and wind resources.
|
||||
`(path_segs, body)`, and `async_send_command` POSTs to those path_segs and
|
||||
applies the optimistic value/settle guard to that same href -- not the bound
|
||||
`/mode/vs/0` href -- so one descriptor drives writes to, and gets fresh state
|
||||
back for, power, mode, temperature and wind resources alike.
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
|
||||
@@ -77,14 +77,6 @@ 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
|
||||
@@ -219,7 +211,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=self._POLL_TIMEOUT_S)
|
||||
code, payload = sess.get(_SEED_PATH, timeout=35.0)
|
||||
except TimeoutError:
|
||||
raise
|
||||
except Exception as e:
|
||||
@@ -555,6 +547,22 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
||||
return
|
||||
path_segs, body = result
|
||||
|
||||
# The write's actual target, not necessarily bound_entity.href. Most
|
||||
# descriptors write to the same resource they're bound to, but a
|
||||
# composite entity -- the AC's ClimateDesc, bound to /mode/vs/0 --
|
||||
# drives writes to several sibling resources via path_segs
|
||||
# (/power/0, /temperature/desired/0, /wind/strength/vs/0, ...) that
|
||||
# write_fn picks per payload (see airconditioner._climate_write).
|
||||
# Applying the optimistic value and settle guard below to
|
||||
# bound_entity.href instead of this target protected the wrong
|
||||
# resource: /mode/vs/0 got the (nonsensical, wrong-shaped) optimistic
|
||||
# merge while the resource the climate entity actually displays from
|
||||
# (e.g. /power/0) never got one, so HA kept showing the pre-write
|
||||
# state until the next real read of that resource -- the 20-60s lag
|
||||
# in issues #17/#53, which survived the earlier optimistic-apply fix
|
||||
# (issue #27) because that fix applied to the wrong href too.
|
||||
write_href = '/' + '/'.join(path_segs)
|
||||
|
||||
# Apply the write optimistically before starting the settle guard,
|
||||
# not after -- mark_write_pending gates every source (poll, sweep,
|
||||
# observe) through the same apply(), itself included, so flipping
|
||||
@@ -563,43 +571,19 @@ 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 a 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). A shorter window expires while that confirm poll is
|
||||
# still in flight, so its result -- stale, if the device's own
|
||||
# resource tree hadn't caught up to the instant physical change
|
||||
# yet -- lands unprotected and reverts the optimistic value, with
|
||||
# nothing to correct it again until the next scheduled summary poll
|
||||
# up to SUMMARY_INTERVAL_S later. That's the 20-60s lag reported in
|
||||
# issues #17/#53 even after the optimistic-apply fix above.
|
||||
self._observe.apply(href, body, source='optimistic')
|
||||
self._observe.mark_write_pending(
|
||||
href, settle_s=self._POST_TIMEOUT_S + self._POLL_TIMEOUT_S
|
||||
)
|
||||
self._observe.apply(write_href, body, source='optimistic')
|
||||
self._observe.mark_write_pending(write_href)
|
||||
|
||||
def _do_put():
|
||||
sess = self._session
|
||||
if sess is None:
|
||||
raise RuntimeError("no session")
|
||||
code, _ = sess.post(path_segs, cbor2.dumps(body), timeout=self._POST_TIMEOUT_S)
|
||||
self._log.info("PUT %s → code %#04x", href, code)
|
||||
code, _ = sess.post(path_segs, cbor2.dumps(body), timeout=8.0)
|
||||
self._log.info("PUT %s → code %#04x", write_href, code)
|
||||
|
||||
try:
|
||||
await self.hass.async_add_executor_job(_do_put)
|
||||
except Exception as e:
|
||||
self._log.error("command failed for %s: %s", href, e)
|
||||
# The write's own confirmation never happened, so don't hold
|
||||
# the (possibly wrong) optimistic value hostage against real
|
||||
# updates for the rest of the long settle window above.
|
||||
self._observe.clear_write_pending(href)
|
||||
self._log.error("command failed for %s: %s", write_href, e)
|
||||
else:
|
||||
await self.async_request_refresh()
|
||||
# The confirming refresh has now run and applied its result
|
||||
# (subject to the settle guard above), so this write's own
|
||||
# round trip is done -- release the guard rather than leaving
|
||||
# real subsequent updates (another automation, the physical
|
||||
# remote) shut out for whatever's left of settle_s.
|
||||
self._observe.clear_write_pending(href)
|
||||
|
||||
@@ -82,22 +82,6 @@ class ObserveManager:
|
||||
with self._settle_lock:
|
||||
self._settle_until[href] = time.monotonic() + settle_s
|
||||
|
||||
def clear_write_pending(self, href: str) -> None:
|
||||
"""End a write's settle window early, once its own confirming
|
||||
refresh has actually completed (see coordinator.async_send_command).
|
||||
|
||||
mark_write_pending's caller sizes settle_s to safely outlast that
|
||||
confirm round trip so the guard can't lapse mid-flight (see issues
|
||||
#17/#53) -- but that same generous duration would needlessly hold
|
||||
the cache hostage against real, unrelated updates (another
|
||||
automation, the physical remote) for the rest of the window once
|
||||
the round trip is already done. Called from both the success and
|
||||
failure paths of a write, so a failed write doesn't leave a wrong
|
||||
optimistic value shielded from correction for the full window either.
|
||||
"""
|
||||
with self._settle_lock:
|
||||
self._settle_until.pop(href, None)
|
||||
|
||||
def _is_settling(self, href: str) -> bool:
|
||||
with self._settle_lock:
|
||||
until = self._settle_until.get(href)
|
||||
|
||||
@@ -644,10 +644,12 @@ async def test_write_marks_href_pending_before_post(
|
||||
) -> None:
|
||||
"""async_send_command must call mark_write_pending before POSTing so a
|
||||
slow-to-settle device can't immediately revert the optimistic write --
|
||||
and the window must still be open through the POST itself (checked from
|
||||
inside the fake POST, since the guard is released once the write's own
|
||||
confirming refresh completes -- see
|
||||
test_send_command_applies_write_optimistically_before_settling)."""
|
||||
and it must guard the write's actual target href (write_fn's own
|
||||
path_segs), not bound_entity.href. Those differ for a composite entity
|
||||
like the AC's ClimateDesc (bound to /mode/vs/0, but writing power/temp/
|
||||
fan/swing/preset to their own sibling hrefs) -- guarding the bound href
|
||||
protected the wrong resource and left the one the entity actually
|
||||
displays from unprotected (issues #17/#53)."""
|
||||
from custom_components.localthings.registry.discovery import BoundEntity
|
||||
from custom_components.localthings.registry.entities import NumberDesc
|
||||
|
||||
@@ -662,39 +664,27 @@ async def test_write_marks_href_pending_before_post(
|
||||
desc = NumberDesc(key='test', field='value', write_fn=_write_fn)
|
||||
bound = BoundEntity(href='/test/vs/0', capability=coordinator.bound[0].capability, desc=desc)
|
||||
|
||||
settling_during_post = None
|
||||
|
||||
def _post(*a, **k):
|
||||
nonlocal settling_during_post
|
||||
settling_during_post = coordinator._observe._settle_until.get('/test/vs/0') is not None
|
||||
return (0x44, b'')
|
||||
|
||||
with patch.object(fake, 'subscribe'):
|
||||
fake.post = _post
|
||||
fake.post = lambda *a, **k: (0x44, b'')
|
||||
await coordinator.async_send_command(bound, 5)
|
||||
|
||||
assert settling_during_post is True
|
||||
# Released once the write's own confirming refresh has completed, not
|
||||
# left open for the rest of what is now a much longer settle window.
|
||||
assert coordinator._observe._settle_until.get('/some/path') is not None
|
||||
assert coordinator._observe._settle_until.get('/test/vs/0') is None
|
||||
|
||||
|
||||
async def test_send_command_applies_write_optimistically_before_settling(
|
||||
hass: HomeAssistant, mock_entry, mock_coordinator_observe_session, fridge_resources,
|
||||
hass: HomeAssistant, mock_entry, mock_coordinator_observe_session,
|
||||
) -> None:
|
||||
"""The cache must reflect a write immediately, and stay put against a
|
||||
stale echo for the rest of the settle window -- otherwise
|
||||
mark_write_pending has nothing to protect and just delays the real
|
||||
device confirmation instead, which reads to a user as the write being
|
||||
silently reverted (issue #27).
|
||||
"""The cache must reflect a write immediately at the write's actual
|
||||
target href (write_fn's path_segs) -- not bound_entity.href, which
|
||||
differs for a composite entity like the AC's ClimateDesc -- and stay put
|
||||
against a stale echo for the rest of the settle window there.
|
||||
|
||||
The settle window now spans the whole POST + confirming-refresh round
|
||||
trip async_send_command awaits (see coordinator._POST_TIMEOUT_S /
|
||||
_POLL_TIMEOUT_S), not a fixed few seconds -- so this drives the stale
|
||||
echo through _poll_once itself, racing in while that confirming refresh
|
||||
is still in flight (issues #17/#53: a full summary poll on these
|
||||
devices can legitimately take far longer than a short fixed window,
|
||||
which let a stale read land unprotected and revert the write)."""
|
||||
Applying the optimistic value to bound_entity.href instead is exactly
|
||||
how issues #17/#53 survived the original optimistic-apply fix (issue
|
||||
#27): the bound href got a harmless (if nonsensical) optimistic merge,
|
||||
while the resource the entity actually reads from for its displayed
|
||||
state never got one and stayed stale until the next real read of it."""
|
||||
from custom_components.localthings.registry.discovery import BoundEntity
|
||||
from custom_components.localthings.registry.entities import NumberDesc
|
||||
|
||||
@@ -709,29 +699,54 @@ async def test_send_command_applies_write_optimistically_before_settling(
|
||||
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 an independent stale update for the same href (e.g. the
|
||||
# device's resource tree hadn't caught up internally yet, even
|
||||
# though the physical change was instant).
|
||||
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),
|
||||
):
|
||||
with patch.object(fake, 'subscribe'):
|
||||
fake.post = lambda *a, **k: (0x44, b'')
|
||||
await coordinator.async_send_command(bound, 5)
|
||||
|
||||
# The optimistic value is visible right away, without waiting for a
|
||||
# device response, and survived the stale confirm-poll race above.
|
||||
assert coordinator._cache.get('/test/vs/0') == {'value': 5}
|
||||
# The optimistic value is visible right away at the write's real
|
||||
# target, not the bound href.
|
||||
assert coordinator._cache.get('/some/path') == {'value': 5}
|
||||
assert coordinator._cache.get('/test/vs/0') != {'value': 5}
|
||||
|
||||
# The write's own round trip is done, so the guard has been released --
|
||||
# a later, genuinely new update is no longer held back.
|
||||
applied = coordinator._observe.apply('/test/vs/0', {'value': 0}, source='observe')
|
||||
assert applied is True
|
||||
# A stale update racing in behind the write (e.g. a poll/notify that
|
||||
# was already in flight before the PUT) must not clobber it while the
|
||||
# settle window is open.
|
||||
applied = coordinator._observe.apply('/some/path', {'value': 0}, source='observe')
|
||||
assert applied is False
|
||||
assert coordinator._cache.get('/some/path') == {'value': 5}
|
||||
|
||||
|
||||
async def test_climate_power_write_applies_to_its_own_href_not_bound_href(
|
||||
hass: HomeAssistant, mock_entry, mock_coordinator_observe_session
|
||||
) -> None:
|
||||
"""Regression for issues #17/#53, using the real AC capability. The
|
||||
composite climate entity binds /mode/vs/0 (airconditioner.CLIMATE.href),
|
||||
but a power command's write_fn (airconditioner._climate_write) targets
|
||||
the sibling /power/0 -- the href climate.py's `_is_on()` actually reads.
|
||||
The optimistic value and settle guard must land there, not on the bound
|
||||
/mode/vs/0, or the entity never sees the write and shows stale state
|
||||
until the next unrelated read of /power/0."""
|
||||
from custom_components.localthings.registry.capabilities import airconditioner
|
||||
from custom_components.localthings.registry.discovery import BoundEntity
|
||||
|
||||
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]
|
||||
|
||||
bound = BoundEntity(
|
||||
href=airconditioner.CLIMATE.href,
|
||||
capability=coordinator.bound[0].capability,
|
||||
desc=airconditioner.CLIMATE.entities[0],
|
||||
)
|
||||
|
||||
with patch.object(fake, 'subscribe'):
|
||||
fake.post = lambda *a, **k: (0x44, b'')
|
||||
await coordinator.async_send_command(bound, ('power', True))
|
||||
|
||||
assert coordinator._cache.get('/power/0') == {'value': True}
|
||||
assert coordinator._cache.get(airconditioner.CLIMATE.href) != {'value': True}
|
||||
assert coordinator._observe._settle_until.get('/power/0') is not None
|
||||
|
||||
|
||||
class TestRemoteControlEnabled:
|
||||
@@ -834,7 +849,7 @@ async def test_send_command_allowed_when_remote_control_enabled(
|
||||
fake.post = lambda *a, **k: (0x44, b'')
|
||||
await coordinator.async_send_command(bound, 5)
|
||||
|
||||
assert coordinator._cache.get('/test/vs/0') == {'value': 5}
|
||||
assert coordinator._cache.get('/some/path') == {'value': 5}
|
||||
|
||||
|
||||
async def test_send_command_remote_control_check_precedes_validate_fn(
|
||||
|
||||
Reference in New Issue
Block a user