Configuring django for centralised log monitoring with ELK stack with custom logging option (eg. client ip, username, request & response data)

When you are lucky enough to have enough users that you decide to roll another cloud instance for your django app, logging becomes a little bit tough because in your architecture now you would be needing a load balancer which will be proxying request from one instance to another instance based on requirement. Previously we had log in one machine to log monitoring was easier, when someone reported a error we went to that instance and looked for errors, but now as we have multiple instance we have to go to all the instance, regardless of security risks, i would say it is a lot of work. So I think it would be wise to have a centralized log aggregating service.

For log management and monitoring we are using Elastic Logstash and Kibana popularly known as ELK stack. For this blog we will be logging pretty much all the request and its corresponding responses so that debugging process gets handy for us. To serve this purpose we will leverage django middlewares and python-logstash.

First of all let’s configure our settings.py for logging:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        
        'standard': {
            'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
        },
        'logstash': {
            '()': 'proj_name.formatter.SadafNoorLogstashFormatter',
        },
    },
    'handlers': {
        'default': {
            'level':'DEBUG',
            'class':'logging.handlers.RotatingFileHandler',
            'filename': '/var/log/proj_name/django.log',
            'maxBytes': 1024*1024*5, # 5 MB
            'backupCount': 5,
            'formatter':'standard',
        },  
        'logstash': {
          'level': 'DEBUG',
          'class': 'logstash.TCPLogstashHandler',
          'host': 'ec2*****.compute.amazonaws.com',
          'port': 5959, # Default value: 5959
          'version': 1, # Version of logstash event schema. Default value: 0 (for backward compatibility of the library)
          'message_type': 'logstash',  # 'type' field in logstash message. Default value: 'logstash'.
          'fqdn': False, # Fully qualified domain name. Default value: false.
          #'tags': ['tag1', 'tag2'], # list of tags. Default: None.
          'formatter': 'logstash',
      },

        'request_handler': {
            'level':'DEBUG',
            'class':'logging.handlers.RotatingFileHandler',
            'filename': '/var/log/proj_name/django.log',
            'maxBytes': 1024*1024*5, # 5 MB
            'backupCount': 5,
            'formatter': 'standard',
        },
    },
    'loggers': {
        'sadaf_logger': {
            'handlers': ['default', 'logstash'],
            'level': 'DEBUG',
            'propagate': True
        },
    }
}

As you can see we are using a custom logging format. We can leave this configuration and by default LogstashFormatterVersion1 is the logging format that will work just fine. But I chose to define my own logging format because my requirement is different, I am running behind a proxy server, I want to log who has done that and from which IP. So roughly my Log Formatter looks like following:

from logstash.formatter import LogstashFormatterVersion1

from django.utils.deprecation import MiddlewareMixin
class SadafNoorLogstashFormatter(LogstashFormatterVersion1):
    def __init__(self,*kargs, **kwargs):
        print(*kargs, **kwargs)
        super().__init__(*kargs, **kwargs)


    def format(self, record,sent_request=None):
        print(record)
        print(sent_request, "old req")
        caddr = "unknown"
        #print(record.request.META)

        if 'HTTP_X_FORWARDED_FOR' in record.request.META:
            caddr = record.request.META['HTTP_X_FORWARDED_FOR'] #.split(",")[0].strip()
        
#        print(record.request.POST,record.request.GET, record.request.user)
        message = {
            '@timestamp': self.format_timestamp(record.created),
            '@version': '1',
            'message': record.getMessage(),
            'host': self.host,
            
            'client': caddr,
            'username': str(record.request.user),

            'path': record.pathname,
            'tags': self.tags,
            'type': self.message_type,
            #'request': self.record

            # Extra Fields
            'level': record.levelname,
            'logger_name': record.name,
        }

        # Add extra fields
#        print(type(self.get_extra_fields(record)['request']))
        message.update(self.get_extra_fields(record))

        # If exception, add debug info
        if record.exc_info:
            message.update(self.get_debug_fields(record))

        return self.serialize(message)

As our requirement is to log every request our middleware may look like following:

import logging

request_logger = logging.getLogger('sadaf_logger')
from datetime import datetime
from django.utils.deprecation import MiddlewareMixin
class LoggingMiddleware(MiddlewareMixin):
    """
    Provides full logging of requests and responses
    """
    _initial_http_body = None
    def __init__(self, get_response):
        self.get_response = get_response

    def process_request(self, request):
        self._initial_http_body = request.body # this requires because for some reasons there is no way to access request.body in the 'process_response' method.


    def process_response(self, request, response):
        """
        Adding request and response logging
        """
#        print(response.content, "xxxx")
        if request.path.startswith('/') and \
                (request.method == "POST" and
                         request.META.get('CONTENT_TYPE') == 'application/json'
                 or request.method == "GET"):
            status_code = getattr(response, 'status_code', None)
            print(status_code)

            if status_code:
                if status_code >= 400:
                    log_lvl = logging.ERROR
                else:
                    log_lvl = logging.INFO

            #request_logger.log(logging.DEBUG,)
            request_logger.log(log_lvl,
                               "GET: {}"
                               ""
                               .format(
                                   request.GET,
                                   ), 
                                   extra ={
                                       'request': request,
                                       'request_method': request.method,
                                       'request_url': request.build_absolute_uri(),
                                       'request_body': self._initial_http_body.decode("utf-8"),
                                       'response_body':response.content,
                                       'status': response.status_code
                                   }
                                       #extra={
                    #'tags': {
                    #    'url': request.build_absolute_uri()
                    #}
                #}
                )
#            print(request.POST,"fff")
        print("hot")
        return response

So pretty much you are done. Go login to your Kibana dashboard, make index pattern that you are interest and see your log:

[Code snippet] Django rest framework social oauth2 user sign up and sign in

At my serializers.py I have got the following:

from django.contrib.auth.models import User
from rest_framework import serializers
 
 
class UserSerializer(serializers.ModelSerializer):
    class Meta:
        model = User
        fields = ('username', 'email', 'password')

    def create(self, validated_data):
        return User.objects.create_user(**validated_data)

at my views.py I have got the following:

import serializers
from rest_framework.decorators import permission_classes, api_view
from rest_framework.permissions import AllowAny
from django.views.decorators.csrf import csrf_exempt
from rest_framework.parsers import JSONParser
from rest_framework.response import Response
from rest_framework import status
import json
from django.http import JsonResponse

from oauth2_provider.models import Application, AccessToken

@permission_classes((AllowAny,))
@csrf_exempt
@api_view(['POST'])
def create_auth(request, format=None):
    if request.user.is_authenticated():
        return Response({"already_registered": "User with that username has already registered"}, status=701)
    
    data = request.data
    print data

    
    serializer = UserSerializer(data=data, partial=True)
    if serializer.is_valid():
        u=serializer.save(username= data.get(u'username') )
        application=Application.objects.create(user=u, client_type="public", authorization_grant_type="password",name="general")
        client_id = application.client_id #call the url to get your tokens, use urllib or something similar
        client_secret = application.client_secret
        return JsonResponse({'client_id': client_id, 'client_password' : client_secret}, status=201)
    else:
        return JsonResponse({'errors': serializer.errors}, status=400)

I have added following at my urls.py

urlpatterns = patterns(
    '',
    url(r'^register/', 'social_app.views.create_auth'),
    url(r'^auth/', include('rest_framework_social_oauth2.urls')),
)

Testing:

 
sadaf2605@pavilion-g4:~$ curl -X POST -H "Content-Type: application/json" -d '{"email":"boba@athingy09876.com", "password":"p4ssword", "username": "user100"}' http://localhost:8000/register/

returns:

{"client_password": "EjQKMCAGmsUEm3L26uO7XSKnrZZVSVBQJUuvqfwi63pRB7d5y3ndlbZV0cBgQU7t3lCy078DS0FLqhaYoe9JZF0cQCIAgFKo7lfYU3npP7Eyv1PLk2eLPRnD3lF3OUUP", "client_id": "JhbwqqvE34vVjWiuMPnkV1eE636QQ3SzyQXLjmgs"}
sadaf2605@pavilion-g4:~$ curl -X POST -d "client_id=JhbwqqvE34vVjWiuMPnkV1eE636QQ3SzyQXLjmgs&client;_secret=EjQKMCAGmsUEm3L26uO7XSKnrZZVSVBQJUuvqfwi63pRB7d5y3ndlbZV0cBgQU7t3lCy078DS0FLqhaYoe9JZF0cQCIAgFKo7lfYU3npP7Eyv1PLk2eLPRnD3lF3OUUP&grant;_type=password&username;=user100&password;=p4ssword" http://localhost:8000/auth/token
{"access_token": "bssEYlDNaXefq8TPNRuu8oLolqYJp2", "token_type": "Bearer", "expires_in": 36000, "refresh_token": "fankCVPC3P84pQWI5oWOIhtWLCky4w", "scope": "read write"}