Duplicate log capture when an initially non-propagating logger enables propagation #15064

I ran into a case where one logging call is captured twice if a logger is non-propagating when pytest starts capture and
enables propagation during the test.

Here is a minimal reproducer:

import logging


logger = logging.getLogger("example")
logger.propagate = False


def test_log_is_captured_once(caplog):
    logger.propagate = True
    logger.warning("only once")

    assert caplog.messages == ["only once"]

On current main, caplog.messages is:

['only once', 'only once']

I reconfirmed this on pytest-dev/pytest main at 6a0de9be56365e75ff30d75cee9654739ca95f97.

I can also reproduce the duplicate in captured failure-report sections, --log-cli-level output, and --log-file
output.

Environment

• macOS 26.7 (Apple silicon)
• Python 3.13.13
• pytest 9.2.0.dev0

PyYAML==6.0.3
Pygments==2.21.0
argcomplete==3.7.2
attrs==26.1.0
certifi==2026.7.22
charset-normalizer==3.5.1
coverage==7.16.1
elementpath==5.1.4
execnet==2.1.2
hypothesis==6.168.0
idna==3.20
iniconfig==2.3.0
mock==5.2.0
numpy==2.5.3
packaging==26.3
pexpect==4.9.0
pluggy==1.6.0
ptyprocess==0.7.0
pytest-xdist==3.8.0
pytest==9.2.0.dev0
requests==2.34.2
setuptools==84.0.0
sortedcontainers==2.4.0
urllib3==2.8.0
xmlschema==4.3.2

Why it happens

#14375 fixed #3697 by attaching pytest's active logging handlers to root and to every logger which is non-propagating
when capture begins. That is necessary for a record which cannot reach root.

In the example above, the same handler is therefore attached to both example and root. After example.propagate
becomes true, one Logger.callHandlers walk invokes that handler at example and then invokes the same object again at
root.

The inverse limitation is unchanged: a logger which becomes non-propagating after capture starts may still be missed
because it was not part of the entry snapshot.

Possible scoped fix

I have a local prototype which leaves the real pytest handlers exactly where they are today. A private mixin on pytest's
capture, file, and live-output handlers suppresses later occurrences of that same handler during one standard
Logger.callHandlers invocation.

The important part is the scope: this does not deduplicate records globally or by message/record identity. It identifies
the exact active callHandlers frame, processes the first occurrence normally, and suppresses only later occurrences
from that same frame. Reusing one LogRecord in a later dispatch, reentrant logging, and overlapping threads remain
separate dispatches.

Direct Handler.handle() calls and custom Logger.callHandlers methods keep their native behavior. If the
implementation cannot prove that the caller is the standard dispatcher, it fails open and handles the record normally.

This keeps handler identity, filters, levels, formatters, locking, replacement records, and logger.handlers behavior
in the stdlib path. I tried forwarding handlers first (including one shared proxy per logger), but those designs had
subtle filter/identity semantics and much higher setup and cleanup complexity.

Design question

The tradeoff is that the prototype uses sys._getframe(1), compares its code object with
logging.Logger.callHandlers.__code__, and reads self, c, and record from that frame. It works on the supported
CPython versions and PyPy in local testing, and audit-hook denial falls back to native handling, but it is still an
implementation-sensitive dependency.

PR #10303 approached this family of problems by intercepting Logger.propagate and was closed because the mechanism was
considered too complex/invasive. I have a draft PR ready so the implementation can be reviewed concretely, but I would
like maintainer feedback on two points: is the narrower frame-based approach acceptable here, and is the False -> True
transition behavior something pytest wants to support?

There are two other limits I would document in a PR:

• pruning assumes one active Python f_back chain per OS thread, so native greenlet-style stack switching can fail open
  to a duplicate; and
• after an abnormal nested dispatch on a worker, exact frame identity can keep one returned frame per abandoned
  reentrant level alive until that worker next uses the handler or exits. Sequential failures do not accumulate, but a
  retained record payload can be large.

Clearing another worker's pending frame during context teardown caused a real race and duplicate in an earlier
prototype, so the local implementation keeps route ownership thread-local and treats this bounded retention as an
explicit tradeoff rather than hiding it.

Local evidence

The local patch has focused regressions for all four parent/child propagation states, the mixed child/parent transition,
levels, normal and replacement filters, caplog/report/CLI/file output, record reuse, reentrancy, threads, a true
mid-dispatch fork, custom dispatchers, denied frame access, abandoned routes, concurrent activation-refcount updates,
and cleanup.

These checks were completed against base 7d90c44cca8f2e37dc0ab3d9643a4672a8a3f7f9. The one newer upstream commit does
not touch logging code or tests; I will refresh the final PR evidence after rebasing the draft implementation onto
current main.

• CPython 3.10–3.15 and PyPy logging matrix: all passed (123 tests on 3.12–3.15; 122 plus one expected skip on 3.10,
  3.11, and PyPy)
• free-threaded CPython 3.13.13 logging: 123 passed with the GIL confirmed disabled before and after the run
• Python 3.13 coverage/lsof: 123 passed; logging.py 96%; lsof clean
• full Python 3.13 suite: 4,640 passed, 51 skipped, 15 xfailed, 5 xpassed
• focused stability: 20 fresh processes, 580/580 aggregate tests passed
• Ruff, formatting, mypy, C901 <= 10, PLR0915, and diff check: clean
• temporary mutation harness: 26/26 selected non-equivalent mutants killed, including removal of the activation and
  deactivation counter locks
• lifecycle/thread stress: 1,000 collectible lifecycle cycles; 10,000 sequential abandoned routes bounded and pruned;
  16,000 unique threaded records captured exactly once
• 21-pair HEAD/candidate benchmarks: maximum workload regression 1.868%; maximum emission ratio 1.29631x; 1,000-logger
  context setup 0.238 ms

For this validation pass, the host had the project environments but no tox executable. The matrix, coverage, and lsof
commands therefore ran directly through the provisioned .tox interpreters with PYTHONPATH=src; the tox
packaging/setup phase was not exercised. The separate free-threaded run used an installed CPython 3.13.13t build and
confirmed sys._is_gil_enabled() == False.

I would include the raw benchmark method and results in the PR rather than only reporting the favorable paths.

Related work

• Handling of loggers with propagate=False #3697
• logging: also capture logs from non-propagating loggers #14375
• Automatically attach to non-propagating loggers #10303
• pytest 9.1.0 add handlers to non-propagated loggers #14603
• downstream example: mcp(test[middleware]): Fix caplog double-capture on pytest 9.1.0 tmux-python/libtmux-mcp#83

I repeated open/closed issue and PR searches on 2026-09-19 using both behavior and implementation terms. I also checked
every pytest logging item created or updated since 2026-09-18. The only new logging item was #15062, an unrelated
set_log_path() documentation PR; I did not find a duplicate of this report.