From be85a4531f8f333bb72757b64ae95794794296e7 Mon Sep 17 00:00:00 2001 From: Mattia Almansi Date: Wed, 20 Mar 2024 18:35:37 +0100 Subject: [PATCH 1/2] improve logging --- cads_api_client/legacy_api_client.py | 79 ++++++++++++++++--- cads_api_client/processing.py | 7 +- .../integration_test_50_legacy_api_client.py | 23 ++++++ 3 files changed, 94 insertions(+), 15 deletions(-) diff --git a/cads_api_client/legacy_api_client.py b/cads_api_client/legacy_api_client.py index 0a16064..3349822 100644 --- a/cads_api_client/legacy_api_client.py +++ b/cads_api_client/legacy_api_client.py @@ -1,8 +1,10 @@ from __future__ import annotations import functools +import logging import warnings -from typing import Any, Callable, overload +from types import TracebackType +from typing import Any, Callable, TypeVar, cast, overload import cdsapi.api import requests @@ -29,12 +31,42 @@ "session", ] +F = TypeVar("F", bound=Callable[..., Any]) + + +class LoggingContext: + def __init__(self, quiet: bool, debug: bool) -> None: + self.logger = processing.logger + self.old_level = self.logger.level + + if quiet: + self.logger.setLevel(logging.WARNING) + else: + self.logger.setLevel(logging.DEBUG if debug else logging.INFO) + + self.new_handlers = [] + if not self.logger.handlers: + formatter = logging.Formatter("%(asctime)s %(levelname)s %(message)s") + handler = logging.StreamHandler() + handler.setFormatter(formatter) + self.logger.addHandler(handler) + self.new_handlers.append(handler) + + def __enter__(self) -> logging.Logger: + return self.logger + + def __exit__( + self, + exc_type: type[BaseException] | None, + exc_val: BaseException | None, + exc_tb: TracebackType | None, + ) -> None: + self.logger.setLevel(self.old_level) + for handler in self.new_handlers: + self.logger.removeHandler(handler) -class LegacyApiClient(cdsapi.api.Client): # type: ignore[misc] - def __new__(cls, *args: Any, **kwargs: Any) -> LegacyApiClient: - instantiated: LegacyApiClient = super(cdsapi.api.Client, cls).__new__(cls) - return instantiated +class LegacyApiClient(cdsapi.api.Client): # type: ignore[misc] def __init__( self, url: str | None = None, @@ -61,6 +93,9 @@ def __init__( "retry_after": self.sleep_max, } + self.quiet = kwargs.pop("quiet", False) + self._debug = kwargs.pop("debug", False) + if kwargs: warnings.warn( "This is a beta version." @@ -68,12 +103,33 @@ def __init__( UserWarning, ) + with LoggingContext(quiet=self.quiet, debug=self._debug) as logger: + logger.debug( + "CDSAPI %s", + { + "url": self.url, + "key": self.key, + "quiet": self.quiet, + "timeout": self.timeout, + "sleep_max": self.sleep_max, + "retry_max": self.retry_max, + }, + ) + @classmethod def raise_not_implemented_error(self) -> None: raise NotImplementedError( "This is a beta version. This functionality has not been implemented yet." ) + def logging_decorator(self, func: F) -> F: + @functools.wraps(func) + def wrapper(*args: Any, **kwargs: Any) -> Any: + with LoggingContext(quiet=self.quiet, debug=self._debug): + return func(*args, **kwargs) + + return cast(F, wrapper) + @overload def retrieve(self, name: str, request: dict[str, Any], target: str) -> str: ... @@ -85,17 +141,18 @@ def retrieve( def retrieve( self, name: str, request: dict[str, Any], target: str | None = None ) -> str | processing.Results: - result = self.client.submit_and_wait_on_result( - collection_id=name, - retry_options=self.retry_options, - **request, - ) + with LoggingContext(quiet=self.quiet, debug=self._debug): + result = self.client.submit_and_wait_on_result( + collection_id=name, + retry_options=self.retry_options, + **request, + ) partial_download: Callable[..., str] = functools.partial( result.download, timeout=self.timeout, retry_options=self.retry_options, ) - result.download = partial_download # type: ignore[method-assign] + result.download = self.logging_decorator(partial_download) # type: ignore[method-assign] return result if target is None else result.download(target) def service(self, name, *args, **kwargs): # type: ignore diff --git a/cads_api_client/processing.py b/cads_api_client/processing.py index 1545d77..f3c19a8 100644 --- a/cads_api_client/processing.py +++ b/cads_api_client/processing.py @@ -184,11 +184,10 @@ def _robust_status(self, retry_options: Dict[str, Any] = {}) -> str: def wait_on_result(self, retry_options: Dict[str, Any] = {}) -> None: sleep = 1.0 - last_status = self._robust_status(retry_options=retry_options) + status = None while True: - status = self._robust_status(retry_options=retry_options) - if last_status != status: - logger.debug(f"status has been updated to {status}") + if status != (status := self._robust_status(retry_options=retry_options)): + logger.info(f"status has been updated to {status}") if status == "successful": # workaround for the server-side 404 due to database replicas out od sync time.sleep(1) diff --git a/tests/integration_test_50_legacy_api_client.py b/tests/integration_test_50_legacy_api_client.py index ae81ddc..81d4477 100644 --- a/tests/integration_test_50_legacy_api_client.py +++ b/tests/integration_test_50_legacy_api_client.py @@ -1,5 +1,7 @@ import pathlib +import pytest + from cads_api_client import legacy_api_client @@ -19,3 +21,24 @@ def test_retrieve(tmp_path: pathlib.Path, api_root_url: str, api_key: str) -> No actual_target = result.download(str(target)) assert str(target) == actual_target assert target.stat().st_size == 1 + + +@pytest.mark.parametrize("quiet", [True, False]) +def test_quiet( + caplog: pytest.LogCaptureFixture, api_root_url: str, api_key: str, quiet: bool +) -> None: + client = legacy_api_client.LegacyApiClient( + url=api_root_url, key=api_key, quiet=quiet + ) + client.retrieve("test-adaptor-dummy", {}) + records = [record for record in caplog.records if record.levelname == "INFO"] + assert not records if quiet else records + + +@pytest.mark.parametrize("debug", [True, False]) +def test_debug( + caplog: pytest.LogCaptureFixture, api_root_url: str, api_key: str, debug: bool +) -> None: + legacy_api_client.LegacyApiClient(url=api_root_url, key=api_key, debug=debug) + records = [record for record in caplog.records if record.levelname == "DEBUG"] + assert records if debug else not records From 3e8c37191527085f08a9afc4ef227cc649e4a6aa Mon Sep 17 00:00:00 2001 From: Mattia Almansi Date: Wed, 20 Mar 2024 18:55:14 +0100 Subject: [PATCH 2/2] improve logging handler --- cads_api_client/legacy_api_client.py | 24 ++++++++++++++---------- 1 file changed, 14 insertions(+), 10 deletions(-) diff --git a/cads_api_client/legacy_api_client.py b/cads_api_client/legacy_api_client.py index 3349822..b6abf0e 100644 --- a/cads_api_client/legacy_api_client.py +++ b/cads_api_client/legacy_api_client.py @@ -31,12 +31,13 @@ "session", ] +LOGGER = logging.getLogger(__name__) F = TypeVar("F", bound=Callable[..., Any]) class LoggingContext: - def __init__(self, quiet: bool, debug: bool) -> None: - self.logger = processing.logger + def __init__(self, logger: logging.Logger, quiet: bool, debug: bool) -> None: + self.logger = logger self.old_level = self.logger.level if quiet: @@ -103,7 +104,9 @@ def __init__( UserWarning, ) - with LoggingContext(quiet=self.quiet, debug=self._debug) as logger: + with LoggingContext( + logger=LOGGER, quiet=self.quiet, debug=self._debug + ) as logger: logger.debug( "CDSAPI %s", { @@ -125,7 +128,9 @@ def raise_not_implemented_error(self) -> None: def logging_decorator(self, func: F) -> F: @functools.wraps(func) def wrapper(*args: Any, **kwargs: Any) -> Any: - with LoggingContext(quiet=self.quiet, debug=self._debug): + with LoggingContext( + logger=processing.logger, quiet=self.quiet, debug=self._debug + ): return func(*args, **kwargs) return cast(F, wrapper) @@ -141,12 +146,11 @@ def retrieve( def retrieve( self, name: str, request: dict[str, Any], target: str | None = None ) -> str | processing.Results: - with LoggingContext(quiet=self.quiet, debug=self._debug): - result = self.client.submit_and_wait_on_result( - collection_id=name, - retry_options=self.retry_options, - **request, - ) + result = self.logging_decorator(self.client.submit_and_wait_on_result)( + collection_id=name, + retry_options=self.retry_options, + **request, + ) partial_download: Callable[..., str] = functools.partial( result.download, timeout=self.timeout,