How to Get Started with Logging in Django

In a previous article, we dived into the fundamentals of logging in Python using the built-in logging module. This tutorial will build on those fundamentals by exploring how they are applied in a real-world application built using Django, a Python web framework that aids with the rapid design and development of web applications.

By following through with this tutorial, you will gain an understanding of the following concepts:

1. Setting up a logging system that is independent of Django.
2. Using the built-in logging system in Django.
3. Integrating Django projects with a log aggregation service.

Prerequisites

While this article explains its concepts in detail, we recommend reading the previous article which discusses the fundamentals of logging in Python as basic concepts such as understanding the use cases of logging and writing meaningful log messages were covered in that article. However, this is optional if you're already familiar with Python's logging module.

To follow through with this article, you should install the latest version of Python on your machine. If you are missing Python, you can find the installation instructions here.

You will also need SQLite. Some machines come with SQLite pre-installed, but you can find the installation instructions here if you don't have it already.

Finally, clone the sample code repository and set up the project on your machine:

git clone https://github.com/betterstack-community/horus.git

cd horus/

pip install -r requirements.txt

python manage.py migrate

Finally, you should sign up for a free OpenWeather account as our sample application relies on it to function. Your OpenWeather API key can be accessed from here:

Copy the key and add the following file and add it to a .env file at the root of your project:

OPEN_WEATHER_API_KEY=<api key>

Breaking down the sample application

For this tutorial, we will implement a basic logging system in a Django-powered weather search application — Horus. This section will introduce the project architecture, technologies used, and discuss some important points about the project.

Project structure

The horus directory follows the standard Django configuration, except for the hierarchy of the views. Instead of having a traditional large views.py file, each view corresponds to a Python file in the horus/views/ folder to make logging easier to implement.

The critical files for this project are as follows:

> horus/
    > views/
        * index.py      — houses the Index view
        * search.py     — houses the Search view
        * weather.py    — houses the Weather view
    * openweather.py    — OpenWeather API access wrapper
    * settings.py       — configurations for the various components of the project
* .env                  — environment variables for the project
* requirements.txt      — required packages for the project

Core views

Each view corresponds to a page in Horus, and there are three in total:

1. Index: the homepage with a search input.
2. Search: displays the search results, allowing users to select the intended location.
3. Weather: displays the weather of the selected location.

To understand the basic construction of a page, open horus/views/search.py in your text editor:

# ...

def search(request):
    if request.method != 'POST':
        return redirect('/')

    location = request.POST['location']

    try:
        locations = search_countries(location)
        return render(request, 'search.html', {'success': True, 'search': location, 'results': locations})
    except OpenWeatherError:
        return render(request, 'search.html', {'success': False})

The routing logic is as follows:

The other pages also rely on their respective templates (found in horus/templates/) to render the data accordingly. However, for this article, it is not crucial to understand how templating works in Django. If you wish to learn more, refer to the Django documentation on templates..

Overall, the general program flow is as follows:

The OpenWeatherMap API

Horus relies on the OpenWeatherMap API to provide up-to-date information about the current weather at a location. It uses two endpoints from the API — geocoding to match the user search query with possible locations and current weather to retrieve the current weather of the selected location.

A basic API wrapper has been built around the endpoints mentioned above and can be found in horus/openweather.py. The built-in requests module is used to query each endpoint with the given parameters and their responses are parsed accordingly:

# ...

def search_countries(search, limit=5):
    response = __request__(
        'http://api.openweathermap.org/geo/1.0/direct',
        {'q': search, 'limit': limit}
    )

    if not response.ok or len(response.json()) == 0:
        raise OpenWeatherError(
            'OpenWeather could not find matching locations - response not OK or response is empty')

    locations = [{
        'name': location['name'],
        'lat': location['lat'],
        'lon': location['lon'],
        'country': pycountry.countries.get(alpha_2=location['country']).name,
        'state': location['state'] if 'state' in location else ''
    } for location in response.json()]

    return locations


def get_current_weather(location, lat, lon):
    response = __request__(
        'https://api.openweathermap.org/data/2.5/weather',
        {'lat': lat, 'lon': lon, 'units': 'metric'}
    )

    if not response.ok:
        raise OpenWeatherError(
            'OpenWeather could not find the weather of the location - response not OK')

    weather = {
        'current': response.json()['weather'][0]['description'].lower(),
        'temp': response.json()['main']['temp'],
        'feels_like': response.json()['main']['feels_like'],
        'location': location
    }

    return weather

Note that this wrapper utilizes error handling for response management. If a request is successful, the wrapper function will return the parsed response from the API. If unsuccessful, the wrapper will raise an error instead. It is up to the developer to catch and handle the error accordingly (which we do).

Limitations-wise, we will use the free tier of the OpenWeatherMap API with certain limits. In our case, however, we will not run into these limits.

Design decisions

We have explicitly avoided using JavaScript or building a Single-Page Application (SPA) to minimize complexity. We're also relying on the SQLite database provided by Django as set up in the Prerequisites section.

To demonstrate multi-user access, each user will have a unique UUID assigned when they first access the Horus homepage. We will explore the usefulness of this approach when integrating Horus with a log aggregation system.

Now that you understand how the project works, let's revise the advanced logging features in Python next.

Recap of Python logging basics

In the introductory piece on logging in Python, we briefly covered the basics of its standard logging module. To recap, we touched base on Loggers, Formatters, Handlers, and Filters, with an emphasis on the first three.

Here's a brief recap of what they all do:

1. Logger: writes log records.
2. Formatter: specifies the structure of each log record.
3. Handler: determines the destination for each records.
4. Filter: determines which log records get sent to the configured destination.

These components follow the general setup process:

Now that we have a general idea of how logging works in Python, we will begin to implement these concepts in Horus.

Creating a Django-independent logging system

In this section, we will explore how to create a basic logging infrastructure that doesn't rely on Django-specific features, and we will use the flowchart above to guide our implementation. Let's take a look at the views/index.py file in the project directory for instructions on achieving this in code.

Throughout this tutorial, we will use Visual Studio Code as our default editor but feel free to use any editor that you are comfortable with.

code horus/views/index.py

When you first open the file in your editor, you will see that we've already set up the general logging infrastructure that will be replicated elsewhere. Let us go through the infrastructure one step at a time.

. . .

logger = logging.getLogger('horus.views.index')

logger.setLevel(logging.INFO)

. . .

First, a new Logger is instantiated and named horus.views.index. This name is included in every log entry produced by the logger so its good to give a descriptive name to easily locate the origin of a record. The minimum log level of the logger is set to INFO so that only messages logged at the INFO level or above are recorded.

. . .
formatter = logging.Formatter('%(name)s at %(asctime)s (%(levelname)s) :: %(message)s')
. . .

Next, a Formatter is created to specify the structure of each log message like this:

<name> at <timestamp> (<level>) :: <message>

There are many other formatting attributes that can be used to format your logs so do check them out.

sh = logging.StreamHandler()
sh.setFormatter(formatter)

An instance of the StreamHandler class also created and used to direct all logs to the standard error. On the next line, the formatter we created is set on the StreamHandler instance so that the correct formatting is applied to each record.

logger.addHandler(sh)

Lastly, the StreamHandler is added instance to our logger such that all logs are created through it are sent to the console.

At this point, we have a basic infrastructure for logging to the console and we can begin to log messages in our project. For example, let's log the unique UUID that is assigned to each new request to the homepage.

def index(request):
    request.session['id'] = str(uuid.uuid4())

    logger.info(f'New user with ID: {request.session["id"]}')

    return render(request, 'index.html', {})

You can see it in action by starting the Django application with the following command:

python manage.py runserver

Watching for file changes with StatReloader
Performing system checks...

System check identified no issues (0 silenced).
August 16, 2022 - 15:13:50
Django version 4.0.4, using settings 'horus.settings'
Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.

Head over to http://localhost:8000 in your browser and observe the following log entry in the terminal:

horus.views.index at 2022-06-21 18:39:00,970 (INFO) :: New user with ID: 889c2532-27df-4b31-99c2-245fd9fe3b8d

Normally, Django projects will have other logs printed to the console, but we have disabled them in the settings.py project so that we can focus solely on the logs generated by Horus itself.

Now that we have implemented a logging infrastructure that is independent of Django-specific features, let's practice by repeating the same process in the openweather.py file. Open the file, and follow the TODO prompts to set up the necessary logging infrastructure (the solution is discussed below).

Notes for practice: Django-independent logging

To create a FileHandler, refer to the documentation for the necessary configurations (Hint: fh = logging.FileHandler('logs.txt')).

One of the prompts requires you to log the OpenWeather API key to the console. This is a bad practice so once you have written up the code for this, ensure that you remove it before moving on to the next section.

For the prompts about logging various information about the program state, follow these general guidelines:

1. Be as specific as possible about the site of the log.
2. Use appropriate log levels that correspond to the respective severities of the events.
3. Include as much information about the log and problem, instead of just printing results.

Once you have completed the prompts, you can refer to the solution by changing to the solution branch.

git switch independent-solutions

Return to the openweather.py file in your editor and observe how each prompt was addressed.

logger = logging.getLogger('horus.openweather')
logger.setLevel(logging.INFO)
formatter = logging.Formatter(
    '%(name)s at %(asctime)s (%(levelname)s) :: %(message)s')

The initialization of the Logger and Formatter is the same as in the index.py example except that the name of the logger is horus.openweather.

sh = logging.StreamHandler()

fh = logging.FileHandler(filename='logging-logs.txt')

The creation of the StreamHandler follows the same the same pattern as in the index.py file. We also created an instance of the FileHandler class for outputting our logs to a file. This handler requires a filename argument that represents the name of the log file that is saved to the filesystem.

fh.setLevel(logging.WARNING)

The next prompt specifies that only logs of WARNING level and above should to be logged to the file, so the minimum log level of the newly created FileHandler is set to WARNING.

sh.setFormatter(formatter)
fh.setFormatter(formatter)

logger.addHandler(sh)
logger.addHandler(fh)

Afterward, the formatter is set on both the StreamHandler and FileHandler instances, and both handlers are subsequently added to the logger.

The prompts about logging program state do not have fixed answers, but it is advisable to follow the above guidelines. The two most important prompts in this section are:

1. Bad example logging:

Remember to delete the log after you have ensured that it works as it is bad practice to log tokens or API keys.

1. Logging when an API request fails:

Use logger.error() instead of logger.info() as we are logging something that goes against the normal program flow. When we are logging on the server, it is important that any failed API requests are logged as errors, not as warnings, so that future debugging will be easier.

   # ...
   if not response.ok or len(response.json()) == 0:
       logger.error(
           'search_countries failed as response returned not OK or no results in returned search')
   # ...

Once you are done inspecting the solutions branch, switch back to your main branch with the command below:

git checkout main

Now that we've set up a basic logging infrastructure independent of Django, we can look how to construct a Django-based logging setup in our application. This should be the preferred approach as it saves you from writing a lot of boilerplate code.

Implementing a Django-specific logging system

Something you might have noticed about the Django-independent logging system above is that setting up the logger, handler and formatter often has to be done within the file that requires logging.

To address this, Python's logging module has a built-in system for centralizing log configurations through the logging.dictConfig() function. This function loads a dictionary of logger configurations as a "global" store of loggers. This centralizes the logging infrastructure and avoids the problem of repeating the setup steps per file.

Django integrates with this built-in dictConfig system so that you can centralize your logging configuration in the settings.py file. Let us begin by looking at a basic example in horus/settings.py. It houses the logging configurations under the LOGGING field towards the end of the file.

Before the LOGGING field in settings.py, the LOGGING_CONFIG field is set to None to disable the automatic configuration process since we're going to set up a custom configuration shortly.

LOGGING_CONFIG = None

Next, we configured the logging behaviour of the requests library by setting it to only display logs equal to or above the ERROR log level.

logging.getLogger("requests").setLevel(logging.ERROR)

Lastly, the LOGGING field is used to setup the dictConfig() method:

logging.config.dictConfig(LOGGING)

These three steps effectively disable the default logging setup provided by Django and allows our application logs to take center stage.

# ...
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
    },
    'handlers': {
    },
    'loggers': {
    }
}

Let's now shift our focus to defining a basic logging setup in Django. We can configure several loggers, formatters, and handlers in a single location and then import them into our code as needed. The disable_existing_loggers key is set to False so that our loggers from the previous section will still work, but you may disable them if you want to restrict the use of loggers in your Django application to only the ones defined in the settings.py file (recommended).

Let's start by defining a new Formatter. Add the following code to the formatters dictionary shown below:

. . .
'formatters': {
    'base': {
        'format': '{name} at {asctime} ({levelname}) :: {message}',
        'style': '{'
    }
},
. . .

The new Formatter is called base and it uses the same log message format in the previous section. Setting the style key to { ensures that we can reference the log message attributes using curly braces.

Similarly, a new Handler is created by adding it to the handlers dictionary within the LOGGING dictionary:

. . .
'handlers': {
    'console': {
        'class': 'logging.StreamHandler',
        'formatter': 'base'
    },
},
. . .

The console handler is a StreamHandler instance that logs to the console, and it uses the base Formatter created earlier to format its output.

Finally, let's define a new Logger under the loggers dictionary as follows:

. . .
'loggers': {
    'horus.views.search': {
        'handlers': ['console'],
        'level': 'INFO'
    }
}
. . .

Our new logger is called horus.views.search and it uses the console handler defined earlier. It is also configured to only record messages with a log level of INFO and above.

With this configuration in place, we can access the horus.views.search logger in any file like this:

logger = logging.getLogger('horus.views.search')

Open the views/search.py file in your editor and observe how this logger was imported and used in several places:

. . .
logger = logging.getLogger('horus.views.search')

def search(request):
    if request.method != 'POST':
        logger.info(
            'Invalid access made to /search, redirecting to /')
        return redirect('/')

    logger.info(f'User {request.session["id"]} has navigated to /search')

    location = request.POST['location']

    logger.info(f'User {request.session["id"]} searched for {location}')

    try:
        locations = search_countries(location)
        return render(request, 'search.html', {'success': True, 'search': location, 'results': locations})
    except OpenWeatherError:
        logger.error(
            'Unable to retrieve matching locations for search', exc_info=True)
        return render(request, 'search.html', {'success': False})

When you search for a city in the application, you will observe that the following logs are recorded to the console:

horus.views.search at 2022-08-16 18:34:00,184 (INFO) :: User b617a3b3-773b-42aa-b679-fc12e2370818 has navigated to /search
horus.views.search at 2022-08-16 18:34:00,184 (INFO) :: User b617a3b3-773b-42aa-b679-fc12e2370818 searched for london

If you try to make a GET request to the /search route, it will redirect you back to the homepage and a INFO message will be logged to the console:

horus.views.search at 2022-08-16 18:36:00,702 (INFO) :: Invalid access made to /search, redirecting to /

In the latter part of the function, logger.error() is used in the except block so that if the search fails, an error is logged to the console. The exc_info argument is used to provide contextual information about the exception within the log message itself. We don't need to raise the exception since it does not impede the overall operation of the application and it is sufficiently handled in the except block by rendering an error page.

You can test it out by typing some gibberish in the search input instead of a location:

Once you click the search button, you will notice that the search was not successful:

And the following error will be logged to the console:

horus.views.search at 2022-08-16 18:42:43,842 (ERROR) :: Unable to retrieve matching locations for search
Traceback (most recent call last):
  File "/home/user/horus/views/search.py", line 35, in search
    locations = search_countries(location)
  File "/home/user/horus/openweather.py", line 61, in search_countries
    raise OpenWeatherError(
horus.openweather.OpenWeatherError: OpenWeather could not find matching locations - response not OK or response is empty

Now that we have seen how a Django-specific logging configuration works in practice, we can dive into some practice in both horus/settings.py and horus/views/weather.py, following the prompts provided in both files.

Notes for practice: Django-specific logging

First, head over to the settings.py file and complete the TODOs to create and configure a new Logger. Afterward, use the newly created Logger in horus/views/weather.py, following the given prompts to add logging to the file.

Once you have completed the prompts, you can refer to the solution by changing to the solution branch using the command below:

git switch specific-solutions

Return to the settings.py file in your text editor:

LOGGING = {
    # ...
    'handlers': {
        # ...
        'file': {
            'class': 'logging.FileHandler',
            'formatter': 'base',
            'level': 'WARNING',
            'filename': 'django-logs.txt'
        }
    },
    # ...
}

In settings.py, a new FileHandler called file is added to the handlers dictionary. Like the FileHandler from the previous section on Django-independent logging, this FileHandler will have a minimum level of WARNING and above. It also needs to have a filename value specified and it uses the base formatter declared earlier.

LOGGING = {
    # ...
    'loggers': {
        # ...
        'horus.views.weather': {
            'handlers': ['console', 'file'],
            'level': 'INFO'
        }
    }
}

Secondly, the horus.views.weather logger is also created and it logs to both the console and file handlers.

For the prompts in views/weather.py, follow the same guidelines as the ones highlighted in the previous section. Because of Django's centralized logging infrastructure, we can use logging.getLogger() to specify the name of the Logger we'd like to use as long as it is defined in settings.py.

logger = logging.getLogger('horus.views.weather')

Once you have explored the suggested solution for this section, change back to the main branch.

git checkout main

We have just explored how Django-independent and Django-specific logging works and the differences between them. Let us now look at log aggregation systems, why they are necessary, and how to get started quickly with aggregating your Django logs in the cloud

Using Log Aggregation systems

Since production applications are often deployed to multiple servers, it is necessary to centralize the logs so that you don't have to log into each server to view them and also so they can be analyzed and monitored for problems automatically. There are many solutions for centralizing application logs but we will go with the simplest option here which is using a hosted cloud service. For this section, we have opted to use Logtail due to its simplicity in getting started.

Setting up a Logtail account

To begin, create a free Logtail account and set up a new log source:

Retrieve the source token and copy it to your system clipboard:

Add the source token to your .env file as shown below:

...
LOGTAIL_SOURCE_TOKEN=<source token>

This step is incredibly important as without it, your project will not be able to integrate with Logtail.

Finally, create a new branch on the repository and call it logtail:

git checkout -b logtail

We have now successfully configured a Logtail source so we will integrate it with our Horus application to ensure that all logs are sent to the service.

Integrating Horus with Logtail

To get started, let us work within views/index.py by adding a Logtail handler:

import environ
from logtail import LogtailHandler

# ...

env = environ.Env()
env.read_env(env.str('ENV_PATH', '.env'))

lh = LogtailHandler(source_token=env('LOGTAIL_SOURCE_TOKEN'))
lh.setFormatter(formatter)
logger.addHandler(lh)

Notice that the general steps to set up Logtail in views/index.py is similar to the steps taken in previous sections. Now, we can kill the Horus server with Ctrl-C and start it up once again:

python manage.py runserver

Visit the Horus homepage to generate a log record. Afterward, head over to the Live tail section on the Logtail dashboard. You should notice the log entry in the dashboard as follows:

Now that you have a general notion of how Logtail is integrated with Django-independent logging infrastructure, try modifying the other files to use LogtailHandler as well. Hint: You only need to modify openweather.py and settings.py.

For Django-specific logging, note that the source_token argument is set as a key in the corresponding handler in settings.py. Also remember to add the handler to the respective loggers. When properly configured, you will only need to add the LogtailHandler to the respective Loggers once in horus/settings.py and the centralized logging infrastructure will handle the rest accordingly.

To view the complete solutions, change to the solution branch:

git switch logtail-solutions

. . .
lh = LogtailHandler(source_token=env('LOGTAIL_SOURCE_TOKEN'))
lh.setFormatter(formatter)
logger.addHandler(lh)
. . .

Setting up Logtail in the openweather.py file involves adding a LogtailHandler to the existing Logger as demonstrated above.

. . .
LOGGING = {
    # ...
    'handlers': {
        # ...
        'logtail': {
            'class': 'logtail.LogtailHandler',
            'formatter': 'base',
            'source_token': env('LOGTAIL_SOURCE_TOKEN')
        },
        # ...
    },
    # ...
}
. . .

In settings.py, we need to add a LogtailHandler to our handlers dictionary, as we have done for both StreamHandler and FileHandler. This time, we specified the source_token key to be the LOGTAIL_SOURCE_TOKEN added to .env earlier.

Afterward, we can add this new logtail handler to any of the loggers as shown below:

LOGGING = {
    # ...
    'loggers': {
        'horus.views.search': {
            'handlers': ['console', 'logtail'],
            'level': 'INFO'
        },
        'horus.views.weather': {
            'handlers': ['console', 'file', 'logtail'],
            'level': 'INFO'
        }
    }
}

Once you successfully integrated Logtail in your application, you will observe the application logs in the Live tail section.

Demonstrating multi-user access and logging

To visualize how log aggregation systems enhance logging for concurrently accessed applications, we can simulate multi-user access using the following variations of browser tabs:

1. 1 incognito tab + 1 non-incognito tab of the same browser
2. 1 non-incognito tab from two separate browsers

Note that any other variation may cause Django to mix up the UUIDs assigned per tab, so use only the two variations provided above.

Access http://localhost:8000 on each tab and you will find that the user sessions are maintained across each tab (simulating a unique user) and whenever an action is performed in a tab, it is properly attributed and logged under the corresponding user.

From the logs above, we can understand that one user attempted to search for an invalid location while the other searched for "Singapore".

Notice how exc_info displayed the full exception caused by the invalid search, providing as much contextual information as possible about the problem for further diagnosis.

You can see that with a log aggregation system like Logtail, all the logs are centralized and easily viewed, making problem diagnosis a lot easier.

Final thoughts

While you can build your logging infrastructure from the ground up, it is often best to consult the documentation of the library/framework you are using as they usually provide built-in mechanisms to enhance the logging process.

In Django, it comes in the form of modifying a central settings.py file with the relevant logging infrastructure and retrieving the relevant configuration with logging.getLogger() in any program file.

I hope this article has provided sufficient details to help you get started with logging in your Django application. If you are interested in learning more about logging in Django, please refer to the official documentation.

This article was contributed by guest author Woo Jia Hao, a Software Developer from Singapore! He is an avid learner who loves solving and talking about complex and interesting problems. Lately, he has been working with Go and Elixir!

Got an article suggestion? Let us know

This work is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 4.0 International License.