Logging in Django

A log is created around when any type of event discretely occurs in a software system. A customer making a payment in the checkout or a product being added to a specific category by a vendor are examples of an event. Events should be observable, so in any case of failure or a flow in disarray then people should take action. One of the ways of making software systems observable is logging. Via logs, we can recreate the event in our development environment and troubleshoot the errors.

We should be aware of a number of things while we’re integrating logging into software systems:

• In which part of the code we will log
• What we will log
• Formatting of the log messages
• Where to send the logs (AWS Lightsail, terminal, send as an email, etc.)

Why don’t just use the print method?

There are mainly two reasons for that:

The print method handles lots of things implicitly. It simply outputs to stdout, so we need to customize almost every print function. To customize as we want that simple print function we need to add a destination, determine the encoding, formatting etc. so it becomes a complexity hell. It’s not scalable. We need a scalable and centric logging structure.

logging library

Django uses and extends Python’s built-in logging library, so before deep diving into Django, we need to investigate the core library first.

Since it’s very easy to do it, we log everything. There are settings for different environments. In the development environment, it’s very natural to want everything to be logged and printed out to stout so we can see what’s happening. However, in a production environment, we want to see only the error or critical logs to make alerts and generally ignore other types of logs (like info) in production as they don’t mean any danger to our products. I mean they are all logged but we specify which one of them to see in our alerts room (emails, AWS Lightsail, etc.). All of these configurations and filter operations are made with the logging library.

Django Logging Mechanism

Django’s default logging configuration has 4 parts:

• Loggers
• Handlers
• Formatters
• Filters

The log flow is through loggers to handlers.

Loggers

The respective logger will be called when an event occurs. The logger will create a Log with the definition and the details of the event that occurred. Then the Log object will be passed to the handlers for further processing.

The default Django loggers are:

    "loggers": {
        "django": {
            "handlers": ["console", "mail_admins"],
            "level": "INFO",
        },
        "django.server": {
            "handlers": ["django.server"],
            "level": "ERROR",
            "propagate": True,
        },
        "myproject.custom": {
            "handlers": ["console", "mail_admins"],
            "level": "INFO",
            "filters": ["special"]
        },
    }

Here there are three loggers django and django.server and myproject.custom. Each logger has its own name and rules.

• django logger passes all messages to the console.
• django.server only handles error messages and sends them as mail to the admins. Then propagates the message to the parent logger which is django logger. So django logger will handle the message too. So we can say that the hierarchy in the loggers is important.
• myproject.custom logger passes info messages with the special filter to the console and also sends mail to server admins.

You can call any of these loggers inside of your code like this:

import logging
logger = logging.getLogger(‘django.server’)
logger.error(message)

This code will create a LogRecord object by using the details of the event and pass it to the handlers.

There are 5 different severity levels of logging:

• debug: useful for development
• info: useful for providing information about usual operations
• warning: indicates that there may be a problem
• error: urges about some part of the product fails, requires troubleshoot
• critical: urges about the system-wide catastrophic errors, requires troubleshoot

Handlers

Handlers decide where to send the logs. It takes over the LogRecord objects from the loggers and does as ruled. For example:

    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'filters': ['special']
        }
    }

There are 2 handlers here. One of them is console and the other is mail_admins. The console handler prints the log message to the console and mail_admins sends the log messages to admins as an email.

You can modify it as you wish. For instance, you can persist the logs to text files or send the warning or more severe log messages directly to the Sentry.

The classes here are the actual log handlers. The log messages are all passed to these classes and they’ll handle the rest. The console handler uses logging.StreamHandler and mail_admins uses django.utils.log.AdminEmailHandler class.

Formatters

Formatters just format the log message via the event detail. For example, on an incoming request, you can format the log message as [date – time – ip_address – response_status].

    'formatters': {
        'verbose': {
            'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
            'style': '{',
        },
        'simple': {
            'format': '{levelname} {message}',
            'style': '{',
        },
    }

On the one hand, verbose formatter adds as much as possible detail, simple only extracts the levelname and message of the LogRecord.

Filters

    'filters': {
        'special': {
            '()': 'project.logging.SpecialFilter',
            'foo': 'bar',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    }

The console handler has a filter require_debug_true which is needed to make sure the app is in debug mode to write the log messages to the console. If the app is not in the debug mode then the record won’t be logged.

Both loggers and handlers can have filters. Using filters in loggers, you can specify what should be logged or not; and using filters in handlers you can specify where the logs should be sent.

Resources
Python and Django Logging in Plain English
Logging in Python – How to Use Logs to Debug Your Django Projects
MELT 101