diff --git a/custom_components/localthings/__init__.py b/custom_components/localthings/__init__.py index 3a21b24..64ec7b8 100644 --- a/custom_components/localthings/__init__.py +++ b/custom_components/localthings/__init__.py @@ -4,7 +4,8 @@ from __future__ import annotations import logging from homeassistant.config_entries import ConfigEntry -from homeassistant.core import HomeAssistant +from homeassistant.const import EVENT_HOMEASSISTANT_STOP +from homeassistant.core import Event, HomeAssistant from homeassistant.exceptions import ConfigEntryNotReady from homeassistant.helpers import device_registry as dr @@ -20,8 +21,46 @@ async def async_setup_entry(hass: HomeAssistant, entry: ConfigEntry) -> bool: try: await coordinator.async_config_entry_first_refresh() except Exception as err: + # Close whatever the failed refresh left open before handing this + # coordinator to the garbage collector. `_poll_once` deliberately + # leaves the session up on a `TimeoutError` (the transfer may just + # be slow -- see its docstring), so a refresh that fails that way + # ends here with a live, bound UDP socket that nothing will ever + # close. HA retries setup on its own backoff with a *new* + # coordinator, and every device's source port is fixed by design + # (`_local_source_port`), so each abandoned socket keeps squatting + # the exact port the next attempt binds -- SO_REUSEADDR lets the + # bind succeed, and then two sockets on one port race for the + # device's datagrams. Failing setup is precisely when retries are + # most likely, so leaking there is what would hurt most. + await coordinator.async_close() raise ConfigEntryNotReady(f"Cannot connect to device: {err}") from err hass.data[DOMAIN][entry.entry_id] = coordinator + + # Send the DTLS close_notify on Core shutdown, not just on unload + # (issue #254). `async_close` otherwise only runs via + # `async_unload_entry` -- a reload or a remove -- and HA does not unload + # config entries on a plain Core restart, so a restart left the previous + # run's association orphaned on the appliance. The device then holds that + # stale session for minutes, which is what makes the next run's handshake + # time out in the first place. Closing cleanly here means there is + # usually nothing to evict on the way back up. This is belt-and-braces + # with the fixed source port (RFC 6347 section 4.2.8 eviction): that + # handles the unclean-shutdown case this cannot, e.g. a power cut or a + # SIGKILL, where no close_notify is ever sent. + # + # Registered as a coroutine listener rather than one that spawns its own + # task: the event bus runs it as a hass-tracked job, so the close is + # awaited by the `async_block_till_done()` inside `hass.async_stop`. A + # detached task would just as likely be cancelled mid-shutdown, which is + # the exact no-close_notify case this exists to prevent. + async def _async_close_on_stop(_event: Event) -> None: + await coordinator.async_close() + + entry.async_on_unload( + hass.bus.async_listen_once(EVENT_HOMEASSISTANT_STOP, _async_close_on_stop) + ) + await hass.config_entries.async_forward_entry_setups(entry, PLATFORMS) return True diff --git a/custom_components/localthings/coordinator.py b/custom_components/localthings/coordinator.py index b76dd33..c887bb8 100644 --- a/custom_components/localthings/coordinator.py +++ b/custom_components/localthings/coordinator.py @@ -791,7 +791,36 @@ class LocalThingsCoordinator(DataUpdateCoordinator[dict[str, Any]]): normal on a flaky device; a run of them is a real problem. Any other exception (a `ConnectionError`, an explicitly closed session) is unambiguous and always reconnects immediately. + + Never defers before the first successful discovery (issue #254). + Deferring is a *mid-session* judgement call: it means "keep the + entities we already have and try again next cycle," which is only + coherent once there are entities to keep. On the very first refresh + the same `TimeoutError` means something completely different — + `_poll_once` calls `_connect_session`, so `connect()`'s own + handshake timeout surfaces here as a `TimeoutError` too, and that is + a dead connection, not a slow transfer. Deferring it made + `_async_update_data` return `flatten([], {})` == `{}` instead of + raising; `DataUpdateCoordinator` counts any non-raising return as + success, so `async_config_entry_first_refresh` saw a healthy first + refresh, skipped `ConfigEntryNotReady`, and setup forwarded the + platforms with `bound` still empty. Every platform enumerates + `bound` exactly once in its `async_setup_entry` and has no dynamic + add-listener, so the device came up with zero entities: a later + cycle would repopulate `bound` (`_discovered` was still False), but + nothing would ever add the entities for it, leaving every restored + entity stuck `unavailable` until a manual per-device reload. + + This is reachable on a plain Core restart because HA doesn't unload + entries on restart, so the device is often still holding the + previous run's DTLS association when we reconnect. Returning False + here puts a pre-discovery failure back on the normal path: one + reconnect attempt, and if that fails too the exception propagates as + `UpdateFailed` -> `ConfigEntryNotReady`, so HA retries on its own + backoff until the handshake goes through — no reload needed. """ + if not self._discovered: + return False if not isinstance(e, TimeoutError): return False if self._observe.mode == MODE_OBSERVE and self._observe.recently_notified(): diff --git a/tests/localthings/test_coordinator.py b/tests/localthings/test_coordinator.py index 3b89d5e..96f1822 100644 --- a/tests/localthings/test_coordinator.py +++ b/tests/localthings/test_coordinator.py @@ -6,6 +6,8 @@ from unittest.mock import AsyncMock, patch import cbor2 import pytest +from homeassistant.config_entries import ConfigEntryState +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 @@ -1244,3 +1246,183 @@ def test_local_source_port_non_ipv4_falls_back_to_hash() -> None: port = _local_source_port('some-hostname') assert port == _local_source_port('some-hostname') assert DTLS_LOCAL_PORT_BASE <= port <= DTLS_LOCAL_PORT_BASE + 0xFF + + +# ---------------------------------------------------------------------- +# Issue #254: a pre-discovery poll failure must never look like a +# successful first refresh. +# ---------------------------------------------------------------------- + + +async def test_first_refresh_timeout_recovers_via_reconnect( + hass: HomeAssistant, mock_entry, fridge_resources +) -> None: + """A handshake timeout on the very first poll reconnects instead of + being deferred (issue #254). + + `_poll_once` connects when there is no session, so `connect()`'s own + handshake timeout arrives here as a `TimeoutError` -- indistinguishable + by type from a slow blockwise transfer, but meaning a dead connection. + Deferring it returned `flatten([], {})` == `{}` without raising, which + `DataUpdateCoordinator` counts as a successful refresh, so the entry + loaded with `bound` empty and every platform added zero entities. + """ + calls = {'n': 0} + + def _poll(self): + calls['n'] += 1 + if calls['n'] == 1: + raise TimeoutError('DTLS handshake timed out') + return fridge_resources + + with ( + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._connect_session'), + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._poll_once', _poll), + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._close_session'), + ): + await hass.config_entries.async_setup(mock_entry.entry_id) + await hass.async_block_till_done() + + # The retry inside the first refresh is what makes this recoverable + # without HA having to fail and re-run setup at all. + assert calls['n'] == 2 + assert mock_entry.state is ConfigEntryState.LOADED + coordinator: LocalThingsCoordinator = hass.data[DOMAIN][mock_entry.entry_id] + assert coordinator.bound, "discovery must have run before platforms are forwarded" + # The regression this guards is entity-visible, not just state on the + # coordinator: platforms enumerate `bound` once and have no dynamic + # add-listener, so an empty `bound` at forward time means the device + # stays entity-less until a manual reload. + assert hass.states.async_all(), "device came up with zero entities" + + +async def test_first_refresh_persistent_timeout_raises_not_ready( + hass: HomeAssistant, mock_entry +) -> None: + """When the reconnect times out too, the first refresh must fail so HA + retries on its backoff -- not load an entity-less entry (issue #254).""" + with ( + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._connect_session'), + patch( + 'custom_components.localthings.coordinator.LocalThingsCoordinator._poll_once', + side_effect=TimeoutError('DTLS handshake timed out'), + ), + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._close_session'), + ): + await hass.config_entries.async_setup(mock_entry.entry_id) + await hass.async_block_till_done() + + assert mock_entry.state is ConfigEntryState.SETUP_RETRY + assert not hass.states.async_all() + + +async def test_first_refresh_timeout_does_not_consume_timeout_budget( + hass: HomeAssistant, mock_entry, fridge_resources +) -> None: + """The pre-discovery gate must not leave `_consecutive_poll_timeouts` + charged for a failure it already handled by reconnecting -- otherwise a + device that stumbles once at startup reaches `_POLL_TIMEOUT_LIMIT` after + fewer real mid-session timeouts than the limit names.""" + calls = {'n': 0} + + def _poll(self): + calls['n'] += 1 + if calls['n'] == 1: + raise TimeoutError('DTLS handshake timed out') + return fridge_resources + + with ( + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._connect_session'), + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._poll_once', _poll), + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._close_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] + assert coordinator._consecutive_poll_timeouts == 0 + + +async def test_post_discovery_timeout_is_still_deferred( + hass: HomeAssistant, mock_entry, mock_coordinator_session +) -> None: + """The issue #254 gate is scoped to the pre-discovery case only: once + discovery has run, a lone poll timeout must still be absorbed without a + reconnect (the slow-blockwise-transfer behavior `_POLL_TIMEOUT_LIMIT` + exists for).""" + 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] + assert coordinator._discovered + + with ( + patch( + 'custom_components.localthings.coordinator.LocalThingsCoordinator._poll_once', + side_effect=TimeoutError('GET /device/0 block 11 timeout'), + ), + patch( + 'custom_components.localthings.coordinator.LocalThingsCoordinator._close_session', + ) as mock_close, + ): + await coordinator.async_request_refresh() + await hass.async_block_till_done() + + mock_close.assert_not_called() + assert coordinator._consecutive_poll_timeouts == 1 + assert coordinator.last_update_success + + +async def test_defer_reconnect_gate_is_false_before_discovery() -> None: + """`_defer_reconnect_for` unit-level: the pre-discovery gate wins over + every other deferral reason, including a healthy-push session.""" + coordinator = LocalThingsCoordinator.__new__(LocalThingsCoordinator) + coordinator._discovered = False + assert coordinator._defer_reconnect_for(TimeoutError('handshake')) is False + + +async def test_session_closed_when_first_refresh_fails( + hass: HomeAssistant, mock_entry +) -> None: + """A failed setup must not leak the session it opened. `_poll_once` + leaves the session up on a `TimeoutError` by design, and every device's + source port is fixed, so an abandoned socket squats the exact port HA's + next setup attempt binds.""" + with ( + patch('custom_components.localthings.coordinator.LocalThingsCoordinator._connect_session'), + patch( + 'custom_components.localthings.coordinator.LocalThingsCoordinator._poll_once', + side_effect=TimeoutError('DTLS handshake timed out'), + ), + patch( + 'custom_components.localthings.coordinator.LocalThingsCoordinator._close_session', + ) as mock_close, + ): + await hass.config_entries.async_setup(mock_entry.entry_id) + await hass.async_block_till_done() + + assert mock_entry.state is ConfigEntryState.SETUP_RETRY + assert mock_close.called, "failed setup left the DTLS socket open" + + +async def test_close_notify_sent_on_homeassistant_stop( + hass: HomeAssistant, mock_entry, mock_coordinator_session +) -> None: + """A plain Core restart must close the DTLS session (issue #254). + + HA does not unload config entries on a Core restart, so `async_close`'s + only other caller (`async_unload_entry`) never runs -- leaving the + association orphaned on the appliance, which is what makes the *next* + run's handshake time out. + """ + 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] + with patch.object( + coordinator, 'async_close', new=AsyncMock() + ) as mock_async_close: + hass.bus.async_fire(EVENT_HOMEASSISTANT_STOP) + await hass.async_block_till_done() + + mock_async_close.assert_awaited_once()