CODEWITHSUNDEEP
pythonunit-testinglogging
Graeme
Graeme

Reputation: 4592

Writing a unit test for Python logger formatted output

How could you write a unittest in Python that would test that the output from a logger is indeed in the format you expect (i.e. set through a call to logging.basicConfig())? I'm thinking along the lines of a custom StreamHandler and use of the 're' library but it doesn't look like LogRecord passed to StreamHandler.emit() can give me the string that will be output.

Upvotes: 10

Views: 5213

Answers (2)

Zlopez
Zlopez

Reputation: 700

If you want to use only standard libraries, this solution could help. It is based on unittest and mock libraries.

For example if you have script.py with following content.

logger = logging.getLogger(__name__)

def log_something():
    logger.debug("something")

You could write a test for it that will look like this.

import unittest

import mock

from script import log_something

@mock.patch("script.logger")
def test_function(mock_log):
    log_something()

    assertTrue(
        "something" in mock_log.debug.call_args_list[0][0][0]
    )

This is using the call_args_list from the mock library.

To explain [0][0][0] at the end:

  1. The call_args_list is a list of call objects, which looks like this [call("something")]. So the first [0] is returning the first call object.

  2. The second [0] returns the tuple of arguments for the call object. It will look like this ("something",).

  3. Third [0] returns the first argument that was given to logger in our case. So the final string will be only "something".

Upvotes: 2

Tadeck
Tadeck

Reputation: 137350

From the documentation (http://packages.python.org/testfixtures/logging.html):

To help with this, TestFixtures allows you to easily capture the output of calls to Python’s logging framework and make sure they were as expected. There are three different techniques, depending on the type of test you are writing.

  1. The context manager
  2. The decorator
  3. The manual usage

The examples are included in the documentation. The shortened version is below.

The context manager

>>> import logging
>>> from testfixtures import LogCapture
>>> with LogCapture() as l:
...     logger = logging.getLogger()
...     logger.info('a message')
...     logger.error('an error')

And after that you can check the logs for equality:

>>> l.check(
...     ('root', 'INFO', 'a message'),
...     ('root', 'ERROR', 'another error'),
...     )
Traceback (most recent call last):
 ...
AssertionError: Sequence not as expected:

same:
(('root', 'INFO', 'a message'),)

first:
(('root', 'ERROR', 'another error'),)

second:
(('root', 'ERROR', 'an error'),)

The decorator

Similar to the previous, but applied to specific function:

from testfixtures import log_capture

@log_capture()
def test_function(l):
    logger = logging.getLogger()
    logger.info('a message')
    logger.error('an error')

    l.check(
        ('root', 'INFO', 'a message'),
        ('root', 'ERROR', 'an error'),
        )

Manual usage

>>> from testfixtures import LogCapture
>>> l = LogCapture()

After which you can also "check" the logs:

>>> l.check(('root', 'INFO', 'a message'))
<...>

EDIT: To access specific logs and analyze them in a custom way, you can just iterate through l.records (where l is just LogCapture's instance) and access some properties of each of them (eg. msg contains message sent to logger, levelname contains codename of the level, and there are plenty other properties).

Upvotes: 7

Related Questions