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:
