From 6bae3ef39ac9ec480a1c8db53128e0cc6a443f4b Mon Sep 17 00:00:00 2001 From: Paul Schilling Date: Thu, 11 May 2023 14:00:58 +0200 Subject: [PATCH] process PR feedback --- .github/workflows/ci.yml | 5 +- README.rst | 17 +- docs/quickstart.rst | 12 +- log_outgoing_requests/admin.py | 53 +- log_outgoing_requests/constants.py | 8 + log_outgoing_requests/datastructures.py | 18 + log_outgoing_requests/formatters.py | 41 +- log_outgoing_requests/handlers.py | 71 +-- ...0002_outgoingrequestslogconfig_and_more.py | 158 ++++- log_outgoing_requests/models.py | 146 +++-- .../log_outgoing_requests/css/admin.css | 11 +- .../log_outgoing_requests/change_form.html | 16 + log_outgoing_requests/utils.py | 150 +++++ setup.cfg | 6 +- testapp/settings.py | 12 +- tests/conftest.py | 59 ++ tests/test_admin.py | 97 +++ tests/test_formatter.py | 46 ++ tests/test_logging.py | 559 ++++++++---------- tests/test_utils.py | 167 ++++++ tox.ini | 9 +- 21 files changed, 1169 insertions(+), 492 deletions(-) create mode 100644 log_outgoing_requests/constants.py create mode 100644 log_outgoing_requests/datastructures.py create mode 100644 log_outgoing_requests/templates/log_outgoing_requests/change_form.html create mode 100644 log_outgoing_requests/utils.py create mode 100644 tests/conftest.py create mode 100644 tests/test_admin.py create mode 100644 tests/test_formatter.py create mode 100644 tests/test_utils.py 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 4dfca82..f8b9f5c 100644 --- a/README.rst +++ b/README.rst @@ -97,8 +97,16 @@ 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_SAVE_BODY = True # save request/response body - LOG_OUTGOING_REQUESTS_LOG_BODY_TO_STDOUT = True # log request/response body to STDOUT + 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 @@ -115,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. The settings for saving logs can by overridden under ``/admin/log_outgoing_requests/outgoingrequestslogconfig/``. +#. 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 70e3301..24c7b9e 100644 --- a/docs/quickstart.rst +++ b/docs/quickstart.rst @@ -58,8 +58,16 @@ Installation } LOG_OUTGOING_REQUESTS_DB_SAVE = True # save logs enabled/disabled based on the boolean value - LOG_OUTGOING_REQUESTS_SAVE_BODY = True # save request/response body - LOG_OUTGOING_REQUESTS_LOG_BODY_TO_STDOUT = True # log request/response body to STDOUT + 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 a05ce64..353692f 100644 --- a/log_outgoing_requests/admin.py +++ b/log_outgoing_requests/admin.py @@ -1,16 +1,14 @@ +from django import forms +from django.conf import settings from django.contrib import admin +from django.shortcuts import get_object_or_404 from django.utils.translation import gettext as _ -from solo.admin import SingletonModelAdmin +from solo.admin import SingletonModelAdmin # type: ignore from .models import OutgoingRequestsLog, OutgoingRequestsLogConfig -@admin.display(description="Response body") -def response_body(obj): - return f"{obj}".upper() - - @admin.register(OutgoingRequestsLog) class OutgoingRequestsLogAdmin(admin.ModelAdmin): fields = ( @@ -26,8 +24,6 @@ class OutgoingRequestsLogAdmin(admin.ModelAdmin): "res_content_type", "req_headers", "res_headers", - "req_body", - "res_body", "trace", ) readonly_fields = fields @@ -40,10 +36,11 @@ class OutgoingRequestsLogAdmin(admin.ModelAdmin): "response_ms", "timestamp", ) - list_filter = ("method", "status_code", "hostname", "timestamp") + 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" def has_add_permission(self, request): return False @@ -54,7 +51,18 @@ def has_change_permission(self, request, obj=None): def query_params(self, obj): return obj.query_params - query_params.short_description = _("Query parameters") + def change_view(self, request, object_id, extra_context=None): + """ + Add log object to to context for use in template. + """ + log = get_object_or_404(OutgoingRequestsLog, id=object_id) + + extra_context = extra_context or {} + extra_context["log"] = log + + return super().change_view(request, object_id, extra_context=extra_context) + + query_params.short_description = _("Query parameters") # type: ignore class Media: css = { @@ -62,13 +70,22 @@ class Media: } +class ConfigAdminForm(forms.ModelForm): + class Meta: + model = OutgoingRequestsLogConfig + fields = "__all__" + widgets = {"allowed_content_types": forms.CheckboxSelectMultiple} + 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": _( + "Wheter 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): - fields = ( - "save_to_db", - "save_body", - ) - list_display = ( - "save_to_db", - "save_body", - ) + form = ConfigAdminForm 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..9ee6a36 --- /dev/null +++ b/log_outgoing_requests/datastructures.py @@ -0,0 +1,18 @@ +""" +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 + + +@dataclass +class ContentType: + """ + Data class for keeping track of content types and associated default encodings + """ + + pattern: str + default_encoding: str diff --git a/log_outgoing_requests/formatters.py b/log_outgoing_requests/formatters.py index b6905c8..047ad4a 100644 --- a/log_outgoing_requests/formatters.py +++ b/log_outgoing_requests/formatters.py @@ -8,32 +8,35 @@ class HttpFormatter(logging.Formatter): def _formatHeaders(self, d): return "\n".join(f"{k}: {v}" for k, v in d.items()) - def _formatBody(self, content: dict, request_or_response: str) -> str: - if settings.LOG_OUTGOING_REQUESTS_LOG_BODY_TO_STDOUT: + 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} {request_body} - ---------------- response ---------------- - {res.status_code} {res.reason} {res.url} - {reshdrs} {response_body} + 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_body=self._formatBody(record.req.body, "Request"), - response_body=self._formatBody(record.res.json(), "Response"), - ) + ---------------- 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 1435083..55d378f 100644 --- a/log_outgoing_requests/handlers.py +++ b/log_outgoing_requests/handlers.py @@ -2,47 +2,31 @@ import traceback from urllib.parse import urlparse -from django.conf import settings - -ALLOWED_CONTENT_TYPES = [ - "application/json", - "multipart/form-data", - "text/html", - "text/plain", - "", - None, -] +from .utils import ( + check_content_length, + check_content_type, + get_default_encoding, + parse_content_type_header, +) class DatabaseOutgoingRequestsHandler(logging.Handler): def emit(self, record): - from .models import OutgoingRequestsLogConfig + from .models import OutgoingRequestsLog, OutgoingRequestsLogConfig config = OutgoingRequestsLogConfig.get_solo() - if config.save_to_db or settings.LOG_OUTGOING_REQUESTS_DB_SAVE: - from .models import OutgoingRequestsLog - - trace = None + if config.save_logs_enabled: + trace = "" # skip requests not coming from the library requests if not record or not record.getMessage() == "Outgoing request": return - # skip requests with non-allowed content - request_content_type = record.req.headers.get("Content-Type", "") - response_content_type = record.res.headers.get("Content-Type", "") - - if not ( - request_content_type in ALLOWED_CONTENT_TYPES - and response_content_type in ALLOWED_CONTENT_TYPES - ): - return - - safe_req_headers = record.req.headers.copy() + scrubbed_req_headers = record.req.headers.copy() - if "Authorization" in safe_req_headers: - safe_req_headers["Authorization"] = "***hidden***" + if "Authorization" in scrubbed_req_headers: + scrubbed_req_headers["Authorization"] = "***hidden***" if record.exc_info: trace = traceback.format_exc() @@ -50,22 +34,39 @@ def emit(self, record): parsed_url = urlparse(record.req.url) kwargs = { "url": record.req.url, - "hostname": parsed_url.hostname, + "hostname": parsed_url.netloc, "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), + "req_headers": self.format_headers(scrubbed_req_headers), "res_headers": self.format_headers(record.res.headers), "trace": trace, } - if config.save_body or settings.LOG_OUTGOING_REQUESTS_SAVE_BODY: - kwargs["req_body"] = (record.req.body,) - kwargs["res_body"] = (record.res.json(),) + if config.save_body_enabled: + # check request + content_type, encoding = parse_content_type_header(record.req) + if check_content_type(content_type) and check_content_length( + record.req, config + ): + kwargs["req_content_type"] = content_type + kwargs["req_body"] = record.req.body or b"" + kwargs["req_body_encoding"] = encoding or get_default_encoding( + content_type + ) + + # check response + content_type, encoding = parse_content_type_header(record.res) + if check_content_type(content_type) and check_content_length( + record.res, config + ): + kwargs["res_content_type"] = content_type + kwargs["res_body"] = record.res.content or b"" + kwargs[ + "res_body_encoding" + ] = record.res.encoding or get_default_encoding(content_type) OutgoingRequestsLog.objects.create(**kwargs) diff --git a/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py b/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py index 3274041..3c99adc 100644 --- a/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py +++ b/log_outgoing_requests/migrations/0002_outgoingrequestslogconfig_and_more.py @@ -1,7 +1,10 @@ -# Generated by Django 4.2.1 on 2023-05-09 07:48 +# 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 = [ @@ -23,55 +26,154 @@ class Migration(migrations.Migration): ), ( "save_to_db", - models.IntegerField( - blank=True, - choices=[(None, "Use default"), (0, "No"), (1, "Yes")], - help_text="Whether request logs should be saved to the database (default: True)", - null=True, + 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.IntegerField( - blank=True, - choices=[(None, "Use default"), (0, "No"), (1, "Yes")], - help_text="Wheter the body of the request and response should be logged (default: False). This option is ignored if 'Save Logs to database' is set to False.", - null=True, + 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 Logs Configuration", - }, - ), - migrations.AlterModelOptions( - name="outgoingrequestslog", - options={ - "permissions": [("can_view_logs", "Can view outgoing request logs")], - "verbose_name": "Outgoing Requests Log", - "verbose_name_plural": "Outgoing Requests Logs", + "verbose_name": "Outgoing Requests Log Configuration", }, ), migrations.AddField( model_name="outgoingrequestslog", name="req_body", - field=models.TextField( - blank=True, - help_text="The request body.", - null=True, - verbose_name="Request 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.JSONField( - blank=True, + field=models.BinaryField( + default=b"", help_text="The response body.", - null=True, 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 9de596e..89831cb 100644 --- a/log_outgoing_requests/models.py +++ b/log_outgoing_requests/models.py @@ -1,18 +1,23 @@ +import logging 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 +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."), ) @@ -22,8 +27,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"), @@ -39,7 +43,6 @@ class OutgoingRequestsLog(models.Model): method = models.CharField( verbose_name=_("Method"), max_length=10, - default="", blank=True, help_text=_("The type of request method."), ) @@ -47,44 +50,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."), ) - req_body = models.TextField( - verbose_name=_("Request body"), - blank=True, - null=True, - help_text=_("The request body."), - ) res_headers = models.TextField( verbose_name=_("Response headers"), - blank=True, - null=True, + default="", help_text=_("The response headers."), ) - res_body = models.JSONField( + req_body = models.BinaryField( + verbose_name=_("Request body"), + default=b"", + help_text=_("The request body."), + ) + res_body = models.BinaryField( verbose_name=_("Response body"), - blank=True, - null=True, + 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( @@ -93,17 +97,13 @@ 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."), ) class Meta: verbose_name = _("Outgoing Requests Log") verbose_name_plural = _("Outgoing Requests Logs") - permissions = [ - ("can_view_logs", "Can view outgoing request logs"), - ] def __str__(self): return ("{hostname} at {date}").format( @@ -118,34 +118,86 @@ def url_parsed(self): def query_params(self): return self.url_parsed.query + @cached_property + def request_body_decoded(self) -> str: + """ + Decoded request 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. + """ + try: + decoded = str(self.req_body, self.res_body_encoding, errors="replace") + except LookupError: + decoded = str(self.req_body, errors="replace") + return decoded + + @cached_property + def response_body_decoded(self) -> str: + """ + Decoded response 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. + """ + try: + decoded = str(self.res_body, self.res_body_encoding, errors="replace") + except LookupError: + decoded = str(self.res_body, errors="replace") + return decoded -class OutgoingRequestsLogConfig(SingletonModel): - class SaveLogsChoices(models.IntegerChoices): - NO = 0, _("No") - YES = 1, _("Yes") - __empty__ = _("Use default") +def get_default_max_content_length(): + """ + Get default value for max content length from settings. + """ + return settings.LOG_OUTGOING_REQUESTS_MAX_CONTENT_LENGTH - save_to_db = models.IntegerField( + +class OutgoingRequestsLogConfig(SingletonModel): + """Configuration options for request logging.""" + + save_to_db = models.CharField( _("Save logs to database"), - choices=SaveLogsChoices.choices, - blank=True, - null=True, - help_text=_( - "Whether request logs should be saved to the database (default: {default})" - ).format(default=settings.LOG_OUTGOING_REQUESTS_DB_SAVE), + max_length=11, + choices=SaveLogsChoice.choices, + default=SaveLogsChoice.use_default, ) - save_body = models.IntegerField( + save_body = models.CharField( _("Save request + response body"), - choices=SaveLogsChoices.choices, - blank=True, - null=True, + 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=_( - "Wheter the body of the request and response should be logged (default: " - "{default}). This option is ignored if 'Save Logs to database' is set to " - "False." - ).format(default=settings.LOG_OUTGOING_REQUESTS_SAVE_BODY), + "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 Logs Configuration") + 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 index 8485b3b..5654b4d 100644 --- a/log_outgoing_requests/static/log_outgoing_requests/css/admin.css +++ b/log_outgoing_requests/static/log_outgoing_requests/css/admin.css @@ -1,6 +1,9 @@ .field-res_body { - display: inline-block; - width: 40rem; - font-family: monospace; - line-height: 1.5rem; + 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..87c5372 --- /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 %} +
+
+ +
{{ log.request_body_decoded }}
+
+
+
+
+ +
{{ log.response_body_decoded }}
+
+
+{% endblock %} diff --git a/log_outgoing_requests/utils.py b/log_outgoing_requests/utils.py new file mode 100644 index 0000000..dd77739 --- /dev/null +++ b/log_outgoing_requests/utils.py @@ -0,0 +1,150 @@ +"""Tests for the utility functions""" + +import logging +from typing import TYPE_CHECKING, Iterable, Tuple, Union + +from django.conf import settings + +# header parsing must be refactored when upgrading to Django 4.2 +# Django <= 4.1: https://github.com/django/django/blob/stable/4.1.x/django/http/multipartparser.py +# Django >= 4.2: https://github.com/django/django/blob/main/django/http/multipartparser.py +from django.http.multipartparser import parse_header + +from requests import PreparedRequest, Response + +from log_outgoing_requests.datastructures import ContentType + +if TYPE_CHECKING: # pragma: nocover + from .models import OutgoingRequestsLogConfig + + +logger = logging.getLogger(__name__) + + +# +# Handler utilities +# +def _get_content_length(http_obj: Union[PreparedRequest, Response]) -> 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 = http_obj.content if isinstance(http_obj, Response) else http_obj.body + if body is not None: + content_length = str(len(body)) + + return content_length + + +def check_content_length( + http_obj: Union[PreparedRequest, Response], + 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: Union[PreparedRequest, Response] +) -> 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_header = http_obj.headers.get("Content-Type", "") + + if not content_type_header: + return ("", "") + + # `parse_header` works on bytes, so we need to encode the header + parsed = parse_header(content_type_header.encode("utf-8")) + + # decode the (representation of the) charset/encoding back to str + encoding = parsed[1].get("charset", b"").decode("utf-8") + + return parsed[0], 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 5eb1286..1744db1 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 @@ -35,7 +34,7 @@ zip_safe = False include_package_data = True packages = find: install_requires = - django >= 3.2 + django <= 4.1 requests django-solo tests_require = @@ -47,6 +46,7 @@ tests_require = flake8 freezegun requests-mock + pyquery [options.packages.find] include = @@ -55,8 +55,10 @@ include = [options.extras_require] tests = + psycopg2 pytest pytest-django + pyquery tox isort black diff --git a/testapp/settings.py b/testapp/settings.py index 9a91f5e..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__)) @@ -92,7 +93,16 @@ # LOG OUTGOING REQUESTS # LOG_OUTGOING_REQUESTS_DB_SAVE = True -LOG_OUTGOING_REQUESTS_SAVE_BODY = False +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..8acb674 --- /dev/null +++ b/tests/test_admin.py @@ -0,0 +1,97 @@ +"""Tests for the admin interface""" + +from datetime import datetime + +from django.urls import reverse + +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=datetime.utcnow(), + ) + 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 fc6bc6c..f926e01 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -1,337 +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.models import OutgoingRequestsLog, OutgoingRequestsLogConfig +from log_outgoing_requests.datastructures import ContentType +from log_outgoing_requests.models import OutgoingRequestsLog + + +# +# 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" -@requests_mock.Mocker() +@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) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=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.assertEqual(request_log.res_body[0], {"test": "data"}) - 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" ) - log = OutgoingRequestsLog.objects.get() - - self.assertIn("Authorization: ***hidden***", log.req_headers) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=False) - def test_data_is_not_saved_when_saving_disabled(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") - 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) - - 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=False) - def test_request_data_is_not_saved_when_saving_disabled(self, m): - self._setUpMocks(m) - - requests.get("http://example.com/some-path?version=2.0") - - self.assertFalse(OutgoingRequestsLog.objects.exists()) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=True) - def test_logging_disallowed_content_type_request(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": "video/mp4", - }, - headers={ - "Date": "Tue, 21 Mar 2023 15:24:08 GMT", - "Content-Type": "text/html", - }, - ) - - func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "video/mp4"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertIsNone(request_log) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=True) - def test_logging_disallowed_content_type_response(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": "video/mp4", - }, - ) - - func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "text/html"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertIsNone(request_log) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=False) - def test_body_not_saved_when_setting_disabled(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", - }, - ) - - func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "text/html"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertIsNone(request_log.res_body) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=False) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=False) - def test_admin_override_db_save(self, m): - config = OutgoingRequestsLogConfig.get_solo() - config.save_to_db = 1 # True - config.save() - - 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", - }, - ) - - func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "text/html"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertIsNotNone(request_log) - self.assertIsNone(request_log.res_body) - - @override_settings(LOG_OUTGOING_REQUESTS_DB_SAVE=True) - @override_settings(LOG_OUTGOING_REQUESTS_SAVE_BODY=False) - def test_admin_override_save_body(self, m): - config = OutgoingRequestsLogConfig.get_solo() - config.save_body = 1 # True - config.save() - - 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", - }, - ) - - func( - "http://example.com/some-path?version=2.0", - headers={"Authorization": "test", "Content-Type": "text/html"}, - ) - - request_log = OutgoingRequestsLog.objects.last() - - self.assertIsNotNone(request_log.res_body) + # 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"}, + ) + + 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_type_not_allowed(request_mock_kwargs, request_variants, settings): + """Assert that request/response bodies are not saved when content type is not allowed""" + + settings.LOG_OUTGOING_REQUESTS_CONTENT_TYPES = [ + ContentType(pattern="text/*", default_encoding="utf-8") + ] + + 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"}, + ) + + assert response.status_code == 200 + + request_log = OutgoingRequestsLog.objects.last() + + 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=