Why is caplog.text empty, even though the function I'm testing is logging?

Question

I'm trying to use pytest to test if my function is logging the expected text, such as addressed this question (the pyunit equivalent would be assertLogs). Following the pytest logging documentation, I am passing the caplog fixture to the tester. The documentation states:

Lastly all the logs sent to the logger during the test run are made available on the fixture in the form of both the logging.LogRecord instances and the final log text.

The module I'm testing is:

import logging
logger = logging.getLogger(__name__)

def foo():
    logger.info("Quinoa")

The tester is:

def test_foo(caplog):
    from mwe16 import foo
    foo()
    assert "Quinoa" in caplog.text

I would expect this test to pass. However, running the test with pytest test_mwe16.py shows a test failure due to caplog.text being empty:

============================= test session starts ==============================
platform linux -- Python 3.7.3, pytest-5.3.0, py-1.8.0, pluggy-0.13.0
rootdir: /tmp
plugins: mock-1.12.1, cov-2.8.1
collected 1 item

test_mwe16.py F                                                          [100%]

=================================== FAILURES ===================================
___________________________________ test_foo ___________________________________

caplog = <_pytest.logging.LogCaptureFixture object at 0x7fa86853e8d0>

    def test_foo(caplog):
        from mwe16 import foo
        foo()
>       assert "Quinoa" in caplog.text
E       AssertionError: assert 'Quinoa' in ''
E        +  where '' = <_pytest.logging.LogCaptureFixture object at 0x7fa86853e8d0>.text

test_mwe16.py:4: AssertionError
============================== 1 failed in 0.06s ===============================

Why is caplog.text empty despite foo() sending text to a logger? How do I use pytest such that caplog.text does capture the logged text, or otherwise verify that the text is being logged?

Answer 1

The documentation is unclear here. From trial and error, and notwithstanding the "all the logs sent to the logger during the test run are made available" text, it still only captures logs with certain log levels. To actually capture all logs, one needs to set the log level for captured log messages using caplog.set_level or the caplog.at_level context manager, so that the test module becomes:

import logging
def test_foo(caplog):
    from mwe16 import foo
    with caplog.at_level(logging.DEBUG):
        foo()
    assert "Quinoa" in caplog.text

Now, the test passes:

============================= test session starts ==============================
platform linux -- Python 3.7.3, pytest-5.3.0, py-1.8.0, pluggy-0.13.0
rootdir: /tmp
plugins: mock-1.12.1, cov-2.8.1
collected 1 item

test_mwe16.py .                                                          [100%]

============================== 1 passed in 0.04s ===============================

Answer 2

In the logger set up, please set logger.propagate=True

Answer 3

This is a limitation of Pytest, cf. the feature request. I've resorted to creating a fixture based on _pytest.logging.LogCaptureFixture with a context manager and using it instead of caplog.

Some code:

from _pytest.logging import LogCaptureHandler, _remove_ansi_escape_sequences


class CatchLogFixture:
"""Fixture to capture logs regardless of the Propagate flag. See
https://github.com/pytest-dev/pytest/issues/3697 for details.
"""

    @property
    def text(self) -> str:
        return _remove_ansi_escape_sequences(self.handler.stream.getvalue())

    @contextmanager
    def catch_logs(self, level: int, logger: logging.Logger) -> LogCaptureHandler:
        """Set the level for capturing of logs. After the end of the 'with' statement,
        the level is restored to its original value.
        """
        self.handler = LogCaptureHandler()
        orig_level = logger.level
        logger.setLevel(level)
        logger.addHandler(self.handler)
        try:
            yield self
        finally:
            logger.setLevel(orig_level)
            logger.removeHandler(self.handler)


@pytest.fixture
def capture_log():
    return CatchLogFixture().catch_logs