Django logging

Tutorial on how to use logging with Django.

Prerequisites

I'm working on an Ubuntu 20.04, Django 3.1.1 and django-extensions 3.0.9 for good measure.

This will not be a complete from zero to hero tutorial, rather I'll assume that you know enough basic Django to be able to apply the shown yourself. I'll also assume that you have a barebone Django project setup, in my examples it will be called 'config' thus generating the settings file in the config.settings.py folder.

Logging flow in Django

Below is a rough graph of how a log message (log record) flows from logger to output (via a formatter).

Django logging flow

Logging in Django

Lets setup a view with an url:

from django.http import HttpResponse
import datetime


def index(request):
    now = datetime.datetime.now()
    html = "<html><body>It is now %s.</body></html>" % now
    return HttpResponse(html)

If we reload the view, we get:

Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
Warning log message
Error log message
Critical log message
[28/Mar/2021 17:28:54] "GET / HTTP/1.1" 200 63

Only the Warning, Error and Critical log levels are showing. So how do we get the other ones to show?
We could manually set the log level in the module:

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

and reloading:

Quit the server with CONTROL-C.
DEBUG:pages.views:Debug log message
INFO:pages.views:Info log message
WARNING:pages.views:Warning log message
ERROR:pages.views:Error log message
CRITICAL:pages.views:Critical log message
[28/Mar/2021 18:05:36] "GET / HTTP/1.1" 200 63

However, this is not how we would typically do in Django; In Django, we can use the LOGGING settings in the config.settings file.

Naming of loggers

In the example above, we used the __name__ for naming the logger; We don't have to. The name itself is used to get (or create) a logger and is also used to identify the logger in the configuration. Another way of naming a logger is by using dot notation, for example:

logger = logging.getLogger('config.pages.html')

which gives a slightly different logging output:

Django version 3.1.7, using settings 'config.settings'
Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
DEBUG:config.pages.html:Debug log message
INFO:config.pages.html:Info log message
WARNING:config.pages.html:Warning log message
ERROR:config.pages.html:Error log message
CRITICAL:config.pages.html:Critical log message
[31/Mar/2021 07:26:45] "GET / HTTP/1.1" 200 63

The main feature of using dot notation is that it can be used to propagage logging calls 'up the tree'.

logging in settings.py

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'root': {
        'handlers': ['console'],
        'level': 'WARNING',
    },
}

I honestly don't really know what function the 'version' keyword has; I have ever only seen it with a 1, but you get an error message if it is missing.

The disable_existing_loggers is important to remember. If you miss it, it will automatically be set to True and then disable all the build in django loggers, which is rarely what you want.

We define one handler called 'console' and assign it the class 'logging.StreamHandler', which will output everything to the console. The 'root' is the name of a logger which is the 'top level' logger that collects all log messages. We set it's level to 'WARNING', meaning, it will only ouput log messages with levels higher than or equal to "WARNING":

Django version 3.1.7, using settings 'config.settings'
Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
Warning log message
Error log message
Critical log message
[31/Mar/2021 07:46:14] "GET / HTTP/1.1" 200 63

See, no INFO or DEBUG messages.

If we remove the root logger and just have:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
}

but set DEBUG = False and get the logger named 'django', we will see that Django doesn't log out DEBUG level log messages. 'django' is a special named logger in the django logging hierarchy.

DEBUG = False
# logging.basicConfig(level=logging.DEBUG)
# logger = logging.getLogger(__name__)
logger = logging.getLogger('django')

If instead, we set DEBUG = True, we get all log messages with log level INFO or above (so no DEBUG level log messages):

Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
Info log message
Warning log message
Error log message
Critical log message
[31/Mar/2021 09:07:49] "GET / HTTP/1.1" 200 63

If we want to include DEBUG level log messages, we have to overwrite the configuration for the django logger:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': 'DEBUG',
        },
    },
}

But, this will display a log of logging, so I won't show that here.

Log output options

We can log to different places, not just the console, but also files. This is done by adjusting the handler to use a different type of handler:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
        'file': {
            'level': 'WARNING',
            'class': 'logging.FileHandler',
            'filename': BASE_DIR / 'filelog.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'INFO',
        },
    },
}

This way, we are defining a new handler, the 'file' with a logging.FileHandler class and a 'filename'; We then attach it to the django logger. A file will now be created with the 'filename':

Warning log message
Error log message
Critical log message

The Python standard logging module defines several log handlers, like FileHandler and StreamHandler Logging Handlers, and one additional Django specific handler: AdminEmailHandler.

Formatters

Formatters format the output and can be handy when you want to include timestamps or loglevel information for example. We can create a formatter like this:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,

    'formatters': {
        'verbose': {
            'format': '{levelname} {asctime} {module} {message}',
            'style': '{',
        },
    },

    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'verbose'
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': 'INFO',
        },
    },
}

And the output would now look like:

Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
INFO 2021-03-31 11:17:29,346 views Info log message
WARNING 2021-03-31 11:17:29,346 views Warning log message
ERROR 2021-03-31 11:17:29,346 views Error log message
CRITICAL 2021-03-31 11:17:29,347 views Critical log message
INFO 2021-03-31 11:17:29,347 basehttp "GET / HTTP/1.1" 200 63

More information on how to 'format' formatters can be found here: Formatting formatters

References

django logging official documentation