Issue 37258: Logging cache not cleared properly when setting level
Issue37258
Created on 2019-06-12 21:48 by David Wang, last changed 2022-04-11 14:59 by admin. This issue is now closed.
| Files | ||||
|---|---|---|---|---|
| File name | Uploaded | Description | Edit | |
| test.py | David Wang, 2019-06-12 21:48 | |||
| Pull Requests | |||
|---|---|---|---|
| URL | Status | Linked | Edit |
| PR 14229 | merged | vinay.sajip, 2019-06-19 10:26 | |
| PR 14230 | merged | miss-islington, 2019-06-19 10:47 | |
| PR 14231 | merged | miss-islington, 2019-06-19 10:47 | |
| Messages (6) | |||
|---|---|---|---|
| msg345414 - (view) | Author: David Wang (David Wang) | Date: 2019-06-12 21:48 | |
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 ``` self.level = _checkLevel(level) self.manager._clear_cache() self._cache.clear() ``` Note the following: - I made sure the subclass has a handler attached so setLevel() should work - This bug does not occur if you use logging.getLogger(). This is because logging.getLogger() returns the root logger, and the cache clear specifically targets the root logger's cache to be cleared. It occurs when the logger is specifically subclassed from logging.getLoggerClass() - The cache was added in Python 3.7, so this bug is specific to this version of python. |
|||
| msg345490 - (view) | Author: Karthikeyan Singaravelan (xtreak) * ![]() |
Date: 2019-06-13 10:01 | |
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 #20037 |
|||
| msg346036 - (view) | Author: Vinay Sajip (vinay.sajip) * ![]() |
Date: 2019-06-19 10:12 | |
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. |
|||
| msg346037 - (view) | Author: Vinay Sajip (vinay.sajip) * ![]() |
Date: 2019-06-19 10:47 | |
New changeset 015000165373f8db263ef5bc682f02d74e5782ac by Vinay Sajip in branch 'master': bpo-37258: Not a bug, but added a unit test and updated documentation. (GH-14229) https://github.com/python/cpython/commit/015000165373f8db263ef5bc682f02d74e5782ac |
|||
| msg346046 - (view) | Author: Vinay Sajip (vinay.sajip) * ![]() |
Date: 2019-06-19 13:46 | |
New changeset 9eb4b2c8a3387ea901dad793e8d5586880a5968e 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) https://github.com/python/cpython/commit/9eb4b2c8a3387ea901dad793e8d5586880a5968e |
|||
| msg346047 - (view) | Author: Vinay Sajip (vinay.sajip) * ![]() |
Date: 2019-06-19 13:46 | |
New changeset 95ff622028b4f5d2eefbff557eadbb08fbcd42b1 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) https://github.com/python/cpython/commit/95ff622028b4f5d2eefbff557eadbb08fbcd42b1 |
|||
| History | |||
|---|---|---|---|
| Date | User | Action | Args |
| 2022-04-11 14:59:16 | admin | set | github: 81439 |
| 2019-06-19 16:06:11 | vinay.sajip | set | stage: resolved |
| 2019-06-19 16:05:48 | vinay.sajip | set | stage: resolved -> (no value) |
| 2019-06-19 13:47:45 | vinay.sajip | set | status: open -> closed stage: patch review -> resolved |
| 2019-06-19 13:46:59 | vinay.sajip | set | messages: + msg346047 |
| 2019-06-19 13:46:43 | vinay.sajip | set | messages: + msg346046 |
| 2019-06-19 10:47:33 | miss-islington | set | pull_requests: + pull_request14067 |
| 2019-06-19 10:47:20 | miss-islington | set | pull_requests: + pull_request14066 |
| 2019-06-19 10:47:17 | vinay.sajip | set | messages: + msg346037 |
| 2019-06-19 10:26:07 | vinay.sajip | set | keywords:
+ patch stage: patch review pull_requests: + pull_request14065 |
| 2019-06-19 10:12:42 | vinay.sajip | set | resolution: not a bug messages: + msg346036 |
| 2019-06-14 05:21:05 | rhettinger | set | assignee: vinay.sajip |
| 2019-06-13 10:01:27 | xtreak | set | nosy:
+ xtreak messages:
+ msg345490 |
| 2019-06-13 00:33:50 | xtreak | set | nosy:
+ vinay.sajip |
| 2019-06-12 21:48:28 | David Wang | create | |
