diff --git a/custom_components/localthings/coordinator.py b/custom_components/localthings/coordinator.py index f10ff54..b6ab809 100644 --- a/custom_components/localthings/coordinator.py +++ b/custom_components/localthings/coordinator.py @@ -1169,7 +1169,38 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): if self._session is None: # _poll_once already connects on a real poll; only fires if # the session was closed out from under us concurrently. - await self.hass.async_add_executor_job(self._connect_session) + try: + await self.hass.async_add_executor_job(self._connect_session) + except Exception as e: + # Not a poll failure -- the poll that reached this line + # already succeeded, and observe mode is only an + # optimization on top of it. Give up on push this cycle + # the same way the two branches below do, rather than + # letting this escape _async_update_data uncaught: none + # of this integration's reconnect bookkeeping would run, + # and the base coordinator logs an ERROR traceback in + # place of the deliberately quiet "poll failed, + # reconnecting" voice used everywhere else in this file. + # + # Not counted by _reconnect_is_frequent() (that window + # records reconnects the poll path itself performed -- + # feeding it a secondary path's failure would push the + # next routine poll reconnect over the warn threshold), + # and nothing to _close_session(): _connect_session only + # publishes self._session once connect() and + # start_reader() have both already succeeded, so it's + # still None here. No _resubscribe_due either -- that + # flag means "a live session nothing has tried yet", + # and setting it would re-enter this doomed handshake + # every cycle; _last_observe_attempt_ts (stamped above) + # already paces the retry to _RECOVERY_RETRY_S. + self._log.info( + "observe-mode reconnect failed (%s), staying on polling: %s", + type(e).__name__, + e, + ) + self._observe.abandon_observe_attempt() + return sess = self._session if sess is None: return @@ -1327,9 +1358,22 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): # cycle's snapshot so discovery sees every subdevice on the # first poll rather than waiting a cycle. async with self._session_lock: - resources = await self.hass.async_add_executor_job( - self._enumerate_subdevices_blocking, resources - ) + try: + resources = await self.hass.async_add_executor_job( + self._enumerate_subdevices_blocking, resources + ) + except Exception as e: + # _connect_session() inside here only runs at all if the + # session the poll above just used got closed out from + # under us within this same cycle -- rare, but not + # impossible, and unguarded before this. Losing the + # subdevice probe isn't losing first discovery: `resources` + # keeps the value _poll_once already returned, so + # discovery below still runs on the master's own data, + # same posture _poll_subdevice_seed takes for one sibling + # going quiet. self.subdevices/_discovered are still + # unset, so the probe retries naturally next cycle. + self._log.debug("subdevice enumeration failed: %s", e) source = "sweep" if self._discovered else "poll" first_cycle = not self._discovered @@ -1631,9 +1675,23 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): ) norm_href = "/" + "/".join(path_segs) async with self._session_lock: - return await self.hass.async_add_executor_job( - self._raw_read_blocking, path_segs, norm_href - ) + try: + return await self.hass.async_add_executor_job( + self._raw_read_blocking, path_segs, norm_href + ) + except Exception as e: + # Unlike async_raw_write_sequence, there's nothing to + # reconnect-and-retry here -- a live debug read either lands + # or it doesn't, and a service call is the one place on this + # path a raw session exception would otherwise reach a user + # untranslated (write_resource already goes through + # HomeAssistantError; this brings read_resource in line). + self._log.warning("debug read failed for %s: %s", norm_href, e) + raise HomeAssistantError( + translation_domain=DOMAIN, + translation_key="debug_read_failed", + translation_placeholders={"href": norm_href, "error": str(e)}, + ) from e async def async_raw_write_sequence( self, @@ -1741,9 +1799,22 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): verified: dict[str, Any] = {} async with self._session_lock: for href in dict.fromkeys(r["href"] for r in results): - vcode, vrep, _vbody = await self.hass.async_add_executor_job( - self._raw_read_blocking, _href_to_path_segs(href), href - ) + try: + vcode, vrep, _vbody = await self.hass.async_add_executor_job( + self._raw_read_blocking, _href_to_path_segs(href), href + ) + except Exception as e: + # The write already landed -- see `results` above, + # built before this wait ever started. A failed + # confirmation read (the session dying in the gap + # verify_after just waited out, say) must not lose + # that outcome behind a raised exception here, and + # one href's failure shouldn't stop the rest of the + # batch from being checked. Same "couldn't verify" + # posture as a 4.04/empty read below: held stays + # None, not False. + self._log.debug("raw write verification read failed for %s: %s", href, e) + vcode, vrep = 0, {} # None, not False, when the re-read brought back nothing # to compare: every comparison against an empty rep is # False, which would report a 4.04 as a revert -- the one diff --git a/custom_components/localthings/translations/cs.json b/custom_components/localthings/translations/cs.json index 9873b61..1b833b5 100644 --- a/custom_components/localthings/translations/cs.json +++ b/custom_components/localthings/translations/cs.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "Příkaz pro {href} selhal i po opětovném připojení: {error}" }, + "debug_read_failed": { + "message": "Čtení z {href} selhalo: {error}" + }, "debug_too_many_writes": { "message": "Zadejte 1 až 10 zápisů." }, diff --git a/custom_components/localthings/translations/de.json b/custom_components/localthings/translations/de.json index 649bce1..a2d33ee 100644 --- a/custom_components/localthings/translations/de.json +++ b/custom_components/localthings/translations/de.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "Der Befehl an {href} ist auch nach erneutem Verbinden fehlgeschlagen: {error}" }, + "debug_read_failed": { + "message": "Das Lesen von {href} ist fehlgeschlagen: {error}" + }, "debug_too_many_writes": { "message": "Geben Sie zwischen 1 und 10 Schreibvorgänge an." }, diff --git a/custom_components/localthings/translations/en.json b/custom_components/localthings/translations/en.json index b4e96c8..30839a7 100644 --- a/custom_components/localthings/translations/en.json +++ b/custom_components/localthings/translations/en.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "The command to {href} failed even after reconnecting: {error}" }, + "debug_read_failed": { + "message": "The read from {href} failed: {error}" + }, "debug_too_many_writes": { "message": "Provide between 1 and 10 writes." }, diff --git a/custom_components/localthings/translations/es.json b/custom_components/localthings/translations/es.json index 05bbe46..763d485 100644 --- a/custom_components/localthings/translations/es.json +++ b/custom_components/localthings/translations/es.json @@ -173,6 +173,9 @@ "command_failed": { "message": "El comando para {href} falló incluso después de reconectar: {error}" }, + "debug_read_failed": { + "message": "La lectura desde {href} falló: {error}" + }, "debug_too_many_writes": { "message": "Proporciona entre 1 y 10 escrituras." }, diff --git a/custom_components/localthings/translations/it.json b/custom_components/localthings/translations/it.json index f96e426..d785c6f 100644 --- a/custom_components/localthings/translations/it.json +++ b/custom_components/localthings/translations/it.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "Il comando per {href} è fallito anche dopo la riconnessione: {error}" }, + "debug_read_failed": { + "message": "La lettura da {href} è fallita: {error}" + }, "debug_too_many_writes": { "message": "Specificare da 1 a 10 scritture." }, diff --git a/custom_components/localthings/translations/ko.json b/custom_components/localthings/translations/ko.json index c6230ff..540d48e 100644 --- a/custom_components/localthings/translations/ko.json +++ b/custom_components/localthings/translations/ko.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "재연결 후에도 {href} 명령이 실패했습니다: {error}" }, + "debug_read_failed": { + "message": "{href}에서 읽기가 실패했습니다: {error}" + }, "debug_too_many_writes": { "message": "1~10개의 쓰기를 지정하세요." }, diff --git a/custom_components/localthings/translations/nl.json b/custom_components/localthings/translations/nl.json index 12875d3..4ed576e 100644 --- a/custom_components/localthings/translations/nl.json +++ b/custom_components/localthings/translations/nl.json @@ -1558,6 +1558,9 @@ "command_failed": { "message": "Het commando naar {href} is ook na opnieuw verbinden mislukt: {error}" }, + "debug_read_failed": { + "message": "Het lezen van {href} is mislukt: {error}" + }, "debug_too_many_writes": { "message": "Geef tussen de 1 en 10 schrijfacties op." }, diff --git a/tests/localthings/test_coordinator.py b/tests/localthings/test_coordinator.py index cc289fc..5c11caa 100644 --- a/tests/localthings/test_coordinator.py +++ b/tests/localthings/test_coordinator.py @@ -13,6 +13,7 @@ from homeassistant.const import EVENT_HOMEASSISTANT_STOP from homeassistant.core import HomeAssistant from homeassistant.exceptions import ServiceValidationError from homeassistant.helpers import issue_registry as ir +from smartthings_local.errors import SessionError from custom_components.localthings.const import ( CONF_BYPASS_REMOTE_CONTROL, @@ -786,6 +787,38 @@ async def test_attempt_observe_mode_discards_stale_commit_after_session_swap( assert coordinator._resubscribe_due is True +async def test_attempt_observe_mode_survives_a_failed_reconnect( + hass: HomeAssistant, mock_entry, mock_coordinator_observe_session +) -> None: + """The session was closed out from under this attempt concurrently + (rare, but real -- see the docstring above), and the reconnect it tries + on the way back in fails too (smartthings-local >= 0.1.3's redacted + SessionError, or any other exception). That must not escape + _async_update_data uncaught: it should land in the same "give up on + push this cycle" state the subscribe-failed and stale-session branches + already produce, not skip this integration's own logging/state handling + entirely.""" + 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] + coordinator._session = None + coordinator._reconnect_times = [] + + with patch.object( + coordinator, + "_connect_session", + side_effect=SessionError(), + ): + await coordinator._attempt_observe_mode() # must not raise + + assert coordinator.observe_mode == MODE_POLL + assert coordinator._observe.subscribed_hrefs == set() + assert coordinator._resubscribe_due is False + # Not the poll path's own reconnect-frequency window (see the fix's + # comment) -- this failure must not count toward it. + assert coordinator._reconnect_times == [] + + async def test_maybe_retry_observe_mode_uses_most_recent_attempt_not_just_mode_change( hass: HomeAssistant, mock_entry, mock_coordinator_observe_session ) -> None: diff --git a/tests/test_coordinator_error_handling.py b/tests/test_coordinator_error_handling.py new file mode 100644 index 0000000..967633f --- /dev/null +++ b/tests/test_coordinator_error_handling.py @@ -0,0 +1,67 @@ +"""Regression tests for a handful of call sites in coordinator.py that used +to let a smartthings-local exception (EndpointError, SessionError, +SessionTimeoutError, SessionClosedError, ... -- or the equivalent bare +ConnectionError/TimeoutError/OSError an older library version raised) escape +uncaught instead of going through this integration's own reconnect/logging +or getting translated into a HomeAssistantError for a service caller. +""" + +from __future__ import annotations + +from homeassistant.core import HomeAssistant +from pytest_homeassistant_custom_component.common import MockConfigEntry + +from custom_components.localthings.const import ( + CONF_HOST, + CONF_LEAF_CERT_PEM, + CONF_LEAF_KEY_PEM, + CONF_PORT, + DOMAIN, +) +from custom_components.localthings.coordinator import LocalThingsCoordinator + +ENTRY_DATA = { + CONF_HOST: "10.0.0.198", + CONF_PORT: 49154, + CONF_LEAF_CERT_PEM: "-----BEGIN CERTIFICATE-----\nTEST-LEAF\n-----END CERTIFICATE-----", + CONF_LEAF_KEY_PEM: "-----BEGIN PRIVATE KEY-----\nTEST-LEAF-KEY\n-----END PRIVATE KEY-----", +} + + +def _coordinator(hass: HomeAssistant) -> LocalThingsCoordinator: + entry = MockConfigEntry( + domain=DOMAIN, + data=ENTRY_DATA, + unique_id="localthings_ERRHANDLING-TEST", + ) + entry.add_to_hass(hass) + return LocalThingsCoordinator(hass, entry) + + +async def test_subdevice_enumeration_failure_does_not_abort_first_discovery( + hass: HomeAssistant, +) -> None: + """_enumerate_subdevices_blocking's own _connect_session() call only + fires if the session the poll above just used got closed out from under + it within the same cycle -- rare, but until this fix, unguarded: an + exception there escaped _async_update_data entirely instead of going + through this integration's own logging, matching what already happens + for the main poll's own reconnect. + + Empty resources keep _run_discovery from binding anything (hot/warm + hrefs stay empty), so _attempt_observe_mode's own session touch never + runs either -- this test is purely about the enumeration failure not + escaping _async_update_data. + """ + coordinator = _coordinator(hass) + coordinator._poll_once = dict + + def _boom(_resources): + raise ConnectionError("session closed") + + coordinator._enumerate_subdevices_blocking = _boom + + result = await coordinator._async_update_data() + + assert coordinator._discovered is True + assert result == {} diff --git a/tests/test_services.py b/tests/test_services.py index 84b3b57..3d7f686 100644 --- a/tests/test_services.py +++ b/tests/test_services.py @@ -324,6 +324,39 @@ async def test_write_resource_verify_after_reports_reverted(hass, coordinator, d assert verified["rep"] == {"x.field": "original"} +async def test_write_resource_verify_after_survives_a_failed_confirmation_read( + hass, coordinator, device_id, monkeypatch +): + """The write itself already landed (see `results`, built before + verify_after's wait even starts) by the time the confirmation read runs + -- a session dying in the gap verify_after waits out (smartthings-local's + redacted SessionClosedError/SessionTimeoutError, or any other exception) + must not lose that outcome behind a raised exception. Same "couldn't + verify" posture as a 4.04/empty read: `held` stays None, not False.""" + fake = _FakeSession() + fake.queue_get("mode/vs/0", {"x.field": "target"}) # write's own follow-up read + coordinator._session = fake + + def _boom(path_segs, href): + raise ConnectionError("session closed") + + monkeypatch.setattr(coordinator, "_raw_read_blocking", _boom) + + with patch(_SLEEP_TARGET, new_callable=AsyncMock): + response = await _call_write( + hass, + device_id, + writes=[{"href": "/mode/vs/0", "payload": {"x.field": "target"}}], + verify_after=30, + ) + + # The write's own results survive even though verification blew up. + assert response["results"][0]["accepted"] is True + verified = response["verified"]["/mode/vs/0"] + assert verified["held"] is None + assert verified["rep"] == {} + + async def test_write_resource_no_verified_key_when_verify_after_is_zero( hass, coordinator, device_id ): @@ -605,6 +638,24 @@ async def test_read_resource_surfaces_a_collections_list_body(hass, coordinator, assert response["body"] == batch +async def test_read_resource_failure_is_surfaced_as_a_home_assistant_error( + hass, coordinator, device_id, monkeypatch +): + """A session/network failure during a live debug read (e.g. + smartthings-local's redacted SessionError, or any other exception) must + not reach the service caller raw and untranslated -- write_resource + already goes through HomeAssistantError on failure, and async_raw_read + must match that instead of letting the exception escape uncaught.""" + + def _boom(path_segs, href): + raise ConnectionError("session closed") + + monkeypatch.setattr(coordinator, "_raw_read_blocking", _boom) + + with pytest.raises(HomeAssistantError): + await _call_read(hass, device_id, href="/mode/vs/0") + + async def test_read_resource_without_href_returns_cached_snapshot_and_does_not_get( hass, coordinator, device_id ):