From d60e39c47815fd25f18c914cd131715af3e7034a Mon Sep 17 00:00:00 2001 From: Armaan Sandhu Date: Thu, 29 Oct 2026 20:28:22 -0400 Subject: [PATCH 1/4] gh-160936: Make logging setLevel() and disable() cost O(cached loggers) Manager._clear_cache() walked every logger in loggerDict on each setLevel() or disable() call, so configuring N loggers one at a time was quadratic. Track loggers that have populated their isEnabledFor cache in a WeakSet and clear only those. --- Lib/logging/__init__.py | 10 ++++++++-- .../2026-10-29-20-30-00.gh-issue-160936.lgCach.rst | 1 + 2 files changed, 9 insertions(+), 2 deletions(-) create mode 100644 Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 15d5ac281791839..01e94143268089e 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -1356,6 +1356,8 @@ def __init__(self, rootnode): self.disable = 0 self.emittedNoHandlerWarning = False self.loggerDict = {} + # Loggers whose isEnabledFor cache may be populated; see _clear_cache. + self._cached_loggers = weakref.WeakSet() self.loggerClass = None self.logRecordFactory = None @@ -1471,9 +1473,12 @@ def _clear_cache(self): """ with _lock: - for logger in self.loggerDict.values(): - if isinstance(logger, Logger): + # Only loggers that have populated a cache are visited, so + # setLevel() costs O(loggers with cached results), not O(loggers). + for logger in list(self._cached_loggers): + if self.loggerDict.get(logger.name) is logger: logger._cache.clear() + self._cached_loggers.discard(logger) self.root._cache.clear() #--------------------------------------------------------------------------- @@ -1799,6 +1804,7 @@ def isEnabledFor(self, level): return self._cache[level] except KeyError: with _lock: + self.manager._cached_loggers.add(self) if self.manager.disable >= level: is_enabled = self._cache[level] = False else: diff --git a/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst b/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst new file mode 100644 index 000000000000000..b079fb011600958 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst @@ -0,0 +1 @@ +Speed up :meth:`logging.Logger.setLevel` and :func:`logging.disable` when there are many loggers: only loggers that have cached results are now cleared, instead of every logger. From b586b0b1aacca9ace560cbcca0e55da43808b841 Mon Sep 17 00:00:00 2001 From: Armaan Sandhu Date: Sun, 1 Nov 2026 17:16:59 -0500 Subject: [PATCH 2/4] gh-160936: Clear all cached loggers unconditionally in _clear_cache Skipping loggers that are not in loggerDict kept them in the set forever, and per-item discard left the set's table large after a bulk clear, so later setLevel() calls stayed slower than on main. Clear every tracked logger and empty the set instead. This also fixes a stale isEnabledFor cache on loggers that are not registered with the manager. --- Lib/logging/__init__.py | 7 +++---- Lib/test/test_logging.py | 19 +++++++++++++++++++ ...-10-29-20-30-00.gh-issue-160936.lgCach.rst | 5 ++++- 3 files changed, 26 insertions(+), 5 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 01e94143268089e..2675c487afab43f 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -1475,10 +1475,9 @@ def _clear_cache(self): with _lock: # Only loggers that have populated a cache are visited, so # setLevel() costs O(loggers with cached results), not O(loggers). - for logger in list(self._cached_loggers): - if self.loggerDict.get(logger.name) is logger: - logger._cache.clear() - self._cached_loggers.discard(logger) + for logger in self._cached_loggers: + logger._cache.clear() + self._cached_loggers.clear() self.root._cache.clear() #--------------------------------------------------------------------------- diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index c45d8ea7901b80d..c6523ed4eee5d93 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -6398,6 +6398,25 @@ def test_pickling(self): unpickled = pickle.loads(s) self.assertIs(unpickled, logger) + def test_caching_unregistered_logger(self): + # A logger that is not in loggerDict must not keep a stale cache. + logger = logging.Logger("unregistered") + logger.setLevel(logging.DEBUG) + self.assertTrue(logger.isEnabledFor(logging.DEBUG)) + logger.setLevel(logging.ERROR) + self.assertEqual(logger._cache, {}) + self.assertFalse(logger.isEnabledFor(logging.DEBUG)) + + def test_clear_cache_empties_cached_loggers(self): + manager = logging.root.manager + registered = logging.getLogger("cached.registered") + unregistered = logging.Logger("cached.unregistered") + for logger in (registered, unregistered): + logger.isEnabledFor(logging.DEBUG) + self.assertIn(logger, manager._cached_loggers) + registered.setLevel(logging.INFO) + self.assertEqual(len(manager._cached_loggers), 0) + def test_caching(self): root = self.root_logger logger1 = logging.getLogger("abc") diff --git a/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst b/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst index b079fb011600958..888e9cfa88c5295 100644 --- a/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst +++ b/Misc/NEWS.d/next/Library/2026-10-29-20-30-00.gh-issue-160936.lgCach.rst @@ -1 +1,4 @@ -Speed up :meth:`logging.Logger.setLevel` and :func:`logging.disable` when there are many loggers: only loggers that have cached results are now cleared, instead of every logger. +Speed up :meth:`logging.Logger.setLevel` and :func:`logging.disable` when +there are many loggers: only loggers that have cached results are now cleared, +instead of every logger. This also clears the cache of loggers that are not +registered with the manager, which could previously keep a stale result. From 593b3565cf0ae72199cc45a645c71921eae0d5e9 Mon Sep 17 00:00:00 2001 From: Armaan Sandhu Date: Sun, 1 Nov 2026 18:18:56 -0500 Subject: [PATCH 3/4] gh-160936: Check cache state before and after in the new logging tests --- Lib/test/test_logging.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index c6523ed4eee5d93..0c98e4e6a40d9f7 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -6401,21 +6401,32 @@ def test_pickling(self): def test_caching_unregistered_logger(self): # A logger that is not in loggerDict must not keep a stale cache. logger = logging.Logger("unregistered") + self.assertEqual(logger._cache, {}) logger.setLevel(logging.DEBUG) + self.assertEqual(logger._cache, {}) self.assertTrue(logger.isEnabledFor(logging.DEBUG)) + self.assertEqual(logger._cache, {logging.DEBUG: True}) logger.setLevel(logging.ERROR) self.assertEqual(logger._cache, {}) self.assertFalse(logger.isEnabledFor(logging.DEBUG)) + self.assertEqual(logger._cache, {logging.DEBUG: False}) def test_clear_cache_empties_cached_loggers(self): manager = logging.root.manager registered = logging.getLogger("cached.registered") unregistered = logging.Logger("cached.unregistered") + # Start from a known state: other tests may have cached results. + manager._clear_cache() + self.assertEqual(len(manager._cached_loggers), 0) for logger in (registered, unregistered): logger.isEnabledFor(logging.DEBUG) self.assertIn(logger, manager._cached_loggers) + self.assertEqual(len(manager._cached_loggers), 2) registered.setLevel(logging.INFO) self.assertEqual(len(manager._cached_loggers), 0) + # A later cache miss starts tracking the logger again. + registered.isEnabledFor(logging.DEBUG) + self.assertEqual(list(manager._cached_loggers), [registered]) def test_caching(self): root = self.root_logger From 1edc2b1603e66ed191eea64383ea526180a29c62 Mon Sep 17 00:00:00 2001 From: Armaan Sandhu Date: Sun, 1 Nov 2026 18:23:31 -0500 Subject: [PATCH 4/4] gh-160936: Clear the logger cache after the new logging tests --- Lib/test/test_logging.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 0c98e4e6a40d9f7..abd3b21ef5e9b58 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -6400,6 +6400,7 @@ def test_pickling(self): def test_caching_unregistered_logger(self): # A logger that is not in loggerDict must not keep a stale cache. + self.addCleanup(logging.root.manager._clear_cache) logger = logging.Logger("unregistered") self.assertEqual(logger._cache, {}) logger.setLevel(logging.DEBUG) @@ -6413,6 +6414,7 @@ def test_caching_unregistered_logger(self): def test_clear_cache_empties_cached_loggers(self): manager = logging.root.manager + self.addCleanup(manager._clear_cache) registered = logging.getLogger("cached.registered") unregistered = logging.Logger("cached.unregistered") # Start from a known state: other tests may have cached results.