From 9fc04e179eae361f32304ae86810745618f3c73c Mon Sep 17 00:00:00 2001 From: Marc Billow Date: Sun, 2 Aug 2026 23:26:50 +0000 Subject: [PATCH] Fix devices coming up entity-less after a Core restart A failed DTLS handshake on the very first poll was being swallowed, so the config entry loaded with no entities at all and stayed that way until the user reloaded that device by hand (issue #254). _poll_once() connects when there is no session yet, so connect()'s handshake timeout reaches _async_update_data as a TimeoutError -- the same type a slow blockwise transfer raises mid-session. _defer_reconnect_for() only knew the mid-session meaning and deferred it, making _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 and skipped ConfigEntryNotReady, and setup forwarded the platforms with `bound` still empty. Platforms enumerate `bound` once and have no dynamic add-listener, so a later cycle repopulating it added nothing: every restored entity sat unavailable until a manual reload. Gate the deferral on self._discovered. Before the first discovery a poll failure now takes the normal path -- one reconnect attempt, then UpdateFailed -> ConfigEntryNotReady -- so HA retries on its own backoff until the handshake goes through. Two related fixes in the same failure path: - Close the DTLS session on EVENT_HOMEASSISTANT_STOP, not only on entry unload. HA does not unload entries on a Core restart, so async_close() never ran and the previous run's association was left orphaned on the appliance -- which is what makes the next run's handshake time out in the first place. The fixed source port still covers the unclean-exit case where no close_notify can be sent. - Close the session when first refresh fails. _poll_once deliberately leaves it open on a TimeoutError, so a failed setup abandoned a bound UDP socket on a port that is fixed per device by design, and each HA retry bound another socket to that same port. --- custom_components/localthings/__init__.py | 41 ++++- custom_components/localthings/coordinator.py | 29 +++ tests/localthings/test_coordinator.py | 182 +++++++++++++++++++ 3 files changed, 251 insertions(+), 1 deletion(-) 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()