Django error logs

Logging¶

Python programmers will often use print() in their code as a quick and
convenient debugging tool. Using the logging framework is only a little more
effort than that, but it’s much more elegant and flexible. As well as being
useful for debugging, logging can also provide you with more — and better
structured — information about the state and health of your application.

import os

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

import os

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'root': {
        'handlers': ['console'],
        'level': 'WARNING',
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
            'propagate': False,
        },
    },
}

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

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']
        }
    }
}

LOGGING_CONFIG = None

import logging.config
logging.config.dictConfig(...)

{
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'style': '{',
        }
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
        },
        'django.server': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'django.server',
        },
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'django.utils.log.AdminEmailHandler'
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
        },
        'django.server': {
            'handlers': ['django.server'],
            'level': 'INFO',
            'propagate': False,
        },
    }
}

'handlers': {
    'null': {
        'class': 'logging.NullHandler',
    },
},
'loggers': {
    'django.security.DisallowedHost': {
        'handlers': ['null'],
        'propagate': False,
    },
},

Back to Top

Some time has passed since EMP’s most helpful code submission. I just now implemented it, and while thrashing around with some manage.py option, to try to chase down a bug, I got a deprecation warning to the effect that with my current version of Django (1.5.?) a require_debug_false filter is now needed for the mail_admins handler.

Here is the revised code:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
         'require_debug_false': {
             '()': 'django.utils.log.RequireDebugFalse'
         }
     },
    'handlers': {
        # Include the default Django email handler for errors
        # This is what you'd get without configuring logging at all.
        'mail_admins': {
            'class': 'django.utils.log.AdminEmailHandler',
            'level': 'ERROR',
            'filters': ['require_debug_false'],
             # But the emails are plain text by default - HTML is nicer
            'include_html': True,
        },
        # Log to a text file that can be rotated by logrotate
        'logfile': {
            'class': 'logging.handlers.WatchedFileHandler',
            'filename': '/home/username/public_html/djangoprojectname/logfilename.log'
        },
    },
    'loggers': {
        # Again, default Django configuration to email unhandled exceptions
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        },
        # Might as well log any errors anywhere else in Django
        'django': {
            'handlers': ['logfile'],
            'level': 'ERROR',
            'propagate': False,
        },
        # Your own app - this assumes all your logger names start with "myapp."
        'myapp': {
            'handlers': ['logfile'],
            'level': 'DEBUG', # Or maybe INFO or WARNING
            'propagate': False
        },
    },
}

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

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.

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.

• 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!

Быстрый обзор¶

Django использует и расширяет встроенный модуль Python logging для ведения системного журнала. Этот модуль подробно рассматривается в собственной документации Python; в данном разделе представлен краткий обзор.

Последствия для безопасности¶

Система протоколирования обрабатывает потенциально конфиденциальную информацию. Например, запись журнала может содержать информацию о веб-запросе или трассировке стека, а некоторые данные, которые вы собираете в собственных регистраторах, также могут иметь отношение к безопасности. Вы должны быть уверены в том, что знаете:

• какая информация собирается
• где он будет впоследствии храниться
• как она будет передана
• кто может иметь к нему доступ.

Чтобы помочь контролировать сбор конфиденциальной информации, вы можете явно указать определенную конфиденциальную информацию, которая будет отфильтрована из отчетов об ошибках — читайте подробнее о том, как это сделать filter error reports.

Настройка протоколирования¶

Библиотека протоколирования Python предоставляет несколько способов настройки протоколирования, начиная от программного интерфейса и заканчивая конфигурационными файлами. По умолчанию Django использует dictConfig format.

Для настройки протоколирования вы используете LOGGING для определения словаря настроек протоколирования. Эти настройки описывают регистраторы, обработчики, фильтры и форматеры, которые вы хотите использовать в своей настройке протоколирования, а также уровни протоколирования и другие свойства, которыми должны обладать эти компоненты.

По умолчанию установка LOGGING объединяется с Django’s default logging configuration по следующей схеме.

Если ключ disable_existing_loggers в директ-конфиге LOGGING установлен в True (что является dictConfig по умолчанию, если ключ отсутствует), то все регистраторы из конфигурации по умолчанию будут отключены. Отключенные регистраторы — это не то же самое, что удаленные; регистратор будет по-прежнему существовать, но будет молча отбрасывать все, что записывается в него, даже не передавая записи в родительский регистратор. Таким образом, вы должны быть очень осторожны, используя 'disable_existing_loggers': True; вероятно, это не то, что вам нужно. Вместо этого вы можете установить disable_existing_loggers в False и переопределить некоторые или все логгеры по умолчанию; или вы можете установить LOGGING_CONFIG в None и handle logging config yourself.

Логирование настраивается как часть общей функции Django setup(). Поэтому вы можете быть уверены, что логгеры всегда готовы к использованию в коде вашего проекта.

import os

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

import os

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'root': {
        'handlers': ['console'],
        'level': 'WARNING',
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
            'propagate': False,
        },
    },
}

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

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']
        }
    }
}

LOGGING_CONFIG = None

import logging.config
logging.config.dictConfig(...)

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

pip install -r requirements.txt

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.

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:

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.

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.

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:

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!

Next article

→