Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Python 3 Unit Testing - Assert Logger NOT called

I know how to assert that a log message was generated, but I can't seem to figure out how to assert that a log message was not generated. Here's the unit test I have now (sanitized). Note that XYZ class takes the logger as a param, and test_check_unexpected_keys_found passes as expected.

import unittest
import logging

class TestXYZ(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        cls.test_logger = logging.getLogger('test_logger')
        cls.test_logger.addHandler(logging.NullHandler())

    def test_check_unexpected_keys_found(self):
        test_dict = {
            'unexpected': 0,
            'expected1': 1,
            'expected2': 2,
        }
        xyz = XYZ(self.test_logger)
        with self.assertLogs('test_logger', level='WARNING'):
            xyz._check_unexpected_keys(test_dict)

    def test_check_unexpected_keys_none(self):
        test_dict = {
            'expected1': 1,
            'expected2': 2,
        }
        xyz = XYZ(self.test_logger)
        xyz._check_unexpected_keys(test_dict)
        # assert that 'test_logger' was not called ??

I tried using unittest.patch like so:

with patch('TestXYZ.test_logger.warning') as mock_logwarn:
    xyz._check_unexpected_keys(test_dict)
    self.assertFalse(mock_logwarn.called)

But I get

ImportError: No module named 'TestXYZ'
I tried some variants on that as well, but got nowhere.

Anyone know how to handle this?

like image 649
Jim Wood Avatar asked Mar 08 '16 15:03

Jim Wood


2 Answers

A new assertNoLogs method is added in Python 3.10.
Until then, here is a workaround: add a dummy log, and then assert it is the only log.

with self.assertLogs(logger, logging.WARN) as cm:
    # We want to assert there are no warnings, but the 'assertLogs' method does not support that.
    # Therefore, we are adding a dummy warning, and then we will assert it is the only warning.
    logger.warn("Dummy warning")
    # DO STUFF

self.assertEqual(
    ["Dummy warning"],
    cm.output,
)

If you need to do this is more than once, then to avoid duplication you can do the following. Assuming you have a base class from which all your test classes inherit, override assertLogs in that class as follows:

class TestBase(TestCase):
    def assertLogs(self, logger_to_watch=None, level=None) -> 'CustomAssertLogsContext':
        """
        This method overrides the one in `unittest.case.TestCase`, and has the same behavior, except for not causing a failure when there are no log messages.
        The point is to allow asserting there are no logs.
        Get rid of this once this is resolved: https://github.com/python/cpython/pull/18067
        """
        return CustomAssertLogsContext(self, logger_to_watch, level)

class CustomAssertLogsContext(_AssertLogsContext):    
    def __exit__(self, exc_type, exc_val, exc_tb) -> Optional[bool]:
        # Fool the original exit method to think there is at least one record, to avoid causing a failure
        self.watcher.records.append("DUMMY")
        result = super().__exit__(exc_type, exc_val, exc_tb)
        self.watcher.records.pop()
        return result
like image 63
Joe Avatar answered Oct 12 '22 14:10

Joe


Building on Joe's answer, here is an implementation of an assertNoLogs(...) routine, as a mixin class, which can be used until a formal version is released in Python 3.10:

import logging
import unittest

def assertNoLogs(self, logger, level):
    """ functions as a context manager.  To be introduced in python 3.10
    """

    class AssertNoLogsContext(unittest.TestCase):
        def __init__(self, logger, level):
            self.logger = logger
            self.level = level
            self.context = self.assertLogs(logger, level)

        def __enter__(self):
            """ enter self.assertLogs as context manager, and log something
            """
            self.initial_logmsg = "sole message"
            self.cm = self.context.__enter__()
            self.logger.log(self.level, self.initial_logmsg)
            return self.cm

        def __exit__(self, exc_type, exc_val, exc_tb):
            """ cleanup logs, and then check nothing extra was logged """
            # assertLogs.__exit__ should never fail because of initial msg
            self.context.__exit__(exc_type, exc_val, exc_tb)
            if len(self.cm.output) > 1:
                """ override any exception passed to __exit__ """
                self.context._raiseFailure(
                    "logs of level {} or higher triggered on : {}"
                    .format(logging.getLevelName(self.level),
                            self.logger.name, self.cm.output[1:]))

    return AssertNoLogsContext(logger, level)

To use it, just start your test case with

class Testxxx(unittest.TestCase, AssertNoLog):
    ...

The following test case shows how it works:

import unittest
import logging
class TestAssertNL(unittest.TestCase, AssertNoLog):

    def test_assert_no_logs(self):
        """ check it works"""
        log = logging.getLogger()
        with self.assertNoLogs(log, logging.INFO):
            _a = 1
            log.debug("not an info message")

    @unittest.expectedFailure
    def test2_assert_no_logs(self):
        """ check it records failures """
        log = logging.getLogger()
        with self.assertNoLogs(log, logging.INFO):
            _a = 1
            log.info("an info message")

    def test3_assert_no_logs_exception_handling(self):
        log = logging.getLogger()
        with self.assertRaises(TypeError):
            with self.assertNoLogs(log, logging.INFO):
                raise TypeError('this is not unexpected')

    def test4_assert_no_logs_exception_handling(self):
        """ the exception gets reported as the failure.
        This matches the behaviour of assertLogs(...) """
        log = logging.getLogger()
        with self.assertRaises(AssertionError):
            with self.assertNoLogs(log, logging.INFO):
                log.info("an info message")
                raise TypeError('this is not unexpected')
like image 45
simonltwick Avatar answered Oct 12 '22 15:10

simonltwick