From 59801038add05c24eacae133252ab4450caf5818 Mon Sep 17 00:00:00 2001 From: sdebasek Date: Fri, 21 Aug 2026 13:25:51 +0200 Subject: [PATCH] fix: Correct the supported Home Assistant floor and three cost defects hacs.json declared 2025.2.0, but every platform module imports AddConfigEntryEntitiesCallback, which Home Assistant only gained in 2025.3.0. HACS gates installation on that declared floor, so anyone on the 2025.2 line was allowed to install and then had every platform fail to import, including the event entities, leaving a traceback instead of the clean "needs a newer Home Assistant" message HACS exists to give. The floor was established by resolving every homeassistant import in the package against 2025.2.5 and 2025.3.0 wheels, not by taking the review at its word: that one symbol is the only thing missing at 2025.2.5, and nothing in the import surface pushes it higher. Two CI jobs now keep that honest. One installs the declared minimum and imports every module, so the claim cannot drift again. One runs the suite against the newest Home Assistant, which is what the weekly schedule was documented to do and could not, because the test requirements pin a single version, so every scheduled run re-tested exactly what the last push had. Both are scheduled or manual only, so neither can block a pull request for something a contributor did not do. Setup no longer blocks for twenty seconds on an unreachable device. Provisioning moves off the setup path, so platforms stop queueing behind it, and a device whose shape is already remembered gets a shorter first deadline because that poll is only fetching values the next one will bring anyway. A device nothing is known about deliberately keeps the full deadline: there, the poll is the only thing that can create its entities at all. The slow refresh cadence counted refreshes rather than seconds, so every requested refresh advanced it and metadata was polled more often than its own docstring claimed. It is now measured in elapsed time and named for it. Automatic-mode healing retried forever, one error line and one extra request a minute for as long as the entry existed. It now backs off on repeated failure, keyed on what the attempt would do rather than on the error, so freeing a slot in the wBox app is acted on at the next cycle instead of at the end of the backoff, and a genuinely new problem is never delayed by an old one. CONTRIBUTING no longer claims lint blocks the build, since branch protection decides that and does not currently require it. --- .github/dependabot.yml | 4 +- .github/workflows/validate.yml | 74 +++++++- CONTRIBUTING.md | 36 +++- README.md | 6 +- custom_components/blebox_advanced/__init__.py | 30 ++- .../blebox_advanced/blebox_actions.py | 24 +++ custom_components/blebox_advanced/const.py | 46 ++++- .../blebox_advanced/coordinator.py | 101 +++++++++- hacs.json | 2 +- tests/test_advanced.py | 176 ++++++++++++++++++ tests/test_integration.py | 133 +++++++++++++ tests/test_transport.py | 23 +++ 12 files changed, 628 insertions(+), 27 deletions(-) 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 --------------------------------------------------------------------