From 8611e8f47f4943415362b58f122f8e764e5d2af4 Mon Sep 17 00:00:00 2001 From: Steven Bal Date: Thu, 8 Feb 2024 16:24:01 +0100 Subject: [PATCH 1/2] :bug: [#34] Properly log data for error responses the handler previously did not log `status_code`, `response_ms` and `res_headers` because truthy checks on `Response` evaluate to false for error responses --- log_outgoing_requests/handlers.py | 16 ++++++++++------ log_outgoing_requests/utils.py | 12 ++++++------ 2 files changed, 16 insertions(+), 12 deletions(-) diff --git a/log_outgoing_requests/handlers.py b/log_outgoing_requests/handlers.py index 4dbbca4..697b811 100644 --- a/log_outgoing_requests/handlers.py +++ b/log_outgoing_requests/handlers.py @@ -92,14 +92,18 @@ def emit(self, record: AnyLogRecord): "url": request.url if request else "(unknown)", "hostname": parsed_url.netloc if parsed_url else "(unknown)", "params": parsed_url.params if parsed_url else "(unknown)", - "status_code": response.status_code if response else None, + "status_code": response.status_code if response is not None else None, "method": request.method if request else "(unknown)", "timestamp": timestamp, - "response_ms": int(response.elapsed.total_seconds() * 1000) - if response - else 0, + "response_ms": ( + int(response.elapsed.total_seconds() * 1000) + if response is not None + else 0 + ), "req_headers": self.format_headers(scrubbed_req_headers), - "res_headers": self.format_headers(response.headers if response else {}), + "res_headers": self.format_headers( + response.headers if response is not None else {} + ), "trace": "\n".join(format_exception(exception)) if exception else "", } @@ -121,7 +125,7 @@ def emit(self, record: AnyLogRecord): # check response if ( - response + response is not None and ( processed_response_body := process_body(response, config) ).allow_saving_to_db diff --git a/log_outgoing_requests/utils.py b/log_outgoing_requests/utils.py index be00f5b..6663613 100644 --- a/log_outgoing_requests/utils.py +++ b/log_outgoing_requests/utils.py @@ -113,9 +113,9 @@ def check_content_type(content_type: str) -> bool: For patterns containing a wildcard ("text/*"), check if `content_type.pattern` is a substring of any pattern contained in the list. """ - allowed_content_types: Iterable[ - ContentType - ] = settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES + allowed_content_types: Iterable[ContentType] = ( + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES + ) regular_patterns = [ item.pattern for item in allowed_content_types if not item.pattern.endswith("*") ] @@ -133,9 +133,9 @@ def get_default_encoding(content_type_pattern: str) -> str: """ Get the default encoding for the `ContentType` with the associated pattern. """ - allowed_content_types: Iterable[ - ContentType - ] = settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES + allowed_content_types: Iterable[ContentType] = ( + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES + ) regular_types = [ item for item in allowed_content_types if not item.pattern.endswith("*") From 3fb7733e936558f96a4c15799445fb4d10240898 Mon Sep 17 00:00:00 2001 From: Steven Bal Date: Thu, 8 Feb 2024 16:36:01 +0100 Subject: [PATCH 2/2] :white_check_mark: [#34] Add test for logging error response data --- tests/conftest.py | 19 +++++++++++++++ tests/test_logging.py | 54 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 73 insertions(+) diff --git a/tests/conftest.py b/tests/conftest.py index 0cf6fba..84041c1 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -69,6 +69,25 @@ def request_mock_kwargs(): } +@pytest.fixture +def request_mock_kwargs_error(): + return { + "url": "http://example.com:8000/some-path-that-doesnt-exist?version=2.0", + "status_code": 404, + "content": b"404 Not Found", + "request_headers": { + "Authorization": "test", + "Content-Type": "application/json", + "Content-Length": "24", + }, + "headers": { + "Date": "Tue, 21 Mar 2023 15:24:08 GMT", + "Content-Type": "text/plain", + "Content-Length": "13", + }, + } + + @pytest.fixture def request_mock_kwargs_binary(): return { diff --git a/tests/test_logging.py b/tests/test_logging.py index 9c62774..46030c0 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -1,6 +1,8 @@ """Integration tests for the core functionality of the library""" +import datetime import logging +from unittest.mock import patch import pytest import requests @@ -10,6 +12,11 @@ from log_outgoing_requests.models import OutgoingRequestsLog +def set_elapsed(response, *args, **kwargs): + response.elapsed = datetime.timedelta(seconds=2) + return response + + # # Local pytest fixtures # @@ -111,6 +118,53 @@ def test_data_is_saved(request_mock_kwargs, request_variants, expected_headers): assert request_log.res_body_encoding == "utf-8" +@pytest.mark.django_db +@freeze_time("2021-10-18 13:00:00") +def test_data_is_saved_for_error_response( + request_mock_kwargs_error, request_variants, expected_headers +): + for method, request_func, request_mock in request_variants: + request_mock(**request_mock_kwargs_error) + with patch( + "requests.sessions.default_hooks", return_value={"response": [set_elapsed]} + ): + response = request_func( + request_mock_kwargs_error["url"], + headers=request_mock_kwargs_error["request_headers"], + json={"test": "request data"}, + ) + + assert response.status_code == 404 + + request_log = OutgoingRequestsLog.objects.last() + + assert request_log.method == method + assert request_log.status_code == 404 + assert request_log.hostname == "example.com:8000" + assert request_log.params == "" + assert request_log.query_params == "version=2.0" + assert request_log.response_ms == 2000 + assert request_log.trace == "" + assert str(request_log) == "example.com:8000 at 2021-10-18 13:00:00+00:00" + assert ( + request_log.timestamp.strftime("%Y-%m-%d %H:%M:%S") == "2021-10-18 13:00:00" + ) + # headers + assert request_log.req_headers == expected_headers + assert ( + request_log.res_headers == "Date: Tue, 21 Mar 2023 15:24:08 GMT\n" + "Content-Type: text/plain\nContent-Length: 13" + ) + # request body + assert request_log.req_content_type == "application/json" + assert bytes(request_log.req_body) == b'{"test": "request data"}' + assert request_log.req_body_encoding == "utf-8" + # response body + assert request_log.res_content_type == "text/plain" + assert bytes(request_log.res_body) == b"404 Not Found" + assert request_log.res_body_encoding == "utf-8" + + # # test decoding of binary content #