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

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" : "[email protected]",
                    "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:[email protected]:27017/mongolog'



MIDDLEWARE = [
    ....

    'path.to.middleware.SessionLogMiddleware',
]

Answer 2

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).