[New-bugs-announce] [issue34999] Different behavior of copied loggers in 3.7
sebix
report at bugs.python.org
Tue Oct 16 11:39:27 EDT 2018
New submission from sebix <sebix+bugs.python.org at sebix.at>:
For the unittests of project I mock the function returning the logger. The code to tests can re-initialize the logger because of updated configuration (It's a deamon), so it needs to do that correctly and I test if it works. By mocking the function returning I can always control the loggers's and parameters and always return a copy of the same logger. This worked until 3.6 but does no longer work in 3.7 (I tested 3.7.1rc2).
Why do I copy it? Because if the tested program sets (for example) a different log level, that would affect my "master copy".
I created a minimal example splitted into two files, the code to test and the test itself.
The tested code:
------
def log(log_level):
pass
class Bot(object):
def __init__(self):
self.logger = None
self.__init_logger(logging_level='INFO')
self.logger.info('Initialized')
self.logger.handlers = [] # remove all existing handlers
self.__init_logger(logging_level='DEBUG')
self.logger.debug('test')
self.logger.info("Bot stopped.")
def __init_logger(self, logging_level):
self.logger = log(log_level=logging_level)
-----
And the test:
-----
import copy
import io
import logging
import unittest.mock as mock
from intelmq.bot import Bot
bot_id = 'test-bot'
log_stream = io.StringIO()
logger = logging.getLogger(bot_id)
logger.setLevel("INFO")
console_formatter = logging.Formatter('%(levelname)s - %(message)s')
console_handler = logging.StreamHandler(log_stream)
console_handler.setFormatter(console_formatter)
logger.addHandler(console_handler)
def mocked_log(log_level):
# Return a copy as the bot may modify the logger and we should always return the intial logger
logger_new = copy.copy(logger)
logger_new.setLevel(log_level)
return logger_new
with mock.patch('intelmq.bot.log', mocked_log):
bot = Bot()
loglines_buffer = log_stream.getvalue()
loglines = loglines_buffer.splitlines()
print(loglines_buffer)
print("INFO - Initialized" in loglines[0])
print('DEBUG - test' in loglines_buffer)
print("INFO - Bot stopped." in loglines[-1])
-----
Adapt the import of the "Bot" if you try to run it.
In Python 3.4-3.6 it gives:
-----
INFO - Initialized
DEBUG - test
INFO - Bot stopped.
True
True
True
-----
And in Python 3.7:
-------
INFO - Initialized
True
False
False
-------
The minimal code is also here: https://github.com/wagner-certat/intelmq/tree/minimal-1269
----------
components: Library (Lib)
messages: 327838
nosy: sebix
priority: normal
severity: normal
status: open
title: Different behavior of copied loggers in 3.7
versions: Python 3.7
_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue34999>
_______________________________________
More information about the New-bugs-announce
mailing list