Capfd doesn't capture logging StreamHandler

[KaiaSage]

This is essentially the capfd version of #10486 capsys. I globally initialize and configure logging to write to a StreamHandler(sys.stdout). Then, I write to that logger within a pytest test that uses capfd as a fixture. That message isn't caught by capfd, and either gets caught by the global fd-redirection, or prints to console if run with -s.

I find it extra odd since it seems like redirecting stdout at a file-descriptor level should make it impossible for anything to output, right?

For full context, I ran into this trying to make a context-manager that can suppress all stdout output (SO question), including direct writes to fd's. Pytest's capfd seems like something close to this, but still has edge cases like this.

import sys
import os
import logging
import pytest

logging.basicConfig()
_log = logging.getLogger()
_log.setLevel(logging.DEBUG)
_log.handlers = [logging.StreamHandler(sys.stdout)]

def test_read_stdout(capfd):
    sys.stdout.write("hello from stdout!\n")
    captured = capfd.readouterr()
    assert captured.out == 'hello from stdout!\n' #  passes

def test_read_log(capfd):
    _log.debug("hello from logger!")
    captured = capfd.readouterr()
    assert captured.out == 'hello from logger!\n' #  fails

This gives the output:

$ python -m pytest -s .\test_logger_capfd.py
===================================== test session starts =====================================
platform win32 -- Python 3.11.9, pytest-8.4.2, pluggy-1.6.0
rootdir: ~
configfile: pyproject.toml
collected 2 items                                                                               

test_logger_capfd.py .hello from logger!

F

========================================== FAILURES =====================================
________________________________________ test_read_log ________________________________________ 

capfd = <_pytest.capture.CaptureFixture object at 0x00000167734F64D0>

    def test_read_log(capfd: pytest.CaptureFixture):
        _log.debug("hello from logger!\n")
        captured = capfd.readouterr()
>       assert captured.out == 'hello from logger!\n'
E       AssertionError: assert '' == 'hello from logger!\n'
E
E         - hello from logger!

test_logger_capfd.py:19: AssertionError
-------------------------------------- Captured log call -------------------------------------- 
DEBUG    root:test_logger_capfd.py:17 hello from logger!
=================================== short test summary info =================================== 
FAILED test_logger_capfd.py::test_read_log - AssertionError: assert '' == 'hello from logger!\n'================================= 1 failed, 1 passed in 0.14s ================================= 

Note how hello from logger! gets printed to stdout in the middle of the tests. (If I ran without -s, it would get captured by the global output capture, so this is a bit of an artificial issue)

Here's an example using _pytest.capture.FDCapture(1) directly:

import sys
import logging
import _pytest.capture

# Required, otherwise we get a logging error.
_pytest.capture._windowsconsoleio_workaround(sys.stdout)

logging.basicConfig()
_log = logging.getLogger()
_log.setLevel(logging.DEBUG)
_log.handlers = [logging.StreamHandler(sys.stdout)]

cap = _pytest.capture.FDCapture(1)
cap.start()
_log.debug("hello from logger!")
captured = cap.snap()
cap.done()
print("=== Capture: ===")
print(captured)
print("================")

Which outputs

hello from logger!
=== Capture: ===

================

Removing the _windowsconsoleio_workaround() gives:

--- Logging error ---
Traceback (most recent call last):
  File "C:\Python311\Lib\logging\__init__.py", line 1113, in emit
    stream.write(msg + self.terminator)
OSError: [WinError 6] The handle is invalid
Call stack:
  File "test_logger_capfd.py", line 14, in <module>
    _log.debug("hello from logger!")
Message: 'hello from logger!'
Arguments: ()
hello from logger!
=== Capture: ===

================

System details:

Win10 Version 10.0.19045.6093
Python 3.11.9 (tags/v3.11.9:de54cf5, Apr  2 2024, 10:12:12) [MSC v.1938 64 bit (AMD64)] on win32
Fresh venv (`python -m venv`) on Powershell. 
$ pip freeze  
colorama==0.4.6
iniconfig==2.1.0
packaging==25.0
pluggy==1.6.0
Pygments==2.19.2
pytest==8.4.2

Related:

• Logging StreamHandler fails when set up in fixture with capsys #10486
• Can't capture output of logger in stdout #13402

[RonnyPfannschmidt]

please use caplog to deal with logging - pytest formally is unable to correctly and logging handling with user provided logging configruation as we cannot know what we are allowed to do and/or how incorrectly the user uses the logging objects

in particular stream handlers when used on stdio are always incorrect