Implement logging in your Django App

Implement logging in your Django App

How to use Django logger for better debugging

As a developer, you are bound to face multiple errors during and after your development phase and will be responsible for debugging them.

Debugging an application can become a nightmare if logging is not implemented properly.

You might end up either with too many logs or too many and both of them are only gonna make your task difficult, great implementation of logging act's as life support for your application and can give you a great boost in making your application as stable as it should be.

Why is logging important?

Once your local development is over, you will lose access to your great IDE features, and suddenly the task of debugging any error will increase manifolds, once it is deployed to a production-ready server.

A deployed code comes with its own set of problems, and debugging them becomes a nightmare because the majority of the issues which come are from corner cases we haven't even thought about.

A good implementation of a logging framework hence becomes even more important as it gives you some very important features just for debugging your application.

Thankfully, Django comes with Python's built-in logging module to leverage logging.

The Python logging module has four main parts:

  1. Loggers

  2. Handlers

  3. Filters

  4. Formatters

Django Official Documentation explains every feature in great detail, here is a starter guide I feel is good enough for getting started.

Let's discuss a few lines on the four parts of a logging framework

Django Logging Module

Loggers

Loggers are the entry point for the logging module and are the first point of contact for developers. Messages along with their log levels are passed on by these loggers to handlers for further processing.

  • DEBUG: Designates fine-grained informational events that are most useful to debug an application.

  • INFO: Designates informational messages that highlight the progress of the application at a coarse-grained level.

  • WARNING: Designates potentially harmful situations.

  • ERROR: Designates error events that might still allow the application to continue running.

  • CRITICAL: Designates very severe error events that will presumably lead the application to abort.

Handlers

Handlers decide what happens to each message in a logger, for example, whether to write messages to a screen or a file etc.

Same as loggers, handlers also have log levels and if the log level does meet the level of a handler, it will simply ignore the message.

A logger can have multiple handlers, and each handler can have different log levels, it is possible to provide different forms of notification depending on the importance of a message. For example, we can have one handler that sends ERROR and CRITICAL messages to some service, while another handler logs all messages including ERROR and CRITICAL messages to a file for later analysis.

Filters

A filter can sit between a Logger and a Handler and is used to provide additional control over which log records are passed from the logger to the handler.

For example, You can set a filter for CRITICAL messages which only allow a particular source to be processed.

Multiple filters can be used in a chain to perform multiple filtering actions.

Formatters

Ultimately, a log record needs to be rendered as text and formatters describe the exact format of that text.

Adding below are a few attributes which can be used while formatting logs output.

How to implement logging?

Configuring logging

Although Django comes with its default logging configuration, records with levels lower than WARNING will not appear in the console by default.

Python's Logging library provides several ways to configure logging, ranging from a programmatic way to configuration files. Default configuration settings use the dictConfig format, which we are going to use here.

We will use LOGGING variable to define a dictionary of settings. By default, these configs are merged with Django's default config.

If you wish to remove these default configs, you

can set them in Settings.py

LOGGING_CONFIG = None

Configuring a handler

The below example configures a handler named file, that uses Python’s FileHandler to save logs of level DEBUG and higher to the file general.log (at the project root)

LOGGING = {
    [...],   
    'handlers': {
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'general.log',
        },
    },
}

Django provides one log handler in addition to those provided by the Python logging module.

Configuring a logger

To use file hander for our logger, we will give its name in handlers list.

By default propagate is true, in this case we have made this as False which stop logs from given logger to be propagated to parents loggers.

LOGGING = {
    [...]
    'loggers': {
        '': { # configuration name ('') That means that it will process records from all loggers
            'level': 'DEBUG',
            'handlers': ['file'],
            'propagate': False,
        },
    },
}

Example Configurations

I am adding a few example configurations which can be used to set config in Django and are supposed to be put in Django projects settings.py file

  • A basic config that allows us to output all log messages with log levels WARNING or higher to the console.

      import os
    
      LOGGING = {
          'version': 1,
          'disable_existing_loggers': False,
          'handlers': {
              'console': {
                  'class': 'logging.StreamHandler',
              },
          },
          'root': {
              'handlers': ['console'],
              'level': 'WARNING',  # By having INFO or DEBUG we can display more messages to console.
          },
      }
    
  • Here is a config, which writes all logging from Django named logger to a local file.

      LOGGING = {
          'version': 1,
          'disable_existing_loggers': False,
          'handlers': {
              'file': {
                  'level': 'DEBUG',
                  'class': 'logging.FileHandler',
                  'filename': '/logFileLocation/debug.log',
              },
          },
          'loggers': {
              'django': {
                  'handlers': ['file'],
                  'level': 'DEBUG',
                  'propagate': True,
              },
          },
      }
    
  • Below is a relatively complex debug configuration which defines,

      LOGGING = { 
          'version': 1,
          'disable_existing_loggers': False,
          'formatters': {
              'verbose': {
                  'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
                  'style': '{',
              },
              'simple': {
                  'format': '{levelname} {message}',
                  'style': '{',
              },
          },
          'filters': {
              'special': {
                  '()': 'project.logging.SpecialFilter',
                  'foo': 'bar',
              },
              'require_debug_true': {
                  '()': 'django.utils.log.RequireDebugTrue',
              },
          },
          'handlers': {
              'console': {
                  'level': 'INFO',
                  'filters': ['require_debug_true'],
                  'class': 'logging.StreamHandler',
                  'formatter': 'simple'
              },
              'mail_admins': {
                  'level': 'ERROR',
                  'class': 'django.utils.log.AdminEmailHandler',
                  'filters': ['special']
              }
          },
          'loggers': {
              'django': {
                  'handlers': ['console'],
                  'propagate': True,
              },
              'django.request': {
                  'handlers': ['mail_admins'],
                  'level': 'ERROR',
                  'propagate': False,
              },
              'myproject.custom': {
                  'handlers': ['console', 'mail_admins'],
                  'level': 'INFO',
                  'filters': ['special']
              }
          }
      }
    
    • Two formatters,

      • verbose outputs log level, time, module details, process, thread and message.

      • simple outputs log level and message.

    • Two filters,

      • special is an alias for project.logging.SpecialFilter and passes the bar value to the foo parameter.

      • require_debug_true is an alias for `django.utils.log.RequireDebugTrue` , which passes record only when DEBUG is True.

    • Two handlers,

      • console which prints any INFO or higher messages to the console, this uses a simple filter.

      • mail_admins, emails any ERROR or higher message to site ADMINS, which uses a special filter.

    • Configures three loggers,

      • Django, passes all messages to the console handler.

      • Django.request, which passes all ERROR messages to the mail_admins handler. In addition, this logger is marked to not propagate messages. This means that log messages written to django.request will not be handled by the Django logger.

      • myproject.custom, which passes all messages at INFO or higher that also passes the special filter to two handlers – the console, and mail_admins. This means that all INFO level messages (or higher) will be printed to the console.ERROR and CRITICAL messages will also be output via email.


Prefered LOGGING configuration

This is the configuration I am using for my projects, below configuration uses colorlog to colour output based on log levels.

  • DEBUG: white

  • INFO: green

  • WARNING: yellow

  • ERROR: red

  • CRITICAL: bold_red

The configuration saves log level WARNING and above to a text file using the verbose formatter and parallelly all logs are printed to the console using the simple formatter.

If required, you can also override the log level to be saved to a file using a DJANGO_LOG_LEVEL environment variable.

LOGGING = {
    'version': 1,
    # The version number of our log
    'disable_existing_loggers': False,
    'formatters': {
        # Simple format for console logs
        'simple': {
            '()': 'colorlog.ColoredFormatter',
            'format': '%(log_color)s%(levelname)s [%(name)s] - %(message)s',
            'log_colors': {
                'DEBUG': 'white',
                'INFO': 'green',
                'WARNING': 'yellow',
                'ERROR': 'red',
                'CRITICAL': 'bold_red',
            },
        },
        # verbose format for console logs
        'verbose': {
            '()': 'colorlog.ColoredFormatter',
            'format': '%(log_color)s%(levelname)s %(asctime)s [%(name)s] - %(message)s',
            'log_colors': {
                'DEBUG': 'white',
                'INFO': 'green',
                'WARNING': 'yellow',
                'ERROR': 'red',
                'CRITICAL': 'bold_red',
            },
        },
    },
    'handlers': {
        # A handler for WARNING. It is basically writing the WARNING messages into a file called WARNING.log
        'file': {
            'level': os.getenv('DJANGO_LOG_LEVEL', 'WARNING'),
            'class': 'logging.FileHandler',
            'filename': BASE_DIR / 'WARNING.log',
            'formatter': 'verbose'
        },
        # A handler for all other logs, and will be used to print logs to console
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
    },
    'loggers': {
        '': {
            'handlers': ['file', 'console'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

Start capturing logs

Once the basic configs for loggers, handlers, filters and formatters are done we can start using the logger as shown in the example below

# import the logging library
import logging

# Get an instance of a logger
logger = logging.getLogger(__name__)

def my_view(request):
    ...
    if bad_response:
        # Log an error message
        logger.error('Something went wrong!')