From e0ff224e921c562fad56d3bfa116ea25068ee9e7 Mon Sep 17 00:00:00 2001 From: puddly <32534428+puddly@users.noreply.github.com> Date: Wed, 10 Aug 2022 10:02:55 -0600 Subject: [PATCH 1/3] Explicitly close serial port after connection and startup failures (#481) * Always close the serial port if an error occurs * Use `%r` formatting * Clear `_ezsp` property when closing * Fix unit tests referencing `app._ezsp` after it disappears * Add unit tests * Allow the maximum number of watchdog failures to be configurable --- bellows/config/__init__.py | 2 ++ bellows/ezsp/__init__.py | 31 ++++++++++++++++++++----------- bellows/uart.py | 2 +- bellows/zigbee/application.py | 22 ++++++++++++---------- tests/test_application.py | 6 ++++-- tests/test_ezsp.py | 19 ++++++++++++++++++- 6 files changed, 57 insertions(+), 25 deletions(-) diff --git a/bellows/config/__init__.py b/bellows/config/__init__.py index b6dfd059..6a2fd199 100644 --- a/bellows/config/__init__.py +++ b/bellows/config/__init__.py @@ -19,6 +19,7 @@ CONF_DEVICE_BAUDRATE = "baudrate" CONF_EZSP_CONFIG = "ezsp_config" CONF_EZSP_POLICIES = "ezsp_policies" +CONF_PARAM_MAX_WATCHDOG_FAILURES = "max_watchdog_failures" CONF_PARAM_SRC_RTG = "source_routing" CONF_PARAM_UNK_DEV = "handle_unknown_devices" CONF_FLOW_CONTROL = "flow_control" @@ -36,6 +37,7 @@ CONFIG_SCHEMA = CONFIG_SCHEMA.extend( { vol.Required(CONF_DEVICE): SCHEMA_DEVICE, + vol.Optional(CONF_PARAM_MAX_WATCHDOG_FAILURES, default=4): int, vol.Optional(CONF_PARAM_SRC_RTG, default=False): cv_boolean, vol.Optional(CONF_PARAM_UNK_DEV, default=False): cv_boolean, vol.Optional(CONF_EZSP_CONFIG, default={}): dict, diff --git a/bellows/ezsp/__init__.py b/bellows/ezsp/__init__.py index 06516ba8..74c1ee72 100644 --- a/bellows/ezsp/__init__.py +++ b/bellows/ezsp/__init__.py @@ -7,7 +7,6 @@ import logging from typing import Any, Awaitable, Callable, Dict, List, Tuple, Union -import serial from zigpy.typing import DeviceType from bellows.config import ( @@ -17,7 +16,7 @@ CONF_PARAM_SRC_RTG, SCHEMA_DEVICE, ) -from bellows.exception import APIException, EzspError +from bellows.exception import EzspError import bellows.types as t import bellows.uart @@ -59,7 +58,7 @@ async def probe(cls, device_config: Dict) -> bool | dict[str, int | str | bool]: try: await asyncio.wait_for(ezsp._probe(), timeout=PROBE_TIMEOUT) return config - except (asyncio.TimeoutError, serial.SerialException, APIException) as exc: + except Exception as exc: LOGGER.debug( "Unsuccessful radio probe of '%s' port", device_config[CONF_DEVICE_PATH], @@ -73,19 +72,29 @@ async def probe(cls, device_config: Dict) -> bool | dict[str, int | str | bool]: async def _probe(self) -> None: """Open port and try sending a command""" await self.connect() - await self.reset() - self.close() + + try: + await self.reset() + finally: + self.close() @classmethod async def initialize(cls, zigpy_config: Dict) -> "EZSP": """Return initialized EZSP instance.""" ezsp = cls(zigpy_config[CONF_DEVICE]) await ezsp.connect() - await ezsp.reset() - await ezsp.version() - await ezsp._protocol.initialize(zigpy_config) - if zigpy_config[CONF_PARAM_SRC_RTG]: - await ezsp.set_source_routing() + + try: + await ezsp.reset() + await ezsp.version() + await ezsp._protocol.initialize(zigpy_config) + + if zigpy_config[CONF_PARAM_SRC_RTG]: + await ezsp.set_source_routing() + except Exception: + ezsp.close() + raise + return ezsp async def connect(self) -> None: @@ -216,7 +225,7 @@ def connection_lost(self, exc): LOGGER.debug( "%s connection lost unexpectedly: %s", self._config[CONF_DEVICE_PATH], exc ) - self.enter_failed_state("Serial connection loss: {}".format(exc)) + self.enter_failed_state(f"Serial connection loss: {exc!r}") def enter_failed_state(self, error): """UART received error frame.""" diff --git a/bellows/uart.py b/bellows/uart.py index 86251fa2..38cbfa26 100644 --- a/bellows/uart.py +++ b/bellows/uart.py @@ -204,7 +204,7 @@ async def reset(self): LOGGER.debug("Resetting ASH") if self._reset_future is not None: LOGGER.error( - ("received new reset request while an existing " "one is in progress") + "received new reset request while an existing one is in progress" ) return await self._reset_future diff --git a/bellows/zigbee/application.py b/bellows/zigbee/application.py index f3af3dcd..4219bb69 100644 --- a/bellows/zigbee/application.py +++ b/bellows/zigbee/application.py @@ -17,6 +17,7 @@ import bellows from bellows.config import ( + CONF_PARAM_MAX_WATCHDOG_FAILURES, CONF_PARAM_SRC_RTG, CONF_PARAM_UNK_DEV, CONFIG_SCHEMA, @@ -46,7 +47,6 @@ EZSP_COUNTERS_CLEAR_IN_WATCHDOG_PERIODS = 180 EZSP_DEFAULT_RADIUS = 0 EZSP_MULTICAST_NON_MEMBER_RADIUS = 3 -MAX_WATCHDOG_FAILURES = 4 MFG_ID_RESET_DELAY = 180 RESET_ATTEMPT_BACKOFF_TIME = 5 WATCHDOG_WAKE_PERIOD = 10 @@ -455,6 +455,7 @@ async def disconnect(self): self._reset_task.cancel() if self._ezsp is not None: self._ezsp.close() + self._ezsp = None async def force_remove(self, dev): # This should probably be delivered to the parent device instead @@ -636,7 +637,7 @@ async def _reset_mfg_id(self, mfg_id: int) -> None: def _handle_reset_request(self, error): """Reinitialize application controller.""" - LOGGER.debug("Resetting ControllerApplication. Cause: '%s'", error) + LOGGER.debug("Resetting ControllerApplication. Cause: %r", error) self.controller_event.clear() if self._reset_task: LOGGER.debug("Preempting ControllerApplication reset") @@ -653,8 +654,8 @@ async def _reset_controller_loop(self): break except Exception as exc: LOGGER.warning( - "ControllerApplication reset unsuccessful: %s", - repr(exc), + "ControllerApplication reset unsuccessful: %r", + exc, exc_info=exc, ) await asyncio.sleep(RESET_ATTEMPT_BACKOFF_TIME) @@ -665,7 +666,10 @@ async def _reset_controller_loop(self): async def _reset_controller(self): """Reset Controller.""" - self._ezsp.close() + if self._ezsp is not None: + self._ezsp.close() + self._ezsp = None + await asyncio.sleep(0.5) await self.startup() @@ -957,9 +961,9 @@ async def _watchdog(self): failures = 0 except (asyncio.TimeoutError, EzspError) as exc: - LOGGER.warning("Watchdog heartbeat timeout: %s", str(exc)) + LOGGER.warning("Watchdog heartbeat timeout: %s", repr(exc)) failures += 1 - if failures > MAX_WATCHDOG_FAILURES: + if failures > self.config[CONF_PARAM_MAX_WATCHDOG_FAILURES]: break except asyncio.CancelledError: raise @@ -972,9 +976,7 @@ async def _watchdog(self): await asyncio.sleep(WATCHDOG_WAKE_PERIOD) self.state.counters[COUNTERS_CTRL][COUNTER_WATCHDOG].increment() - self._handle_reset_request( - "Watchdog timeout. Heartbeat timeouts: {}".format(failures) - ) + self._handle_reset_request(f"Watchdog timeout. Heartbeat timeouts: {failures}") async def _get_free_buffers(self) -> Optional[int]: status, value = await self._ezsp.getValue( diff --git a/tests/test_application.py b/tests/test_application.py index 5a4ee99f..99b0227c 100644 --- a/tests/test_application.py +++ b/tests/test_application.py @@ -912,10 +912,11 @@ async def reset_controller_mock(): async def test_reset_controller_routine(app): app._ezsp.reconnect = AsyncMock() app.startup = AsyncMock() + ezsp = app._ezsp await app._reset_controller() - assert app._ezsp.close.call_count == 1 + assert ezsp.close.call_count == 1 assert app.startup.call_count == 1 @@ -1079,6 +1080,7 @@ async def test_shutdown(app): watchdog_f = asyncio.Future() app._reset_task = reset_f app._watchdog_task = watchdog_f + ezsp = app._ezsp await app.shutdown() assert app.controller_event.is_set() is False @@ -1086,7 +1088,7 @@ async def test_shutdown(app): assert reset_f.cancelled() is True assert watchdog_f.done() is True assert watchdog_f.cancelled() is True - assert app._ezsp.close.call_count == 1 + assert ezsp.close.call_count == 1 @pytest.fixture diff --git a/tests/test_ezsp.py b/tests/test_ezsp.py index 1bd25ce5..59b0394a 100644 --- a/tests/test_ezsp.py +++ b/tests/test_ezsp.py @@ -281,7 +281,7 @@ async def test_probe_success(mock_connect, mock_reset): @pytest.mark.parametrize( - "exception", (asyncio.TimeoutError, serial.SerialException, EzspError) + "exception", (asyncio.TimeoutError, serial.SerialException, EzspError, RuntimeError) ) async def test_probe_fail(exception): """Test device probing fails.""" @@ -325,6 +325,23 @@ async def test_ezsp_init( assert src_mock.await_count == 1 +@patch.object(ezsp.EZSP, "version", side_effect=RuntimeError("Uh oh")) +@patch.object(ezsp.EZSP, "reset", new_callable=AsyncMock) +@patch.object(ezsp.EZSP, "close", new_callable=MagicMock) +@patch("bellows.uart.connect", return_value=MagicMock(spec_set=uart.Gateway)) +async def test_ezsp_init_failure(conn_mock, close_mock, reset_mock, version_mock): + """Test initialize method failing.""" + zigpy_config = config.CONFIG_SCHEMA({"device": DEVICE_CONFIG}) + + with pytest.raises(RuntimeError): + await ezsp.EZSP.initialize(zigpy_config) + + assert conn_mock.await_count == 1 + assert reset_mock.await_count == 1 + assert version_mock.await_count == 1 + assert close_mock.call_count == 1 + + async def test_ezsp_newer_version(ezsp_f): """Test newer version of ezsp.""" with patch.object( From 28ee2c700057631d6c46bef466f68e0e0ac25687 Mon Sep 17 00:00:00 2001 From: puddly <32534428+puddly@users.noreply.github.com> Date: Wed, 10 Aug 2022 10:07:30 -0600 Subject: [PATCH 2/3] Probe with 115200 baud first (#480) --- bellows/ezsp/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bellows/ezsp/__init__.py b/bellows/ezsp/__init__.py index 74c1ee72..a0525082 100644 --- a/bellows/ezsp/__init__.py +++ b/bellows/ezsp/__init__.py @@ -53,7 +53,7 @@ def __init__(self, device_config: Dict): @classmethod async def probe(cls, device_config: Dict) -> bool | dict[str, int | str | bool]: """Probe port for the device presence.""" - for config in (device_config, {**device_config, CONF_DEVICE_BAUDRATE: 115200}): + for config in ({**device_config, CONF_DEVICE_BAUDRATE: 115200}, device_config): ezsp = cls(SCHEMA_DEVICE(config)) try: await asyncio.wait_for(ezsp._probe(), timeout=PROBE_TIMEOUT) From 4c8a2a81b836819fddae08426385cfb2b731322d Mon Sep 17 00:00:00 2001 From: puddly <32534428+puddly@users.noreply.github.com> Date: Wed, 10 Aug 2022 10:53:14 -0600 Subject: [PATCH 3/3] 0.32.0 version bump --- bellows/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bellows/__init__.py b/bellows/__init__.py index 4ad2a87d..c3bd5a2c 100644 --- a/bellows/__init__.py +++ b/bellows/__init__.py @@ -1,5 +1,5 @@ MAJOR_VERSION = 0 MINOR_VERSION = 32 -PATCH_VERSION = "0.dev0" +PATCH_VERSION = "0" __short_version__ = f"{MAJOR_VERSION}.{MINOR_VERSION}" __version__ = f"{__short_version__}.{PATCH_VERSION}"