Django Logging

Introduction to Django logging with Best Practices

by

Django logging is one of few basic Django concepts that developers usually neglect but is important to master.

So what exactly is logging?
Logging in Django is the process of storing certain records in some form of container (file, database, memory,…) which then helps us in certain stages of development.

Firstly, we need to understand the concept of logging, its advantages, disadvantages, and why we use it.

A good understanding, writing, and reading of logs can in the future make debugging easier and, among other things, prevent problems that may occur. While it may not seem like it, the key to creating large stable Django applications lies in logging.

What is Django logging?

Django logging module consists of 4 parts:

  • Loggers (interface to log events from the application)
  • Handlers (describes logging behavior, such as writing a message to the screen, to a file, or a network socket)
  • Filters (providing additional control over recording logs)
  • Formatters (provides control over rendered text – custom formats, etc.)

The simplest example of using a logging module is shown in the following example:

Example 1.

import logging

# logger instance with name of module where it’s used (good practice)
logger = logging.getLogger(__name__)

logger.error(“Dummy text”)

And that’s it, the logger instance is defined and ready to use! No need to install additional libraries or modules. Plug and play!

Official Django documentation on logging.

Loggers, Log levels, and when to use one?

Loggers have certain log levels that describe events on our backend, let’s dive into it!

  • DEBUG
    • It would be a good practice to use debug method instead of print (read Logging vs printing section)
  • INFO
    • Used to log some general information as well as capture bottlenecks
  • WARNING
    • Describes problems that are small and potentially dangerous, such as missing CSRF_COOKIE
  • ERROR
    • Used when some exception is raised but not caught
  • CRITICAL
    • Never practically used in Django projects
LevelNumeric value
CRITICAL50
ERROR40
WARNING30
INFO20
DEBUG10

All Django logging log levels in the implementation receive the same arguments, ie the structure of arguments (args) and keyword arguments (kwargs) is the same for all -> (msg, * args, ** kwargs).

Kwargs can receive 4 arguments:

  • exc_info defaults False, if True it causes exception information to be added to logging message
  • stack_info defaults False, if True logging message contains stack information till logger is called
  • stacklevel defaults 1, if not 1, the exact number of stack frames are skipped when computing the line number and function name
  • extra dictionary in which we can put whatever information we find useful 🙂

Let’s see some basic logging examples:

Example 1.

from django.http import HttpResponse
import logging

logger = logging.getLogger(__name__)


def my_view(request):

    logging.debug("DEBUG")
    logging.info("INFO")
    logging.warning("WARNING")
    logging.error("ERROR")
    logging.critical("CRITICAL")

    return HttpResponse("Django logging example")






We come to an interesting output. WARNING, ERROR, and CRITICAL log levels are recorded but we don’t have DEBUG and INFO in the record.
This happens because the default level logging is WARNING and all “less critical” levels will not be recorded.





We can change this with a simple configuration.





Example 2.





from django.http import HttpResponse
import logging

logging.basicConfig(level=logging.DEBUG)
logger = logging.getLogger(__name__)


def my_view(request):
    logging.debug("DEBUG")
    logging.info("INFO")
    logging.warning("WARNING")
    logging.error("ERROR")
    logging.critical("CRITICAL")
    return HttpResponse("Django logging example")






Output:

Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.

DEBUG:root:DEBUG
INFO:root:INFO
WARNING:root:WARNING
ERROR:root:ERROR
CRITICAL:root:CRITICAL

[26/Nov/2021 15:35:59] "GET /example/logging/ HTTP/1.1" 200 22





Next example shows arguments and keyword arguments usage:





Example 3.





from django.http import HttpResponse
import logging

logger = logging.getLogger(__name__)

def my_view(request):
    logging.error('Internal server error: %s', request.path,
                  exc_info=True, #default False
                  stack_info=True, #default True
                  stacklevel=1, #default 1
                  extra={
                      "status_code": 500,
                      "request": request
                  }
     )

    return HttpResponse("Django logging example")






Output:

ERROR:root:Internal server error: /example/logging/
NoneType: None
Stack (most recent call last):
	. . .
          File ".../django_logging/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 181, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File ".../django_logging/example/views.py", line 8, in my_view
    logging.error('Internal server error: %s', request.path,

[26/Nov/2021 16:08:15] "GET /example/logging/ HTTP/1.1" 200 22





exc_info=True outputs NoneType:None because no exception is caught.





stack_info=True produces Stack output (most recent call last)





Documentation on Module-level functions. 





Handlers and handler classes





Handlers determine what happens to messages, whether we print them to standard output, to a file, or something else.





Several handler classes are set by default within the logging module, each of which I will briefly describe, and the choice depends on the use case.





HandlerOutputs
StreamHandlerStreams, any object that supports write() and flush()
FileHandlerFile
NullHandlerNone
usage explained: If you don’t want to produce any logs, it’s easier to change handler to NullHandler instead of removing logs
WatchedFileHandlerFile
BaseRotatingHandlerNone
Used only for extending (to override methods)
RotatingFileHandlerFile
When the given size is about to be exceeded, a new file is opened
TimedRotatingFileHandlerFile
The new file is opened based on interval or when
SockerHandlerNetwork socket
DatagramHandlerLogging messages over UDP sockets
SysLogHandlerLogging messages to a remote or local Unix Syslog.
NTEventLogHandlerLogging messages to a local Windows NT, Windows 2000, or Windows XP event log.
SMTPHandlerLogging messages to an email address
MemoryHandlerLogging records in memory
HTTPHandlerLogging messages to a web server
QueueHandlerLogging messages to a queue
QueueListenerNot itself a handler, it is documented here because it works hand-in-hand with QueueHandler





TIP - If unsure use RotatingFileHandler class.





WARNING - WatchedFileHandler should not be used on Windows.





Filter overview





Filters exist to give us extra control over handlers and loggers.





To create your filter inherit the Filter class.





Filter class has a filter method that receives a record in arguments. Also, the Filter class must return True if we want it to enter the logs, otherwise, the log is ignored.





Enough theory, let’s show what it looks like in practice!





Example 1.





import logging
from logging import Filter


class CustomFilter(Filter):
    MODULE = ['example.views']

    def filter(self, record: logging.LogRecord) -> bool:
        if record.name in self.MODULE:
            return False
        return True






We defined CustomFilter class in which we inherited Filter, in the CustomFilter class we defined the module from which we do not want to receive logs.





In the filter method, we checked whether record.name (name of the module) is in the defined MODULE list, if located we do not record that log.





Let’s see how we added this filter to the logger instance.





from django.http import HttpResponse
import logging

from core.logging_filters import CustomFilter

logger = logging.getLogger(__name__)
custom_filter = CustomFilter()
logger.addFilter(custom_filter)


def my_view(request):
    logger.error("ERROR")
    return HttpResponse("Django logging example")





Documentation on filters.





Formatter overview





Formatter works similarly to the filter, we initialize our Custom class in which we inherit the Formatter class, we have more methods in it that we can override, I will focus on the most used format method.





Let’s look at the implementation!





Example 1.





from logging import Formatter, LogRecord


class CustomFormatter(Formatter):

    def format(self, record: LogRecord) -> str:
        return "Any type of information you want in your logs"






format method returns a string (what will be written in the log file).





The formatter is not added directly to the logger but the handler, as shown in the example:





from logging.handlers import RotatingFileHandler

from django.http import HttpResponse
import logging

from core.logging_formatters import CustomFormatter

logger = logging.getLogger(__name__)

handler = RotatingFileHandler('example.log', maxBytes=1000, backupCount=2)
custom_formatter = CustomFormatter()
handler.setFormatter(custom_formatter)
logger.addHandler(handler)


def my_view(request):
    logger.error("ERROR")
    return HttpResponse("Django logging example")






Documentation on formatters.





Logging vs printing





Why is it recommended to use a logging library instead of a print?
The goal is to have the most detailed view of what we want to show through the application.
Logging solves it through the log level, in each stage of the code, we can know whether we want to display error, warning, debug, or info.





Additionally, logging can be set to display eg timestamps and other application contexts with a fairly simple configuration. We have more control over the logger, which is always a better thing for a developer.





Print statements are not recorded, unlike logs.





Finally, depending on the webserver, a forgotten print statement may crash your entire server.





Django logging tips and best practices





  • f-strings don’t work with loggers
  • use ISO-8601 Format for Timestamps





import logging
logging.basicConfig(format='%(asctime)s %(message)s') #could be added as formatter






  • Add logging before the app grows too much 🙂
  • When DEBUG=False and ERROR log level is triggered, email is sent to every email listed ADMINS
  • Don’t import and reuse logger from other modules, define a new logger
    • gives you the ability to turn off and on certain loggers
  • Use log rotation (RotatingFileHandler class) to prevent logs to grow too much
    • the mechanism that is used to prevent full disks
    • works by compressing and deleting old log files





import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger(__name__)
handler = RotatingFileHandler('log_file.log', maxBytes=1000, backupCount=5)
logger.addHandler(handler)






  • Use correct log levels!
  • Logutils package ( https://pypi.org/project/logutils/ ) contains useful new and improved handlers





Use Django logging alternatives?





The logging module of the standard pyhon implementation has been tested and brought to perfection.





For each new version of Python, there is a possibility that each “third party module” breaks, and thus the logging in your application does not work.





I would not recommend using anything other than the above module for the pure reason that the alternatives are practically the same.





Don’t invent the wheel if it’s already invented. 🙂










Django projects with logging and analysis tools hide great power – so don’t be afraid to use it to improve your application!