From 1ee1633d3a3eabf5f2aee4f7a5c8ef975dbc4b55 Mon Sep 17 00:00:00 2001 From: Lucas Pedroza Date: Thu, 10 Oct 2024 14:20:45 +0200 Subject: [PATCH 1/3] feat: add debug logging --- README.md | 17 ++++++++++++ fauna/client/client.py | 5 +++- fauna/http/httpx_client.py | 54 +++++++++++++++++++++++++++++++++----- 3 files changed, 69 insertions(+), 7 deletions(-) diff --git a/README.md b/README.md index 9f848615..44f19f50 100644 --- a/README.md +++ b/README.md @@ -568,6 +568,23 @@ options = ChangeFeedOptions( client.change_feed(fql('Product.all().toStream()'), options) ``` +## Logging + +Debug logging is handled by the standard logging package in under the `fauna` namespace. We will log the request with body, excluding the Authorization header, as well as the full response. + +In your application, you can enable debug logging with the following. Given this is a standard convention in Python, you may want more fine-grained control over which libraries log. See Python's how-to at https://docs.python.org/3/howto/logging.html. +```python +import logging +from fauna.client import Client +from fauna import fql + +logging.basicConfig( + level=logging.DEBUG +) +c = Client() +c.query(fql("42")) +``` + ## Setup ```bash diff --git a/fauna/client/client.py b/fauna/client/client.py index d1cac5c8..6b03ad6d 100644 --- a/fauna/client/client.py +++ b/fauna/client/client.py @@ -1,3 +1,4 @@ +import logging from dataclasses import dataclass from datetime import timedelta from typing import Any, Dict, Iterator, Mapping, Optional, Union, List @@ -14,6 +15,8 @@ from fauna.query import Query, Page, fql from fauna.query.models import StreamToken +logger = logging.getLogger("fauna") + DefaultHttpConnectTimeout = timedelta(seconds=5) DefaultHttpReadTimeout: Optional[timedelta] = None DefaultHttpWriteTimeout = timedelta(seconds=5) @@ -217,7 +220,7 @@ def __init__( max_keepalive_connections=DefaultMaxIdleConnections, keepalive_expiry=idle_timeout_s, ), - )) + ), logger) fauna.global_http_client = c self._session = fauna.global_http_client diff --git a/fauna/http/httpx_client.py b/fauna/http/httpx_client.py index c317d7fa..0961054c 100644 --- a/fauna/http/httpx_client.py +++ b/fauna/http/httpx_client.py @@ -1,4 +1,5 @@ import json +import logging from contextlib import contextmanager from json import JSONDecodeError from typing import Mapping, Any, Optional, Iterator @@ -50,9 +51,12 @@ def close(self) -> None: class HTTPXClient(HTTPClient): - def __init__(self, client: httpx.Client): + def __init__(self, + client: httpx.Client, + logger: logging.Logger = logging.getLogger("fauna")): super(HTTPXClient, self).__init__() self._c = client + self._logger = logger def request( self, @@ -69,14 +73,29 @@ def request( json=data, headers=headers, ) + + if self._logger.isEnabledFor(logging.DEBUG): + headers_to_log = request.headers.copy() + headers_to_log.pop("Authorization") + self._logger.debug( + f"query.request method={request.method} url={request.url} headers={headers_to_log} data={data}" + ) + except httpx.InvalidURL as e: raise ClientError("Invalid URL Format") from e try: - return HTTPXResponse(self._c.send( + response = self._c.send( request, stream=False, - )) + ) + + if self._logger.isEnabledFor(logging.DEBUG): + self._logger.debug( + f"query.response status_code={response.status_code} headers={response.headers} data={response.text}" + ) + + return HTTPXResponse(response) except (httpx.HTTPError, httpx.InvalidURL) as e: raise NetworkError("Exception re-raised from HTTP request") from e @@ -87,14 +106,37 @@ def stream( headers: Mapping[str, str], data: Mapping[str, Any], ) -> Iterator[Any]: - with self._c.stream( - "POST", url=url, headers=headers, json=data) as response: + request = self._c.build_request( + method="POST", + url=url, + headers=headers, + json=data, + ) + + if self._logger.isEnabledFor(logging.DEBUG): + headers_to_log = request.headers.copy() + headers_to_log.pop("Authorization") + self._logger.debug( + f"stream.request method={request.method} url={request.url} headers={headers_to_log} data={data}" + ) + + response = self._c.send( + request=request, + stream=True, + ) + + try: yield self._transform(response) + finally: + response.close() def _transform(self, response): try: for line in response.iter_lines(): - yield json.loads(line) + loaded = json.loads(line) + if self._logger.isEnabledFor(logging.DEBUG): + self._logger.debug(f"stream.data data={loaded}") + yield loaded except httpx.ReadTimeout as e: raise NetworkError("Stream timeout") from e except (httpx.HTTPError, httpx.InvalidURL) as e: From c888a5322f0a4ec83235e9c66642bc6d270f9898 Mon Sep 17 00:00:00 2001 From: Lucas Pedroza Date: Thu, 10 Oct 2024 15:18:55 +0200 Subject: [PATCH 2/3] fix: stream retry test --- fauna/client/client.py | 1 - tests/integration/test_stream.py | 12 ++++++++---- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/fauna/client/client.py b/fauna/client/client.py index 6b03ad6d..1ff793ae 100644 --- a/fauna/client/client.py +++ b/fauna/client/client.py @@ -446,7 +446,6 @@ def stream( if opts.cursor is not None: raise ClientError( "The 'cursor' configuration can only be used with a stream token.") - token = self.query(fql).data else: token = fql diff --git a/tests/integration/test_stream.py b/tests/integration/test_stream.py index 9d312fed..12562060 100644 --- a/tests/integration/test_stream.py +++ b/tests/integration/test_stream.py @@ -1,12 +1,11 @@ import threading -import time import httpx import pytest from fauna import fql from fauna.client import Client, StreamOptions -from fauna.errors import ClientError, NetworkError, RetryableFaunaException, QueryRuntimeError +from fauna.errors import ClientError, RetryableFaunaException, QueryRuntimeError, NetworkError from fauna.http.httpx_client import HTTPXClient @@ -107,11 +106,16 @@ def test_max_retries(scoped_secret): count = [0] - def stream_func(*args, **kwargs): + old_send = httpx_client.send + + def send_func(*args, **kwargs): + if not kwargs['stream']: + return old_send(*args, **kwargs) + count[0] += 1 raise NetworkError('foo') - httpx_client.stream = stream_func + httpx_client.send = send_func count[0] = 0 with pytest.raises(RetryableFaunaException): From e6f7f494d6c5bc56fedc97e25324dce8c8df9527 Mon Sep 17 00:00:00 2001 From: Lucas Pedroza <40873230+pnwpedro@users.noreply.github.com> Date: Thu, 10 Oct 2024 16:41:19 +0200 Subject: [PATCH 3/3] Apply suggestions from code review Co-authored-by: James Rodewig --- README.md | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index 44f19f50..bd542cc2 100644 --- a/README.md +++ b/README.md @@ -570,9 +570,9 @@ client.change_feed(fql('Product.all().toStream()'), options) ## Logging -Debug logging is handled by the standard logging package in under the `fauna` namespace. We will log the request with body, excluding the Authorization header, as well as the full response. +Logging is handled using Python's standard `logging` package under the `fauna` namespace. Logs include the HTTP request with body (excluding the `Authorization` header) and the full HTTP response. -In your application, you can enable debug logging with the following. Given this is a standard convention in Python, you may want more fine-grained control over which libraries log. See Python's how-to at https://docs.python.org/3/howto/logging.html. +To enable logging: ```python import logging from fauna.client import Client @@ -581,9 +581,10 @@ from fauna import fql logging.basicConfig( level=logging.DEBUG ) -c = Client() -c.query(fql("42")) +client = Client() +client.query(fql('42')) ``` +For configuration options or to set specific log levels, see Python's [Logging HOWTO](https://docs.python.org/3/howto/logging.html). ## Setup