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:
- Setting up a logging system that is independent of Django.
- Using the built-in logging system in Django.
- 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:
- Index: the homepage with a search input.
- Search: displays the search results, allowing users to select the intended location.
- 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:
Logger: writes log records.Formatter: specifies the structure of each log record.Handler: determines the destination for each records.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:
- Be as specific as possible about the site of the log.
- Use appropriate log levels that correspond to the respective severities of the events.
- 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:
- 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.
- 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 incognito tab + 1 non-incognito tab of the same browser
- 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!
dashboards.
This work is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 4.0 International License.
dashboards.