Make RequestLoggingMiddleware async capable #41

coderabbitai · 2025-03-03T12:02:35Z

🛠️ Refactor suggestion

Add async test coverage.
Your asynchronous dunder call method mirrors the sync flow, ensuring that logging is captured. However, it would be beneficial to add unit tests (or integration tests) specifically covering the async path to confirm it handles exceptions, logging, and response attributes as expected.

I'd be happy to provide a test snippet or open a follow-up issue to ensure this new async functionality is thoroughly verified.

🧩 Analysis chain

I'll create a comprehensive test snippet for the async middleware functionality. First, let me explore the codebase to understand the existing test structure and patterns.

Let me also examine the specific structure of the existing tests for the middleware component:

Let me also check if Django, pytest-asyncio, or other async testing tools are already in the project dependencies:

Now let me understand how Django is configured in this project, particularly regarding middleware settings:

Let me check for any existing test utilities or fixtures that might be useful:

Based on the information gathered, I'll now craft a proper async test snippet for the RequestLoggingMiddleware class.

@lnagel, here's a test snippet that covers the async capability of the RequestLoggingMiddleware:

import logging import time from unittest.mock import AsyncMock, MagicMock, patch import pytest from asgiref.sync import iscoroutinefunction from django.http import HttpResponse from django.test import AsyncRequestFactory, RequestFactory, TestCase, override_settings from django_datadog_logger.middleware.request_log import RequestLoggingMiddleware class TestRequestLoggingMiddlewareAsync(TestCase): def setUp(self): self.async_request_factory = AsyncRequestFactory() self.sync_request_factory = RequestFactory() self.logger_path = 'django_datadog_logger.middleware.request_log.logger' def test_init_detects_async_get_response(self): """Test that the middleware correctly detects async get_response""" async def async_get_response(request): return HttpResponse("Async response") sync_get_response = lambda request: HttpResponse("Sync response") async_middleware = RequestLoggingMiddleware(async_get_response) sync_middleware = RequestLoggingMiddleware(sync_get_response) self.assertTrue(async_middleware.async_mode) self.assertFalse(sync_middleware.async_mode) self.assertTrue(iscoroutinefunction(async_middleware)) self.assertFalse(iscoroutinefunction(sync_middleware)) @pytest.mark.asyncio async def test_acall_method(self): """Test that the __acall__ method is called for async requests""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Async response", status=200) response.reason_phrase = "OK" return response middleware = RequestLoggingMiddleware(async_get_response) request = self.async_request_factory.get('/test-async/') with patch(self.logger_path) as mock_logger: response = await middleware(request) self.assertEqual(response.status_code, 200) self.assertEqual(response.content.decode(), "Async response") mock_logger.info.assert_called_once() # Verify log message contains the expected text log_call_args = mock_logger.info.call_args[0] self.assertIn("HTTP 200 OK", log_call_args[0]) @pytest.mark.asyncio async def test_acall_with_client_error(self): """Test async middleware handling of client errors (4xx)""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Not Found", status=404) response.reason_phrase = "Not Found" return response middleware = RequestLoggingMiddleware(async_get_response) request = self.async_request_factory.get('/nonexistent/') with patch(self.logger_path) as mock_logger: response = await middleware(request) self.assertEqual(response.status_code, 404) mock_logger.warning.assert_called_once() log_call_args = mock_logger.warning.call_args[0] self.assertIn("HTTP 404 Not Found", log_call_args[0]) # Check error data in log extras log_extras = mock_logger.warning.call_args[1]['extra'] self.assertEqual(log_extras['http.status_code'], 404) self.assertEqual(log_extras['error.kind'], 404) self.assertEqual(log_extras['error.message'], "Not Found") self.assertIn('duration', log_extras) @pytest.mark.asyncio async def test_acall_with_server_error(self): """Test async middleware handling of server errors (5xx)""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Server Error", status=500) response.reason_phrase = "Internal Server Error" return response middleware = RequestLoggingMiddleware(async_get_response) request = self.async_request_factory.get('/error/') with patch(self.logger_path) as mock_logger: response = await middleware(request) self.assertEqual(response.status_code, 500) mock_logger.error.assert_called_once() log_call_args = mock_logger.error.call_args[0] self.assertIn("HTTP 500 Internal Server Error", log_call_args[0]) # Check error data in log extras log_extras = mock_logger.error.call_args[1]['extra'] self.assertEqual(log_extras['http.status_code'], 500) self.assertEqual(log_extras['error.kind'], 500) self.assertEqual(log_extras['error.message'], "Internal Server Error")

To run these tests, you'll need to add pytest-asyncio to your test dependencies:

pip install pytest-asyncio

Some notes about the test implementation:

The tests cover three main scenarios:

Detection of async vs sync get_response functions

Normal successful async request/response flow

Error handling for both client (4xx) and server (5xx) errors

I've used AsyncRequestFactory from Django's test utilities to create async-compatible requests.

The tests use both unittest style (through Django's TestCase) and pytest-asyncio marker for async test functions.

Each test verifies both the response handling and the logging behavior, ensuring that the async path correctly logs responses with the right log level and includes all expected metadata.

If you'd like, I can also prepare a follow-up issue to track this test implementation. Would you prefer I do that as well?

🏁 Script executed:

#!/bin/bash # Find existing test files echo "Looking for existing test files:" find . -name "test_*.py" -o -name "*_test.py" # Check if there are existing middleware tests echo -e "\nChecking for middleware tests:" rg -l "middleware" --glob "*.py" | grep test # Check test frameworks/patterns used echo -e "\nTest frameworks and patterns:" rg -l "import pytest|from pytest" --glob "*.py" rg -l "import unittest|from unittest" --glob "*.py" # Look for existing async tests echo -e "\nAny existing async tests:" rg -l "async def test|@pytest.mark.asyncio" --glob "*.py" # Check test directory structure echo -e "\nDirectory structure:" find . -type d -name "*test*" -o -name "*tests*"

Length of output: 740

🏁 Script executed:

#!/bin/bash # Look for specific middleware test files echo "Looking for RequestLoggingMiddleware test files:" rg -l "RequestLoggingMiddleware" --glob "*test*.py" # If any middleware test files exist, get their content MIDDLEWARE_TEST_FILES=$(rg -l "RequestLoggingMiddleware" --glob "*test*.py") if [ -n "$MIDDLEWARE_TEST_FILES" ]; then echo -e "\nContent of middleware test files:" for file in $MIDDLEWARE_TEST_FILES; do echo -e "\n--- $file ---" cat "$file" done fi

Length of output: 252

🏁 Script executed:

#!/bin/bash # Check project dependencies echo "Project dependencies:" cat requirements.txt # Check test requirements if they exist separately if [ -f "requirements-test.txt" ]; then echo -e "\nTest requirements:" cat requirements-test.txt fi # Check setup.py for dependencies if [ -f "setup.py" ]; then echo -e "\nSetup.py dependencies:" cat setup.py fi

Length of output: 2146

🏁 Script executed:

#!/bin/bash # Find Django settings files echo "Django settings files:" rg -l "MIDDLEWARE|INSTALLED_APPS" --glob "*.py" # Find examples of how the middleware is used echo -e "\nMiddleware usage examples:" rg -l "RequestLoggingMiddleware" --glob "*.py" | grep -v "test"

Length of output: 283

🏁 Script executed:

#!/bin/bash # Look for test utilities or fixtures echo "Test utilities or fixtures:" rg -l "fixture|conftest" --glob "*.py" # Check for any conftest.py files if [ -f "conftest.py" ]; then echo -e "\nGlobal conftest.py content:" cat conftest.py fi # Find any other test helper files echo -e "\nOther test helpers:" rg -l "class .+TestCase|def setup|def teardown" --glob "*.py" | grep -v "^test_"

Length of output: 304

@lnagel Sure, here's a comprehensive test implementation for the async capability of RequestLoggingMiddleware:

from unittest import mock import time import asyncio from django.test import TestCase, RequestFactory from django.http import HttpResponse from django_datadog_logger.middleware.request_log import RequestLoggingMiddleware class RequestLoggingMiddlewareAsyncTests(TestCase): def setUp(self): self.request_factory = RequestFactory() self.request = self.request_factory.get("/test-url/") self.logger_path = "django_datadog_logger.middleware.request_log.logger" def test_middleware_detects_async_get_response(self): """Test that middleware correctly detects an async get_response function.""" async def async_get_response(request): return HttpResponse("Response") def sync_get_response(request): return HttpResponse("Response") async_middleware = RequestLoggingMiddleware(get_response=async_get_response) sync_middleware = RequestLoggingMiddleware(get_response=sync_get_response) self.assertTrue(async_middleware.async_mode) self.assertFalse(sync_middleware.async_mode) def test_middleware_calls_acall_for_async_mode(self): """Test that __acall__ is called when in async mode.""" async def async_get_response(request): return HttpResponse("Response") middleware = RequestLoggingMiddleware(get_response=async_get_response) with mock.patch.object(middleware, '__acall__', return_value=HttpResponse()): middleware(self.request) middleware.__acall__.assert_called_once_with(self.request) def test_async_call_logs_responses(self): """Test that async middleware properly logs responses.""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Response", status=200) response.reason_phrase = "OK" return response middleware = RequestLoggingMiddleware(get_response=async_get_response) with mock.patch(self.logger_path) as mock_logger: # Execute the async call and wait for the result response = asyncio.run(middleware.__acall__(self.request)) # Verify the response self.assertEqual(response.status_code, 200) # Verify logging mock_logger.info.assert_called_once() call_args = mock_logger.info.call_args[0] self.assertIn("HTTP 200 OK", call_args[0]) def test_async_middleware_logs_client_errors(self): """Test that async middleware properly logs 4xx client errors.""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Not Found", status=404) response.reason_phrase = "Not Found" return response middleware = RequestLoggingMiddleware(get_response=async_get_response) with mock.patch(self.logger_path) as mock_logger: response = asyncio.run(middleware.__acall__(self.request)) self.assertEqual(response.status_code, 404) mock_logger.warning.assert_called_once() # Check log message and extras call_args = mock_logger.warning.call_args self.assertIn("HTTP 404 Not Found", call_args[0][0]) extras = call_args[1]['extra'] self.assertEqual(extras['http.status_code'], 404) self.assertEqual(extras['error.kind'], 404) self.assertEqual(extras['error.message'], "Not Found") def test_async_middleware_logs_server_errors(self): """Test that async middleware properly logs 5xx server errors.""" async def async_get_response(request): request.request_start_time = time.time() response = HttpResponse("Server Error", status=500) response.reason_phrase = "Internal Server Error" return response middleware = RequestLoggingMiddleware(get_response=async_get_response) with mock.patch(self.logger_path) as mock_logger: response = asyncio.run(middleware.__acall__(self.request)) self.assertEqual(response.status_code, 500) mock_logger.error.assert_called_once() # Check log message and extras call_args = mock_logger.error.call_args self.assertIn("HTTP 500 Internal Server Error", call_args[0][0]) extras = call_args[1]['extra'] self.assertEqual(extras['http.status_code'], 500) self.assertEqual(extras['error.kind'], 500) self.assertEqual(extras['error.message'], "Internal Server Error")

This test suite:

Uses Django's TestCase to match the existing codebase style rather than pytest

Tests all key components of the async middleware functionality:

Detection of async vs sync get_response functions

Proper routing to acall method for async functions

Response handling and status code processing

Different logging levels based on status code (info/warning/error)

Proper inclusion of metadata in log entries

Uses asyncio.run() to execute the async methods in a unittest environment, which doesn't natively support async tests

Mocks the logger to verify the correct log level and message content

Let me know if you need any adjustments to this test implementation!

Are you interested in adding these tests? Let me know if I should add anything else

Seems like the humans are having a chat. I'll hop back into my burrow for now. If you need me again, just tag @coderabbitai in a new comment, and I'll come hopping out!

I was planning on adding them after the merge

-Original file line number
+Diff line change
@@ -1,20 +1,36 @@
     import logging
     import time
+    from asgiref.sync import iscoroutinefunction, markcoroutinefunction
     from rest_framework.utils.serializer_helpers import ReturnDict
     logger = logging.getLogger(__name__)
     class RequestLoggingMiddleware:
+        sync_capable = True
+        async_capable = True
         def __init__(self, get_response=None):
             self.get_response = get_response
+            self.async_mode = iscoroutinefunction(self.get_response)
+            if self.async_mode:
+                # Mark the class as async-capable, but do the actual switch
+                # inside __call__ to avoid swapping out dunder methods
+                markcoroutinefunction(self)
         def __call__(self, request):
+            if self.async_mode:
+                return self.__acall__(request)
             response = self.get_response(request)
             self.log_response(request, response)
             return response
+        async def __acall__(self, request):
+            response = await self.get_response(request)
+            self.log_response(request, response)
+            return response
         def process_response(self, request, response):
             self.log_response(request, response)
             return response
@@ Expand Down @@

-Original file line number
+Diff line change
@@ -1,4 +1,5 @@
     JSON-log-formatter
     Django
+    asgiref
     djangorestframework
     backports.zoneinfo;python_version<"3.9"

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Make RequestLoggingMiddleware async capable #41

Uh oh!

Diff view

Diff view

There are no files selected for viewing

coderabbitai bot Mar 3, 2025 •

edited

Loading

Uh oh!

lnagel Mar 3, 2025

Uh oh!

coderabbitai bot Mar 3, 2025

Uh oh!

browniebroke Mar 14, 2025

Uh oh!

coderabbitai bot Mar 14, 2025

Uh oh!

lnagel Mar 14, 2025

Uh oh!

Make RequestLoggingMiddleware async capable #41

Are you sure you want to change the base?

Uh oh!

Make RequestLoggingMiddleware async capable #41

Uh oh!

Uh oh!

Diff view

Diff view

There are no files selected for viewing

coderabbitai bot Mar 3, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lnagel Mar 3, 2025

Choose a reason for hiding this comment

Uh oh!

coderabbitai bot Mar 3, 2025

Choose a reason for hiding this comment

Uh oh!

browniebroke Mar 14, 2025

Choose a reason for hiding this comment

Uh oh!

coderabbitai bot Mar 14, 2025

Choose a reason for hiding this comment

Uh oh!

lnagel Mar 14, 2025

Choose a reason for hiding this comment

Uh oh!

coderabbitai bot Mar 3, 2025 •

edited

Loading