diff --git a/README.md b/README.md index 11fa0b6..28aaaf7 100644 --- a/README.md +++ b/README.md @@ -142,7 +142,9 @@ The response has one `results` entry per write, with `before`/`after` reps and a } ``` -`verify_after` (0-60s, default 0, omit to skip) is what actually answers the "did it stick" question: after the sequence finishes, it waits that long and then re-reads every distinct href the sequence touched, reporting the result under `verified`, keyed by canonical href. `changed` tells you the write was accepted and reflected immediately; `held` tells you whether it was still there N seconds later, or whether the board quietly put it back — issue #300's exact symptom. Where an href was written more than once in a sequence, `held` compares against the *last* payload sent to it. +`verify_after` (0-60s, default 0, omit to skip) is what actually answers the "did it stick" question: after the sequence finishes, it waits that long and then re-reads every distinct href the sequence touched, reporting the result under `verified`, keyed by canonical href. `changed` tells you the write was accepted and reflected immediately; `held` tells you whether it was still there N seconds later, or whether the board quietly put it back — issue #300's exact symptom. Where an href was written more than once in a sequence, `held` compares against the *last* payload sent to it. A `held` of `null` means the re-read itself didn't come back (check `code` next to it) — unknown, deliberately not reported as a revert. + +If the session drops partway through a sequence, the action raises rather than returning, and the error names how many writes completed and which — the appliance is left holding a partial sequence, so knowing where it stopped is the difference between a usable result and starting over blind. `read_resource` is the read half, and it's deliberately not just a cache lookup: diff --git a/custom_components/localthings/coordinator.py b/custom_components/localthings/coordinator.py index 9c1a09e..5c3b502 100644 --- a/custom_components/localthings/coordinator.py +++ b/custom_components/localthings/coordinator.py @@ -114,6 +114,22 @@ def _href_to_path_segs(href: str) -> list[str]: return [s for s in str(href).strip("/").split("/") if s] +def normalize_href(href: str) -> str: + """A user-typed href in the one canonical spelling the rest of the debug + path assumes: exactly one leading slash, no trailing slash, no empty + segments. + + Public because services.py has to normalize *before* handing an href to + `Subdevice.to_actual` (issue #300). That transform is purely textual -- + an indexed subdevice rewrites only a trailing '0' segment -- so + '/mode/vs/0/' slips through it unchanged and then normalizes here to + '/mode/vs/0', silently landing the write on the master's resource + instead of the subdevice's while still reporting 2.04. Normalizing on + the way in makes the two agree. + """ + return "/" + "/".join(_href_to_path_segs(href)) + + def _coap_code_str(code: int) -> str: """Raw CoAP response code -> its 'C.DD' rendering (e.g. 0x44 -> '2.04'), the class/detail split RFC 7252 §12.1.2 defines. `raw_code` is kept @@ -1280,30 +1296,55 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): results: list[dict[str, Any]] = [] last_payload_by_href: dict[str, dict] = {} - async with self._session_lock: - for i, (path_segs, href, payload, settle) in enumerate(parsed): - before = self.resource(href) - code, after = await self.hass.async_add_executor_job( - self._raw_write_blocking, path_segs, payload, href - ) - last_payload_by_href[href] = payload - results.append( - { - "href": href, - "code": _coap_code_str(code), - "raw_code": code, - "accepted": _coap_accepted(code), - "before": before, - "after": after, - "changed": all(after.get(k) == v for k, v in payload.items()), - } - ) - # settle is "how long to wait before the next write" -- the - # last item has no next write, so it gets no wait here; - # verify_after (below) is the equivalent wait after the - # sequence as a whole. - if settle and i < len(parsed) - 1: - await asyncio.sleep(settle) + try: + async with self._session_lock: + for i, (path_segs, href, payload, settle) in enumerate(parsed): + before = self.resource(href) + code, after = await self.hass.async_add_executor_job( + self._raw_write_blocking, path_segs, payload, href + ) + last_payload_by_href[href] = payload + results.append( + { + "href": href, + "code": _coap_code_str(code), + "raw_code": code, + "accepted": _coap_accepted(code), + "before": before, + "after": after, + "changed": all(after.get(k) == v for k, v in payload.items()), + } + ) + # settle is "how long to wait before the next write" -- the + # last item has no next write, so it gets no wait here; + # verify_after (below) is the equivalent wait after the + # sequence as a whole. + # + # Held across this wait, unlike verify_after's below: a + # poll landing between two writes is exactly what this + # sequence exists to rule out, since it blurs which write + # the appliance was reacting to. Bounded by the caps above + # -- 10 writes x 30s is the worst a caller can ask for. + if settle and i < len(parsed) - 1: + await asyncio.sleep(settle) + except Exception as err: + # A session drop partway leaves the appliance holding whatever + # already landed. Raising bare would throw that away, and knowing + # which writes got through is the difference between a usable + # probe result and having to start the sequence over blind. + done = ", ".join(r["href"] for r in results) or "none" + self._log.warning( + "raw write sequence failed after %d of %d writes (completed: %s): %s", + len(results), + len(parsed), + done, + err, + ) + await self.async_request_refresh() + raise HomeAssistantError( + f"Raw write sequence failed after {len(results)} of {len(parsed)} writes " + f"(completed: {done}). The appliance may be holding a partial sequence." + ) from err response: dict[str, Any] = {"results": results} if verify_after > 0: @@ -1319,12 +1360,22 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): vcode, vrep = await self.hass.async_add_executor_job( self._raw_read_blocking, _href_to_path_segs(href), href ) + # `held` is None, not False, when the re-read itself + # didn't come back with a representation to compare. + # _raw_read_blocking answers a non-2.05 with an empty + # rep, against which every payload comparison is False -- + # so a 4.04 or a dropped read would otherwise be reported + # as "the board reverted your write", which is the exact + # distinction verify_after exists to draw. + read_ok = _coap_accepted(vcode) and bool(vrep) verified[href] = { "code": _coap_code_str(vcode), "raw_code": vcode, "rep": vrep, - "held": all( - vrep.get(k) == v for k, v in last_payload_by_href[href].items() + "held": ( + all(vrep.get(k) == v for k, v in last_payload_by_href[href].items()) + if read_ok + else None ), } response["verified"] = verified diff --git a/custom_components/localthings/services.py b/custom_components/localthings/services.py index 968324f..82f260d 100644 --- a/custom_components/localthings/services.py +++ b/custom_components/localthings/services.py @@ -23,7 +23,7 @@ from homeassistant.helpers import config_validation as cv from homeassistant.helpers import device_registry as dr from .const import DOMAIN, SERVICE_READ_RESOURCE, SERVICE_WRITE_RESOURCE -from .coordinator import LocalThingsCoordinator +from .coordinator import LocalThingsCoordinator, normalize_href from .registry.subdevices import MAIN, Subdevice ATTR_HREF = "href" @@ -119,13 +119,19 @@ async def _async_write_resource(hass: HomeAssistant, call: ServiceCall) -> Servi # (issue #177): the coordinator's raw-write primitive has no notion of # subdevices, only the hrefs it's told to hit -- identity transform for # MAIN, so a device targeting MAIN behaves exactly as it always has. + # + # Normalized first: to_actual is a textual transform, so an un-normalized + # '/mode/vs/0/' passes through it untouched and only gets tidied up + # downstream, quietly hitting the master's resource instead of the + # subdevice's (see coordinator.normalize_href). + canonicals = [normalize_href(w[ATTR_HREF]) for w in writes_in] raw_writes = [ { - "href": subdevice.to_actual(w[ATTR_HREF]), + "href": subdevice.to_actual(canonical), "payload": w.get(ATTR_PAYLOAD), "settle": w.get(ATTR_SETTLE, 0.0), } - for w in writes_in + for canonical, w in zip(canonicals, writes_in, strict=True) ] sequence = await coordinator.async_raw_write_sequence( raw_writes, verify_after=call.data.get(ATTR_VERIFY_AFTER, 0.0) @@ -133,7 +139,7 @@ async def _async_write_resource(hass: HomeAssistant, call: ServiceCall) -> Servi results = [ { - "href": original[ATTR_HREF], + "href": canonical, "actual_href": result["href"], "code": result["code"], "raw_code": result["raw_code"], @@ -142,11 +148,14 @@ async def _async_write_resource(hass: HomeAssistant, call: ServiceCall) -> Servi "after": result["after"], "changed": result["changed"], } - for original, result in zip(writes_in, sequence["results"], strict=True) + for canonical, result in zip(canonicals, sequence["results"], strict=True) ] response: dict[str, Any] = {"device_id": device_id, "results": results} if "verified" in sequence: - canonical_by_actual = {subdevice.to_actual(w[ATTR_HREF]): w[ATTR_HREF] for w in writes_in} + # Keyed off the same normalized canonicals the sequence was built + # from, so the lookup can't miss and hand back an actual href where + # the documented contract promises a canonical one. + canonical_by_actual = {subdevice.to_actual(c): c for c in canonicals} response["verified"] = { canonical_by_actual.get(actual_href, actual_href): verified for actual_href, verified in sequence["verified"].items() @@ -165,10 +174,12 @@ async def _async_read_resource(hass: HomeAssistant, call: ServiceCall) -> Servic snapshot: dict[str, Any] = {"resources": coordinator.canonical_resources(subdevice)} return cast(ServiceResponse, snapshot) - actual_href = subdevice.to_actual(href) + # Same normalize-before-translate order as the write path above. + canonical = normalize_href(href) + actual_href = subdevice.to_actual(canonical) code, rep = await coordinator.async_raw_read(actual_href) read_result: dict[str, Any] = { - "href": href, + "href": canonical, "actual_href": actual_href, "code": f"{code >> 5}.{code & 0x1F:02d}", "raw_code": code, diff --git a/tests/test_services.py b/tests/test_services.py index 4f63d9c..ab4414e 100644 --- a/tests/test_services.py +++ b/tests/test_services.py @@ -14,7 +14,7 @@ from unittest.mock import AsyncMock, patch import cbor2 import pytest from homeassistant.core import HomeAssistant -from homeassistant.exceptions import ServiceValidationError +from homeassistant.exceptions import HomeAssistantError, ServiceValidationError from homeassistant.helpers import device_registry as dr from pytest_homeassistant_custom_component.common import MockConfigEntry @@ -345,6 +345,129 @@ async def test_write_resource_translates_href_for_indexed_subdevice(hass, coordi assert result["actual_href"] == "/mode/vs/1" +async def test_write_resource_normalizes_href_before_subdevice_translation(hass, coordinator): + """A trailing slash must not silently retarget the write at the master. + + `Subdevice.to_actual` is a textual transform that rewrites only a + trailing '0' segment, so '/mode/vs/0/' passes through it unchanged and + then normalizes downstream to the master's '/mode/vs/0' -- landing on + the wrong cavity while still answering 2.04. Nothing in the response + would have given that away. + """ + sub = Subdevice(kind="indexed", key="1", seed_path=("device", "1")) + coordinator.subdevices = [sub] + dev_reg = dr.async_get(hass) + device = dev_reg.async_get_or_create( + config_entry_id=coordinator._entry.entry_id, + identifiers=coordinator.device_info_for(sub)["identifiers"], + ) + fake = _FakeSession() + coordinator._session = fake + + response = await _call_write( + hass, device.id, writes=[{"href": "/mode/vs/0/", "payload": {"x": 1}}] + ) + + assert fake.post_calls[0][0] == ["mode", "vs", "1"] + result = response["results"][0] + assert result["href"] == "/mode/vs/0" + assert result["actual_href"] == "/mode/vs/1" + + +async def test_write_resource_verified_is_keyed_by_canonical_href_for_subdevice(hass, coordinator): + """`verified` promises canonical keys; the coordinator reports actual + ones, so the translation back has to line up with what was sent.""" + sub = Subdevice(kind="indexed", key="1", seed_path=("device", "1")) + coordinator.subdevices = [sub] + dev_reg = dr.async_get(hass) + device = dev_reg.async_get_or_create( + config_entry_id=coordinator._entry.entry_id, + identifiers=coordinator.device_info_for(sub)["identifiers"], + ) + fake = _FakeSession() + fake.queue_get("/mode/vs/1", {"x": 1}) + coordinator._session = fake + + response = await _call_write( + hass, + device.id, + writes=[{"href": "/mode/vs/0", "payload": {"x": 1}}], + verify_after=1, + ) + + assert list(response["verified"]) == ["/mode/vs/0"] + assert response["verified"]["/mode/vs/0"]["held"] is True + + +async def test_write_resource_failure_midway_names_the_writes_that_landed( + hass, coordinator, device_id +): + """A drop partway through leaves the appliance holding a partial + sequence; the error has to say how far it got, or the operator can't + tell what state the device is in without starting over blind.""" + + class _DropsOnSecondWrite(_FakeSession): + def post(self, path_segs, payload, timeout=None): + if len(self.post_calls) == 1: + raise OSError("session dropped") + return super().post(path_segs, payload, timeout) + + coordinator._session = _DropsOnSecondWrite() + + with pytest.raises(HomeAssistantError) as excinfo: + await _call_write( + hass, + device_id, + writes=[ + {"href": "/mode/vs/0", "payload": {"a": 1}}, + {"href": "/temperatures/vs/0", "payload": {"b": 2}}, + {"href": "/operational/state/vs/0", "payload": {"c": 3}}, + ], + ) + + message = str(excinfo.value) + assert "1 of 3" in message + assert "/mode/vs/0" in message + # Entities still get pulled back in line with whatever did land. + coordinator.async_request_refresh.assert_awaited() + + +async def test_write_resource_held_is_none_when_the_verify_read_fails(hass, coordinator, device_id): + """A re-read that doesn't come back is not evidence of a revert. + + _raw_read_blocking answers a non-2.05 with an empty rep, and every + payload comparison against {} is False -- so without this, a 4.04 or a + dropped verify read is reported as `held: false`, indistinguishable + from the board quietly putting the old value back. That distinction is + the whole reason verify_after exists (issue #300). + """ + + class _FailingVerifyRead(_FakeSession): + def get(self, path_segs, timeout=None): + self.get_calls.append(list(path_segs)) + # The write's own follow-up GET succeeds; the later verify + # re-read of the same href is the one that fails. + if len(self.get_calls) == 1: + return 0x45, cbor2.dumps({"x": 1}) + return 0x84, b"" + + coordinator._session = _FailingVerifyRead() + + response = await _call_write( + hass, + device_id, + writes=[{"href": "/mode/vs/0", "payload": {"x": 1}}], + verify_after=1, + ) + + verified = response["verified"]["/mode/vs/0"] + assert verified["held"] is None + assert verified["code"] == "4.04" + # The immediate readback still saw the value land -- only the delayed + # confirmation is unknown, and the two must not be conflated. + assert response["results"][0]["changed"] is True + + # ---------------------------------------------------------------------- # Validation caps # ----------------------------------------------------------------------