Improve retry mechanisms with logging and type annotations (#1922)

This will make sure that backoff requests are added to the Overkiz
logger. Default logging is info for backoff, thus it will show up for
debug in Home Assistant as well.

Author: iMicknl

pyoverkiz/client.py

@@ -4,10 +4,10 @@
 
 import asyncio
 import datetime
+import logging
 import os
 import ssl
 import urllib.parse
-from collections.abc import Mapping
 from json import JSONDecodeError
 from types import TracebackType
 from typing import Any, cast
@@ -22,6 +22,7 @@
     FormData,
     ServerDisconnectedError,
 )
+from backoff.types import Details
 from botocore.client import BaseClient
 from botocore.config import Config
 from warrant_lite import WarrantLite
@@ -91,15 +92,22 @@
 from pyoverkiz.obfuscate import obfuscate_sensitive_data
 from pyoverkiz.types import JSON
 
+_LOGGER = logging.getLogger(__name__)
 
-async def relogin(invocation: Mapping[str, Any]) -> None:
-    """Small helper used by retry decorators to re-authenticate the client."""
-    await invocation["args"][0].login()
 
+def _get_client_from_invocation(invocation: Details) -> OverkizClient:
+    """Return the `OverkizClient` instance from a backoff invocation."""
+    return cast(OverkizClient, invocation["args"][0])
 
-async def refresh_listener(invocation: Mapping[str, Any]) -> None:
-    """Helper to refresh an event listener when retrying listener-related operations."""
-    await invocation["args"][0].register_event_listener()
+
+async def relogin(invocation: Details) -> None:
+    """Re-authenticate using the main `OverkizClient` instance."""
+    await _get_client_from_invocation(invocation).login()
+
+
+async def refresh_listener(invocation: Details) -> None:
+    """Refresh the listener using the main `OverkizClient` instance."""
+    await _get_client_from_invocation(invocation).register_event_listener()
 
 
 # Reusable backoff decorators to reduce code duplication
@@ -108,37 +116,43 @@ async def refresh_listener(invocation: Mapping[str, Any]) -> None:
     (NotAuthenticatedException, ServerDisconnectedError),
     max_tries=2,
     on_backoff=relogin,
+    logger=_LOGGER,
 )
 
 retry_on_connection_failure = backoff.on_exception(
     backoff.expo,
     (TimeoutError, ClientConnectorError),
     max_tries=5,
+    logger=_LOGGER,
 )
 
 retry_on_concurrent_requests = backoff.on_exception(
     backoff.expo,
     TooManyConcurrentRequestsException,
     max_tries=5,
+    logger=_LOGGER,
 )
 
 retry_on_too_many_executions = backoff.on_exception(
     backoff.expo,
     TooManyExecutionsException,
     max_tries=10,
+    logger=_LOGGER,
 )
 
 retry_on_listener_error = backoff.on_exception(
     backoff.expo,
     (InvalidEventListenerIdException, NoRegisteredEventListenerException),
     max_tries=2,
     on_backoff=refresh_listener,
+    logger=_LOGGER,
 )
 
 retry_on_execution_queue_full = backoff.on_exception(
     backoff.expo,
     ExecutionQueueFullException,
     max_tries=5,
+    logger=_LOGGER,
 )
 
 # pylint: disable=too-many-instance-attributes, too-many-branches

tests/test_client.py

@@ -8,7 +8,7 @@
 
 import json
 import os
-from unittest.mock import patch
+from unittest.mock import AsyncMock, patch
 
 import aiohttp
 import pytest
@@ -102,6 +102,83 @@ async def test_fetch_events_simple_cast(self, client: OverkizClient):
             assert isinstance(int_state_event.value, int)
             assert int_state_event.type == DataType.INTEGER
 
+    @pytest.mark.asyncio
+    async def test_backoff_relogin_on_auth_error(self, client: OverkizClient):
+        """Ensure auth backoff retries and triggers `login()` on failure."""
+        client.login = AsyncMock()
+
+        with (
+            patch("backoff._async.asyncio.sleep", new=AsyncMock()) as sleep_mock,
+            patch.object(
+                OverkizClient,
+                "_OverkizClient__get",
+                new=AsyncMock(
+                    side_effect=[
+                        exceptions.NotAuthenticatedException("expired"),
+                        {"protocolVersion": "1"},
+                    ]
+                ),
+            ) as get_mock,
+        ):
+            result = await client.get_api_version()
+
+        assert result == "1"
+        assert get_mock.await_count == 2
+        assert client.login.await_count == 1
+        assert sleep_mock.await_count == 1
+
+    @pytest.mark.asyncio
+    async def test_backoff_refresh_listener_on_listener_error(
+        self, client: OverkizClient
+    ) -> None:
+        """Ensure listener backoff retries and triggers `register_event_listener()`."""
+        client.event_listener_id = "listener-1"
+        client.register_event_listener = AsyncMock(return_value="listener-2")
+
+        with (
+            patch("backoff._async.asyncio.sleep", new=AsyncMock()) as sleep_mock,
+            patch.object(
+                OverkizClient,
+                "_OverkizClient__post",
+                new=AsyncMock(
+                    side_effect=[
+                        exceptions.InvalidEventListenerIdException("bad listener"),
+                        [],
+                    ]
+                ),
+            ) as post_mock,
+        ):
+            events = await client.fetch_events()
+
+        assert events == []
+        assert post_mock.await_count == 2
+        assert client.register_event_listener.await_count == 1
+        assert sleep_mock.await_count == 1
+
+    @pytest.mark.asyncio
+    async def test_backoff_retries_on_concurrent_requests(
+        self, client: OverkizClient
+    ) -> None:
+        """Ensure concurrent request backoff retries and succeeds afterwards."""
+        with (
+            patch("backoff._async.asyncio.sleep", new=AsyncMock()) as sleep_mock,
+            patch.object(
+                OverkizClient,
+                "_OverkizClient__post",
+                new=AsyncMock(
+                    side_effect=[
+                        exceptions.TooManyConcurrentRequestsException("busy"),
+                        {"id": "listener-3"},
+                    ]
+                ),
+            ) as post_mock,
+        ):
+            listener_id = await client.register_event_listener()
+
+        assert listener_id == "listener-3"
+        assert post_mock.await_count == 2
+        assert sleep_mock.await_count == 1
+
     @pytest.mark.parametrize(
         "fixture_name",
         [