How to log requests and responses in Django?

Question

How can I log all my requests and responses (headers and body) in Django using a middleware? I'm using Django 2.2 with Django rest framework, so sometimes the requests and responses are original Django type, sometimes of drf. The app is served behind gunicorn. I've developed middleware but the main problem is I can't read request's body twice as it gives me error.

Answer 1

Here's an example of logging requests in the database.

Note: This will hit the database once extra with each request. So it will slow down the response time.

models.py

class Request(models.Model):
    endpoint = models.CharField(max_length=100, null=True) # The url the user requested
    user = models.ForeignKey(User, on_delete=models.SET_NULL, null=True) # User that made request, if authenticated
    response_code = models.PositiveSmallIntegerField() # Response status code
    method = models.CharField(max_length=10, null=True)  # Request method
    remote_address = models.CharField(max_length=20, null=True) # IP address of user
    exec_time = models.IntegerField(null=True) # Time taken to create the response
    date = models.DateTimeField(auto_now=True) # Date and time of request
    body_response = models.TextField() # Response data
    body_request = models.TextField() # Request data

middleware.py

class SaveRequest:
    def __init__(self, get_response):
        self.get_response = get_response

        # Filter to log all request to url's that start with any of the strings below.
        # With example below:
        # /example/test/ will be logged.
        # /other/ will not be logged.
        self.prefixs = [
            '/example'
        ]

    def __call__(self, request):
        _t = time.time() # Calculated execution time.
        response = self.get_response(request) # Get response from view function.
        _t = int((time.time() - _t)*1000)    

        # If the url does not start with on of the prefixes above, then return response and dont save log.
        # (Remove these two lines below to log everything)
        if not list(filter(request.get_full_path().startswith, self.prefixs)): 
            return response 

        # Create instance of our model and assign values
        request_log = Request(
            endpoint=request.get_full_path(),
            response_code=response.status_code,
            method=request.method,
            remote_address=self.get_client_ip(request),
            exec_time=_t,
            body_response=str(response.content),
            body_request=str(request.body)
        )

        # Assign user to log if it's not an anonymous user
        if not request.user.is_anonymous:
            request_log.user = request.user

        # Save log in db
        request_log.save() 
        return response

    # get clients ip address
    def get_client_ip(self, request):
        x_forwarded_for = request.META.get('HTTP_X_FORWARDED_FOR')
        if x_forwarded_for:
            _ip = x_forwarded_for.split(',')[0]
        else:
            _ip = request.META.get('REMOTE_ADDR')
        return _ip

settings.py

# Activate the middleware in settings.py like this.
MIDDLEWARE = [
    ... # Django default middleware
    '<your_appname>.middleware.SaveRequest'
]

Answer 2

Previously, I have the same problem. the request and response body is caputed at all. This example below is what I was configured in my previous project with a mongodb (using mongolog module).

You can also remove the mongolog (mongodb) configuration to use default file logger. I choose the mongoDB to easily track the request, response body or url also.

1. middleware.py

import json
import logging
import traceback

from django.http import Http404
from django.http.request import RawPostDataException
from django.utils.deprecation import MiddlewareMixin

# if you want to track it
# from sentry_sdk import capture_exception


def get_client_ip(request):
    """
    get client ip address

    used in:
        - apps/models_helper/visitor.py
    """
    ip_address = request.META.get('HTTP_X_FORWARDED_FOR', None)
    if ip_address:
        ip_address = ip_address.split(', ')[0]
    else:
        ip_address = request.META.get('REMOTE_ADDR', '')
    return ip_address


class SessionLogMiddleware(MiddlewareMixin):
    """
    this middleware to create a log
    by current user
    """

    def save_mongodb_logging(self, request, response=None, exception=None, status_code=None):
        """
        {
            "_id" : ObjectId("5d2d7200b2b76e29fc94080f"),
            "module" : "middleware",
            "line" : 94,
            "thread" : NumberLong(140471566464768),
            "created" : ISODate("2019-07-16T13:43:12.820Z"),
            "level" : "INFO",
            "path" : "/home/projectname/envs/env-projectname/projectname-django/apps/utils/middleware.py",
            "msg" : {
                "REQUEST_DATA" : {
                    "start_time" : "2019-07-04 16:38:01",
                    "finish_time" : "2019-07-04 16:39:22",
                    "quiz_choices_id" : [5, 30, 1, 3, 9]
                },
                "METHOD" : "POST",
                "URL" : "http://localhost:8000/api/quiz",
                "RESPONSE_DATA" : {
                    "message" : "Answer successfully created!",
                    "customer_quiz" : {
                        "customer_quiz_id" : 34,
                        "created_at" : "2019-07-16T13:43:12.538089",
                        "total_correct_answers" : 3,
                        "customer" : 1,
                        "start_time" : "2019-07-16T13:43:12.538062",
                        "total_incorrect_answers" : 2,
                        "deleted_at" : null,
                        "finish_time" : "2019-07-04T16:39:22",
                        "updated_at" : "2019-07-16T13:43:12.538098"
                    },
                    "action" : true
                },
                "HEADERS" : {
                    "Cache-Control" : "no-cache",
                    "Accept-Encoding" : "gzip, deflate",
                    "User-Agent" : "PostmanRuntime/7.6.1",
                    "Connection" : "keep-alive",
                    "Content-Type" : "application/json",
                    "Cookie" : "sessionid=ugs3iaw9ltqtdrh65rhfbpo2ct6uq83o",
                    "Accept" : "*/*",
                    "Content-Length" : "116",
                    "Host" : "localhost:8000",
                    "Authorization" : "Token  5dace55366d8f36102c04c7b9fbdbdd7352f2ffc",
                    "Postman-Token" : "61873e1e-0c1b-43f0-b048-a84bbd87ca4f"
                },
                "USER" : {
                    "ip_address": "186.291.22.5",
                    "email" : "user@gmail.com",
                    "phone_number" : "0821xxxxx",
                    "username" : "si-fulan",
                    "model": "Customer",
                    "id" : 1
                },
                "ERROR_MESSAGE": null,
                "STATUS_CODE": 200
            },
            "func" : "save_mongodb_logging",
            "dates" : [
                ISODate("2019-07-16T13:43:12.820Z")
            ],
            "name" : "logger:mongolog",
            "counter" : 1,
            "uuid" : "ebe40b9a7bfb598ab3ec1c473fb93e31",
            "process" : 26388,
            "filename" : "middleware.py"
        }
        """
        # this `user` usage for models.User or models.Customer
        user = request._cached_user if hasattr(request, '_cached_user') else request.user
        if hasattr(request, 'auth') and request.auth:
            if hasattr(request.auth, 'customer'):
                user = request.auth.customer or user

        headers = eval(str(request.headers))
        response_data = None
        request_data = None

        def clean_text(text):
            if isinstance(text, bytes):
                try:
                    return text.decode('utf-8')\
                               .replace('\\n', '')\
                               .replace('\\t', '')\
                               .replace('\\r', '')
                except Exception:
                    pass
            return str(text)

        try:
            request_data = json.loads(clean_text(request.body))
        except RawPostDataException:
            response_data = "RawPostDataException: You cannot access body after reading from request's data stream"
        except Exception:
            try:
                request_data = clean_text(request.body)
            except Exception:
                pass

        if not headers.get('Content-Type') == 'application/x-www-form-urlencoded':
            try:
                response_data = json.loads(clean_text(response.content))
            except RawPostDataException:
                response_data = "RawPostDataException: You cannot access body after reading from request's data stream"
            except Exception:
                try:
                    response_data = clean_text(response.content)
                except Exception:
                    pass

        log_data = {
            'HEADERS': headers,
            'METHOD': request.method,
            'USER': {
                'id': user.pk if hasattr(user, 'pk') else None,
                'username': user.username if hasattr(user, 'username') else None,
                'phone_number': user.phone_number if hasattr(user, 'phone_number') else None,
                'email': user.email if hasattr(user, 'email') else None,
                'model': 'User' if hasattr(user, 'is_superuser') else 'Customer',
                'ip_address': get_client_ip(request)
            },
            'URL': request.build_absolute_uri(),
            'REQUEST_DATA': request_data,
            'RESPONSE_DATA': response_data,
            'ERROR_MESSAGE': exception,
            'STATUS_CODE': status_code
        }

        log = logging.getLogger('logger:mongolog')
        log.error(log_data) if exception else log.debug(log_data)

    def process_exception(self, request, exception):
        # print(type(exception), exception)  # just for debug
        status_code = 404 if isinstance(exception, Http404) else 500

        try:
            self.save_mongodb_logging(request,
                                      exception=exception,
                                      status_code=status_code)
        except Exception:
            # error = traceback.format_exc()
            # capture_exception(error)
            print(error)

        return  # no return anything

    def process_response(self, request, response):
        if not response.status_code >= 400:
            try:
                response_data = {'request': request,
                                 'response': response,
                                 'status_code': response.status_code}
                self.save_mongodb_logging(**response_data)
            except Exception:
                pass
        return response

2. logger.py

import datetime

from django.conf import settings

MONGODB_CONNECTION_URL = getattr(settings, 'MONGODB_CONNECTION_URL', None)

# All logging handlers configurations.
# 'propagate': False = mean is the error logs ins't duplicates to another file logs.

NOW = datetime.datetime.now()
DAY_NAME = NOW.strftime('%A').lower()

MAXIMUM_FILE_LOGS = 1024 * 1024 * 10  # 10 MB
BACKUP_COUNT = 5


LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'standard': {
            'format': '[%(levelname)s] %(asctime)s %(name)s: %(message)s'
        },
    },
    'handlers': {
        'default': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/default.log',
            'maxBytes': MAXIMUM_FILE_LOGS,
            'backupCount': BACKUP_COUNT,
            'formatter': 'standard',
        },
        'mongolog': {
            'level': 'DEBUG',
            'class': 'mongolog.SimpleMongoLogHandler',

            # Set the connection string to the mongo instance.
            # mongodb://[username]:[password]@[host]:[port]/[database]
            'connection': MONGODB_CONNECTION_URL,

            # define mongo collection the log handler should use.  Default is mongolog
            # This is useful if you want different handlers to use different collections
            'collection': 'mongolog',
            'formatter': 'standard',
        },
        'request_debug_handler': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/request_debug.log',
            'maxBytes': MAXIMUM_FILE_LOGS,
            'backupCount': BACKUP_COUNT,
            'formatter': 'standard',
        },
        'request_error_handler': {
            'level': 'ERROR',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/request_error.log',
            'maxBytes': MAXIMUM_FILE_LOGS,
            'backupCount': BACKUP_COUNT,
            'formatter': 'standard',
        },
        'mail_admins_handler': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'email_backend': 'django.core.mail.backends.smtp.EmailBackend'
        },
    },
    'root': {
        'handlers': ['default', 'mongolog'],
        'level': 'DEBUG'
    },
    'loggers': {
        'django.request': {
            'handlers': [
                'mongolog',
                'request_debug_handler',
                'request_error_handler',
                'mail_admins_handler'
            ],
            'level': 'DEBUG',
            'propagate': False
        },
    }
}

3. settings.py

LOGGING = LOGGING # from the `logger.py` file.
MONGODB_CONNECTION_URL = 'mongodb://db_user:db_password@127.0.0.1:27017/mongolog'



MIDDLEWARE = [
    ....

    'path.to.middleware.SessionLogMiddleware',
]

Answer 3

I originally tried to do something like request = copy.copy(request) but clearly it's a mistake because shallow copying does not copy nested objects. So the correct approach is (__call__ is middleware's class instance method):

def __call__(self, request):
    request_body = copy.copy(request.body)
    # Here goes more code for further processing
    # and now I can safely use request_body before or after
    # the view code runs

Update

As Felix Eklöf suggested, you can also use str(request.body) and python will handle copying the body contents, cause strings are immutable in python. (I guess it has better readability too).