unittest.assertLogs passes unexpectedly

[mrbean-bremen]

BPO	41943
Nosy	@vsajip, @miss-islington, @iritkatriel, @mrbean-bremen
PRs	bpo-41943: Fix bug where assertLogs doesn't correctly filter messages… #22565

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2021-04-16.23:13:51.345>
created_at = <Date 2020-10-05.14:39:59.981>
labels = ['type-bug', 'library', '3.10']
title = 'unittest.assertLogs passes unexpectedly'
updated_at = <Date 2021-04-16.23:13:51.344>
user = 'https://github.com/mrbean-bremen'

bugs.python.org fields:

activity = <Date 2021-04-16.23:13:51.344>
actor = 'iritkatriel'
assignee = 'none'
closed = True
closed_date = <Date 2021-04-16.23:13:51.345>
closer = 'iritkatriel'
components = ['Library (Lib)']
creation = <Date 2020-10-05.14:39:59.981>
creator = 'mrbean-bremen'
dependencies = []
files = []
hgrepos = []
issue_num = 41943
keywords = ['patch']
message_count = 2.0
messages = ['378035', '380246']
nosy_count = 4.0
nosy_names = ['vinay.sajip', 'miss-islington', 'iritkatriel', 'mrbean-bremen']
pr_nums = ['22565']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue41943'
versions = ['Python 3.10']

[mrbean-bremen]

Related to https://bugs.python.org/issue41898, creating a new issue after the discussion with Irit Katriel on StackOverflow (https://stackoverflow.com/a/64142338/12480730).

Consider the following:

import logging
import unittest

logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)


class TestLogging(unittest.TestCase):
    def test_logging(self):
        with self.assertLogs(level=logging.WARNING):
            logger.info('foo')

From the docs:
The test passes if at least one message emitted inside the with block matches the logger and level conditions, otherwise it fails.

This means that this test should fail (nothing has been logged at warning level or above), but it passes.

The reason 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 no logger is passed into the call, the temporary log level is set in the root level. If any descendant logger has it's own log level set (as in this example to INFO), this logger will still log at it's own level, and the test will pass.

This will always happen on the condition that a descendent of the passed logger has it's own log level set that is smaller than the asserted level, and it does some logging at this level inside the assertLog context manager.

[miss-islington]

New changeset 6fdfcec by Irit Katriel in branch 'master':
bpo-41943: Fix bug where assertLogs doesn't correctly filter messages… (GH-22565)
6fdfcec