update request handler logic (#85)

* fix get_max_width for min width + better handling of closed connection on cache + add debug print for error

* simplify request handling driver logic + adjust default backoff values + adjust request logs/exception logic

* adjust logging in request handler

* fix failing test

musify/api/cache/backend/sqlite.py

@@ -330,19 +330,27 @@ def __await__(self) -> Generator[Any, None, Self]:
         return self._connect().__await__()
 
     async def __aexit__(self, __exc_type, __exc_value, __traceback) -> None:
-        if not self.closed:  # TODO: this shouldn't be needed?
-            await self.commit()
-            await self.connection.__aexit__(__exc_type, __exc_value, __traceback)
-            self.connection = None
+        if self.closed:
+            return
+
+        await self.commit()
+        await self.connection.__aexit__(__exc_type, __exc_value, __traceback)
+        self.connection = None
 
     async def commit(self):
         """Commit the transactions to the database."""
+        if self.closed:
+            return
+
         try:
             await self.connection.commit()
         except ValueError:
             pass
 
     async def close(self):
+        if self.closed:
+            return
+
         try:
             await self.commit()
             await self.connection.close()

musify/api/request.py

@@ -50,7 +50,7 @@ def timeout(self) -> int:
         When the response gives a time to wait until (i.e. retry-after),
         the program will exit if this time is above this timeout (in seconds)
         """
-        return sum(self.backoff_start * self.backoff_factor ** i for i in range(self.backoff_count + 1))
+        return int(sum(self.backoff_start * self.backoff_factor ** i for i in range(self.backoff_count + 1)))
 
     @property
     def closed(self):
@@ -86,9 +86,9 @@ def __init__(self, connector: Callable[[], ClientSession], authoriser: APIAuthor
         self.authoriser = authoriser
 
         #: The initial backoff time for failed requests
-        self.backoff_start = 0.5
+        self.backoff_start = 0.2
         #: The factor by which to increase backoff time for failed requests i.e. backoff_start ** backoff_factor
-        self.backoff_factor = 1.5
+        self.backoff_factor = 1.932
         #: The maximum number of request attempts to make before giving up and raising an exception
         self.backoff_count = 10
 
@@ -144,24 +144,23 @@ async def request(self, method: str, url: str | URL, **kwargs) -> dict[str, Any]
 
         while True:
             async with self._request(method=method, url=url, **kwargs) as response:
-                if response is not None and response.status < 400:
-                    data = await self._response_as_json(response)
+                if response is None:
+                    raise APIError("No response received")
+
+                if response.ok and (data := await self._response_as_json(response)):
                     break
 
-                waited = None
-                if response is not None:
-                    await self._log_response(response=response, method=method, url=url)
-                    await self._handle_unexpected_response(response=response)
-                    waited = await self._handle_wait_time(response=response)
-
-                if not waited and backoff < self.backoff_final:  # exponential backoff
-                    self.logger.warning(f"Request failed: retrying in {backoff} seconds...")
-                    sleep(backoff)
-                    backoff *= self.backoff_factor
-                elif waited is False:  # max backoff exceeded
+                await self._log_response(response=response, method=method, url=url)
+                await self._handle_unexpected_response(response=response)
+                waited = await self._handle_wait_time(response=response)
+
+                if not waited and backoff > self.backoff_final:
                     raise APIError("Max retries exceeded")
-                elif waited is None:  # max backoff exceeded
-                    raise APIError("No response received")
+
+                # exponential backoff
+                self.logger.info_extra(f"Request failed: retrying in {backoff} seconds...")
+                sleep(backoff)
+                backoff *= self.backoff_factor
 
         return data
 
@@ -192,7 +191,7 @@ async def _request(
             async with self.session.request(method=method.upper(), url=url, **kwargs) as response:
                 yield response
         except aiohttp.ClientError as ex:
-            self.logger.warning(str(ex))
+            self.logger.debug(str(ex))
             yield
 
     def log(
@@ -226,10 +225,16 @@ async def _log_response(self, response: ClientResponse, method: str, url: str |
         response_headers = response.headers
         if isinstance(response.headers, Mapping):  # format headers if JSON
             response_headers = json.dumps(dict(response.headers), indent=2)
-        self.logger.warning(
-            f"\33[91m{method.upper():<7}: {url} | Code: {response.status} | Response text and headers follow:\n"
-            f"Response text:\n\t{(await response.text()).replace("\n", "\n\t")}\n"
-            f"Headers:\n\t{response_headers.replace("\n", "\n\t")}\33[0m"
+        self.log(
+            method=f"\33[91m{method.upper()}",
+            url=url,
+            messages=[
+                f"Status code: {response.status}",
+                "Response text and headers follow:\n"
+                f"Response text:\n\t{(await response.text()).replace("\n", "\n\t")}\n"
+                f"Headers:\n\t{response_headers.replace("\n", "\n\t")}"
+                f"\33[0m"
+            ]
         )
 
     async def _handle_unexpected_response(self, response: ClientResponse) -> bool:
@@ -253,12 +258,14 @@ async def _handle_wait_time(self, response: ClientResponse) -> bool:
 
         wait_time = int(response.headers["retry-after"])
         wait_str = (datetime.now() + timedelta(seconds=wait_time)).strftime("%Y-%m-%d %H:%M:%S")
-        self.logger.info(f"\33[91mRate limit exceeded. Retrying again at {wait_str}\33[0m")
 
         if wait_time > self.timeout:  # exception if too long
-            raise APIError(f"Rate limit exceeded and wait time is greater than timeout of {self.timeout} seconds")
+            raise APIError(
+                f"Rate limit exceeded and wait time is greater than timeout of {self.timeout} seconds. "
+                f"Retry again at {wait_str}"
+            )
 
-        # wait if time is short
+        self.logger.info_extra(f"\33[93mRate limit exceeded. Retrying again at {wait_str}\33[0m")
         sleep(wait_time)
         return True
 

musify/utils.py

@@ -106,7 +106,7 @@ def get_max_width(values: Collection[Any], min_width: int = 15, max_width: int =
     Uses width as would be seen in a fixed-width font taking into account characters with varying widths.
     """
     if len(values) == 0:
-        return 0
+        return min_width
     max_len = unicode_len(max(map(str, values), key=unicode_len))
     return limit_value(value=max_len + 1, floor=min_width, ceil=max_width)
 

tests/test_utils.py

@@ -52,7 +52,7 @@ def test_get_max_width():
     assert get_max_width(values, min_width=5, max_width=50) == 31  # +1 for trailing space
     assert get_max_width(values, min_width=50, max_width=100) == 50
 
-    assert get_max_width([]) == 0
+    assert get_max_width([], min_width=10) == 10
 
 
 def test_align_string_truncate_left():