diff --git a/pyproject.toml b/pyproject.toml index 24c596d..55f298e 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -14,8 +14,8 @@ readme = "README.md" license = {text = "GPL-3.0"} requires-python = ">=3.8" dependencies = [ - "zigpy>=0.70.0", - "async_timeout", + "zigpy>=0.78.0", + 'async-timeout; python_version<"3.11"', "voluptuous", "coloredlogs", "jsonschema", diff --git a/tests/api/test_request.py b/tests/api/test_request.py index a87fe30..1f46747 100644 --- a/tests/api/test_request.py +++ b/tests/api/test_request.py @@ -1,8 +1,13 @@ +import sys import asyncio import logging import pytest -import async_timeout + +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover import zigpy_znp.types as t import zigpy_znp.config as conf @@ -66,7 +71,7 @@ async def test_cleanup_timeout_external(connected_znp): # This request will timeout because we didn't send anything back with pytest.raises(asyncio.TimeoutError): - async with async_timeout.timeout(0.1): + async with asyncio_timeout(0.1): await znp.request(c.UTIL.TimeAlive.Req()) # We should be cleaned up @@ -80,7 +85,7 @@ async def test_callback_rsp_cleanup_timeout_external(connected_znp): # This request will timeout because we didn't send anything back with pytest.raises(asyncio.TimeoutError): - async with async_timeout.timeout(0.1): + async with asyncio_timeout(0.1): await znp.request_callback_rsp( request=c.UTIL.TimeAlive.Req(), callback=c.SYS.ResetInd.Callback(partial=True), @@ -262,7 +267,7 @@ async def test_znp_sreq_srsp(connected_znp): # Each SREQ must have a corresponding SRSP, so this will fail with pytest.raises(asyncio.TimeoutError): - async with async_timeout.timeout(0.5): + async with asyncio_timeout(0.5): await znp.request(c.SYS.Ping.Req()) # This will work diff --git a/tests/api/test_response.py b/tests/api/test_response.py index d8ffad4..5d683ae 100644 --- a/tests/api/test_response.py +++ b/tests/api/test_response.py @@ -1,7 +1,12 @@ +import sys import asyncio import pytest -import async_timeout + +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover import zigpy_znp.types as t import zigpy_znp.commands as c @@ -61,7 +66,7 @@ async def send_soon(delay): asyncio.create_task(send_soon(0.1)) - async with async_timeout.timeout(0.5): + async with asyncio_timeout(0.5): assert (await znp.wait_for_response(c.SYS.Ping.Rsp(partial=True))) == response # The response was successfully received so we should have no outstanding listeners @@ -71,7 +76,7 @@ async def send_soon(delay): asyncio.create_task(send_soon(0.6)) with pytest.raises(asyncio.TimeoutError): - async with async_timeout.timeout(0.5): + async with asyncio_timeout(0.5): assert ( await znp.wait_for_response(c.SYS.Ping.Rsp(partial=True)) ) == response diff --git a/tests/application/test_joining.py b/tests/application/test_joining.py index ba50d98..587db09 100644 --- a/tests/application/test_joining.py +++ b/tests/application/test_joining.py @@ -205,6 +205,8 @@ async def test_on_zdo_device_join(device, make_application, mocker): app.handle_join.assert_called_once_with(nwk=nwk, ieee=ieee, parent_nwk=0x0001) + app.get_device(nwk=0x1234).cancel_initialization() + await app.shutdown() @@ -269,9 +271,6 @@ async def test_on_zdo_device_join_and_announce_fast(device, make_application, mo app.get_device(ieee=ieee).cancel_initialization() await app.shutdown() - with pytest.raises(asyncio.CancelledError): - await app.get_device(ieee=ieee)._initialize_task - @mock.patch("zigpy_znp.zigbee.application.DEVICE_JOIN_MAX_DELAY", new=0.1) @mock.patch( diff --git a/tests/application/test_requests.py b/tests/application/test_requests.py index c17765a..4c7e4dc 100644 --- a/tests/application/test_requests.py +++ b/tests/application/test_requests.py @@ -10,7 +10,6 @@ import zigpy_znp.types as t import zigpy_znp.config as conf import zigpy_znp.commands as c -from zigpy_znp.exceptions import InvalidCommandResponse from ..conftest import ( FORMED_DEVICES, @@ -145,10 +144,10 @@ async def test_zigpy_request_failure(device, make_application, mocker): mocker.spy(app, "send_packet") # Fail to turn on the light - with pytest.raises(InvalidCommandResponse): + with pytest.raises(DeliveryError): await device.endpoints[1].on_off.on() - assert app.send_packet.call_count == 1 + assert app.send_packet.call_count >= 1 await app.shutdown() @@ -425,7 +424,7 @@ async def inner(): asyncio.create_task(inner()) - data_req = znp_server.reply_once_to( + znp_server.reply_to( c.AF.DataRequestExt.Req(partial=True), responses=[ c.AF.DataRequestExt.Rsp(Status=t.Status.SUCCESS), @@ -444,7 +443,6 @@ async def inner(): data=b"\x00", ) - await data_req await delayed_reply_sent assert app._znp._unhandled_command.call_count == 0 @@ -532,9 +530,6 @@ def set_route_discovered(req): await was_route_discovered await zdo_req - # 6 accounts for the loopback requests - assert sum(c.value for c in app.state.counters["Retry_NONE"].values()) == 6 + 1 - await app.shutdown() @@ -583,15 +578,6 @@ def set_route_discovered(req): ], ) - # Ignore the source routing request as well - znp_server.reply_to( - c.AF.DataRequestSrcRtg.Req(partial=True), - responses=[ - c.AF.DataRequestSrcRtg.Rsp(Status=t.Status.SUCCESS), - data_confirm_replier, - ], - ) - await app.request( device=device, profile=260, @@ -603,75 +589,6 @@ def set_route_discovered(req): ) await was_route_discovered - assert ( - sum(c.value for c in app.state.counters["Retry_RouteDiscovery"].values()) == 1 - ) - - await app.shutdown() - - -@pytest.mark.parametrize("device", [FormedLaunchpadCC26X2R1]) -async def test_request_recovery_use_ieee_addr(device, make_application, mocker): - app, znp_server = make_application(server_cls=device) - - await app.startup(auto_form=False) - - # The data confirm timeout must be shorter than the ARSP timeout - mocker.patch("zigpy_znp.zigbee.application.DATA_CONFIRM_TIMEOUT", new=0.1) - app._znp._config[conf.CONF_ZNP_CONFIG][conf.CONF_ARSP_TIMEOUT] = 1 - - device = app.add_initialized_device(ieee=t.EUI64(range(8)), nwk=0xABCD) - - was_ieee_addr_used = False - - def data_confirm_replier(req): - nonlocal was_ieee_addr_used - - if req.DstAddrModeAddress.mode == t.AddrMode.IEEE: - status = t.Status.SUCCESS - was_ieee_addr_used = True - else: - status = t.Status.MAC_NO_ACK - - return c.AF.DataConfirm.Callback(Status=status, Endpoint=1, TSN=1) - - znp_server.reply_once_to( - c.ZDO.ExtRouteDisc.Req( - Dst=device.nwk, Options=c.zdo.RouteDiscoveryOptions.UNICAST, partial=True - ), - responses=[c.ZDO.ExtRouteDisc.Rsp(Status=t.Status.SUCCESS)], - ) - - znp_server.reply_to( - c.AF.DataRequestExt.Req(partial=True), - responses=[ - c.AF.DataRequestExt.Rsp(Status=t.Status.SUCCESS), - data_confirm_replier, - ], - ) - - # Ignore the source routing request as well - znp_server.reply_to( - c.AF.DataRequestSrcRtg.Req(partial=True), - responses=[ - c.AF.DataRequestSrcRtg.Rsp(Status=t.Status.SUCCESS), - c.AF.DataConfirm.Callback(Status=t.Status.MAC_NO_ACK, Endpoint=1, TSN=1), - ], - ) - - await app.request( - device=device, - profile=260, - cluster=1, - src_ep=1, - dst_ep=1, - sequence=1, - data=b"\x00", - ) - - assert was_ieee_addr_used - assert sum(c.value for c in app.state.counters["Retry_IEEEAddress"].values()) == 1 - await app.shutdown() @@ -686,7 +603,6 @@ async def test_request_recovery_assoc_remove( await app.startup(auto_form=False) mocker.patch("zigpy_znp.zigbee.application.DATA_CONFIRM_TIMEOUT", new=0.1) - mocker.patch("zigpy_znp.zigbee.application.REQUEST_ERROR_RETRY_DELAY", new=0) app._znp._config[conf.CONF_ZNP_CONFIG][conf.CONF_ARSP_TIMEOUT] = 1 @@ -713,14 +629,6 @@ def data_confirm_replier(req): ], ) - znp_server.reply_to( - c.AF.DataRequestSrcRtg.Req(partial=True), - responses=[ - c.AF.DataRequestSrcRtg.Rsp(Status=t.Status.SUCCESS), - data_confirm_replier, - ], - ) - def assoc_get_with_addr(req): nonlocal assoc_device @@ -730,7 +638,7 @@ def assoc_get_with_addr(req): return c.UTIL.AssocGetWithAddress.Rsp(Device=assoc_device) - did_assoc_get = znp_server.reply_once_to( + did_assoc_get = znp_server.reply_to( c.UTIL.AssocGetWithAddress.Req(IEEE=device.ieee, partial=True), responses=[assoc_get_with_addr], ) @@ -750,12 +658,12 @@ def assoc_remove(req): assoc_device = None return c.UTIL.AssocRemove.Rsp(Status=t.Status.SUCCESS) - did_assoc_remove = znp_server.reply_once_to( + did_assoc_remove = znp_server.reply_to( c.UTIL.AssocRemove.Req(IEEE=device.ieee), responses=[assoc_remove], ) - did_assoc_add = znp_server.reply_once_to( + did_assoc_add = znp_server.reply_to( c.UTIL.AssocAdd.Req( NWK=device.nwk, IEEE=device.ieee, @@ -791,102 +699,23 @@ def assoc_remove(req): await req if fw_assoc_remove: - await did_assoc_remove + assert len(did_assoc_remove.mock_calls) >= 1 if final_status != t.Status.SUCCESS: # The association is re-added on failure - await did_assoc_add + assert len(did_assoc_add.mock_calls) >= 1 else: - assert not did_assoc_add.done() + assert len(did_assoc_add.mock_calls) == 0 elif issubclass(device_cls, FormedLaunchpadCC26X2R1): - await did_assoc_get - assert was_route_discovered.call_count >= 1 + assert len(did_assoc_get.mock_calls) >= 1 else: # Don't even attempt this with older firmwares - assert not did_assoc_get.done() + assert len(did_assoc_get.mock_calls) == 0 assert was_route_discovered.call_count == 0 await app.shutdown() -@pytest.mark.parametrize("device", [FormedLaunchpadCC26X2R1]) -@pytest.mark.parametrize("succeed", [True, False]) -@pytest.mark.parametrize("relays", [[0x1111, 0x2222, 0x3333], []]) -async def test_request_recovery_manual_source_route( - device, succeed, relays, make_application, mocker -): - app, znp_server = make_application(server_cls=device) - - await app.startup(auto_form=False) - - mocker.patch("zigpy_znp.zigbee.application.DATA_CONFIRM_TIMEOUT", new=0.1) - mocker.patch("zigpy_znp.zigbee.application.REQUEST_ERROR_RETRY_DELAY", new=0) - - app._znp._config[conf.CONF_ZNP_CONFIG][conf.CONF_ARSP_TIMEOUT] = 1 - - device = app.add_initialized_device(ieee=t.EUI64(range(8)), nwk=0xABCD) - device.relays = relays - - def data_confirm_replier(req): - if isinstance(req, c.AF.DataRequestExt.Req) or not succeed: - return c.AF.DataConfirm.Callback( - Status=t.Status.MAC_NO_ACK, - Endpoint=1, - TSN=1, - ) - else: - return c.AF.DataConfirm.Callback( - Status=t.Status.SUCCESS, - Endpoint=1, - TSN=1, - ) - - normal_data_request = znp_server.reply_to( - c.AF.DataRequestExt.Req(partial=True), - responses=[ - c.AF.DataRequestExt.Rsp(Status=t.Status.SUCCESS), - data_confirm_replier, - ], - ) - - source_routing_data_request = znp_server.reply_to( - c.AF.DataRequestSrcRtg.Req(partial=True), - responses=[ - c.AF.DataRequestSrcRtg.Rsp(Status=t.Status.SUCCESS), - data_confirm_replier, - ], - ) - - znp_server.reply_to( - c.ZDO.ExtRouteDisc.Req( - Dst=device.nwk, Options=c.zdo.RouteDiscoveryOptions.UNICAST, partial=True - ), - responses=[c.ZDO.ExtRouteDisc.Rsp(Status=t.Status.SUCCESS)], - ) - - req = app.request( - device=device, - profile=260, - cluster=1, - src_ep=1, - dst_ep=1, - sequence=1, - data=b"\x00", - ) - - if succeed: - await req - else: - with pytest.raises(DeliveryError): - await req - - # In either case only one source routing attempt is performed - assert source_routing_data_request.call_count == 1 - assert normal_data_request.call_count >= 1 - - await app.shutdown() - - @pytest.mark.parametrize("device", [FormedLaunchpadCC26X2R1]) async def test_route_discovery_concurrency(device, make_application): app, znp_server = make_application(server_cls=device) diff --git a/tests/conftest.py b/tests/conftest.py index e71991e..059981b 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -353,10 +353,13 @@ async def callback(request): await self._send_responses(request, responses) callback.call_count = 0 + callback_mock = Mock(side_effect=callback) - self.callback_for_response(request, lambda r: asyncio.create_task(callback(r))) + self.callback_for_response( + request, lambda r: asyncio.create_task(callback_mock(r)) + ) - return callback + return callback_mock def send(self, response): if response is not None and self._uart is not None: diff --git a/zigpy_znp/api.py b/zigpy_znp/api.py index 975a171..82d35d9 100644 --- a/zigpy_znp/api.py +++ b/zigpy_znp/api.py @@ -1,6 +1,7 @@ from __future__ import annotations import os +import sys import time import typing import asyncio @@ -12,7 +13,12 @@ from collections import Counter, defaultdict import zigpy.state -import async_timeout + +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover + import zigpy.zdo.types as zdo_t import zigpy.exceptions from zigpy.exceptions import NetworkNotFormed @@ -296,7 +302,7 @@ async def start_network(self): ) # Both versions still end with this callback - async with async_timeout.timeout(STARTUP_TIMEOUT): + async with asyncio_timeout(STARTUP_TIMEOUT): await started_as_coordinator except asyncio.TimeoutError as e: raise zigpy.exceptions.FormationFailure( @@ -666,7 +672,7 @@ async def ping_task(): # First, just try pinging try: - async with async_timeout.timeout(CONNECT_PING_TIMEOUT): + async with asyncio_timeout(CONNECT_PING_TIMEOUT): return await self.request(c.SYS.Ping.Req()) except asyncio.TimeoutError: pass @@ -682,7 +688,7 @@ async def ping_task(): # At this point we have nothing left to try while True: try: - async with async_timeout.timeout(2 * CONNECT_PING_TIMEOUT): + async with asyncio_timeout(2 * CONNECT_PING_TIMEOUT): return await self.request(c.SYS.Ping.Req()) except asyncio.TimeoutError: pass @@ -691,7 +697,7 @@ async def ping_task(): ping_task = asyncio.create_task(ping_task()) try: - async with async_timeout.timeout(CONNECT_PROBE_TIMEOUT): + async with asyncio_timeout(CONNECT_PROBE_TIMEOUT): result = await responses.get() except Exception: ping_task.cancel() @@ -706,7 +712,7 @@ async def ping_task(): LOGGER.debug("Giving ping task %0.2fs to finish", CONNECT_PING_TIMEOUT) try: - async with async_timeout.timeout(CONNECT_PING_TIMEOUT): + async with asyncio_timeout(CONNECT_PING_TIMEOUT): result = await ping_task # type:ignore[misc] except asyncio.TimeoutError: ping_task.cancel() @@ -1066,7 +1072,7 @@ async def request( self._uart.send(frame) # We should get a SRSP in a reasonable amount of time - async with async_timeout.timeout( + async with asyncio_timeout( timeout or self._znp_config[conf.CONF_SREQ_TIMEOUT] ): # We lock until either a sync response is seen or an error occurs @@ -1108,7 +1114,7 @@ async def request_callback_rsp( # Typical request/response/callbacks are not backgrounded if not background: try: - async with async_timeout.timeout(timeout): + async with asyncio_timeout(timeout): await self.request(request, timeout=timeout, **response_params) return await callback_rsp @@ -1119,7 +1125,7 @@ async def request_callback_rsp( start_time = time.monotonic() try: - async with async_timeout.timeout(timeout): + async with asyncio_timeout(timeout): request_rsp = await self.request(request, **response_params) except Exception: # If the SREQ/SRSP pair fails, we must cancel the AREQ listener @@ -1131,7 +1137,7 @@ async def request_callback_rsp( # the timeout async def callback_catcher(timeout): try: - async with async_timeout.timeout(timeout): + async with asyncio_timeout(timeout): await callback_rsp finally: self.remove_listener(listener) diff --git a/zigpy_znp/tools/flash_read.py b/zigpy_znp/tools/flash_read.py index a6b840e..a383381 100644 --- a/zigpy_znp/tools/flash_read.py +++ b/zigpy_znp/tools/flash_read.py @@ -2,7 +2,10 @@ import asyncio import logging -import async_timeout +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover import zigpy_znp.commands as c from zigpy_znp.api import ZNP @@ -14,7 +17,7 @@ async def read_firmware(znp: ZNP) -> bytearray: try: - async with async_timeout.timeout(5): + async with asyncio_timeout(5): handshake_rsp = await znp.request_callback_rsp( request=c.UBL.HandshakeReq.Req(), callback=c.UBL.HandshakeRsp.Callback(partial=True), diff --git a/zigpy_znp/tools/flash_write.py b/zigpy_znp/tools/flash_write.py index 331ac09..4dee3d9 100644 --- a/zigpy_znp/tools/flash_write.py +++ b/zigpy_znp/tools/flash_write.py @@ -4,7 +4,11 @@ import asyncio import logging -import async_timeout +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover + import zigpy_znp.types as t import zigpy_znp.commands as c @@ -70,7 +74,7 @@ async def write_firmware(znp: ZNP, firmware: bytes, reset_nvram: bool): ) try: - async with async_timeout.timeout(5): + async with asyncio_timeout(5): handshake_rsp = await znp.request_callback_rsp( request=c.UBL.HandshakeReq.Req(), callback=c.UBL.HandshakeRsp.Callback(partial=True), diff --git a/zigpy_znp/zigbee/application.py b/zigpy_znp/zigbee/application.py index 2c22f13..21dee94 100644 --- a/zigpy_znp/zigbee/application.py +++ b/zigpy_znp/zigbee/application.py @@ -1,6 +1,7 @@ from __future__ import annotations import os +import sys import asyncio import logging @@ -11,7 +12,12 @@ import zigpy.types import zigpy.config import zigpy.device -import async_timeout + +if sys.version_info[:2] < (3, 11): + from async_timeout import timeout as asyncio_timeout # pragma: no cover +else: + from asyncio import timeout as asyncio_timeout # pragma: no cover + import zigpy.profiles import zigpy.zdo.types as zdo_t import zigpy.application @@ -39,39 +45,12 @@ EXTENDED_DATA_CONFIRM_TIMEOUT = 30 DEVICE_JOIN_MAX_DELAY = 5 -REQUEST_MAX_RETRIES = 5 -REQUEST_ERROR_RETRY_DELAY = 0.5 - -# Errors that go away on their own after waiting for a bit -REQUEST_TRANSIENT_ERRORS = { - t.Status.BUFFER_FULL, - t.Status.MAC_CHANNEL_ACCESS_FAILURE, - t.Status.MAC_TRANSACTION_OVERFLOW, - t.Status.MAC_NO_RESOURCES, - t.Status.MEM_ERROR, - t.Status.NWK_TABLE_FULL, -} - -REQUEST_ROUTING_ERRORS = { - t.Status.APS_NO_ACK, - t.Status.APS_NOT_AUTHENTICATED, - t.Status.NWK_NO_ROUTE, - t.Status.NWK_INVALID_REQUEST, - t.Status.MAC_NO_ACK, - t.Status.MAC_TRANSACTION_EXPIRED, -} - -REQUEST_RETRYABLE_ERRORS = REQUEST_TRANSIENT_ERRORS | REQUEST_ROUTING_ERRORS - LOGGER = logging.getLogger(__name__) class RetryMethod(t.bitmap8): NONE = 0 AssocRemove = 2 << 0 - RouteDiscovery = 2 << 1 - LastGoodRoute = 2 << 2 - IEEEAddress = 2 << 3 class ControllerApplication(zigpy.application.ControllerApplication): @@ -91,7 +70,7 @@ def __init__(self, config: conf.ConfigType): @classmethod async def probe(cls, device_config): try: - async with async_timeout.timeout(PROBE_TIMEOUT): + async with asyncio_timeout(PROBE_TIMEOUT): return await super().probe(device_config) except asyncio.TimeoutError: return False @@ -511,7 +490,7 @@ def on_zdo_tc_device_join(self, msg: c.ZDO.TCDevInd.Callback) -> None: # Perform route discovery (just in case) when a device joins the network so that # we can begin initialization as soon as possible. - asyncio.create_task(self._discover_route(msg.SrcNwk)) + self.create_task(self._discover_route(msg.SrcNwk)) if msg.SrcIEEE in self._join_announce_tasks: self._join_announce_tasks.pop(msg.SrcIEEE).cancel() @@ -636,7 +615,7 @@ async def _set_led_mode(self, *, led: t.uint8_t, mode: c.util.LEDMode) -> None: # XXX: If Z-Stack is not compiled with HAL_LED, it will just not respond at all try: - async with async_timeout.timeout(0.5): + async with asyncio_timeout(0.5): await self._znp.request( c.UTIL.LEDControl.Req(LED=led, Mode=mode), RspStatus=t.Status.SUCCESS, @@ -840,7 +819,7 @@ async def _send_request_raw( # Broadcasts and ZDO requests will not receive a confirmation await self._znp.request(request=request, RspStatus=t.Status.SUCCESS) else: - async with async_timeout.timeout( + async with asyncio_timeout( EXTENDED_DATA_CONFIRM_TIMEOUT if extended_timeout else DATA_CONFIRM_TIMEOUT @@ -919,20 +898,15 @@ async def send_packet(self, packet: zigpy.types.ZigbeePacket) -> None: dst_addr = t.AddrModeAddress.from_zigpy_type(packet.dst) succeeded = False - association = None - force_relays = None - - if packet.source_route is not None: - force_relays = packet.source_route - - retry_methods = RetryMethod.NONE - last_retry_method = RetryMethod.NONE + child_association = None + tried_assoc_remove = False - # Don't release the concurrency-limiting semaphore until we are done trying. - # There is no point in allowing requests to take turns getting buffer errors. try: - async with self._limit_concurrency(priority=packet.priority): - for attempt in range(REQUEST_MAX_RETRIES): + # We retry sending twice but the only devices that will use the second retry + # attempt are sleeping end devices that silently switched parents from the + # coordinator, all others will fail immediately + for _retry_attempt in range(2): + async with self._limit_concurrency(priority=packet.priority): try: # ZDO requests do not generate `AF.DataConfirm` messages # indicating that a route is missing so we need to explicitly @@ -966,68 +940,23 @@ async def send_packet(self, packet: zigpy.types.ZigbeePacket) -> None: options=options, radius=packet.radius or 0, data=packet.data.serialize(), - relays=force_relays, + relays=packet.source_route, extended_timeout=packet.extended_timeout, ) succeeded = True break except InvalidCommandResponse as e: - status = e.response.Status - - if status not in REQUEST_RETRYABLE_ERRORS: - raise - - # Just retry if: - # - this is our first failure - # - the error is transient and is not a routing issue - # - or we are not sending a unicast request - if ( - attempt == 0 - or status in REQUEST_TRANSIENT_ERRORS - or dst_addr.mode not in (t.AddrMode.NWK, t.AddrMode.IEEE) - ): - LOGGER.debug( - "Request failed (%s), retry attempt %s of %s (%s)", - e, - attempt + 1, - REQUEST_MAX_RETRIES, - retry_methods.name, - ) - await asyncio.sleep(3 * REQUEST_ERROR_RETRY_DELAY) - continue - - # If we can't contact the device by forcing a specific route, - # there is no point in trying this more than once. - if ( - retry_methods & RetryMethod.LastGoodRoute - and force_relays is not None - ): - force_relays = None - - # If we fail to contact the device with its IEEE address, don't - # try again. - if ( - retry_methods & RetryMethod.IEEEAddress - and dst_addr.mode == t.AddrMode.IEEE - and device is not None - ): - dst_addr = t.AddrModeAddress( - mode=t.AddrMode.NWK, - address=device.nwk, - ) - # Child aging is disabled so if a child switches parents from # the coordinator to another router, we will not be able to # re-discover a route to it. We have to manually drop the child # to do this. if ( - status == t.Status.MAC_TRANSACTION_EXPIRED + e.response.Status == t.Status.MAC_TRANSACTION_EXPIRED and device is not None - and association is None - and not retry_methods & RetryMethod.AssocRemove + and child_association is None and self._znp.version >= 3.30 ): - association = await self._znp.request( + child_association = await self._znp.request( c.UTIL.AssocGetWithAddress.Req( IEEE=device.ieee, NWK=0x0000, # IEEE takes priority @@ -1035,86 +964,46 @@ async def send_packet(self, packet: zigpy.types.ZigbeePacket) -> None: ) if ( - association.Device.nodeRelation - != c.util.NodeRelation.NOTUSED + child_association.Device.nodeRelation + == c.util.NodeRelation.NOTUSED ): - try: - await self._znp.request( - c.UTIL.AssocRemove.Req(IEEE=device.ieee) - ) - retry_methods |= RetryMethod.AssocRemove - last_retry_method = RetryMethod.AssocRemove - - # Route discovery must be performed right after - await self._discover_route(device.nwk) - except CommandNotRecognized: - LOGGER.debug( - "The UTIL.AssocRemove command is available only" - " in Z-Stack 3 releases built after 20201017" - ) - elif ( - not retry_methods & RetryMethod.LastGoodRoute - and device is not None - ): - # `ZDO.SrcRtgInd` callbacks tell us the last path taken by - # messages from the device back to the coordinator. Sending - # packets backwards via this same route may work. - force_relays = (device.relays or [])[::-1] - retry_methods |= RetryMethod.LastGoodRoute - last_retry_method = RetryMethod.LastGoodRoute - elif ( - not retry_methods & RetryMethod.RouteDiscovery - and dst_addr.mode == t.AddrMode.NWK - ): - # If that doesn't work, try re-discovering the route. - # While we can in theory poll and wait until it is fixed, - # letting the retry mechanism deal with it simpler. - await self._discover_route(dst_addr.address) - retry_methods |= RetryMethod.RouteDiscovery - last_retry_method = RetryMethod.RouteDiscovery - elif ( - not retry_methods & RetryMethod.IEEEAddress - and device is not None - and dst_addr.mode == t.AddrMode.NWK - ): - # Try using the device's IEEE address instead of its NWK. - # If it works, the NWK will be updated when relays arrive. - retry_methods |= RetryMethod.IEEEAddress - last_retry_method = RetryMethod.IEEEAddress - dst_addr = t.AddrModeAddress( - mode=t.AddrMode.IEEE, - address=device.ieee, - ) - - LOGGER.debug( - "Request failed (%s), retry attempt %s of %s (%s)", - e, - attempt + 1, - REQUEST_MAX_RETRIES, - retry_methods.name, - ) - - # We've tried everything already so at this point just wait - await asyncio.sleep(REQUEST_ERROR_RETRY_DELAY) - else: - raise DeliveryError( - f"Request failed after {REQUEST_MAX_RETRIES} attempts:" - f" {status!r}", - status=status, - ) + raise - self.state.counters[f"Retry_{last_retry_method.name}"][ - attempt - ].increment() + try: + await self._znp.request( + c.UTIL.AssocRemove.Req(IEEE=device.ieee) + ) + tried_assoc_remove = True + + # Route discovery must be performed right after + await self._discover_route(device.nwk) + except CommandNotRecognized: + LOGGER.debug( + "The UTIL.AssocRemove command is available only" + " in Z-Stack 3 releases built after 20201017" + ) + raise e from None + else: + continue + + # Perform route discovery explicitly if the stack fails + if e.response.Status == t.Status.NWK_NO_ROUTE: + await self._discover_route(device.nwk) + + raise + except InvalidCommandResponse as e: + status = e.response.Status + raise DeliveryError(f"Failed to send request: {status!r}", status=status) finally: # We *must* re-add the device association if we previously removed it but # the request still failed. Otherwise, it may be a direct child and we will # not be able to find it again. - if not succeeded and retry_methods & RetryMethod.AssocRemove: + if not succeeded and tried_assoc_remove: + assert child_association is not None await self._znp.request( c.UTIL.AssocAdd.Req( - NWK=association.Device.shortAddr, + NWK=child_association.Device.shortAddr, IEEE=device.ieee, - NodeRelation=association.Device.nodeRelation, + NodeRelation=child_association.Device.nodeRelation, ) )