Repository navigation
logging: capture a record once when a non-propagating logger starts propagating (#15064) - #15138
Open
RonnyPfannschmidt wants to merge 3 commits into
Open
RonnyPfannschmidt wants to merge 3 commits into
RonnyPfannschmidt wants to merge 3 commits into
Conversation
RonnyPfannschmidt
marked this pull request as ready for review
October 7, 2026 17:07
RonnyPfannschmidt
requested review from
bluetech and
nicoddemus
and removed request for
bluetech
October 7, 2026 17:08
…ropagating (pytest-dev#15064) catching_logs attached the capture handler itself to every logger that was non-propagating at enter. Once such a logger propagates again, the record reaches the handler on the logger and on root. Attach a stand-in instead, which decides at emit time, from the current propagate values up the chain, whether the walk still ends below root at a logger nothing else delivers on. Co-Authored-By: Claude Opus 5.5 via Claude Code <noreply@anthropic.com>
Ancestors of loggers that are non-propagating at enter now get a stand-in as well, so a record stopping at an ancestor that becomes non-propagating mid-test (e.g. from a sibling) is still captured. Loggers sharing one handlers list cannot tell their records apart, so such a list gets the pytest handler itself, as before pytest-dev#15064; with a stand-in per logger every record was captured twice. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_0183Jee4Yw5vPqSEfExPfgL9
Registering every short-lived stand-in in logging's global handler list dominated the cost of entering catching_logs once ancestors get one too. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_0183Jee4Yw5vPqSEfExPfgL9
RonnyPfannschmidt
force-pushed
the
fix-15064-propagation-stand-in
branch
from
October 9, 2026 05:11
328519c to
391300f
Compare
This branch has not been deployed
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Requested by Ronny · project thread
🤖 Written by Claude Opus 5.5 via Claude Code for the pytest maintainers; I prompted it, it did the work, I read it.
Fixes #15064.
Since #14375,
catching_logsattaches the capture handler to root and also directly to every logger that is non-propagating at enter. Once such a logger propagates again, a record reaches the handler on the logger and again on root.Change
propagateis true. It forwards to the capture handler only if that walk ends below root at a logger that nothing else delivers on. Otherwise root, or a stand-in further up, delivers the record. Because ancestors have stand-ins, a record that stops at an ancestor which became non-propagating mid-test (for example from a sibling logger) is still captured.handlerslist cannot tell their records apart, so such a list gets the capture handler itself, as on main. A stand-in per logger there would capture every record twice.handle(), notemit(), and takes no lock (lock = None, aslogging.NullHandlerdoes). It therefore cannot deadlock against the target handler's lock. It also skipsHandler.__init__, so it is not registered in logging's global handler list.Tests
12 new tests on public behaviour (
caplog, report sections, live log), acrosstesting/logging/test_fixture.pyandtest_reporting.py:handlerslist.Cost
CPython 3.13, medians of 3 runs (emit in ns per record, enter+exit in µs), end to end median of 5:
At realistic depths the difference is within noise. The visible cost is one stand-in visit, about 190 ns, per ancestor a propagating record passes on its way to root, so it grows with the depth of the logger tree below a non-propagating logger. An experiment that kept stand-ins on every logger, to also cover the remaining gap below, cost 1.4–1.5x on every emitted record, so this PR does not do that.
Behaviour notes and open questions
handlerslists keep main's behaviour, including its duplicate when one of those loggers starts propagating.logger.handlersnow shows the stand-in, not the capture handler. Socaplog.handler in logger.handlerschanges from True to False for non-propagating loggers. Filters or a formatter added to the stand-in are ignored. Should it honour filters too?LoggingPlugin.The first commit was verified on CPython 3.14 and 3.11, the follow-ups on 3.13. At the head commit the full suite passes on 3.14, and so does
pre-commit run -a.