From bb9522a0bc5d6bf9667d5cde507ac40c63f238ab Mon Sep 17 00:00:00 2001 From: Mathieu Leplatre Date: Wed, 21 Feb 2024 17:15:06 +0100 Subject: [PATCH 1/2] Add querystring to MozLog request.summary --- src/dockerflow/django/middleware.py | 2 ++ src/dockerflow/fastapi/middleware.py | 2 ++ src/dockerflow/flask/app.py | 1 + src/dockerflow/sanic/app.py | 2 ++ tests/django/test_django.py | 11 +++++++++++ tests/fastapi/test_fastapi.py | 3 ++- tests/flask/test_flask.py | 10 ++++++++++ tests/sanic/test_sanic.py | 8 ++++++++ 8 files changed, 38 insertions(+), 1 deletion(-) diff --git a/src/dockerflow/django/middleware.py b/src/dockerflow/django/middleware.py index 358f3c6..0ab84f5 100644 --- a/src/dockerflow/django/middleware.py +++ b/src/dockerflow/django/middleware.py @@ -1,6 +1,7 @@ import logging import re import time +import urllib import uuid from django.utils.deprecation import MiddlewareMixin @@ -42,6 +43,7 @@ def _build_extra_meta(self, request): "lang": request.META.get("HTTP_ACCEPT_LANGUAGE", ""), "method": request.method, "path": request.path, + "querystring": urllib.parse.unquote(request.META.get("QUERY_STRING", "")), } # HACK: It's possible some other middleware has replaced the request we diff --git a/src/dockerflow/fastapi/middleware.py b/src/dockerflow/fastapi/middleware.py index 9be8b45..fbf0993 100644 --- a/src/dockerflow/fastapi/middleware.py +++ b/src/dockerflow/fastapi/middleware.py @@ -3,6 +3,7 @@ import logging import sys import time +import urllib from typing import Any, Dict from asgiref.typing import ( @@ -73,4 +74,5 @@ def _format(self, scope: HTTPScope, info) -> Dict[str, Any]: "code": info["response"]["status"], "lang": info["request_headers"].get("accept-language"), "t": int(request_duration_ms), + "querystring": urllib.parse.unquote(scope["query_string"].decode()), } diff --git a/src/dockerflow/flask/app.py b/src/dockerflow/flask/app.py index dd16a83..a74e860 100644 --- a/src/dockerflow/flask/app.py +++ b/src/dockerflow/flask/app.py @@ -257,6 +257,7 @@ def summary_extra(self): "lang": flask.request.headers.get("Accept-Language", ""), "method": flask.request.method, "path": flask.request.path, + "querystring": flask.request.query_string.decode(), } # set the uid value to the current user ID diff --git a/src/dockerflow/sanic/app.py b/src/dockerflow/sanic/app.py index cffc19e..656b100 100644 --- a/src/dockerflow/sanic/app.py +++ b/src/dockerflow/sanic/app.py @@ -4,6 +4,7 @@ import logging import time +import urllib import uuid import warnings from inspect import isawaitable @@ -159,6 +160,7 @@ def summary_extra(self, request): "lang": request.headers.get("Accept-Language", ""), "method": request.method, "path": request.path, + "querystring": urllib.parse.unquote(request.query_string), "uid": "", } diff --git a/tests/django/test_django.py b/tests/django/test_django.py index c3ac859..9766433 100644 --- a/tests/django/test_django.py +++ b/tests/django/test_django.py @@ -169,6 +169,17 @@ def test_request_summary(admin_user, caplog, dockerflow_middleware, dockerflow_r assert getattr(dockerflow_request, "uid", None) is None +def test_request_summary_querystring(admin_user, caplog, dockerflow_middleware, rf): + request = rf.get("/?x=%D8%B4%D9%83%D8%B1") + response = dockerflow_middleware.process_request(request) + response = dockerflow_middleware.process_response(request, response) + + assert len(caplog.records) == 1 + record = caplog.records[0] + assert record.querystring == "x=شكر" + assert isinstance(record.t, int) + + def test_request_summary_admin_user( admin_user, caplog, dockerflow_middleware, dockerflow_request ): diff --git a/tests/fastapi/test_fastapi.py b/tests/fastapi/test_fastapi.py index 4b14775..dbe833f 100644 --- a/tests/fastapi/test_fastapi.py +++ b/tests/fastapi/test_fastapi.py @@ -44,7 +44,7 @@ def test_lbheartbeat_head(client): def test_mozlog(client, caplog): client.get( - "/__lbheartbeat__", + "/__lbheartbeat__?x=شكر", headers={ "User-Agent": "dockerflow/tests", "Accept-Language": "en-US", @@ -58,6 +58,7 @@ def test_mozlog(client, caplog): assert record.method == "GET" assert record.code == 200 assert record.path == "/__lbheartbeat__" + assert record.querystring == "x=شكر" assert isinstance(record.t, int) diff --git a/tests/flask/test_flask.py b/tests/flask/test_flask.py index ca4ceb5..3185fa7 100644 --- a/tests/flask/test_flask.py +++ b/tests/flask/test_flask.py @@ -297,6 +297,16 @@ def test_request_summary(caplog, app, client, setup_request_summary_logger): assert getattr(request, "uid", None) is None +def test_request_summary_querystring(caplog, app, client, setup_request_summary_logger): + caplog.set_level(logging.INFO) + with app.test_request_context("/"): + client.get("/?x=شكر", headers=headers) + + assert len(caplog.records) == 1 + record = caplog.records[0] + assert record.querystring == "x=شكر" + + def test_preserves_existing_request_id(dockerflow, app): with app.test_client() as test_client: diff --git a/tests/sanic/test_sanic.py b/tests/sanic/test_sanic.py index c799091..8106653 100644 --- a/tests/sanic/test_sanic.py +++ b/tests/sanic/test_sanic.py @@ -258,6 +258,14 @@ def test_request_summary(caplog, setup_request_summary_logger, test_client): assert_log_record(caplog, rid=request.ctx.id) +def test_request_summary_querystring(caplog, setup_request_summary_logger, test_client): + _, _ = test_client.get("/?x=شكر", headers=headers) + records = [r for r in caplog.records if r.name == "request.summary"] + assert len(records) == 1 + record = caplog.records[0] + assert record.querystring == "x=شكر" + + def test_request_summary_exception(app, caplog, dockerflow, test_client): @app.route("/exception") def exception_raiser(request): From a6e6481f24d999b3ec2c3a3d23a2624b70d9071c Mon Sep 17 00:00:00 2001 From: Mathieu Leplatre Date: Fri, 23 Feb 2024 10:48:28 +0100 Subject: [PATCH 2/2] Put querystring logging behing a flag --- docs/django.rst | 8 +++++++- docs/fastapi.rst | 9 +++++++++ docs/flask.rst | 4 ++++ docs/sanic.rst | 5 +++++ src/dockerflow/django/middleware.py | 7 ++++++- src/dockerflow/fastapi/middleware.py | 7 +++++-- src/dockerflow/flask/app.py | 4 +++- src/dockerflow/sanic/app.py | 4 +++- tests/django/test_django.py | 6 +++++- tests/fastapi/test_fastapi.py | 4 +++- tests/flask/test_flask.py | 1 + tests/sanic/test_sanic.py | 5 ++++- 12 files changed, 55 insertions(+), 9 deletions(-) diff --git a/docs/django.rst b/docs/django.rst index 292310d..882f822 100644 --- a/docs/django.rst +++ b/docs/django.rst @@ -287,7 +287,7 @@ spec: .. http:get:: /__heartbeat__ The heartbeat view will go through the list of configured Dockerflow - checks in the :ref:`DOCKERFLOW_CHECKS` setting, run each check, and, if + checks in the :ref:`DOCKERFLOW_CHECKS` setting, run each check, and, if `settings.DEBUG` is `True`, add their results to a JSON response. The view will return HTTP responses with either a status code of 200 if @@ -398,6 +398,12 @@ configure **at least** the ``request.summary`` logger that way:: } } +In order to include querystrings in the request summary log, set this flag in settings: + +.. code-block:: python + + DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + .. _django-static: diff --git a/docs/fastapi.rst b/docs/fastapi.rst index 9f15112..9d8fecf 100644 --- a/docs/fastapi.rst +++ b/docs/fastapi.rst @@ -307,6 +307,15 @@ for at least the ``request.summary`` logger: } }) + +In order to include querystrings in the request summary log, set this flag in the application state: + +.. code-block:: python + + app.state.DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + + + .. _fastapi-static: Static content diff --git a/docs/flask.rst b/docs/flask.rst index db11ea2..598ab00 100644 --- a/docs/flask.rst +++ b/docs/flask.rst @@ -453,6 +453,10 @@ for at least the ``request.summary`` logger:: } }) +In order to include querystrings in the request summary log, set this flag in :ref:`configuration `:: + + DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + .. _flask-static: Static content diff --git a/docs/sanic.rst b/docs/sanic.rst index 646bae6..0615dd1 100644 --- a/docs/sanic.rst +++ b/docs/sanic.rst @@ -452,6 +452,11 @@ Alternatively you can also pass the same logging config dictionary to the sanic = Sanic(__name__) +In order to include querystrings in the request summary log, set this flag in :ref:`configuration `:: + + DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + + .. _sanic-static: Static content diff --git a/src/dockerflow/django/middleware.py b/src/dockerflow/django/middleware.py index 0ab84f5..8b20936 100644 --- a/src/dockerflow/django/middleware.py +++ b/src/dockerflow/django/middleware.py @@ -4,6 +4,7 @@ import urllib import uuid +from django.conf import settings from django.utils.deprecation import MiddlewareMixin from . import views @@ -43,9 +44,13 @@ def _build_extra_meta(self, request): "lang": request.META.get("HTTP_ACCEPT_LANGUAGE", ""), "method": request.method, "path": request.path, - "querystring": urllib.parse.unquote(request.META.get("QUERY_STRING", "")), } + if getattr(settings, "DOCKERFLOW_SUMMARY_LOG_QUERYSTRING", False): + out["querystring"] = urllib.parse.unquote( + request.META.get("QUERY_STRING", "") + ) + # HACK: It's possible some other middleware has replaced the request we # modified earlier, so be sure to check for existence of these # attributes before trying to use them. diff --git a/src/dockerflow/fastapi/middleware.py b/src/dockerflow/fastapi/middleware.py index fbf0993..7533a38 100644 --- a/src/dockerflow/fastapi/middleware.py +++ b/src/dockerflow/fastapi/middleware.py @@ -67,12 +67,15 @@ def _format(self, scope: HTTPScope, info) -> Dict[str, Any]: info["request_headers"][header_key] = header_val request_duration_ms = (info["end_time"] - info["start_time"]) * 1000.0 - return { + fields = { "agent": info["request_headers"].get("user-agent", ""), "path": scope["path"], "method": scope["method"], "code": info["response"]["status"], "lang": info["request_headers"].get("accept-language"), "t": int(request_duration_ms), - "querystring": urllib.parse.unquote(scope["query_string"].decode()), } + + if getattr(scope["app"].state, "DOCKERFLOW_SUMMARY_LOG_QUERYSTRING", False): + fields["querystring"] = urllib.parse.unquote(scope["query_string"].decode()) + return fields diff --git a/src/dockerflow/flask/app.py b/src/dockerflow/flask/app.py index a74e860..abae0ea 100644 --- a/src/dockerflow/flask/app.py +++ b/src/dockerflow/flask/app.py @@ -257,9 +257,11 @@ def summary_extra(self): "lang": flask.request.headers.get("Accept-Language", ""), "method": flask.request.method, "path": flask.request.path, - "querystring": flask.request.query_string.decode(), } + if flask.current_app.config.get("DOCKERFLOW_SUMMARY_LOG_QUERYSTRING", False): + out["querystring"] = flask.request.query_string.decode() + # set the uid value to the current user ID user_id = self.user_id() if user_id is None: diff --git a/src/dockerflow/sanic/app.py b/src/dockerflow/sanic/app.py index 656b100..fa592f7 100644 --- a/src/dockerflow/sanic/app.py +++ b/src/dockerflow/sanic/app.py @@ -160,10 +160,12 @@ def summary_extra(self, request): "lang": request.headers.get("Accept-Language", ""), "method": request.method, "path": request.path, - "querystring": urllib.parse.unquote(request.query_string), "uid": "", } + if request.app.config.get("DOCKERFLOW_SUMMARY_LOG_QUERYSTRING", False): + out["querystring"] = urllib.parse.unquote(request.query_string) + # the rid value to the current request ID try: out["rid"] = request.ctx.id diff --git a/tests/django/test_django.py b/tests/django/test_django.py index 9766433..5464e97 100644 --- a/tests/django/test_django.py +++ b/tests/django/test_django.py @@ -169,7 +169,11 @@ def test_request_summary(admin_user, caplog, dockerflow_middleware, dockerflow_r assert getattr(dockerflow_request, "uid", None) is None -def test_request_summary_querystring(admin_user, caplog, dockerflow_middleware, rf): +def test_request_summary_querystring( + settings, admin_user, caplog, dockerflow_middleware, rf +): + settings.DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + request = rf.get("/?x=%D8%B4%D9%83%D8%B1") response = dockerflow_middleware.process_request(request) response = dockerflow_middleware.process_response(request, response) diff --git a/tests/fastapi/test_fastapi.py b/tests/fastapi/test_fastapi.py index dbe833f..4c51da9 100644 --- a/tests/fastapi/test_fastapi.py +++ b/tests/fastapi/test_fastapi.py @@ -42,7 +42,9 @@ def test_lbheartbeat_head(client): assert response.content == b"" -def test_mozlog(client, caplog): +def test_mozlog(app, client, caplog): + app.state.DOCKERFLOW_SUMMARY_LOG_QUERYSTRING = True + client.get( "/__lbheartbeat__?x=شكر", headers={ diff --git a/tests/flask/test_flask.py b/tests/flask/test_flask.py index 3185fa7..ac8f09a 100644 --- a/tests/flask/test_flask.py +++ b/tests/flask/test_flask.py @@ -298,6 +298,7 @@ def test_request_summary(caplog, app, client, setup_request_summary_logger): def test_request_summary_querystring(caplog, app, client, setup_request_summary_logger): + app.config["DOCKERFLOW_SUMMARY_LOG_QUERYSTRING"] = True caplog.set_level(logging.INFO) with app.test_request_context("/"): client.get("/?x=شكر", headers=headers) diff --git a/tests/sanic/test_sanic.py b/tests/sanic/test_sanic.py index 8106653..14ea640 100644 --- a/tests/sanic/test_sanic.py +++ b/tests/sanic/test_sanic.py @@ -258,7 +258,10 @@ def test_request_summary(caplog, setup_request_summary_logger, test_client): assert_log_record(caplog, rid=request.ctx.id) -def test_request_summary_querystring(caplog, setup_request_summary_logger, test_client): +def test_request_summary_querystring( + app, caplog, setup_request_summary_logger, test_client +): + app.config["DOCKERFLOW_SUMMARY_LOG_QUERYSTRING"] = True _, _ = test_client.get("/?x=شكر", headers=headers) records = [r for r in caplog.records if r.name == "request.summary"] assert len(records) == 1