CODEWITHSUNDEEP
pythonloggingpython-unittest
DaveA
DaveA

Reputation: 1287

Why is the python logger in unit testing not working after setLevel called

I have the following code in my unittest TestCase:

class StatsdLogHandler(logging.Handler):
    def emit(self, record):
        log_entry = self.format(record)
        statsd_client.incr(log_entry)

def setup_statsd_logging(logger, level=logging.WARNING):
    # set up statsd counts for logging
    statsd_format = "pegasus.logger.%(levelname)s.%(name)s"
    formatter = logging.Formatter(statsd_format)
    statsd_handler = StatsdLogHandler()
    statsd_handler.setFormatter(formatter)
    statsd_handler.setLevel(level)
    logger.addHandler(statsd_handler)

class TestLogging(unittest.TestCase):
    @mock.patch('.statsd_client')
    def test_logging_to_statsd(self, statsd_mock):
        """Make sure log calls go to statsd"""
        root_logger = logging.getLogger()
        setup_statsd_logging(root_logger)
        root_logger.setLevel(logging.DEBUG)
        root_logger.warning('warning')
        statsd_mock.incr.assert_called_with('pegasus.logger.WARNING.root')

However, when I run the TestLogging test case, I get

AssertionError: Expected call: incr(u'pegasus.logger.WARNING.root')

Not called

I would expect this call to be successful. Why is this happening?

Upvotes: 2

Views: 1381

Answers (1)

DaveA
DaveA

Reputation: 1287

When I debugged this behavior, I found that root_logger.manager.disable was set to the value of 30, meaning that all logging with a level of WARNING or lower was not being printed.

The logging Manager object isn't documented anywhere that I could easily find, but it is the object that describes and stores all the loggers, including the root logger. It is defined in code here. What I found was that there were calls elsewhere in the test cases to logging.disable(logging.WARNING). This sets the value of root_logger.manager.disable to 30. The manager disable level trumps the effective level of the logger (see this code).

By adding the line logging.disable(logging.NOTSET) to my test case at the beginning of the test case, I ensure that the logging manager disable property was set to the default value of 0, which caused my test cases to pass.

Upvotes: 2

Related Questions