I am trying to test that a warning is logged in a unit test. It seems that the following test should fail:
import logging
import unittest
LOG_FORMAT = '%(levelname)-10s %(asctime)s: %(message)s'
def set_up_logger(app_name, level=logging.INFO, file="test.log"):
formatter = logging.Formatter(LOG_FORMAT)
log = logging.getLogger(app_name)
# The next line lets the test pass
log.setLevel(level)
return log
logger = set_up_logger(__name__)
class TestLogging(unittest.TestCase):
def test_logging(self):
with self.assertLogs(level=logging.WARNING):
logger.info('foo')
However, it passes with python 3.8.5.
If I remove the log.setLevel(level)
line, the test fails, like expected. If I replace the logger.info
line with pass
, then the test also fails as expected.
Why does setting the level on the logger let the test incorrectly pass?
I'm not completely sure if this behavior is wanted, as it is a bit unexpected. To fix the test, you have to pass the logger:
The reason why it does work that way is that in the
assertLogs
context manager, the log level of the passed logger is temporarily set to the passed level, and if no logging has happened on exit, the test will fail.If you don't pass the logger, the root logger is used instead. If you don't set the level on your logger, it will use the level of the root logger, which during the call is set to
WARNING
by the context manager - so nothing will be logged, and the test fails as expected.If you do set the log level, this log level will be used regardless of the root logger level, so logging will be done and the test passes (which is not what I would have expected, either).
Update:
There is now a Python issue that describes the problem, which is now fixed in master and Python 3.10.