How Should I Verify A Log Message When Testing Python Code Under Nose?

June 29, 2023 Post a Comment

I'm trying to write a simple unit test that will verify that, under a certain condition, a class in my application will log an error via the standard logging API. I can't work out

Solution 1:

From python 3.4 on, the standard unittest library offers a new test assertion context manager, assertLogs. From the docs:

with self.assertLogs('foo', level='INFO') as cm:
    logging.getLogger('foo').info('first message')
    logging.getLogger('foo.bar').error('second message')
    self.assertEqual(cm.output, ['INFO:foo:first message',
                                 'ERROR:foo.bar:second message'])

Solution 2:

Fortunately this is not something that you have to write yourself; the testfixtures package provides a context manager that captures all logging output that occurs in the body of the with statement. You can find the package here:

http://pypi.python.org/pypi/testfixtures

And here are its docs about how to test logging:

http://testfixtures.readthedocs.org/en/latest/logging.html

Solution 3:

UPDATE: No longer any need for the answer below. Use the built-in Python way instead!

This answer extends the work done in https://stackoverflow.com/a/1049375/1286628. The handler is largely the same (the constructor is more idiomatic, using super). Further, I add a demonstration of how to use the handler with the standard library's unittest.

classMockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs.

    Messages are available from an instance's ``messages`` dict, in order, indexed by
    a lowercase log level string (e.g., 'debug', 'info', etc.).
    """def__init__(self, *args, **kwargs):
        self.messages = {'debug': [], 'info': [], 'warning': [], 'error': [],
                         'critical': []}
        super(MockLoggingHandler, self).__init__(*args, **kwargs)

    defemit(self, record):
        "Store a message from ``record`` in the instance's ``messages`` dict."try:
            self.messages[record.levelname.lower()].append(record.getMessage())
        except Exception:
            self.handleError(record)

    defreset(self):
        self.acquire()
        try:
            for message_list in self.messages.values():
                message_list.clear()
        finally:
            self.release()

Then you can use the handler in a standard-library unittest.TestCase like so:

import unittest
import logging
import foo

classTestFoo(unittest.TestCase):

    @classmethoddefsetUpClass(cls):
        super(TestFoo, cls).setUpClass()
        # Assuming you follow Python's logging module's documentation's# recommendation about naming your module's logs after the module's# __name__,the following getLogger call should fetch the same logger# you use in the foo module
        foo_log = logging.getLogger(foo.__name__)
        cls._foo_log_handler = MockLoggingHandler(level='DEBUG')
        foo_log.addHandler(cls._foo_log_handler)
        cls.foo_log_messages = cls._foo_log_handler.messages

    defsetUp(self):
        super(TestFoo, self).setUp()
        self._foo_log_handler.reset() # So each test is independentdeftest_foo_objects_fromble_nicely(self):
        # Do a bunch of frombling with foo objects# Now check that they've logged 5 frombling messages at the INFO level
        self.assertEqual(len(self.foo_log_messages['info']), 5)
        for info_message in self.foo_log_messages['info']:
            self.assertIn('fromble', info_message)

Solution 4:

I used to mock loggers, but in this situation I found best to use logging handlers, so I wrote this one based on the document suggested by jkp(now dead, but cached on Internet Archive)

classMockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs."""def__init__(self, *args, **kwargs):
        self.reset()
        logging.Handler.__init__(self, *args, **kwargs)

    defemit(self, record):
        self.messages[record.levelname.lower()].append(record.getMessage())

    defreset(self):
        self.messages = {
            'debug': [],
            'info': [],
            'warning': [],
            'error': [],
            'critical': [],
        }

Solution 5:

Brandon's answer:

pip install testfixtures

snippet:

import logging
from testfixtures import LogCapture
logger = logging.getLogger('')


with LogCapture() as logs:
    # my awesome code
    logger.error('My code logged an error')
assert'My code logged an error'instr(logs)

Note: the above does not conflict with calling nosetests and getting the output of logCapture plugin of the tool

Python Channel