diff --git a/src/devices/heating.py b/src/devices/heating.py index de458d71..934aa562 100644 --- a/src/devices/heating.py +++ b/src/devices/heating.py @@ -164,20 +164,13 @@ async def get_mode(self, device: Device): Returns: str: Current Mode """ - state = None - final = None - device_name = device.ha_name - - try: - data = self.session.data.products[device.hive_id] - state = data["state"]["mode"] - if state == "BOOST": - state = self._get_product_state(device, "props", "previous", "mode") - final = HIVETOHA[self.heating_type].get(state, state) - except KeyError as e: - _LOGGER.error("get_mode - KeyError getting mode for %s: %s", device_name, e) - - return final + state = self._get_product_state(device, "state", "mode") + if state is None: + _LOGGER.debug("get_mode - No mode in state for %s.", device.ha_name) + return None + if state == "BOOST": + state = self._get_product_state(device, "props", "previous", "mode") + return HIVETOHA[self.heating_type].get(state, state) async def get_state(self, device: Device): """Get heating current state. diff --git a/src/devices/hotwater.py b/src/devices/hotwater.py index d4774c81..b36ca8d0 100644 --- a/src/devices/hotwater.py +++ b/src/devices/hotwater.py @@ -31,20 +31,13 @@ async def get_mode(self, device: Device): Returns: str: Return mode. """ - state = None - final = None - device_name = device.ha_name - - try: - data = self.session.data.products[device.hive_id] - state = data["state"]["mode"] - if state == "BOOST": - state = self._get_product_state(device, "props", "previous", "mode") - final = HIVETOHA[self.hotwater_type].get(state, state) - except KeyError as e: - _LOGGER.error("get_mode - KeyError getting mode for %s: %s", device_name, e) - - return final + state = self._get_product_state(device, "state", "mode") + if state is None: + _LOGGER.debug("get_mode - No mode in state for %s.", device.ha_name) + return None + if state == "BOOST": + state = self._get_product_state(device, "props", "previous", "mode") + return HIVETOHA[self.hotwater_type].get(state, state) @staticmethod async def get_operation_modes(): diff --git a/src/session/__init__.py b/src/session/__init__.py index bb9f1920..a36503bf 100644 --- a/src/session/__init__.py +++ b/src/session/__init__.py @@ -72,6 +72,7 @@ def __init__( self.hub_id = None self._last_poll_slow = False self._slow_poll_threshold = 3 + self._stale_state_polls: dict[str, int] = {} self._refresh_threshold = 0.90 self._update_task: asyncio.Task | None = None diff --git a/src/session/polling.py b/src/session/polling.py index e9e97849..2cfc254d 100644 --- a/src/session/polling.py +++ b/src/session/polling.py @@ -15,14 +15,24 @@ _LOGGER = logging.getLogger(__name__) +# Consecutive polls for which state keys missing from a response are carried +# over from the previous poll before the response is accepted as it is. +MAX_STALE_STATE_POLLS = 5 + +# State keys Hive always sends for a product that has them. Only these are +# carried over: other keys (``boost``, the colour keys) are legitimately +# omitted at times, so keeping their old value would report stale state. +REQUIRED_STATE_KEYS = frozenset({"mode", "name", "status", "target"}) + class PollingMixin: """Device polling, rate-limiting, and entity-cache methods. Expects ``self.config``, ``self.tokens``, ``self.api``, ``self.update_lock``, ``self._update_task``, - ``self._last_poll_slow``, and ``self._slow_poll_threshold`` - to be set up by the owning class's ``__init__``. + ``self._last_poll_slow``, ``self._slow_poll_threshold``, and + ``self._stale_state_polls`` to be set up by the owning class's + ``__init__``. """ # Attributes provided by HiveSession.__init__ @@ -35,6 +45,7 @@ class PollingMixin: _update_task: asyncio.Task | None _last_poll_slow: bool _slow_poll_threshold: int + _stale_state_polls: dict[str, int] @staticmethod def _entity_cache_key(device) -> str: @@ -70,6 +81,69 @@ def should_use_cached_data(self): return self._update_task is None or current_task is not self._update_task return False + def _keep_missing_state(self, new_products: dict) -> None: + """Carry over required state keys that a poll response has dropped. + + Hive sometimes answers a poll with products whose ``state`` block is + missing keys it normally has. Keep the last known value for the keys + in ``REQUIRED_STATE_KEYS``, for up to ``MAX_STALE_STATE_POLLS`` + consecutive polls. + + Args: + new_products (dict): Products from the latest response, keyed by ID. + """ + incomplete = [] + for product_id, product in new_products.items(): + previous = self.data.products.get(product_id) or {} + previous_state = previous.get("state") + new_state = product.get("state") + if not isinstance(new_state, dict): + new_state = {} + missing: list[str] = [] + if isinstance(previous_state, dict): + missing = sorted( + (previous_state.keys() & REQUIRED_STATE_KEYS) - new_state.keys() + ) + if not isinstance(previous_state, dict) or not missing: + self._stale_state_polls.pop(product_id, None) + continue + name = previous_state.get("name", product_id) + product_type = product.get("type") + _LOGGER.debug( + "Hive API state for %s %s arrived with keys: %s", + product_type, + product_id, + ", ".join(sorted(new_state)), + ) + polls = self._stale_state_polls.get(product_id, 0) + 1 + self._stale_state_polls[product_id] = polls + if polls > MAX_STALE_STATE_POLLS: + _LOGGER.warning( + "Hive API state for %s (%s %s) is still missing %s after %d " + "polls — no longer keeping the last known values.", + name, + product_type, + product_id, + ", ".join(missing), + MAX_STALE_STATE_POLLS, + ) + continue + product["state"] = { + **{key: previous_state[key] for key in missing}, + **new_state, + } + incomplete.append( + f"{name} ({product_type} {product_id}) missing {', '.join(missing)}" + ) + for product_id in self._stale_state_polls.keys() - new_products.keys(): + del self._stale_state_polls[product_id] + if incomplete: + _LOGGER.warning( + "Hive API returned incomplete state — keeping the last known " + "values: %s", + "; ".join(sorted(incomplete)), + ) + async def _poll_devices(self) -> bool: """Fetch latest device state from the Hive API.""" return await self.get_devices("No_ID") @@ -205,6 +279,7 @@ async def get_devices(self, _n_id: str): # pylint: disable=too-many-locals,too- len(tmp_actions), ) if tmp_products: + self._keep_missing_state(tmp_products) self.data.products = tmp_products if tmp_devices: self.data.devices = tmp_devices diff --git a/tests/module/test_session_polling.py b/tests/module/test_session_polling.py index dac27d5e..2a2abd03 100644 --- a/tests/module/test_session_polling.py +++ b/tests/module/test_session_polling.py @@ -30,6 +30,7 @@ class StubPolling(PollingMixin): p._update_task = None p._last_poll_slow = False p._slow_poll_threshold = 3 + p._stale_state_polls = {} p._poll_devices = AsyncMock(return_value=True) return p diff --git a/tests/unit/test_heating.py b/tests/unit/test_heating.py index 56c13ca0..181d2237 100644 --- a/tests/unit/test_heating.py +++ b/tests/unit/test_heating.py @@ -493,3 +493,28 @@ async def test_cached_none_falls_through_to_normal_path(self): result = await climate.get_climate(_make_device()) assert result is not None climate.session.attr.online_offline.assert_called_once() + + +# --------------------------------------------------------------------------- +# get_mode — state block present but mode missing (incomplete API response) +# --------------------------------------------------------------------------- + + +class TestGetModeMissingMode: + """get_mode must not log an error per call when state has no mode.""" + + async def test_missing_mode_returns_none_without_error_log(self): + """state without 'mode' returns None and logs nothing at ERROR.""" + climate = _make_climate({"heat-1": {"state": {"target": 7}}}) + with patch("apyhiveapi.devices.heating._LOGGER") as mock_log: + result = await climate.get_mode(_make_device()) + assert result is None + mock_log.error.assert_not_called() + + async def test_schedule_lookup_with_missing_mode_returns_none(self): + """get_schedule_now_next_later returns None quietly when mode is missing.""" + climate = _make_climate({"heat-1": {"state": {"schedule": {}}}}) + with patch("apyhiveapi.devices.heating._LOGGER") as mock_log: + result = await climate.get_schedule_now_next_later(_make_device()) + assert result is None + mock_log.error.assert_not_called() diff --git a/tests/unit/test_hotwater.py b/tests/unit/test_hotwater.py index 5da4e336..e308695d 100644 --- a/tests/unit/test_hotwater.py +++ b/tests/unit/test_hotwater.py @@ -326,3 +326,17 @@ async def test_cached_none_falls_through(self): result = await hw.get_water_heater(_make_device()) assert result is not None hw.session.attr.online_offline.assert_called_once() + + +class TestHotwaterGetModeMissingMode: + """get_mode must not log an error per call when state has no mode.""" + + async def test_missing_mode_returns_none_without_error_log(self): + """state without 'mode' returns None and logs nothing at ERROR.""" + from unittest.mock import patch + + hw = _make_hotwater({"hw-1": {"state": {"status": "OFF"}}}) + with patch("apyhiveapi.devices.hotwater._LOGGER") as mock_log: + result = await hw.get_mode(_make_device()) + assert result is None + mock_log.error.assert_not_called() diff --git a/tests/unit/test_polling.py b/tests/unit/test_polling.py index 77062a0b..b32df7c1 100644 --- a/tests/unit/test_polling.py +++ b/tests/unit/test_polling.py @@ -31,6 +31,7 @@ class StubPolling(PollingMixin): p._update_task = None p._last_poll_slow = False p._slow_poll_threshold = 3 + p._stale_state_polls = {} return p diff --git a/tests/unit/test_session_get_devices.py b/tests/unit/test_session_get_devices.py index b284b1ec..7ac4b37c 100644 --- a/tests/unit/test_session_get_devices.py +++ b/tests/unit/test_session_get_devices.py @@ -35,6 +35,7 @@ class StubPolling(PollingMixin): p._update_task = None p._last_poll_slow = False p._slow_poll_threshold = 3 + p._stale_state_polls = {} # External dependencies (provided by HiveSession in real code) p.api = MagicMock() @@ -423,3 +424,188 @@ async def poll_that_replaces_task(): # finally block left _update_task alone because it no longer matched # current_task (the False branch — line 113->116) assert p._update_task is sentinel + + +# --------------------------------------------------------------------------- +# get_devices — incomplete product state in an otherwise successful response +# --------------------------------------------------------------------------- + + +def _products_response(*products): + return {"original": 200, "parsed": {"products": list(products)}} + + +class TestGetDevicesIncompleteState: + """A poll that drops state keys must not wipe the last known values.""" + + def _stub(self, state): + p = _make_stub() + p.tokens = MagicMock() + p.data.products = {"heat-1": {"id": "heat-1", "state": dict(state)}} + return p + + async def test_missing_state_key_keeps_previous_value(self): + """state.mode absent from the response keeps the previous mode.""" + p = self._stub({"name": "Hallway", "mode": "OFF", "target": 7}) + p.api.get_all = AsyncMock( + return_value=_products_response( + { + "id": "heat-1", + "type": "heating", + "state": {"name": "Hallway", "target": 20}, + } + ) + ) + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + assert await p.get_devices("No_ID") is True + assert p.data.products["heat-1"]["state"] == { + "name": "Hallway", + "mode": "OFF", + "target": 20, + } + mock_log.warning.assert_called_once() + assert mock_log.warning.call_args.args[1] == ( + "Hallway (heating heat-1) missing mode" + ) + + async def test_warning_lists_every_product_and_missing_key(self): + """One warning per poll names each product and its missing keys.""" + p = self._stub({"mode": "OFF", "target": 7, "boost": None}) + p.data.products["hw-1"] = {"id": "hw-1", "state": {"mode": "OFF"}} + p.api.get_all = AsyncMock( + return_value=_products_response( + {"id": "heat-1", "type": "heating", "state": {"boost": None}}, + {"id": "hw-1", "type": "hotwater"}, + ) + ) + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + await p.get_devices("No_ID") + mock_log.warning.assert_called_once() + assert mock_log.warning.call_args.args[1] == ( + "heat-1 (heating heat-1) missing mode, target; " + "hw-1 (hotwater hw-1) missing mode" + ) + + async def test_debug_logs_the_state_keys_that_arrived(self): + """Debug shows the keys received for an incomplete product, not values.""" + p = self._stub({"mode": "OFF", "target": 7, "boost": None}) + p.api.get_all = AsyncMock( + return_value=_products_response( + {"id": "heat-1", "type": "heating", "state": {"target": 20, "boost": 5}} + ) + ) + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + await p.get_devices("No_ID") + shape_calls = [ + c.args for c in mock_log.debug.call_args_list if "arrived" in c.args[0] + ] + assert len(shape_calls) == 1 + assert shape_calls[0][1:] == ("heating", "heat-1", "boost, target") + + async def test_missing_state_block_keeps_previous_state(self): + """A product with no state block at all keeps the previous state.""" + p = self._stub({"mode": "OFF", "target": 7}) + p.api.get_all = AsyncMock(return_value=_products_response({"id": "heat-1"})) + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"] == {"mode": "OFF", "target": 7} + + async def test_null_value_is_not_treated_as_missing(self): + """A key present with a None value replaces the previous value.""" + p = self._stub({"mode": "OFF", "boost": 30}) + p.api.get_all = AsyncMock( + return_value=_products_response( + {"id": "heat-1", "state": {"mode": "OFF", "boost": None}} + ) + ) + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"] == {"mode": "OFF", "boost": None} + mock_log.warning.assert_not_called() + + async def test_new_product_is_accepted_as_is(self): + """A product with no previous record is stored unchanged.""" + p = self._stub({"mode": "OFF"}) + p.api.get_all = AsyncMock( + return_value=_products_response( + {"id": "heat-1", "state": {"mode": "OFF"}}, + {"id": "heat-2", "state": {"target": 7}}, + ) + ) + await p.get_devices("No_ID") + assert p.data.products["heat-2"]["state"] == {"target": 7} + + async def test_gives_up_after_max_consecutive_incomplete_polls(self): + """A key that stays missing is eventually dropped, not kept forever.""" + from apyhiveapi.session.polling import MAX_STALE_STATE_POLLS + + p = self._stub({"mode": "OFF", "target": 7}) + p.api.get_all = AsyncMock( + side_effect=lambda: _products_response( + {"id": "heat-1", "state": {"target": 7}} + ) + ) + for _ in range(MAX_STALE_STATE_POLLS): + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"]["mode"] == "OFF" + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"] == {"target": 7} + # The shorter state is now the baseline, so the next poll is complete. + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + await p.get_devices("No_ID") + mock_log.warning.assert_not_called() + assert not p._stale_state_polls + + async def test_complete_response_resets_the_count(self): + """A complete response between incomplete ones restarts the count.""" + p = self._stub({"mode": "OFF"}) + p.api.get_all = AsyncMock( + side_effect=[ + _products_response({"id": "heat-1", "state": {}}), + _products_response({"id": "heat-1", "state": {"mode": "MANUAL"}}), + _products_response({"id": "heat-1", "state": {}}), + ] + ) + await p.get_devices("No_ID") + assert p._stale_state_polls == {"heat-1": 1} + await p.get_devices("No_ID") + assert not p._stale_state_polls + await p.get_devices("No_ID") + assert p._stale_state_polls == {"heat-1": 1} + assert p.data.products["heat-1"]["state"] == {"mode": "MANUAL"} + + async def test_optional_key_dropped_by_hive_is_not_carried_over(self): + """Keys Hive may legitimately omit (e.g. boost) are never kept stale.""" + p = self._stub({"mode": "MANUAL", "target": 20, "boost": 30, "hue": 10}) + p.api.get_all = AsyncMock( + return_value=_products_response( + {"id": "heat-1", "state": {"mode": "MANUAL", "target": 20}} + ) + ) + with patch("apyhiveapi.session.polling._LOGGER") as mock_log: + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"] == {"mode": "MANUAL", "target": 20} + mock_log.warning.assert_not_called() + assert not p._stale_state_polls + + async def test_only_required_keys_are_carried_over(self): + """A truncated state keeps required keys but not optional ones.""" + p = self._stub({"mode": "MANUAL", "target": 20, "boost": 30}) + p.api.get_all = AsyncMock( + return_value=_products_response({"id": "heat-1", "state": {}}) + ) + await p.get_devices("No_ID") + assert p.data.products["heat-1"]["state"] == {"mode": "MANUAL", "target": 20} + + async def test_count_is_dropped_for_products_no_longer_returned(self): + """A product that leaves the response does not leave a count behind.""" + p = self._stub({"mode": "OFF"}) + p.api.get_all = AsyncMock( + side_effect=[ + _products_response({"id": "heat-1", "state": {}}), + _products_response({"id": "heat-2", "state": {"mode": "OFF"}}), + ] + ) + await p.get_devices("No_ID") + assert p._stale_state_polls == {"heat-1": 1} + await p.get_devices("No_ID") + assert not p._stale_state_polls