diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 4e1c27c..92204c8 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -15,11 +15,8 @@ jobs: runs-on: ubuntu-latest strategy: matrix: - python: ["3.7", "3.8", "3.9", "3.10"] + python: ["3.8", "3.9", "3.10"] django: ["3.2", "4.1"] - exclude: - - python: "3.7" - django: "4.1" name: Run the test suite (Python ${{ matrix.python }}, Django ${{ matrix.django }}) diff --git a/README.rst b/README.rst index 2ad5883..f8b9f5c 100644 --- a/README.rst +++ b/README.rst @@ -97,6 +97,17 @@ To use this with your project you need to follow these steps: } LOG_OUTGOING_REQUESTS_DB_SAVE = True # save logs enabled/disabled based on the boolean value + LOG_OUTGOING_REQUESTS_DB_SAVE_BODY = True # save request/response body + LOG_OUTGOING_REQUESTS_EMIT_BODY = True # log request/response body + LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + "text/*", + "application/json", + "application/xml", + "application/soap+xml", + ] # save request/response bodies with matching content type + LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH = 524_288 # maximal size (in bytes) for the request/response body + LOG_OUTGOING_REQUESTS_LOG_BODY_TO_STDOUT = True + #. Run the migrations @@ -112,8 +123,9 @@ To use this with your project you need to follow these steps: res = requests.get("https://httpbin.org/json") print(res.json()) -#. Check stdout for the printable output, and navigate to ``/admin/log_outgoing_requests/outgoingrequestslog/`` to see - the saved log records +#. Check stdout for the printable output, and navigate to ``Admin > Miscellaneous > Outgoing Requests Logs`` + to see the saved log records. In order to override the settings for saving logs, navigate to + ``Admin > Miscellaneous > Outgoing Requests Log Configuration``. Local development diff --git a/docs/quickstart.rst b/docs/quickstart.rst index d1fabcb..24c7b9e 100644 --- a/docs/quickstart.rst +++ b/docs/quickstart.rst @@ -58,6 +58,17 @@ Installation } LOG_OUTGOING_REQUESTS_DB_SAVE = True # save logs enabled/disabled based on the boolean value + LOG_OUTGOING_REQUESTS_DB_SAVE_BODY = True # save request/response body + LOG_OUTGOING_REQUESTS_EMIT_BODY = True # log request/response body + LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + "text/*", + "application/json", + "application/xml", + "application/soap+xml", + ] # save request/response bodies with matching content type + LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH = 524_288 # maximal size (in bytes) for the request/response body + LOG_OUTGOING_REQUESTS_LOG_BODY_TO_STDOUT = True + #. Run ``python manage.py migrate`` to create the necessary database tables. diff --git a/log_outgoing_requests/admin.py b/log_outgoing_requests/admin.py index fdc9531..bb536a7 100644 --- a/log_outgoing_requests/admin.py +++ b/log_outgoing_requests/admin.py @@ -1,7 +1,11 @@ +from django import forms +from django.conf import settings from django.contrib import admin from django.utils.translation import gettext as _ -from .models import OutgoingRequestsLog +from solo.admin import SingletonModelAdmin + +from .models import OutgoingRequestsLog, OutgoingRequestsLogConfig @admin.register(OutgoingRequestsLog) @@ -31,10 +35,16 @@ class OutgoingRequestsLogAdmin(admin.ModelAdmin): "response_ms", "timestamp", ) - list_filter = ("method", "status_code", "hostname") + list_filter = ("method", "timestamp", "status_code", "hostname") search_fields = ("url", "params", "hostname") date_hierarchy = "timestamp" show_full_result_count = False + change_form_template = "log_outgoing_requests/change_form.html" + + class Media: + css = { + "all": ("log_outgoing_requests/css/admin.css",), + } def has_add_permission(self, request): return False @@ -42,7 +52,26 @@ def has_add_permission(self, request): def has_change_permission(self, request, obj=None): return False + @admin.display(description=_("Query parameters")) def query_params(self, obj): return obj.query_params - query_params.short_description = _("Query parameters") + +class ConfigAdminForm(forms.ModelForm): + class Meta: + model = OutgoingRequestsLogConfig + fields = "__all__" + help_texts = { + "save_to_db": _( + "Whether request logs should be saved to the database (default: {default})." + ).format(default=settings.LOG_OUTGOING_REQUESTS_DB_SAVE), + "save_body": _( + "Whether the body of the request and response should be logged (default: " + "{default})." + ).format(default=settings.LOG_OUTGOING_REQUESTS_DB_SAVE_BODY), + } + + +@admin.register(OutgoingRequestsLogConfig) +class OutgoingRequestsLogConfigAdmin(SingletonModelAdmin): + form = ConfigAdminForm diff --git a/log_outgoing_requests/compat.py b/log_outgoing_requests/compat.py new file mode 100644 index 0000000..2992046 --- /dev/null +++ b/log_outgoing_requests/compat.py @@ -0,0 +1,60 @@ +import django + +# Taken from djangorestframework, see +# https://github.com/encode/django-rest-framework/blob/376a5cbbba3f8df9c9db8c03a7c8fa2a6e6c05f4/rest_framework/compat.py#LL156C1-L177C10 +# +# License: +# +# Copyright © 2011-present, [Encode OSS Ltd](https://www.encode.io/). +# All rights reserved. +# +# Redistribution and use in source and binary forms, with or without +# modification, are permitted provided that the following conditions are met: +# +# * Redistributions of source code must retain the above copyright notice, this +# list of conditions and the following disclaimer. +# +# * Redistributions in binary form must reproduce the above copyright notice, +# this list of conditions and the following disclaimer in the documentation +# and/or other materials provided with the distribution. +# +# * Neither the name of the copyright holder nor the names of its +# contributors may be used to endorse or promote products derived from +# this software without specific prior written permission. +# +# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND +# ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED +# WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE +# DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE +# FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL +# DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR +# SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER +# CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, +# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE +# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + +if django.VERSION >= (4, 2): + # Django 4.2+: use the stock parse_header_parameters function + # Note: Django 4.1 also has an implementation of parse_header_parameters + # which is slightly different from the one in 4.2, it needs + # the compatibility shim as well. + from django.utils.http import parse_header_parameters # type: ignore +else: + # Django <= 4.1: create a compatibility shim for parse_header_parameters + from django.http.multipartparser import parse_header + + def parse_header_parameters(line): + # parse_header works with bytes, but parse_header_parameters + # works with strings. Call encode to convert the line to bytes. + main_value_pair, params = parse_header(line.encode()) + return main_value_pair, { + # parse_header will convert *some* values to string. + # parse_header_parameters converts *all* values to string. + # Make sure all values are converted by calling decode on + # any remaining non-string values. + k: v if isinstance(v, str) else v.decode() + for k, v in params.items() + } + + +__all__ = ["parse_header_parameters"] diff --git a/log_outgoing_requests/constants.py b/log_outgoing_requests/constants.py new file mode 100644 index 0000000..87522f0 --- /dev/null +++ b/log_outgoing_requests/constants.py @@ -0,0 +1,8 @@ +from django.db import models +from django.utils.translation import gettext_lazy as _ + + +class SaveLogsChoice(models.TextChoices): + use_default = "use_default", _("Use default") + yes = "yes", _("Yes") + no = "no", _("No") diff --git a/log_outgoing_requests/datastructures.py b/log_outgoing_requests/datastructures.py new file mode 100644 index 0000000..136b69a --- /dev/null +++ b/log_outgoing_requests/datastructures.py @@ -0,0 +1,27 @@ +""" +Datastructure(s) for use in settings.py + +Note: do not place any Django-specific imports in this file, as +it must be imported in settings.py. +""" + +from dataclasses import dataclass +from typing import Union + + +@dataclass +class ContentType: + """ + Data class for keeping track of content types and associated default encodings + """ + + pattern: str + default_encoding: str + + +@dataclass +class ProcessedBody: + allow_saving_to_db: bool + content: Union[bytes, str] + content_type: str + encoding: str diff --git a/log_outgoing_requests/formatters.py b/log_outgoing_requests/formatters.py index 8144286..047ad4a 100644 --- a/log_outgoing_requests/formatters.py +++ b/log_outgoing_requests/formatters.py @@ -1,30 +1,42 @@ import logging import textwrap +from django.conf import settings + class HttpFormatter(logging.Formatter): def _formatHeaders(self, d): return "\n".join(f"{k}: {v}" for k, v in d.items()) + def _formatBody(self, content: str, request_or_response: str) -> str: + if settings.LOG_OUTGOING_REQUESTS_EMIT_BODY: + return f"\n{request_or_response} body:\n{content}" + return "" + def formatMessage(self, record): result = super().formatMessage(record) - if record.name == "requests": - result += textwrap.dedent( - """ - ---------------- request ---------------- - {req.method} {req.url} - {reqhdrs} - ---------------- response ---------------- - {res.status_code} {res.reason} {res.url} - {reshdrs} + if record.name != "requests": + return result + result += textwrap.dedent( """ - ).format( - req=record.req, - res=record.res, - reqhdrs=self._formatHeaders(record.req.headers), - reshdrs=self._formatHeaders(record.res.headers), - ) + ---------------- request ---------------- + {req.method} {req.url} + {reqhdrs} {request_body} + + ---------------- response ---------------- + {res.status_code} {res.reason} {res.url} + {reshdrs} {response_body} + + """ + ).format( + req=record.req, + res=record.res, + reqhdrs=self._formatHeaders(record.req.headers), + reshdrs=self._formatHeaders(record.res.headers), + request_body=self._formatBody(record.req.body, "Request"), + response_body=self._formatBody(record.res.content, "Response"), + ) return result diff --git a/log_outgoing_requests/handlers.py b/log_outgoing_requests/handlers.py index 631f147..f067be2 100644 --- a/log_outgoing_requests/handlers.py +++ b/log_outgoing_requests/handlers.py @@ -1,44 +1,91 @@ +# NOTE: Avoid import Django specifics at the module level to prevent circular imports. +# The handler is loaded eagerly at django startup when configuring settings. import logging import traceback +from datetime import datetime +from logging import LogRecord +from typing import Union, cast from urllib.parse import urlparse -from django.conf import settings +from requests.models import PreparedRequest, Response + + +class RequestLogRecord(LogRecord): + requested_at: datetime + req: PreparedRequest + res: Response + + +AnyLogRecord = Union[LogRecord, RequestLogRecord] + + +def is_request_log_record(record: AnyLogRecord) -> bool: + attrs = ("requested_at", "req", "res") + if any(not hasattr(record, attr) for attr in attrs): + return False + return True class DatabaseOutgoingRequestsHandler(logging.Handler): - def emit(self, record): - if settings.LOG_OUTGOING_REQUESTS_DB_SAVE: - from .models import OutgoingRequestsLog - - trace = None - - # save only the requests coming from the library requests - if record and record.getMessage() == "Outgoing request": - safe_req_headers = record.req.headers.copy() - - if "Authorization" in safe_req_headers: - safe_req_headers["Authorization"] = "***hidden***" - - if record.exc_info: - trace = traceback.format_exc() - - parsed_url = urlparse(record.req.url) - kwargs = { - "url": record.req.url, - "hostname": parsed_url.hostname, - "params": parsed_url.params, - "status_code": record.res.status_code, - "method": record.req.method, - "req_content_type": record.req.headers.get("Content-Type", ""), - "res_content_type": record.res.headers.get("Content-Type", ""), - "timestamp": record.requested_at, - "response_ms": int(record.res.elapsed.total_seconds() * 1000), - "req_headers": self.format_headers(safe_req_headers), - "res_headers": self.format_headers(record.res.headers), - "trace": trace, - } - - OutgoingRequestsLog.objects.create(**kwargs) + def emit(self, record: AnyLogRecord): + from .models import OutgoingRequestsLog, OutgoingRequestsLogConfig + from .utils import process_body + + config = cast(OutgoingRequestsLogConfig, OutgoingRequestsLogConfig.get_solo()) + if not config.save_logs_enabled: + return + + # skip requests not coming from the library requests + if not record or not is_request_log_record(record): + return + # Typescript type predicates would be cool here :) + record = cast(RequestLogRecord, record) + + scrubbed_req_headers = record.req.headers.copy() + + if "Authorization" in scrubbed_req_headers: + scrubbed_req_headers["Authorization"] = "***hidden***" + + trace = traceback.format_exc() if record.exc_info else "" + + parsed_url = urlparse(record.req.url) + kwargs = { + "url": record.req.url, + "hostname": parsed_url.netloc, + "params": parsed_url.params, + "status_code": record.res.status_code, + "method": record.req.method, + "timestamp": record.requested_at, + "response_ms": int(record.res.elapsed.total_seconds() * 1000), + "req_headers": self.format_headers(scrubbed_req_headers), + "res_headers": self.format_headers(record.res.headers), + "trace": trace, + } + + if config.save_body_enabled: + # check request + processed_request_body = process_body(record.req, config) + if processed_request_body.allow_saving_to_db: + kwargs.update( + { + "req_content_type": processed_request_body.content_type, + "req_body": processed_request_body.content, + "req_body_encoding": processed_request_body.encoding, + } + ) + + # check response + processed_response_body = process_body(record.res, config) + if processed_response_body.allow_saving_to_db: + kwargs.update( + { + "res_content_type": processed_response_body.content_type, + "res_body": processed_response_body.content, + "res_body_encoding": processed_response_body.encoding, + } + ) + + OutgoingRequestsLog.objects.create(**kwargs) def format_headers(self, headers): return "\n".join(f"{k}: {v}" for k, v in headers.items()) diff --git a/log_outgoing_requests/log_requests.py b/log_outgoing_requests/log_requests.py index e32a513..f89dd79 100644 --- a/log_outgoing_requests/log_requests.py +++ b/log_outgoing_requests/log_requests.py @@ -20,16 +20,16 @@ def install_outgoing_requests_logging(): Log all outgoing requests which are made by the library requests during a session. """ - if hasattr(Session, "_original_request"): + if hasattr(Session, "_initial_request"): logger.debug( - "Session is already patched OR has an ``_original_request`` attribute." + "Session is already patched OR has an ``_initial_request`` attribute." ) return - Session._original_request = Session.request + Session._initial_request = Session.request # type: ignore def new_request(self, *args, **kwargs): self.hooks["response"].append(hook_requests_logging) - return self._original_request(*args, **kwargs) + return self._initial_request(*args, **kwargs) Session.request = new_request diff --git a/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py b/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py new file mode 100644 index 0000000..3c99adc --- /dev/null +++ b/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py @@ -0,0 +1,179 @@ +# Generated by Django 3.2.1 on 2023-06-02 16:22 + +import django.core.validators +from django.db import migrations, models + +import log_outgoing_requests.models + + +class Migration(migrations.Migration): + dependencies = [ + ("log_outgoing_requests", "0001_initial"), + ] + + operations = [ + migrations.CreateModel( + name="OutgoingRequestsLogConfig", + fields=[ + ( + "id", + models.AutoField( + auto_created=True, + primary_key=True, + serialize=False, + verbose_name="ID", + ), + ), + ( + "save_to_db", + models.CharField( + choices=[ + ("use_default", "Use default"), + ("yes", "Yes"), + ("no", "No"), + ], + default="use_default", + max_length=11, + verbose_name="Save logs to database", + ), + ), + ( + "save_body", + models.CharField( + choices=[ + ("use_default", "Use default"), + ("yes", "Yes"), + ("no", "No"), + ], + default="use_default", + max_length=11, + verbose_name="Save request + response body", + ), + ), + ( + "max_content_length", + models.IntegerField( + default=log_outgoing_requests.models.get_default_max_content_length, + help_text="The maximal size of the request/response content (in bytes). If 'Require content length' is not checked, this setting has no effect.", + validators=[django.core.validators.MinValueValidator(0)], + verbose_name="Maximal content size", + ), + ), + ], + options={ + "verbose_name": "Outgoing Requests Log Configuration", + }, + ), + migrations.AddField( + model_name="outgoingrequestslog", + name="req_body", + field=models.BinaryField( + default=b"", help_text="The request body.", verbose_name="Request body" + ), + ), + migrations.AddField( + model_name="outgoingrequestslog", + name="req_body_encoding", + field=models.CharField(default="", max_length=24), + ), + migrations.AddField( + model_name="outgoingrequestslog", + name="res_body", + field=models.BinaryField( + default=b"", + help_text="The response body.", + verbose_name="Response body", + ), + ), + migrations.AddField( + model_name="outgoingrequestslog", + name="res_body_encoding", + field=models.CharField(default="", max_length=24), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="hostname", + field=models.CharField( + default="", + help_text="The netloc/hostname part of the url.", + max_length=255, + verbose_name="Hostname", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="method", + field=models.CharField( + blank=True, + help_text="The type of request method.", + max_length=10, + verbose_name="Method", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="req_content_type", + field=models.CharField( + default="", + help_text="The content type of the request.", + max_length=50, + verbose_name="Request content type", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="req_headers", + field=models.TextField( + default="", + help_text="The request headers.", + verbose_name="Request headers", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="res_content_type", + field=models.CharField( + default="", + help_text="The content type of the response.", + max_length=50, + verbose_name="Response content type", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="res_headers", + field=models.TextField( + default="", + help_text="The response headers.", + verbose_name="Response headers", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="response_ms", + field=models.PositiveIntegerField( + default=0, + help_text="This is the response time in ms.", + verbose_name="Response in ms", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="trace", + field=models.TextField( + default="", + help_text="Text providing information in case of request failure.", + verbose_name="Trace", + ), + ), + migrations.AlterField( + model_name="outgoingrequestslog", + name="url", + field=models.URLField( + default="", + help_text="The url of the outgoing request.", + max_length=1000, + verbose_name="URL", + ), + ), + ] diff --git a/log_outgoing_requests/models.py b/log_outgoing_requests/models.py index 215e481..81249cb 100644 --- a/log_outgoing_requests/models.py +++ b/log_outgoing_requests/models.py @@ -1,15 +1,24 @@ +import logging +from typing import Union from urllib.parse import urlparse +from django.conf import settings +from django.core.validators import MinValueValidator from django.db import models from django.utils.functional import cached_property from django.utils.translation import gettext_lazy as _ +from solo.models import SingletonModel # type: ignore + +from .constants import SaveLogsChoice + +logger = logging.getLogger(__name__) + class OutgoingRequestsLog(models.Model): url = models.URLField( verbose_name=_("URL"), max_length=1000, - blank=True, default="", help_text=_("The url of the outgoing request."), ) @@ -19,8 +28,7 @@ class OutgoingRequestsLog(models.Model): verbose_name=_("Hostname"), max_length=255, default="", - blank=True, - help_text=_("The hostname part of the url."), + help_text=_("The netloc/hostname part of the url."), ) params = models.TextField( verbose_name=_("Parameters"), @@ -36,7 +44,6 @@ class OutgoingRequestsLog(models.Model): method = models.CharField( verbose_name=_("Method"), max_length=10, - default="", blank=True, help_text=_("The type of request method."), ) @@ -44,32 +51,45 @@ class OutgoingRequestsLog(models.Model): verbose_name=_("Request content type"), max_length=50, default="", - blank=True, help_text=_("The content type of the request."), ) res_content_type = models.CharField( verbose_name=_("Response content type"), max_length=50, default="", - blank=True, help_text=_("The content type of the response."), ) req_headers = models.TextField( verbose_name=_("Request headers"), - blank=True, - null=True, + default="", help_text=_("The request headers."), ) res_headers = models.TextField( verbose_name=_("Response headers"), - blank=True, - null=True, + default="", help_text=_("The response headers."), ) + req_body = models.BinaryField( + verbose_name=_("Request body"), + default=b"", + help_text=_("The request body."), + ) + res_body = models.BinaryField( + verbose_name=_("Response body"), + default=b"", + help_text=_("The response body."), + ) + req_body_encoding = models.CharField( + max_length=24, + default="", + ) + res_body_encoding = models.CharField( + max_length=24, + default="", + ) response_ms = models.PositiveIntegerField( verbose_name=_("Response in ms"), default=0, - blank=True, help_text=_("This is the response time in ms."), ) timestamp = models.DateTimeField( @@ -78,8 +98,7 @@ class OutgoingRequestsLog(models.Model): ) trace = models.TextField( verbose_name=_("Trace"), - blank=True, - null=True, + default="", help_text=_("Text providing information in case of request failure."), ) @@ -99,3 +118,88 @@ def url_parsed(self): @property def query_params(self): return self.url_parsed.query + + def _decode_body(self, content: Union[bytes, memoryview], encoding: str) -> str: + """ + Decode body for use in template. + + If the stored encoding is not found (either because it is empty or because of + spelling errors etc.), we decode "blindly", replacing chars that could not be + decoded. + + Inspired on :meth:`requests.models.Response.text`, which is Apache 2.0 licensed. + """ + try: + return str(content, encoding, errors="replace") + except LookupError: + # A LookupError is raised if the encoding was not found which could + # indicate a misspelling or similar mistake. + return str(content, errors="replace") + + @cached_property + def request_body_decoded(self) -> str: + """ + Decoded request body for use in template. + """ + return self._decode_body(self.req_body, self.req_body_encoding) + + @cached_property + def response_body_decoded(self) -> str: + """ + Decoded response body for use in template. + """ + return self._decode_body(self.res_body, self.res_body_encoding) + + +def get_default_max_content_length(): + """ + Get default value for max content length from settings. + """ + return settings.LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH + + +class OutgoingRequestsLogConfig(SingletonModel): + """Configuration options for request logging.""" + + save_to_db = models.CharField( + _("Save logs to database"), + max_length=11, + choices=SaveLogsChoice.choices, + default=SaveLogsChoice.use_default, + ) + save_body = models.CharField( + _("Save request + response body"), + max_length=11, + choices=SaveLogsChoice.choices, + default=SaveLogsChoice.use_default, + ) + max_content_length = models.IntegerField( + _("Maximal content size"), + validators=[MinValueValidator(0)], + default=get_default_max_content_length, + help_text=_( + "The maximal size of the request/response content (in bytes). " + "If 'Require content length' is not checked, this setting has no effect." + ), + ) + + @property + def save_logs_enabled(self): + """ + Use configuration option or settings to determine if logs should be saved. + """ + if self.save_to_db == SaveLogsChoice.use_default: + return settings.LOG_OUTGOING_REQUESTS_DB_SAVE + return self.save_to_db == SaveLogsChoice.yes + + @property + def save_body_enabled(self): + """ + Use configuration option or settings to determine if log bodies should be saved. + """ + if self.save_body == SaveLogsChoice.use_default: + return settings.LOG_OUTGOING_REQUESTS_DB_SAVE_BODY + return self.save_body == SaveLogsChoice.yes + + class Meta: + verbose_name = _("Outgoing Requests Log Configuration") diff --git a/log_outgoing_requests/static/log_outgoing_requests/css/admin.css b/log_outgoing_requests/static/log_outgoing_requests/css/admin.css new file mode 100644 index 0000000..5654b4d --- /dev/null +++ b/log_outgoing_requests/static/log_outgoing_requests/css/admin.css @@ -0,0 +1,9 @@ +.field-res_body { + display: inline-block; + width: var(--dlor-body-width, 40rem); + font-family: monospace; + line-height: 1.5rem; +} +input[name="max_content_length"] { + width: 7.25em; +} diff --git a/log_outgoing_requests/templates/log_outgoing_requests/change_form.html b/log_outgoing_requests/templates/log_outgoing_requests/change_form.html new file mode 100644 index 0000000..2bbabca --- /dev/null +++ b/log_outgoing_requests/templates/log_outgoing_requests/change_form.html @@ -0,0 +1,16 @@ +{% extends "admin/change_form.html" %} + +{% block after_field_sets %} +
+
+ +
{{ original.request_body_decoded }}
+
+
+
+
+ +
{{ original.response_body_decoded }}
+
+
+{% endblock %} diff --git a/log_outgoing_requests/utils.py b/log_outgoing_requests/utils.py new file mode 100644 index 0000000..80b6d38 --- /dev/null +++ b/log_outgoing_requests/utils.py @@ -0,0 +1,161 @@ +"""Tests for the utility functions""" + +import logging +from typing import Iterable, Tuple, Union + +from django.conf import settings + +from requests import PreparedRequest, Response + +from .compat import parse_header_parameters +from .datastructures import ContentType, ProcessedBody +from .models import OutgoingRequestsLogConfig + +logger = logging.getLogger(__name__) + +HttpObj = Union[PreparedRequest, Response] + + +def process_body(http_obj: HttpObj, config: OutgoingRequestsLogConfig) -> ProcessedBody: + """ + Process a request or response body by parsing the meta information. + """ + content_type, encoding = parse_content_type_header(http_obj) + if not encoding: + encoding = get_default_encoding(content_type) + allow_persisting = check_content_type(content_type) and check_content_length( + http_obj, config=config + ) + content = _get_body(http_obj) if allow_persisting else b"" + return ProcessedBody( + allow_saving_to_db=allow_persisting, + content=content or b"", + content_type=content_type, + encoding=encoding, + ) + + +# +# Handler utilities +# +def _get_body(http_obj: HttpObj) -> Union[bytes, str, None]: + return http_obj.content if isinstance(http_obj, Response) else http_obj.body + + +def _get_content_length(http_obj: HttpObj) -> str: + """ + Try to determine the size of a request/response content. + + Try `Content-Length` header first. If not present, try to + determine the size by reading `len(body)`. The entire content + is thereby read into memory (the assumption being that the content + will eventually be consumed anyway). + """ + content_length = http_obj.headers.get("Content-Length", "") + + if not content_length: + body = _get_body(http_obj) + if body is not None: + content_length = str(len(body)) + + return content_length + + +def check_content_length( + http_obj: HttpObj, + config: "OutgoingRequestsLogConfig", +) -> bool: + """ + Check `content_length` against settings. + + If `content_length` could not be determined (i.e. `content_length` == ""), the test + passes with a warning. + """ + content_length = _get_content_length(http_obj) + + if not content_length: + # for logging: get netloc (response) or url (request) + target = getattr(http_obj, "netloc", "") or http_obj.url + logger.warning( + "Content length of the request/response (request netloc: %s) could not be determined." + % target + ) + return True + + max_content_length = config.max_content_length + + return int(content_length) <= max_content_length + + +def parse_content_type_header(http_obj: HttpObj) -> Tuple[str, str]: + """ + Wrapper around Django's `parse_header`. + + If a charset/encoding is found, we replace the representation of it with a string. + + :returns: a `tuple` (content_type, encoding) + """ + content_type_line = http_obj.headers.get("Content-Type", "") + if not content_type_line: + return ("", "") + + content_type, params = parse_header_parameters(content_type_line) + encoding = params.get("charset", "") + return content_type, encoding + + +def check_content_type(content_type: str) -> bool: + """ + Check `content_type` against settings. + + The string patterns of the content types specified under `LOG_OUTGOING_REQUESTS_ + CONTENT_TYPES` are split into two groups. For regular patterns not containing a + wildcard ("text/xml"), check if `content_type.pattern` is included in the list. + 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 + regular_patterns = [ + item.pattern for item in allowed_content_types if not item.pattern.endswith("*") + ] + wildcard_patterns = [ + item.pattern for item in allowed_content_types if item.pattern.endswith("*") + ] + + if content_type in regular_patterns: + return True + + return any(content_type.startswith(pattern[:-1]) for pattern in wildcard_patterns) + + +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 + + regular_types = [ + item for item in allowed_content_types if not item.pattern.endswith("*") + ] + wildcard_types = [ + item for item in allowed_content_types if item.pattern.endswith("*") + ] + + content_type = next( + (item for item in regular_types if item.pattern == content_type_pattern), None + ) + if content_type is None: + content_type = next( + ( + item + for item in wildcard_types + if content_type_pattern.startswith(item.pattern[:-1]) + ), + None, + ) + + return content_type.default_encoding if content_type else "" diff --git a/setup.cfg b/setup.cfg index 7fe5f25..5598da6 100644 --- a/setup.cfg +++ b/setup.cfg @@ -24,7 +24,6 @@ classifiers = Operating System :: Unix Operating System :: MacOS Operating System :: Microsoft :: Windows - Programming Language :: Python :: 3.7 Programming Language :: Python :: 3.8 Programming Language :: Python :: 3.9 Programming Language :: Python :: 3.10 @@ -37,6 +36,7 @@ packages = find: install_requires = django >= 3.2 requests + django-solo tests_require = pytest pytest-django @@ -46,6 +46,7 @@ tests_require = flake8 freezegun requests-mock + pyquery [options.packages.find] include = @@ -56,6 +57,7 @@ include = tests = pytest pytest-django + pyquery tox isort black @@ -93,6 +95,8 @@ sections=FUTURE,STDLIB,DJANGO,THIRDPARTY,FIRSTPARTY,LOCALFOLDER [tool:pytest] testpaths = tests DJANGO_SETTINGS_MODULE=testapp.settings +filterwarnings = + error:DateTimeField .* received a naive datetime:RuntimeWarning:django.db.models.fields [pep8] [flake8] diff --git a/testapp/settings.py b/testapp/settings.py index 15ab347..adf56b0 100644 --- a/testapp/settings.py +++ b/testapp/settings.py @@ -1,5 +1,6 @@ import os +from log_outgoing_requests.datastructures import ContentType from log_outgoing_requests.formatters import HttpFormatter BASE_DIR = os.path.abspath(os.path.dirname(__file__)) @@ -16,6 +17,7 @@ INSTALLED_APPS = [ "django.contrib.contenttypes", "django.contrib.auth", + "django.contrib.messages", "django.contrib.sessions", "django.contrib.admin", "log_outgoing_requests", @@ -91,6 +93,16 @@ # LOG OUTGOING REQUESTS # LOG_OUTGOING_REQUESTS_DB_SAVE = True +LOG_OUTGOING_REQUESTS_DB_SAVE_BODY = True +LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + ContentType(pattern="application/json", default_encoding="utf-8"), + ContentType(pattern="application/soap+xml", default_encoding="utf-8"), + ContentType(pattern="application/xml", default_encoding="utf-8"), + ContentType(pattern="text/xml", default_encoding="iso-8859-1"), + ContentType(pattern="text/*", default_encoding="utf-8"), +] +LOG_OUTGOING_REQUESTS_EMIT_BODY = True +LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH = 524_288 # 0.5 MB ROOT_URLCONF = "testapp.urls" diff --git a/tests/conftest.py b/tests/conftest.py new file mode 100644 index 0000000..9762ff1 --- /dev/null +++ b/tests/conftest.py @@ -0,0 +1,59 @@ +"""Global pytest fixtures""" + +import pytest + +from log_outgoing_requests.datastructures import ContentType + + +# +# default settings +# +@pytest.fixture +def default_settings(settings): + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + ContentType(pattern="application/json", default_encoding="utf-8"), + ContentType(pattern="application/soap+xml", default_encoding="utf-8"), + ContentType(pattern="application/xml", default_encoding="utf-8"), + ContentType(pattern="text/xml", default_encoding="iso-8859-1"), + ContentType(pattern="text/*", default_encoding="utf-8"), + ] + return settings + + +# +# requests data +# +@pytest.fixture +def request_mock_kwargs(): + return { + "url": "http://example.com:8000/some-path?version=2.0", + "status_code": 200, + "json": {"test": "response data"}, + "request_headers": { + "Authorization": "test", + "Content-Type": "application/json", + "Content-Length": "24", + }, + "headers": { + "Date": "Tue, 21 Mar 2023 15:24:08 GMT", + "Content-Type": "application/json", + "Content-Length": "25", + }, + } + + +@pytest.fixture +def request_mock_kwargs_binary(): + return { + "url": "http://example.com:8000/some-path?version=2.0", + "status_code": 200, + "content": b"{\x03\xff\x00d", + "request_headers": { + "Authorization": "test", + "Content-Type": "binary", + }, + "headers": { + "Date": "Tue, 21 Mar 2023 15:24:08 GMT", + "Content-Type": "binary", + }, + } diff --git a/tests/test_admin.py b/tests/test_admin.py new file mode 100644 index 0000000..5238036 --- /dev/null +++ b/tests/test_admin.py @@ -0,0 +1,96 @@ +"""Tests for the admin interface""" + +from django.urls import reverse +from django.utils import timezone + +import pytest +import requests +from pyquery import PyQuery + +from log_outgoing_requests.models import OutgoingRequestsLog, OutgoingRequestsLogConfig + + +# +# test display +# +@pytest.mark.django_db +def test_decoded_content_display(admin_client): + """Assert that decoded request/response bodies are properly displayed""" + + log = OutgoingRequestsLog.objects.create( + id=1, + req_body=b"I'm a lumberjack and I'm okay.", + res_body=b"I sleep all night and work all day.", + timestamp=timezone.now(), + ) + url = reverse( + "admin:log_outgoing_requests_outgoingrequestslog_change", args=(log.pk,) + ) + + response = admin_client.get(url) + assert response.status_code == 200 + + html = response.content.decode("utf-8") + doc = PyQuery(html) + request_body = doc.find(".request-body-decoded").text() + response_body = doc.find(".response-body-decoded").text() + + assert request_body == "I'm a lumberjack and I'm okay." + assert response_body == "I sleep all night and work all day." + + +# +# test override of settings +# +@pytest.mark.django_db +def test_admin_override_db_save(requests_mock, request_mock_kwargs): + """Assert that saving logs can be disabled in admin""" + + config = OutgoingRequestsLogConfig.get_solo() + config.save_to_db = "no" + config.save() + + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + request_log = OutgoingRequestsLog.objects.last() + + assert request_log is None + + +@pytest.mark.django_db +def test_admin_override_save_body(requests_mock, request_mock_kwargs): + """Assert that saving body can be disabled in admin""" + + config = OutgoingRequestsLogConfig.get_solo() + config.save_body = "no" + config.save() + + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + request_log = OutgoingRequestsLog.objects.last() + + assert request_log.res_body == b"" + + +@pytest.mark.django_db +def test_admin_override_max_content_length(requests_mock, request_mock_kwargs): + """Assert that `max_content_length` can be overriden in admin""" + + config = OutgoingRequestsLogConfig.get_solo() + config.max_content_length = "10" + config.save() + + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + request_log = OutgoingRequestsLog.objects.last() + + assert request_log.res_body == b"" diff --git a/tests/test_formatter.py b/tests/test_formatter.py new file mode 100644 index 0000000..ded4c45 --- /dev/null +++ b/tests/test_formatter.py @@ -0,0 +1,46 @@ +"""Tests for the HttpFormatter helper class""" + +import logging + +import pytest +import requests + +from log_outgoing_requests.formatters import HttpFormatter + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "log_body, expected", + [ + (True, True), + (False, False), + ], +) +def test_formatter( + requests_mock, + request_mock_kwargs, + caplog, + settings, + log_body, + expected, +): + """Assert that request/response bodies are (not) saved if setting is enabled (disabled)""" + + settings.LOG_OUTGOING_REQUESTS_EMIT_BODY = log_body + + formatter = HttpFormatter() + + with caplog.at_level(logging.DEBUG): + requests_mock.post(**request_mock_kwargs) + requests.post( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) + + record = caplog.records[1] + + res = formatter.formatMessage(record) + + assert ('{"test": "request data"}' in res) is expected + assert ('{"test": "response data"}' in res) is expected diff --git a/tests/test_logging.py b/tests/test_logging.py index e0f8dd2..f926e01 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -1,141 +1,244 @@ -from django.test import TestCase, override_settings +"""Integration tests for the core functionality of the library""" +import logging + +import pytest import requests -import requests_mock from freezegun import freeze_time +from log_outgoing_requests.datastructures import ContentType from log_outgoing_requests.models import OutgoingRequestsLog -@requests_mock.Mocker() +# +# Local pytest fixtures +# +@pytest.fixture() +def request_variants(requests_mock): + return [ + ("GET", requests.get, requests_mock.get), + ("POST", requests.post, requests_mock.post), + ("PUT", requests.put, requests_mock.put), + ("PATCH", requests.patch, requests_mock.patch), + ("DELETE", requests.delete, requests_mock.delete), + ("HEAD", requests.head, requests_mock.head), + ] + + +@pytest.fixture() +def expected_headers(): + return ( + f"User-Agent: python-requests/{requests.__version__}\n" + "Accept-Encoding: gzip, deflate\n" + "Accept: */*\n" + "Connection: keep-alive\n" + "Authorization: ***hidden***\n" + "Content-Type: application/json\n" + "Content-Length: 24" + ) + + +# +# Tests +# +@pytest.mark.django_db +def test_data_is_logged(requests_mock, request_mock_kwargs, caplog): + with caplog.at_level(logging.DEBUG): + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + records = caplog.records + assert records[1].levelname == "DEBUG" + assert records[1].name == "requests" + assert records[1].msg == "Outgoing request" + + +@pytest.mark.django_db @freeze_time("2021-10-18 13:00:00") -class OutgoingRequestsLoggingTests(TestCase): - def _setUpMocks(self, m): - m.get( - "http://example.com/some-path?version=2.0", - status_code=200, - content=b"some content", +def test_data_is_saved(request_mock_kwargs, request_variants, expected_headers): + for method, request_func, request_mock in request_variants: + request_mock(**request_mock_kwargs) + response = request_func( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, ) - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - def test_outgoing_requests_are_logged(self, m): - self._setUpMocks(m) - - with self.assertLogs("requests", level="DEBUG") as logs: - requests.get("http://example.com/some-path?version=2.0") - - self.assertEqual(logs.output, ["DEBUG:requests:Outgoing request"]) - self.assertEqual(logs.records[0].name, "requests") - self.assertEqual(logs.records[0].getMessage(), "Outgoing request") - self.assertEqual(logs.records[0].levelname, "DEBUG") - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - def test_expected_data_is_saved_when_saving_enabled(self, m): - methods = [ - ("GET", requests.get, m.get), - ("POST", requests.post, m.post), - ("PUT", requests.put, m.put), - ("PATCH", requests.patch, m.patch), - ("DELETE", requests.delete, m.delete), - ("HEAD", requests.head, m.head), - ] - - for method, func, mocked in methods: - with self.subTest(): - mocked( - "http://example.com/some-path?version=2.0", - status_code=200, - json={"test": "data"}, - request_headers={ - "Authorization": "test", - "Content-Type": "text/html", - }, - headers={ - "Date": "Tue, 21 Mar 2023 15:24:08 GMT", - "Content-Type": "application/json", - }, - ) - expected_req_headers = ( - f"User-Agent: python-requests/{requests.__version__}\n" - "Accept-Encoding: gzip, deflate\n" - "Accept: */*\n" - "Connection: keep-alive\n" - "Authorization: ***hidden***\n" - "Content-Type: text/html" - ) - if method not in ["HEAD", "GET"]: - expected_req_headers += "\nContent-Length: 0" - - response = func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "text/html"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertEqual( - request_log.url, "http://example.com/some-path?version=2.0" - ) - self.assertEqual(request_log.hostname, "example.com") - self.assertEqual(request_log.params, "") - self.assertEqual(request_log.query_params, "version=2.0") - self.assertEqual(response.status_code, 200) - self.assertEqual(request_log.method, method) - self.assertEqual(request_log.req_content_type, "text/html") - self.assertEqual(request_log.res_content_type, "application/json") - self.assertEqual(request_log.response_ms, 0) - self.assertEqual(request_log.req_headers, expected_req_headers) - self.assertEqual( - request_log.res_headers, - "Date: Tue, 21 Mar 2023 15:24:08 GMT\nContent-Type: application/json", - ) - self.assertEqual( - request_log.timestamp.strftime("%Y-%m-%d %H:%M:%S"), - "2021-10-18 13:00:00", - ) - self.assertIsNone(request_log.trace) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - def test_authorization_header_is_hidden(self, m): - self._setUpMocks(m) + assert response.status_code == 200 - requests.get( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test"}, + request_log = OutgoingRequestsLog.objects.last() + + assert request_log.method == method + assert request_log.hostname == "example.com:8000" + assert request_log.params == "" + assert request_log.query_params == "version=2.0" + assert request_log.response_ms == 0 + 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: application/json\nContent-Length: 25" + ) + # 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 == "application/json" + assert bytes(request_log.res_body) == b'{"test": "response data"}' + assert request_log.res_body_encoding == "utf-8" + + +# +# test decoding of binary content +# +@pytest.mark.parametrize( + "content, encoding, expected", + [ + (b"test\x03\xff\xff{\x03}", "utf-8", "test\x03��{\x03}"), + (b"test\x03\xff\xff{\x03}", "utx-99", "test\x03��{\x03}"), + (b"test{\x03\xff\xff\x00d", "", "test{\x03��\x00d"), + ], +) +@pytest.mark.django_db +def test_decoding_of_binary_content( + content, encoding, expected, requests_mock, request_mock_kwargs_binary, settings +): + """ + Assert that decoding of binary contents works with: + - correct encoding + - wrong (e.g. misspelled) encoding + - missing encoding + """ + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + ContentType(pattern="binary", default_encoding=encoding) + ] + + request_mock_kwargs_binary["content"] = content + + requests_mock.post(**request_mock_kwargs_binary) + response = requests.post( + request_mock_kwargs_binary["url"], + headers=request_mock_kwargs_binary["request_headers"], + data=content, + ) + + assert response.status_code == 200 + + request_log = OutgoingRequestsLog.objects.last() + + assert request_log.response_body_decoded == expected + assert request_log.request_body_decoded == expected + + +@pytest.mark.django_db +def test_authorization_header_is_hidden(requests_mock, request_mock_kwargs): + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + log = OutgoingRequestsLog.objects.get() + + assert "Authorization: ***hidden***" in log.req_headers + + +@pytest.mark.django_db +def test_disable_save_db(request_mock_kwargs, request_variants, caplog, settings): + """Assert that data is logged but not saved to DB when setting is disabled""" + + settings.LOG_OUTGOING_REQUESTS_DB_SAVE = False + + for method, request_func, request_mock in request_variants: + with caplog.at_level(logging.DEBUG): + request_mock(**request_mock_kwargs) + response = request_func( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) + + assert response.status_code == 200 + + # data is logged + records = caplog.records + assert records[1].levelname == "DEBUG" + assert records[1].name == "requests" + assert records[1].msg == "Outgoing request" + + # data is not saved + assert OutgoingRequestsLog.objects.exists() is False + + +@pytest.mark.django_db +def test_disable_save_body(request_mock_kwargs, request_variants, settings): + """Assert that request/response bodies are not saved when setting is disabled""" + + settings.LOG_OUTGOING_REQUESTS_DB_SAVE_BODY = False + + for method, request_func, request_mock in request_variants: + request_mock(**request_mock_kwargs) + response = request_func( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, ) - log = OutgoingRequestsLog.objects.get() - self.assertIn("Authorization: ***hidden***", log.req_headers) + assert response.status_code == 200 - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=False) - def test_data_is_not_saved_when_saving_disabled(self, m): - self._setUpMocks(m) + request_log = OutgoingRequestsLog.objects.last() - with self.assertLogs("requests", level="DEBUG") as logs: - requests.get("http://example.com/some-path?version=2.0") + assert bytes(request_log.req_body) == b"" + assert bytes(request_log.res_body) == b"" - self.assertEqual(logs.output, ["DEBUG:requests:Outgoing request"]) - self.assertEqual(logs.records[0].name, "requests") - self.assertEqual(logs.records[0].getMessage(), "Outgoing request") - self.assertEqual(logs.records[0].levelname, "DEBUG") - self.assertFalse(OutgoingRequestsLog.objects.exists()) - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=False) - def test_outgoing_requests_are_logged_when_saving_disabled(self, m): - self._setUpMocks(m) +@pytest.mark.django_db +def test_content_type_not_allowed(request_mock_kwargs, request_variants, settings): + """Assert that request/response bodies are not saved when content type is not allowed""" - with self.assertLogs("requests", level="DEBUG") as logs: - requests.get("http://example.com/some-path?version=2.0") + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + ContentType(pattern="text/*", default_encoding="utf-8") + ] - self.assertEqual(logs.output, ["DEBUG:requests:Outgoing request"]) - self.assertEqual(logs.records[0].name, "requests") - self.assertEqual(logs.records[0].getMessage(), "Outgoing request") - self.assertEqual(logs.records[0].levelname, "DEBUG") + for method, request_func, request_mock in request_variants: + request_mock(**request_mock_kwargs) + response = request_func( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) + + assert response.status_code == 200 + + request_log = OutgoingRequestsLog.objects.last() + + assert bytes(request_log.req_body) == b"" + assert bytes(request_log.res_body) == b"" + + +@pytest.mark.django_db +def test_content_length_exceeded(request_mock_kwargs, request_variants, settings): + """Assert that body is not saved when content-length exceeds pre-defined max""" + + settings.LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH = 10 + + for method, request_func, request_mock in request_variants: + request_mock(**request_mock_kwargs) + response = request_func( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=False) - def test_request_data_is_not_saved_when_saving_disabled(self, m): - self._setUpMocks(m) + assert response.status_code == 200 - requests.get("http://example.com/some-path?version=2.0") + request_log = OutgoingRequestsLog.objects.last() - self.assertFalse(OutgoingRequestsLog.objects.exists()) + assert bytes(request_log.res_body) == b"" diff --git a/tests/test_utils.py b/tests/test_utils.py new file mode 100644 index 0000000..be1bd45 --- /dev/null +++ b/tests/test_utils.py @@ -0,0 +1,167 @@ +"""Tests for the utility functions""" + +import logging + +import pytest +import requests + +from log_outgoing_requests.datastructures import ContentType +from log_outgoing_requests.models import OutgoingRequestsLogConfig +from log_outgoing_requests.utils import ( + check_content_length, + check_content_type, + get_default_encoding, + parse_content_type_header, +) + + +# +# test check_content_length +# +@pytest.mark.parametrize( + "max_content_length, expected", + [ + (1048, True), + (12, False), + ], +) +@pytest.mark.django_db +def test_check_content_length( + max_content_length, + requests_mock, + request_mock_kwargs, + expected, +): + config = OutgoingRequestsLogConfig.objects.create( + max_content_length=max_content_length, + ) + + # we check the functionality of determining missing content length + # only for the response (the requests library automatically inserts + # the content length for the request) + del request_mock_kwargs["headers"]["Content-Length"] + + mock = requests_mock.post(**request_mock_kwargs) + response = requests.post( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) + + assert response.status_code == 200 + + result_request = check_content_length(mock.last_request, config=config) + assert result_request is expected + + result_response = check_content_length(response, config=config) + assert result_response is expected + + +# +# test parse_content_type_header +# +@pytest.mark.parametrize( + "content_type_header, expected_content_type, expected_encoding", + [ + ("text/xml; charset=us-ascii", "text/xml", "us-ascii"), + ("text/xml", "text/xml", ""), + ("application/json", "application/json", ""), + ("", "", ""), + ], +) +@pytest.mark.django_db +def test_parse_content_type_header( + content_type_header, + requests_mock, + request_mock_kwargs, + expected_content_type, + expected_encoding, +): + request_mock_kwargs["request_headers"]["Content-Type"] = content_type_header + request_mock_kwargs["headers"]["Content-Type"] = content_type_header + + mock = requests_mock.post(**request_mock_kwargs) + response = requests.post( + request_mock_kwargs["url"], + headers=request_mock_kwargs["request_headers"], + json={"test": "request data"}, + ) + + assert response.status_code == 200 + + # check request + parsed_request_header = parse_content_type_header(mock.last_request) + assert parsed_request_header[0] == expected_content_type + assert parsed_request_header[1] == expected_encoding + + # check response + parsed_response_header = parse_content_type_header(response) + assert parsed_response_header[0] == expected_content_type + assert parsed_response_header[1] == expected_encoding + + +# +# test check_content_type +# +@pytest.mark.parametrize( + "allowed_content_types, content_type_pattern, expected", + [ + ([ContentType("text/xml", "iso-8859-1")], "text/xml", True), + ([ContentType("text/xml", "iso-8859-1")], "text/html", False), + ([ContentType("text/xml", "iso-8859-1")], "video/mp4", False), + ([ContentType("text/*", "utf-8")], "text/html", True), + ], +) +@pytest.mark.django_db +def test_check_content_type( + allowed_content_types, + content_type_pattern, + expected, + settings, +): + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES = allowed_content_types + + result = check_content_type(content_type_pattern) + assert result is expected + + +# +# test get_default_encoding +# +@pytest.mark.parametrize( + "content_type_pattern, expected", + [ + ("text/html", "utf-8"), + ("text/xml", "iso-8859-1"), + ("application/json", "utf-8"), + ("application/unknown", ""), + ], +) +@pytest.mark.django_db +def test_get_default_encoding( + content_type_pattern, + expected, +): + result = get_default_encoding(content_type_pattern) + assert result == expected + + +@pytest.mark.django_db +def test_logger_warning_missing_content_length( + requests_mock, request_mock_kwargs, caplog +): + del request_mock_kwargs["request_headers"]["Content-Length"] + + with caplog.at_level(logging.DEBUG): + requests_mock.get(**request_mock_kwargs) + requests.get( + request_mock_kwargs["url"], headers=request_mock_kwargs["request_headers"] + ) + + records = caplog.records + assert records[1].levelname == "WARNING" + assert records[1].name == "log_outgoing_requests.utils" + assert ( + records[1].msg + == "Content length of the request/response (request netloc: example.com:8000) could not be determined." + ) diff --git a/tox.ini b/tox.ini index 8dcf981..c363d71 100644 --- a/tox.ini +++ b/tox.ini @@ -1,6 +1,5 @@ [tox] envlist = - py37-django32 py{38,39,310}-django{32,41} isort black @@ -10,7 +9,6 @@ skip_missing_interpreters = true [gh-actions] python = - 3.7: py37 3.8: py38 3.9: py39 3.10: py310 @@ -24,7 +22,13 @@ DJANGO = setenv = DJANGO_SETTINGS_MODULE=testapp.settings PYTHONPATH={toxinidir} +passenv = + PGPORT + DB_USER + DB_HOST + DB_PASSWORD extras = + db tests coverage deps = @@ -55,6 +59,7 @@ basepython=python changedir=docs skipsdist=true extras = + db tests docs commands=