Repository navigation
Logging cache not cleared properly when setting level #81439
Description
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 = 'https://github.com/vsajip'
closed_at = <Date 2019-06-19.13:47:45.769>
created_at = <Date 2019-06-12.21:48:28.353>
labels = ['type-bug', '3.8', '3.9', 'invalid', '3.7', 'library']
title = 'Logging cache not cleared properly when setting level'
updated_at = <Date 2019-06-19.16:06:11.017>
user = 'https://bugs.python.org/DavidWang'bugs.python.org fields:
activity = <Date 2019-06-19.16:06:11.017>
actor = 'vinay.sajip'
assignee = 'vinay.sajip'
closed = True
closed_date = <Date 2019-06-19.13:47:45.769>
closer = 'vinay.sajip'
components = ['Library (Lib)']
creation = <Date 2019-06-12.21:48:28.353>
creator = 'David Wang'
dependencies = []
files = ['48416']
hgrepos = []
issue_num = 37258
keywords = ['patch']
message_count = 6.0
messages = ['345414', '345490', '346036', '346037', '346046', '346047']
nosy_count = 3.0
nosy_names = ['vinay.sajip', 'xtreak', 'David Wang']
pr_nums = ['14229', '14230', '14231']
priority = 'normal'
resolution = 'not a bug'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue37258'
versions = ['Python 3.7', 'Python 3.8', 'Python 3.9']
Activity
DavidWang commentedon Jun 12, 2019
If you call setLevel() on a subclass of logging.Logger, it does not reset the cache for that logger. This mean that if you make some logging calls, then call setLevel(), the logger still acts like it still has its old level. See the attached python file for a reference.
Currently, the user has to call logger._cache.clear() to manually clear the cache after calling setLevel(). To fix this in Python, we would have to change Logger.setLevel() in /logging/init.py to have the following code
Note the following:
tirkarthi commentedon Jun 13, 2019
A unittest patch for this issue. This occurs in master and 3.8 too.
diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py
index 50148dc2f2..30fd9ee37a 100644
--- a/Lib/test/test_logging.py
+++ b/Lib/test/test_logging.py
@@ -4172,6 +4172,27 @@ class ModuleLevelMiscTest(BaseTest):
logging.setLoggerClass(logging.Logger)
self.assertEqual(logging.getLoggerClass(), logging.Logger)
+ def test_subclass_logger_cache(self):
+
+ class MyLogger(logging.getLoggerClass()):
+ pass
+
+ logger = MyLogger('test')
+ stream = io.StringIO()
+ h = logging.StreamHandler(stream)
+ logger.addHandler(h)
+
+ logger.setLevel(logging.DEBUG)
+ logger.debug("hello")
+ self.assertEqual(stream.getvalue().strip(), "hello")
+
+ stream.truncate(0)
+ stream.seek(0)
+
+ logger.setLevel(logging.INFO)
+ logger.debug("hello")
+ self.assertEqual(stream.getvalue(), "")
+
@support.requires_type_collecting
def test_logging_at_shutdown(self):
# Issue bpo-20037
vsajip commentedon Jun 19, 2019
This is not actually a bug, but happens because the logger is instantiated directly, rather than through logging.getLogger(...). Because of the direct instantiation, the logger cache isn't tracked via setLevel() - because the logger doesn't end up in logging.manager.loggerDict.
However, I will incorporate Karthikeyan's test (modified to avoid direct instantiation), and update the documentation to strengthen the information to avoid direct instantiation of loggers.
vsajip commentedon Jun 19, 2019
New changeset 0150001 by Vinay Sajip in branch 'master':
bpo-37258: Not a bug, but added a unit test and updated documentation. (GH-14229)
0150001
vsajip commentedon Jun 19, 2019
New changeset 9eb4b2c by Vinay Sajip (Miss Islington (bot)) in branch '3.7':
bpo-37258: Not a bug, but added a unit test and updated documentation. (GH-14229) (GH-14231)
9eb4b2c
vsajip commentedon Jun 19, 2019
New changeset 95ff622 by Vinay Sajip (Miss Islington (bot)) in branch '3.8':
bpo-37258: Not a bug, but added a unit test and updated documentation. (GH-14229) (GH-14230)
95ff622