[Python] Assert a logger writes to stdout

I'm trying to assert the fact that my loggers writes to stdout, but I can't get it to work. I ran the logger in a python file to make sure it outputs something in the standard output.

So far, I can assert with pytest that the message is logged:

import logging
import sys

import pytest

STDOUT = sys.stdout


@pytest.fixture
def setup_logging():
logger = logging.getLogger("test")
stdout_handler = logging.StreamHandler(STDOUT)
formatter = logging.Formatter("%(message)s")
stdout_handler.setFormatter(formatter)

def set_verbose(verbose: bool):
if verbose:
logger.setLevel(logging.DEBUG)
logger.handlers.clear()
logger.addHandler(stdout_handler)
else:
logger.setLevel(logging.CRITICAL)
logger.removeHandler(stdout_handler)

return logger, set_verbose


def test_set_verbose_log(caplog, setup_logging):
logger, set_verbose = setup_logging

set_verbose(True)
logger.info("test-2-")
assert "test-2-" in caplog.text

set_verbose(False)
logger.info("test-3-")
assert "test-3-" not in caplog.text

set_verbose(True)
logger.info("test-4-")
assert "test-4-" in caplog.text

set_verbose(False)
logger.info("test-5-")
assert "test-5-" not in caplog.text


def test_set_verbose_sys(capsys, setup_logging):
logger, set_verbose = setup_logging

set_verbose(True)
logger.info("test-6-")
assert "test-6-" in capsys.readouterr().out

set_verbose(False)
logger.info("test-7-")
assert "test-7-" not in capsys.readouterr().out

set_verbose(True)
logger.info("test-8-")
assert "test-8-" in capsys.readouterr().out

set_verbose(False)
logger.info("test-9-")
assert "test-9-" in capsys.readouterr().out


def test_set_verbose_fd(capfd, setup_logging):
logger, set_verbose = setup_logging

set_verbose(True)
logger.info("test-10-")
assert "test-10-" in capfd.readouterr().out

set_verbose(False)
logger.info("test-11-")
assert "test-11-" not in capfd.readouterr().out


and the pytest output is

tests/test_test.py .FF [100%]


tests/test_test.py .FF [100%]

====================================================================== FAILURES ======================================================================
________________________________________________________________ test_set_verbose_sys ________________________________________________________________

capsys = <_pytest.capture.CaptureFixture object at 0x106a6c590>
setup_logging = (<Logger test (DEBUG)>, <function setup_logging.<locals>.set_verbose at 0x106a80ea0>)

def test_set_verbose_sys(capsys, setup_logging):
logger, set_verbose = setup_logging

set_verbose(True)
logger.info("test-6-")
> assert "test-6-" in capsys.readouterr().out
E AssertionError: assert 'test-6-' in ''
E + where '' = CaptureResult(out='', err='').out
E + where CaptureResult(out='', err='') = readouterr()
E + where readouterr = <_pytest.capture.CaptureFixture object at 0x106a6c590>.readouterr

tests/test_test.py:53: AssertionError
---------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------
test-6-
----------------------------------------------------------------- Captured log call ------------------------------------------------------------------
INFO test:test_test.py:52 test-6-
________________________________________________________________ test_set_verbose_fd _________________________________________________________________

capfd = <_pytest.capture.CaptureFixture object at 0x106a4cb90>
setup_logging = (<Logger test (DEBUG)>, <function setup_logging.<locals>.set_verbose at 0x106aa42c0>)

def test_set_verbose_fd(capfd, setup_logging):
logger, set_verbose = setup_logging

set_verbose(True)
logger.info("test-10-")
> assert "test-10-" in capfd.readouterr().out
E AssertionError: assert 'test-10-' in ''
E + where '' = CaptureResult(out='', err='').out
E + where CaptureResult(out='', err='') = readouterr()
E + where readouterr = <_pytest.capture.CaptureFixture object at 0x106a4cb90>.readouterr

tests/test_test.py:73: AssertionError
---------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------
test-10-
----------------------------------------------------------------- Captured log call ------------------------------------------------------------------
INFO test:test_test.py:72 test-10-
============================================================== short test summary info ===============================================================
FAILED tests/test_test.py::test_set_verbose_sys - AssertionError: assert 'test-6-' in ''
FAILED tests/test_test.py::test_set_verbose_fd - AssertionError: assert 'test-10-' in ''
============================================================ 2 failed, 1 passed in 0.05s =============================================================


but when I try to run (approximately) the same thing in a file, I can see test-2- being outputted in the standard output.

import logging
import sys

stdout_handler = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter("%(message)s")
stdout_handler.setFormatter(formatter)
logger = logging.getLogger("test")
logger.addHandler(stdout_handler)


def set_verbose(verbose: bool):
if verbose:
logger.setLevel(logging.DEBUG)
if not logger.hasHandlers():
logger.addHandler(stdout_handler)
else:
logger.setLevel(logging.CRITICAL)
logger.removeHandler(stdout_handler)


logger.info("test-1-")
set_verbose(True)
logger.info("test-2-")
set_verbose(False)
logger.info("test-3-")


Thank you for your time.

Continue reading...