diff --git a/.github/dependabot.yml b/.github/dependabot.yml index c9e7eaa..892249e 100644 --- a/.github/dependabot.yml +++ b/.github/dependabot.yml @@ -8,7 +8,9 @@ updates: # There is deliberately no pip entry. requirements-test.txt pins # pytest-homeassistant-custom-component to match one Home Assistant release, # so moving it is a decision about which Home Assistant version to support, - # not a chore to automate. + # not a chore to automate. The `latest HA` job in validate.yml is what says + # whether the newer release is safe to move to, which is the question a + # Dependabot pull request here could not answer. - package-ecosystem: github-actions directory: "/" schedule: diff --git a/.github/workflows/validate.yml b/.github/workflows/validate.yml index 38d3ee4..d94ca8b 100644 --- a/.github/workflows/validate.yml +++ b/.github/workflows/validate.yml @@ -7,9 +7,14 @@ on: branches: [main] pull_request: # Weekly, so a Home Assistant release that breaks the integration is caught - # without waiting for someone to push. + # without waiting for someone to push. Only the `latest HA` job below can + # actually see that: every other job installs a pinned core and would pass on + # Monday for the same reason it passed on the last push. schedule: - cron: "0 4 * * 1" + # So the weekly jobs can be run on demand rather than only on Monday, which + # matters when a Home Assistant beta is already suspected of breaking things. + workflow_dispatch: # Nothing here writes to the repository, so take less than the repository # default may otherwise grant. @@ -78,3 +83,70 @@ jobs: # every honest refactor a CI failure. Raise it when the real figure has # settled well above it, never lower it to make a red build pass. - run: pytest -q --cov-fail-under=95 + + # HACS refuses to install the integration on a core older than hacs.json's + # `homeassistant` key, so that key is a promise that the code imports there. + # It was wrong once already: the declared floor sat at 2025.2.0 while every + # platform imported a name that only exists from 2025.3.0, which HACS turns + # into a traceback on the user's box instead of the "needs a newer Home + # Assistant" message it exists to produce. Nothing else in this workflow can + # notice, because everything else installs one pinned modern core. + minimum-ha: + name: minimum HA + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v7 + - uses: actions/setup-python@v7 + with: + # Home Assistant supports a narrow band of Python versions, so this + # tracks the declared floor rather than the version the other jobs + # use. Move it when the floor moves past what 3.13 can install. + python-version: "3.13" + # Reading the floor back out of hacs.json rather than repeating it here is + # the point: a second pin could drift from the claim it is meant to guard. + - run: pip install "homeassistant==$(python -c 'import json; print(json.load(open("hacs.json"))["homeassistant"])')" + # Importing every module is enough to catch this class of break, because + # the imports that fail are unconditional and at module scope. Running the + # suite here is not, and would fail on unrelated API drift across the year + # or more between the floor and the version the tests are written against. + - run: | + python - <<'PY' + import importlib + import pathlib + import sys + + sys.path.insert(0, ".") + package = "custom_components.blebox_advanced" + for path in sorted(pathlib.Path(package.replace(".", "/")).glob("*.py")): + name = package if path.stem == "__init__" else f"{package}.{path.stem}" + importlib.import_module(name) + print("imported", name) + PY + + # The job the weekly schedule exists for. `tests` above pins + # pytest-homeassistant-custom-component, which pins one exact Home Assistant, + # so it can never see a core release that removed or renamed an API this + # integration uses. This one installs whatever shipped since. + latest-ha: + name: latest HA + # Scheduled and manual only, on purpose. An upstream release breaking the + # integration is not the contributor's fault, and this must never be able to + # redden their pull request. Keeping it off `pull_request` entirely is + # stronger than continue-on-error, which would also hide a real break behind + # a green run. + if: github.event_name == 'schedule' || github.event_name == 'workflow_dispatch' + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v7 + - uses: actions/setup-python@v7 + with: + # Matches `tests`. If Home Assistant outgrows it, pip fails to resolve + # here first, which is itself the signal to bump both. + python-version: "3.14" + # Deliberately not -r requirements-test.txt: that file is what makes this + # run pointless. pytest-cov is named because pytest.ini always measures + # coverage, so the run needs it even though it also arrives transitively. + - run: pip install pytest-homeassistant-custom-component pytest-cov + # No --cov-fail-under: this run is about whether the integration still + # works against current Home Assistant, not about coverage. + - run: pytest -q diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 2d8efc5..795f653 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -32,12 +32,36 @@ ruff check custom_components tests ruff format custom_components tests ``` -CI runs `hassfest`, HACS validation, `ruff check`, `ruff format --check` and the -test suite on every pull request and on every push to `main`, and a lint finding -fails the build like a test does. CI only checks formatting, it does not rewrite -anything, so run `ruff format` yourself. A weekly scheduled run repeats all of -it, which is how a Home Assistant release breaking the integration gets noticed -without anyone pushing. +CI runs `hassfest`, HACS validation, `ruff check`, `ruff format --check`, an +import check against the declared minimum Home Assistant version and the test +suite on every pull request and on every push to `main`. CI only checks +formatting, it does not rewrite anything, so run `ruff format` yourself. + +Which of those actually block a merge is branch protection on `main`, not the +workflow. It currently requires only `hassfest`, `HACS` and `tests`, so a red +`ruff` job shows a failed check and still leaves the merge button live. The +check names that should be marked required are: + +``` +hassfest +HACS +ruff +tests +``` + +`minimum HA` is intentionally not on that list yet. It installs an old Home +Assistant release from PyPI, so an upstream packaging problem could block merges +for a reason that has nothing to do with the change under review. Add it once it +has proved steady. + +The weekly scheduled run adds the one job a pinned build cannot do. `tests` +installs `requirements-test.txt`, which pins one exact Home Assistant, so it +proves the same thing every Monday that it proved on the last push. `latest HA` +installs `pytest-homeassistant-custom-component` unpinned and runs the suite +against whatever Home Assistant has shipped since, which is how a core release +breaking the integration gets noticed without anyone pushing. It runs only on +the schedule and on `workflow_dispatch`, never on a pull request, because an +upstream break is not the contributor's to fix under review. ## Commit messages diff --git a/README.md b/README.md index 50fbfe5..14bcff3 100644 --- a/README.md +++ b/README.md @@ -65,8 +65,10 @@ and `actionBox` hardware should work too. ## Installation -Requires Home Assistant **2025.2.0** or newer. No cloud account, no BleBox app, -nothing exposed to the internet. +Requires Home Assistant **2025.3.0** or newer. Older cores are missing an +entity-platform API that every platform here imports, so the integration cannot +load at all on them, not even the button events. No cloud account, no BleBox +app, nothing exposed to the internet. ### HACS diff --git a/custom_components/blebox_advanced/__init__.py b/custom_components/blebox_advanced/__init__.py index 0693801..88b6c3e 100644 --- a/custom_components/blebox_advanced/__init__.py +++ b/custom_components/blebox_advanced/__init__.py @@ -32,6 +32,7 @@ DEFAULT_PORT, DOMAIN, MODE_MANUAL, + SETUP_REFRESH_TIMEOUT_S, ) from .coordinator import ( BleBoxEventsConfigEntry, @@ -92,11 +93,34 @@ async def async_setup_entry( # Setup deliberately does not depend on the device answering. A device that # is asleep, moved or on a temporarily unreachable VLAN must not remove the # event entities, and manually configured callbacks keep arriving. - await coordinator.async_refresh() + # + # It should not spend long finding that out, either. The platforms decide + # what to create by inspecting `coordinator.data`, so this poll is only + # load-bearing while nothing is known about the device yet; once its shape + # has been remembered, the entities exist either way and the poll is asked + # for its values on a shorter deadline (`SETUP_REFRESH_TIMEOUT_S`). + if coordinator.data is None: + await coordinator.async_refresh() + else: + with manager.request_timeout(SETUP_REFRESH_TIMEOUT_S): + await coordinator.async_refresh() snapshot = coordinator.data - await async_apply_provisioning( - hass, entry, state=snapshot.actions if snapshot else None + # Nothing in platform setup depends on the device having been provisioned: + # healing does not start until it has been attempted (see `_async_heal`), + # and a manual callback never needed it at all. On an unreachable device it + # is a second full timeout, and on a healthy first-time one it is nine round + # trips, so it runs alongside the platforms rather than in front of them. + # + # Tracked on the entry rather than backgrounded: unloading waits for a + # tracked task but cancels a background one, and a provisioning run cut off + # partway through leaves the device's slot table half written. + entry.async_create_task( + hass, + async_apply_provisioning( + hass, entry, state=snapshot.actions if snapshot else None + ), + "provisioning", ) if snapshot is None: diff --git a/custom_components/blebox_advanced/blebox_actions.py b/custom_components/blebox_advanced/blebox_actions.py index a1fe661..2584ed5 100644 --- a/custom_components/blebox_advanced/blebox_actions.py +++ b/custom_components/blebox_advanced/blebox_actions.py @@ -35,6 +35,8 @@ import asyncio import logging +from collections.abc import Iterator +from contextlib import contextmanager from dataclasses import dataclass, field from typing import Any @@ -560,6 +562,28 @@ def base_url(self) -> str: return f"http://{self._host}:{self._port}" return f"http://{self._host}" + @contextmanager + def request_timeout(self, seconds: float) -> Iterator[None]: + """Run the requests made inside this block on a shorter deadline. + + The device timeout is deliberately generous, because an ESP-based device + on a busy Wi-Fi link is genuinely slow sometimes and giving up on it is + worse than waiting. There is one caller for whom that is the wrong trade + - setting a config entry up, where the answer is only needed to put live + values on entities that already exist - so it asks for a shorter one + rather than every other caller settling for it. + + Not reentrant, and not safe to hold across a caller that must keep the + full deadline: it swaps the deadline for the whole manager, and requests + already in flight keep the one they started with. + """ + previous = self._timeout + self._timeout = aiohttp.ClientTimeout(total=seconds) + try: + yield + finally: + self._timeout = previous + # -- transport ---------------------------------------------------------- async def _get(self, path: str) -> Any: diff --git a/custom_components/blebox_advanced/const.py b/custom_components/blebox_advanced/const.py index 7ed3c4f..6e44715 100644 --- a/custom_components/blebox_advanced/const.py +++ b/custom_components/blebox_advanced/const.py @@ -27,12 +27,48 @@ responsive here as it is there. Input events are pushed and never polled for. """ -SLOW_REFRESH_EVERY: Final = 12 -"""Fetch settings, actions and uptime once every N state polls (5s x 12 = 1min). +SETUP_REFRESH_TIMEOUT_S: Final = 3 +"""Deadline for the first poll when the device's shape is already remembered. + +Setting an entry up deliberately does not depend on the device answering, but +it still waited the whole device timeout to find that out, and until it had, not +one entity existed. Where ``CONF_DEVICE_CACHE`` already says what this device +has, that wait buys values and nothing else, and the ordinary poll five seconds +later fetches those anyway - so a device that is not there is given up on +sooner, and the entities it had come up unavailable rather than late. + +A device that has never answered gets the full deadline instead: there the first +poll is the only thing that can create its entities at all. +""" + +SLOW_REFRESH_SECONDS: Final = 60 +"""How long between fetches of everything that is not relay and power state. + +A full cycle costs five extra requests - device identity, action slots, +settings, network and uptime - and none of those changes on its own more than +occasionally, so polling them at the state cadence would be wasteful. + +Measured as elapsed time rather than counted state polls. Entities ask for an +extra refresh whenever they write a setting or predict a relay move, and a +counter advanced on those too: a device whose button was in regular use polled +its metadata about twice as often as this says, which made the interval depend +on how much the household used the switch. A settings write still forces a full +refresh outright, so the cadence never delays a change made from Home Assistant. +""" + +HEAL_BACKOFF_MAX_CYCLES: Final = 60 +"""Longest gap between retries of a repair that keeps failing, in slow cycles. + +Restoring callbacks that have gone missing is retried on the slow cycle, and +some failures cannot be cleared from Home Assistant at all - the documented one +is a device whose action slots are full of actions the user configured +themselves. Retrying that every cycle for as long as the entry is loaded costs a +request and an error log line a minute, forever, and fixes nothing, so retries +back off exponentially to at most about an hour. -These change rarely and cost an extra three requests, so polling them at the -state cadence would be wasteful. A settings write forces a full refresh anyway, -so the slow cycle never delays a change made from Home Assistant. +The backoff is not a way of waiting for the problem to go away: anything that +changes what the retry would actually do - a slot freed in the wBox app, a +different callback going missing - drops it and retries on the next cycle. """ WRITE_SETTLE_S: Final = 5.0 diff --git a/custom_components/blebox_advanced/coordinator.py b/custom_components/blebox_advanced/coordinator.py index 02f449c..6d689d4 100644 --- a/custom_components/blebox_advanced/coordinator.py +++ b/custom_components/blebox_advanced/coordinator.py @@ -41,11 +41,12 @@ CONF_DEVICE_CACHE, CONF_ENABLED_EVENTS, DOMAIN, + HEAL_BACKOFF_MAX_CYCLES, MODE_AUTOMATIC, SCAN_INTERVAL_SECONDS, SETTING_POWER_MEASURING, SETTING_RELAYS, - SLOW_REFRESH_EVERY, + SLOW_REFRESH_SECONDS, WRITE_SETTLE_S, ) @@ -434,18 +435,28 @@ async def async_apply_provisioning( try: result = await async_provision_entry(hass, entry, state=state) except InsufficientSlotsError as err: + # Only the first of a run of identical failures is logged as one. This + # is retried on a timer, and a message asking the user to go and free a + # slot loses all its force repeated once a minute for as long as Home + # Assistant runs - it buries itself along with everything else in the + # log. A different message, or the same one after a spell of working, + # is a fresh problem and says so. + repeated = status.error == str(err) status.error = str(err) status.result = None - _LOGGER.error( + _LOGGER.log( + logging.DEBUG if repeated else logging.ERROR, "%s: %s. Free some action slots in the wBox app, or switch this " "integration to manual mode", data.device_name, err, ) except BleBoxError as err: + repeated = status.error == str(err) status.error = str(err) status.result = None - _LOGGER.warning( + _LOGGER.log( + logging.DEBUG if repeated else logging.WARNING, "%s: automatic action configuration failed (%s). Existing device " "configuration was left untouched; manual callbacks still work", data.device_name, @@ -486,11 +497,20 @@ def __init__( update_interval=timedelta(seconds=SCAN_INTERVAL_SECONDS), ) self.manager = manager - self._cycle = 0 + # When the slow fetches last landed, so their cadence is elapsed time + # rather than a count of refreshes. `None` means "not yet", which makes + # the first refresh a full one. + self._last_full: float | None = None self._force_full = False self._written: dict[str, _WrittenPayload] = {} self._cached_signature: tuple[Any, ...] | None = None + # What the last repair attempt was for, and how it has been going. See + # `_async_heal_due`. + self._heal_attempt: tuple[Any, ...] | None = None + self._heal_failures = 0 + self._heal_skipped = 0 + # Seeded before the first refresh, because platform setup decides what # to create by inspecting `coordinator.data` and would otherwise create # nothing at all for a device that is not answering right now. @@ -619,7 +639,14 @@ def _async_expire_written(self) -> None: async def _async_update_data(self) -> DeviceSnapshot: """Fetch relay state every cycle, everything else occasionally.""" previous = self.data or DeviceSnapshot() - full = self._force_full or self._cycle == 0 + # Taken once, and taken before the requests, so a cycle's cost does not + # push the next one out and the cadence stays on the poll grid. + now = time.monotonic() + full = ( + self._force_full + or self._last_full is None + or now - self._last_full >= SLOW_REFRESH_SECONDS + ) try: state = await self.manager.async_get_extended_state() @@ -630,7 +657,6 @@ async def _async_update_data(self) -> DeviceSnapshot: raise UpdateFailed(f"Could not reach the device: {err}") from err if not full: - self._cycle = (self._cycle + 1) % SLOW_REFRESH_EVERY self._async_expire_written() return replace(previous, state=state) @@ -681,9 +707,10 @@ async def _async_update_data(self) -> DeviceSnapshot: self._async_update_issues(health) # Only now that the slow fetches have actually landed: anything raising - # above leaves the request pending so the next poll picks it up. + # above leaves the request pending so the next poll picks it up, and + # leaves the cadence measured from the last cycle that really happened. self._force_full = False - self._cycle = (self._cycle + 1) % SLOW_REFRESH_EVERY + self._last_full = now self._async_expire_written() snapshot = DeviceSnapshot( info=info, @@ -818,6 +845,29 @@ async def _async_heal(self, actions: ActionsState | None) -> None: if (item.input_id, item.trigger_type, item.url) not in present ] if not missing: + # Nothing to repair, so nothing to hold against the next repair: a + # problem arising later is a new one and gets tried at once rather + # than at the tail of a backoff earned by an older failure. + self._heal_attempt = None + self._heal_failures = 0 + return + + # Keyed on what this attempt would do rather than on the failure it hit: + # the callbacks that are absent, and the slot layout they have to fit + # into. The user freeing a slot in the wBox app - the fix the error + # message asks for - changes that key. + attempt = ( + tuple((item.input_id, item.trigger_type, item.url) for item in missing), + tuple( + ( + action.get("triggerType"), + action.get("actionType"), + action.get("param"), + ) + for action in actions.actions + ), + ) + if not self._async_heal_due(attempt): return _LOGGER.info( @@ -826,3 +876,38 @@ async def _async_heal(self, actions: ActionsState | None) -> None: len(missing), ) await async_apply_provisioning(self.hass, entry, state=actions) + if data.provisioning.error is None: + self._heal_failures = 0 + else: + # Bounded, because it is an exponent below and an entry can stay + # loaded for months. + self._heal_failures = min(self._heal_failures + 1, HEAL_BACKOFF_MAX_CYCLES) + + @callback + def _async_heal_due(self, attempt: tuple[Any, ...]) -> bool: + """Whether to make this repair attempt now, given how the last ones went. + + A repair that cannot succeed - most often a device with no free action + slot left, which only the user can clear - would otherwise be retried + every cycle for as long as the entry is loaded, costing a request and an + error log line a minute and fixing nothing. So consecutive failures at + the same attempt back off exponentially, up to `HEAL_BACKOFF_MAX_CYCLES`. + + The backoff never outlives the situation it was earned in: an attempt + that differs from the last one, in either the callbacks it would write + or the slot layout it would write them into, starts from zero. + """ + if attempt != self._heal_attempt: + self._heal_attempt = attempt + self._heal_failures = 0 + self._heal_skipped = 0 + return True + if not self._heal_failures: + return True + + due_after = min(2 ** (self._heal_failures - 1), HEAL_BACKOFF_MAX_CYCLES) + if self._heal_skipped < due_after: + self._heal_skipped += 1 + return False + self._heal_skipped = 0 + return True diff --git a/hacs.json b/hacs.json index 5c1c981..5803901 100644 --- a/hacs.json +++ b/hacs.json @@ -1,5 +1,5 @@ { "name": "BleBox Advanced", - "homeassistant": "2025.2.0", + "homeassistant": "2025.3.0", "render_readme": true } diff --git a/tests/test_advanced.py b/tests/test_advanced.py index e3e0732..c1b3c01 100644 --- a/tests/test_advanced.py +++ b/tests/test_advanced.py @@ -59,9 +59,11 @@ HA_EVENT, MODE_AUTOMATIC, MODE_MANUAL, + SCAN_INTERVAL_SECONDS, SETTING_BACKLIGHT, SETTING_RELAYS, SIGNAL_INPUT_EVENT, + SLOW_REFRESH_SECONDS, ) from custom_components.blebox_advanced.coordinator import callback_health @@ -1395,6 +1397,50 @@ async def test_a_failed_poll_keeps_a_requested_full_refresh_pending( assert hass.states.get(entity_id).state == "on" +async def test_the_slow_cycle_is_measured_in_time_not_in_refreshes( + hass: HomeAssistant, +) -> None: + """Device metadata is polled on a clock, whatever else asks for a refresh. + + Regression: the slow cycle counted refreshes rather than seconds, and a + settings write and a press the device answers by moving its relay both ask + for one. A device whose button was in regular use therefore re-read its + settings, slots, network, identity and uptime about twice as often as the + minute the interval promises - so how often it polled came down to how much + the household used the switch. + """ + entry = _entry() + await _setup_with(hass, entry) + coordinator = entry.runtime_data.coordinator + + # More refreshes than the minute holds polls, and not a second passing. + with ( + _reads(), + patch(f"{MANAGER}.async_get_settings", return_value=dict(SETTINGS)) as settings, + ): + for _ in range(SLOW_REFRESH_SECONDS // SCAN_INTERVAL_SECONDS + 4): + await coordinator.async_refresh() + await hass.async_block_till_done() + + assert settings.call_count == 0, "the cadence still counts refreshes" + + with ( + _reads(), + patch(f"{MANAGER}.async_get_settings", return_value=dict(SETTINGS)) as settings, + patch( + f"{COORDINATOR}.time.monotonic", + return_value=time.monotonic() + SLOW_REFRESH_SECONDS, + ), + ): + await coordinator.async_refresh() + await coordinator.async_refresh() + await hass.async_block_till_done() + + # The minute is up, so the first of those two is a full cycle. Only the + # first: the second one happens at the same instant. + assert settings.call_count == 1 + + # --- self-healing of the device's callbacks --------------------------------- # # The switch is not the only thing that writes its action slots: so does the @@ -1646,6 +1692,136 @@ async def test_nothing_is_healed_without_a_home_assistant_url( assert coordinator.last_update_success is True +# --- a repair that cannot succeed ------------------------------------------- +# +# Healing is unattended and runs for as long as the entry is loaded, so a +# failure it cannot do anything about is not a one-off: it is the same failure +# every cycle, forever, on a device the user may well never look at again. + +CROWDED_SLOTS = 6 +"""Every slot the fixture device has, and every one of them the user's own.""" + + +def _slot_index(action: dict[str, Any]) -> int: + """Return an action's slot id, which is where it sits on the device.""" + return int(action["id"]) + + +def _no_free_slots() -> ActionsState: + """Return a device whose action slots are full of the user's own actions. + + The documented dead end: none of these is ours to touch, so there is nothing + the integration can free and no amount of retrying will make room. A stock + two-input switch with short and long press bound natively is already using + four of its six. + """ + return _actions_state( + [ + _slot( + index, + name=f"Toggle {index}", + input=index % 2, + triggerType=TRIGGER_SHORT_CLICK, + actionType=ACTION_RELAY_TOGGLE, + ) + for index in range(CROWDED_SLOTS) + ] + ) + + +async def _heal_cycles( + hass: HomeAssistant, + entry: MockConfigEntry, + state: ActionsState, + cycles: int, +) -> tuple[int, int]: + """Run `cycles` full refreshes against `state`, in automatic mode. + + Returns how many repairs were attempted and how many callbacks were written. + The attempts are counted from the device reads: one per cycle is the poll's + own, and every extra one is the reconciler re-reading the slots under its + lock, which it only does when it has been asked to fix something. + """ + coordinator = entry.runtime_data.coordinator + with ( + _device_reads(), + patch(f"{MANAGER}.async_get_actions_state", return_value=state) as read, + patch(f"{MANAGER}.async_save_action") as save, + ): + for _ in range(cycles): + coordinator.async_request_full_refresh() + await coordinator.async_refresh() + await hass.async_block_till_done() + return read.call_count - cycles, save.call_count + + +async def test_a_repair_that_cannot_succeed_backs_off( + hass: HomeAssistant, caplog: pytest.LogCaptureFixture +) -> None: + """A device with no room for our callbacks is not retried every minute. + + Regression: healing recomputed the same missing callbacks every cycle and + asked for the same impossible run each time, so a device the user cannot + make room on produced one extra request and one identical ERROR line a + minute for as long as the entry was loaded - some 1400 a day, burying the + one message they actually have to act on along with everything else. + """ + crowded = _no_free_slots() + entry = _entry(mode=MODE_AUTOMATIC) + await _setup(hass, entry, crowded) + + # Said once, in full, and actionable: what it needs, what is free, and the + # two ways out. + assert [ + message + for message in _errors(caplog) + if "free action slot" in message and "wBox app" in message + ] + + caplog.clear() + attempts, written = await _heal_cycles(hass, entry, crowded, cycles=8) + + # Retried at the first cycle, the third and the sixth: 1, 2 then 4 cycles + # apart. Backing off, but never giving up - the user may still free a slot. + assert attempts == 3 + assert written == 0, "a run that cannot fit must change nothing" + # And repeating itself in the log is not how it waits. + assert not _errors(caplog) + + +async def test_room_appearing_on_the_device_is_used_at_once( + hass: HomeAssistant, +) -> None: + """Freeing a slot in the wBox app is acted on next cycle, not next backoff. + + The backoff is a way of not repeating pointless work, not a way of waiting + for the problem to go away. The user frees a slot precisely because the log + told them to, so a fix that only took effect an hour later would read as the + integration ignoring them. + """ + crowded = _no_free_slots() + entry = _entry(mode=MODE_AUTOMATIC) + await _setup(hass, entry, crowded) + + # Long enough to be deep into the backoff: the next attempt would otherwise + # be four cycles away. + attempts, _ = await _heal_cycles(hass, entry, crowded, cycles=6) + assert attempts == 3 + + # Three slots cleared in the wBox app, which is exactly what it asked for. + roomy = _actions_state( + [action for action in crowded.actions if _slot_index(action) < 3] + ) + attempts, written = await _heal_cycles(hass, entry, roomy, cycles=1) + assert attempts == 1 + assert written == len(OUR_CALLBACKS), "the callbacks were not restored" + + # A repair that worked is not held against the next one either: the device + # is still reporting them missing, so they are written again. + attempts, written = await _heal_cycles(hass, entry, roomy, cycles=1) + assert (attempts, written) == (1, len(OUR_CALLBACKS)) + + # --- device triggers -------------------------------------------------------- diff --git a/tests/test_integration.py b/tests/test_integration.py index 3d1e51a..acb2bf3 100644 --- a/tests/test_integration.py +++ b/tests/test_integration.py @@ -8,6 +8,7 @@ from __future__ import annotations +import asyncio import dataclasses from contextlib import ExitStack from datetime import timedelta @@ -57,6 +58,7 @@ MODE_MANUAL, RESTART_STATE_RESTORE, SCAN_INTERVAL_SECONDS, + SETUP_REFRESH_TIMEOUT_S, ) BLEBOX_ID = "ae0bfbf927ba" @@ -552,6 +554,137 @@ async def test_setup_survives_an_unreachable_device(hass: HomeAssistant) -> None await hass.async_block_till_done() +# --- what setup is prepared to wait for ------------------------------------- +# +# Setting an entry up must survive an unreachable device (above), which means +# every read it makes can only end by timing out. Each one of those is ten +# seconds during which this entry has no entities at all, so what setup waits +# for is a design decision rather than an ordering accident. + +SETUP_MUST_NOT_BLOCK_S = 5 +"""How long a test lets setup run before calling it blocked. + +Generous, because it is only ever reached when something is wrong: the point of +the deadline is that a regression fails the test instead of hanging the suite. +""" + +ORDINARY_DEADLINE_S = 10 +"""The deadline `BleBoxActionManager` gives every request of its own accord.""" + + +async def test_setup_does_not_wait_for_the_devices_action_slots( + hass: HomeAssistant, +) -> None: + """Provisioning is not allowed to hold the platforms up. + + Regression: an unreachable device cost setup two full timeouts in a row, + because provisioning ran inline and, with no action slots in the failed + poll to work from, went and asked the device for them itself. Nothing in + platform setup needs that answer - healing does not start until provisioning + has been attempted, and manual callbacks never needed it - so twenty seconds + passed before this entry had a single entity. + """ + answered = asyncio.Event() + + async def _answers_only_when_released(*_args: Any, **_kwargs: Any) -> ActionsState: + await answered.wait() + raise BleBoxConnectionError("down") + + entry = _entry(mode=MODE_AUTOMATIC) + entry.add_to_hass(hass) + with ( + _unreachable(), + patch(f"{MANAGER}.async_get_actions_state", _answers_only_when_released), + patch(f"{MANAGER}.async_save_action"), + ): + async with asyncio.timeout(SETUP_MUST_NOT_BLOCK_S): + assert await hass.config_entries.async_setup(entry.entry_id) + + # Reached with the device still not having answered, so these exist + # despite it: that is the whole claim. + assert hass.states.get(_entity_id(hass, 0)) is not None + + answered.set() + await hass.async_block_till_done() + await hass.config_entries.async_unload(entry.entry_id) + await hass.async_block_till_done() + + +async def test_a_remembered_device_is_given_a_shorter_first_deadline( + hass: HomeAssistant, +) -> None: + """A device whose shape is known is not waited out for the full timeout. + + Regression: the first poll always ran on the ordinary ten-second deadline, + so restarting Home Assistant while the switch was unreachable - the exact + case `CONF_DEVICE_CACHE` exists for - left the entry with no entities for + ten seconds, to establish something the entry already knew. The poll is only + being asked for values here, and the ordinary poll five seconds later + fetches those anyway. + """ + entry = _entry() + await _setup(hass, entry) + assert entry.data[CONF_DEVICE_CACHE], "nothing was remembered while it answered" + + deadlines: list[float | None] = [] + + async def _record_the_deadline(manager: Any, *_args: Any, **_kwargs: Any) -> None: + # Which deadline is in force is the manager's business and it offers no + # way to ask, but it is exactly what this test is about. + deadlines.append(manager._timeout.total) + raise BleBoxConnectionError("down") + + with ( + _unreachable(), + patch(f"{MANAGER}.async_get_extended_state", _record_the_deadline), + ): + # A reload is a restart for this purpose: a new coordinator, seeded from + # what the entry remembers before it polls anything. + await hass.config_entries.async_reload(entry.entry_id) + await hass.async_block_till_done() + + assert deadlines == [SETUP_REFRESH_TIMEOUT_S] + # And only for that one poll: everything after it is a device read like + # any other, and giving up early on those would be a regression of its + # own. + assert entry.runtime_data.manager._timeout.total == ORDINARY_DEADLINE_S + + await hass.config_entries.async_unload(entry.entry_id) + await hass.async_block_till_done() + + +async def test_a_device_nothing_is_known_about_is_worth_waiting_for( + hass: HomeAssistant, +) -> None: + """The first poll of an unknown device keeps the full deadline. + + Deliberate asymmetry with the test above. Nothing has ever observed what + this device has, so this poll is the only thing that can create its polled + entities at all: giving up on it early would trade ten seconds of setup for + a device that comes up with no entities and stays that way until the user + reloads it by hand. + """ + deadlines: list[float | None] = [] + + async def _record_the_deadline(manager: Any, *_args: Any, **_kwargs: Any) -> None: + deadlines.append(manager._timeout.total) + raise BleBoxConnectionError("down") + + entry = _entry() + entry.add_to_hass(hass) + with ( + _unreachable(), + patch(f"{MANAGER}.async_get_extended_state", _record_the_deadline), + ): + assert await hass.config_entries.async_setup(entry.entry_id) + await hass.async_block_till_done() + + assert deadlines == [ORDINARY_DEADLINE_S] + + await hass.config_entries.async_unload(entry.entry_id) + await hass.async_block_till_done() + + async def test_unload_stops_accepting_callbacks( hass: HomeAssistant, hass_client_no_auth ) -> None: diff --git a/tests/test_transport.py b/tests/test_transport.py index a9205e3..c8e2031 100644 --- a/tests/test_transport.py +++ b/tests/test_transport.py @@ -346,6 +346,29 @@ async def never_answers(_request: web.Request) -> web.Response: release.set() +async def test_a_shorter_deadline_lasts_only_as_long_as_the_block() -> None: + """`request_timeout` narrows the deadline, then hands it back. + + Setting a config entry up uses this for its first poll: it needs an answer + from an entity's point of view rather than a device's, and the entities are + there either way. Every other caller has to keep the generous deadline, + because an ESP-based device on a busy link really is slow sometimes and + giving up on one is worse than waiting for it. + """ + slow = 0.15 + + async def answers_eventually(_request: web.Request) -> web.Response: + await asyncio.sleep(slow) + return web.Response(text=json.dumps(EXTENDED_STATE)) + + device = DeviceServer({"/state/extended": answers_eventually}) + async with connected(device, timeout=5) as manager: + with manager.request_timeout(slow / 10), pytest.raises(BleBoxConnectionError): + await manager.async_get_extended_state() + + assert await manager.async_get_extended_state() == EXTENDED_STATE + + # --- POST --------------------------------------------------------------------