How To Test Logging In Python?


How To Test Logging In Python?

Python has a highly configurable, extremely flexible, builtin logging facility. Testing logging in earlier versions of Python used to be a bit tricky, but nowadays it’s rather straightforward.

The easiest way to test logging in Python is to use the AssertLogs context manager from unitest

There are some alternatives as well, for example you can mock the logging module, use the LogCapture from the testfixtures package or register your own stream handler.

1. Use The AssertLogs Context Manager From unitest

If you are using unittest - the default Python testing library - you can use the TestCase’s assertLogs. Logs method. It’s easiest to demonstrate its usage with a simple example. Let’s say you want to test that the following function logs the string "Hello, World!"

# example.py

import logging

def method_with_logging():
    logging.info("Hello, World!")

To test whether the logs work properly or not, we can do:

# test.py

from unittest import TestCase
from example import method_with_logging

class TestExample(TestCase):
    def test_logging(self):
        with self.assertLogs() as captured:
            method_with_logging()
        self.assertEqual(len(captured.records), 1) # check that there is only one log message
        self.assertEqual(captured.records[0].getMessage(), "Hello, World!") # and it is the proper one

As you can see it captures all the messages. The captured variable has an output attribute, which contains the raw log output of each message (as a list of strings). But here we’re using the records attribute instead (because we want the unformatted output - to avoid depending on the logging configuration). records contains it is a list of logRecord objects.

The full signature of this method is like this: assertLogs(logger=None, level=None), so you can filter for a specific logger, or a logLevel (CRITICAL, ERROR, WARNING, INFO or DEBUG)

Note: the test will pass, even if the logs are muted in your logging configuration.

2. Mock The logging Module

A more direct approach would be to patch the logging module. Using the same example as before, the test would be:

# test.py                                                                                                                                                                          X

from unittest import TestCase
from unittest.mock import patch
from example import method_with_logging

class TestExample(TestCase):
    @patch("example.logging.info")
    def test_logging(self, info_mock):
        method_with_logging()
        info_mock.assert_called_once_with("Hello, World!")

This version is a bit more brittle, so I’d advise against it. What I mean by brittle is that it depends on how you log, for example if you do something like:

# example.py

import logging

logger = logging.getLogger("example")
logger.info("Hello, World!")

The logging would still work, but the test would break. The test is also tied to the info logLevel now.

3. Use LogCapture From The testfixtures Package

LogCapture works very similarly to assertLogs:

# test.py

from unittest import TestCase
from example import method_with_logging

class TestExample(TestCase):
    def test_logging(self, info_mock):
        with LogCapture() as captured:
            method_with_logging()
            self.assertEqual(len(captured.records), 1) # check that there is only one log message
            self.assertEqual(captured.records[0].getMessage() "Hello, World!") # and it is the proper one

If you’re using unittest there’s probably no point in using LogCapture instead of the builtin assertLogs. It might come handy if you’re on a different testing framework for some reason.

It also provides a check method, which takes a list of expected log records and does the comparisons for you.

4. Add Your Own Stream Handler

If you are using an older version of Python, and for some reason cannot patch the logger and cannot or do not want to install an extra package like textfixtures, as a last resort you can create your own log handler, that collects the log messages for you.

For example you can use something like this MockLogHandler:

# test.py

import logging

class MockLogHandler(logging.Handler):
    records = []

    def emit(self, record):
        self.records.append(record.getMessage())

This log handler just records the log messages in a list. If you register it in your tests, you can simply examine the contents of the records attribute, like so:

# test.py

from unittest import TestCase

class TestExample(TestCase):
    @classmethod
    def setUpClass(cls):
        logger = logging.getLogger("example")
        cls._mock_logger = MockLogHandler(level='DEBUG')
        logger.addHandler(cls._mock_logger)

    def setUp(self):
        self._mock_logger.records = [] # delete the previously recorded messages before each test run

    def test_logging(self):
        method_with_logging()
        self.assertEqual(len(self._mock_logger.records), 1)
        self.assertEqual(self._mock_logger.records[0].getMessage(), "asdf")

Bonus Tip: How To Test Error Logging

Many times you’ll find yourself looking for a way to test error logging. Let’s say you want to test what happens, if the requests.get method raises an exception in the following method.

# example.py

import requests
import logging

def method_with_logging():
    try:
        requests.get("http://example.com")
    except requests.RequestException:
        logging.error("Something went wrong")

If you mock the method in the test, you can make it raise an exception with the side_effect method.

# test.py

from unittest import TestCase
from unittest.mock import patch
from example import method_with_logging
from requests import RequestException
import logging

class TestExample(TestCase):
    @patch("requests.get")
    def test_logging(self, get_mock):
        get_mock.side_effect = RequestException
        with self.assertLogs() as captured:
            method_with_logging()
        self.assertEqual(len(captured.records), 1)
        self.assertEqual(captured.records[0].getMessage(), "Something went wrong")
        self.assertEqual(captured.records[0].level, logging.ERROR)

Summary

To sum it up: thanks to assertLogs, testing logging in Python is pretty straightforward since version 3.4. If you are on an older version your best bet would be to just mock the loggging method that you’re trying to test. If that does not work for you, then you can fall back to the more complicated workarounds, like using the testfixtures package or registering your own logger that records the log messages for you.