Skip to content

--log-cli-level unexpectedly manipulates sys.stdout #10553

Open
@wouterdb

Description

Problem

This testcases manipulating sys.stdout produce different results, depending on whether --log-level-cli is set.
Using 'capsys' fixes this, but that doesn't help if the code under test is doing the manipulation of sys.stdout

It seems this is due to the code which suspends the output capture when logging.

I think this could be solved by tying the logging to 'sys.stdout' as it is when initializing (so it is insensitive to capture, instead of suspending capture), or to make the suspend/resume code more careful.

Work around

  1. surround the problematic testcase with caplog.at_level(logging.FATAL): to override capture

Minimal Example

import sys
import logging
from io import StringIO

def test_order_of_execution():
    saved_stdout = sys.stdout
    try:
        out = StringIO()
        sys.stdout = out
        logging.warning("Some Log")
        print("A", flush=True)
        output = out.getvalue().strip()
        assert output == "A"
    finally:
        sys.stdout = saved_stdout
 pytest test.py
============================= test session starts ==============================
platform linux -- Python 3.10.8, pytest-7.2.0, pluggy-1.0.0
rootdir: /home/wouter/.virtualenvs/tmp-73a7d956b0a674a
collected 1 item                                                               

test.py .                                                                [100%]

============================== 1 passed in 0.00s ===============================

pytest test.py --log-cli-level=INFO
============================= test session starts ==============================
platform linux -- Python 3.10.8, pytest-7.2.0, pluggy-1.0.0
rootdir: /home/wouter/.virtualenvs/tmp-73a7d956b0a674a
collected 1 item                                                               

test.py::test_order_of_execution 
-------------------------------- live log call ---------------------------------
WARNING  root:test.py:10 Some Log
FAILED                                                                   [100%]

=================================== FAILURES ===================================
___________________________ test_order_of_execution ____________________________

    def test_order_of_execution():
        saved_stdout = sys.stdout
        try:
            out = StringIO()
            sys.stdout = out
            logging.warning("Some Log")
            print("A", flush=True)
            output = out.getvalue().strip()
>           assert output == "A"
E           AssertionError: assert '' == 'A'
E             - A

test.py:13: AssertionError
----------------------------- Captured stdout call -----------------------------
A
------------------------------ Captured log call -------------------------------
WARNING  root:test.py:10 Some Log
=========================== short test summary info ============================
FAILED test.py::test_order_of_execution - AssertionError: assert '' == 'A'
============================== 1 failed in 0.01s ===============================

Pip List

pip list
Package        Version
-------------- -------
attrs          22.1.0
exceptiongroup 1.0.4
iniconfig      1.1.1
packaging      21.3
pip            22.3.1
pluggy         1.0.0
pyparsing      3.0.9
pytest         7.2.0
setuptools     65.5.1
tomli          2.0.1
wheel          0.38.4

Activity

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

Metadata

Assignees

No one assigned

    Labels

    plugin: capturerelated to the capture builtin pluginplugin: loggingrelated to the logging builtin plugin

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions