← 输入框|github.com|刷新
Skip to content

gh-160936: Make logging setLevel() and disable() cost O(cached loggers) - #160937

Open
Ar-maan05 wants to merge 1 commit into
python:mainfrom
Ar-maan05:logging-setlevel-cache
Open

Ar-maan05 wants to merge 1 commit into
python:mainfrom
Ar-maan05:logging-setlevel-cache

Conversation

@Ar-maan05

@Ar-maan05 Ar-maan05 commented Oct 30, 2026 •

Copy link
Copy Markdown
Contributor

Logger.setLevel() and logging.disable() call Manager._clear_cache(), which walks every logger in loggerDict to clear its isEnabledFor cache, whether or not it has cached anything. Setting levels on N loggers one at a time is O(N^2):

              before     after
1000 loggers  0.392 s    0.007 s
2000 loggers  1.562 s    0.014 s
4000 loggers  6.255 s    0.028 s
8000 loggers  24.787 s   0.057 s

(debug build of main, script from the issue)

The manager now keeps a WeakSet of loggers that have populated their cache. isEnabledFor adds itself on the cache-miss path, inside the lock it already takes, so the hot cache-hit path is untouched. _clear_cache only visits those loggers, and still only clears ones that are registered in loggerDict under their name, same rule as before.

test_logging passes; the existing test_caching covers the invalidation behaviour.

…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.
@eendebakpt

Copy link
Copy Markdown
Contributor

As mentioned on the issue, is this a real-world problem? There are some issues with the current approach:

  1. Loggers that fail the loggerDict.get(logger.name) is logger check (e.g. created directly with logging.Logger(name)) are never discarded, so every setLevel() keeps visiting them. With 4000 such loggers alive, setLevel() goes from ~1 µs on main to ~1 ms.
  2. Per-item discard() leaves dummy slots in the set, and re-adding the same logger reuses them, so the table never shrinks after one bulk invalidation. After 4000 cached loggers are cleared once, every later setLevel() stays 5-10x slower than on main.

Both go away by clearing all loggers in the set unconditionally and then emptying the set:

        with _lock:
            for logger in self._cached_loggers:
                logger._cache.clear()
            self._cached_loggers.clear()
            self.root._cache.clear()
Some more details Clearing a superset of what `main` clears is safe, and as a bonus it fixes a stale cache for loggers not in `loggerDict` (`Logger("x").setLevel(ERROR)` currently leaves `isEnabledFor(DEBUG)` True). Please add a test for that and for `_cached_loggers` being empty after `setLevel()`.

Reproducer for both:

import logging, time

lg = logging.getLogger("one")

def us_per_setlevel():
    t0 = time.perf_counter()
    for _ in range(2000):
        lg.setLevel(logging.INFO)
        lg.isEnabledFor(logging.DEBUG)
    return (time.perf_counter() - t0) / 2000 * 1e6

print(f"baseline:              {us_per_setlevel():7.1f} us")

registered = [logging.getLogger(f"app.mod{i}") for i in range(4000)]
for l in registered:
    l.isEnabledFor(logging.DEBUG)
lg.setLevel(logging.INFO)
print(f"after bulk invalidate: {us_per_setlevel():7.1f} us")   # (2)

logging.root.manager.loggerDict.clear()
standalone = [logging.Logger(f"s{i}") for i in range(4000)]
for l in standalone:
    l.isEnabledFor(logging.DEBUG)
print(f"4000 standalone alive: {us_per_setlevel():7.1f} us")   # (1)

Another approach would be to check the cache with a global counter.

_cache_version = 0                      # module global, bumped in _clear_cache

    def isEnabledFor(self, level):
        if self.disabled:
            return False
        if self._cache_version == _cache_version:
            return level >= self._threshold
        with _lock:
            threshold = max(self.getEffectiveLevel(), self.manager.disable + 1)
            self._threshold = threshold
            self._cache_version = _cache_version
        return level >= threshold

That might also help with gh-155106 (the PR now is neutral for contention)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants