Registering a root logger during a test leads to empty caplog

[a-recknagel]

This issue was already discovered in #11011, but their solution of "just don't configure a root logger in your test" doesn't work for me.

Repro:

import logging.config


# unit under test
def setup_logging(loglevel):
    logging.config.dictConfig(
        {
            "version": 1,
            "loggers": {"": {"level": loglevel}}
        }
    )
    
# I don't actually want to have this line here, I'd rather have it as part of the test's setup
setup_logging("INFO")


def test_logging_setup_default(caplog):
    log = logging.getLogger("my_project")

    log.info("foo")
    log.debug("bar")

    assert "foo" in caplog.text      # works
    assert "bar" not in caplog.text  # works


def test_logging_setup_debug(caplog):
    setup_logging("DEBUG")
    log = logging.getLogger("my_project")

    log.info("foo")
    log.debug("bar")

    assert "foo" in caplog.text  # doesn't work, `caplog.text` is an empty string
    assert "bar" in caplog.text

Is there a way to re-run the logic caplog uses to hook onto the root logger? At least, that's what I assume is going wrong here, I didn't actually dig into the code.

[mishaga]

Hello, @a-recknagel
I faced the same issue and solved it! 🚀
The problem is not in caplog, but in logging
If you call logging.config.dictConfig twice, you wouldn't see any of your logs not only in caplog, but in console as well 😞

So my suggestions would be these:

• cache setup_logging function (to not call it twice or even more times)
• get rid of parameters in this function (for caching purposes, of course)
• and yes, don't configure a root logger in your test

To do so you might need to pip install pytest-env / poetry add pytest-env and configure your pytest

# sample for pyproject.toml
[tool.pytest_env]
UNIT_TESTS = "true"

# sample for pytest.ini
[pytest]
env =
    UNIT_TESTS=true

And then use UNIT_TESTS variable in your code like this, for instance:

import os
from functools import cache


@cache
def setup_logging():
    if os.getenv('UNIT_TESTS'):
        return
    ...

[RonnyPfannschmidt]

Caplog has tools for per tests level choices

Alternatively actually clean up after yourself

[a-recknagel]

Alternatively actually clean up after yourself

I'm trying, my issue is that the call to logging.config.dictConfig has to be part of the test-code itself, and not the test setup. Maybe my example wasn't clear enough, I'm not trying to set the level in the test. Anyway, I solved the issue to a degree that is Good Enough For Me, and will share it now in case anyone stumbles over this thread:

The issue
When caplog is used in a test function, it runs some setup code which adds logging handlers (two of these, to be exact) to the root logger. It needs those in order to be able to pick up emitted logs. If the test code reconfigures the logging engine in a way that forces a re-instantiation of the root logger, those two handlers are lost, and caplog becomes useless. Note that I'm not reconfiguring logging in order to influence the caplog fixture (as Ronny pointed out, caplog has its own tools for that), I'm reconfiguring because that's what my test-unit does, and I want to test if it does that correctly.

My solution
Wrap the configuration-function (in this example logging.config.dictConfig) with code that re-attaches pytest handlers (I wrote it as a decorator retain_pytest_handlers) in case the root-logger lost them and attach it to all tests that need it (I think autouse makes sense, so I used it for keep_pytest_handlers_during_dict_config).

# unit
import logging.config

def setup_logging(loglevel):
    logging.config.dictConfig(
        {
            "version": 1,
            "root": {"level": loglevel}
        }
    )

# test code
import pytest
import logging.config

def retain_pytest_handlers(f):
    def wrapper(*args, **kwargs):
        pytest_handlers = [
            handler
            for handler in logging.root.handlers
            if handler.__module__ == "_pytest.logging"
        ]
        ret = f(*args, **kwargs)
        for handler in pytest_handlers:
            if handler not in logging.root.handlers:
                logging.root.addHandler(handler)
        return ret

    return wrapper

@pytest.fixture(autouse=True)
def keep_pytest_handlers_during_dict_config(monkeypatch):
    monkeypatch.setattr(
        logging.config,
        "dictConfig",
        retain_pytest_handlers(logging.config.dictConfig)
    )

@pytest.mark.parametrize("level, n_logs", [
    ("DEBUG", 4), 
    ("INFO", 3), 
    ("WARNING", 2), 
    ("ERROR", 1) 
])
def test_setup_logging(level, n_logs, caplog):
    setup_logging(level)
    
    logging.log(logging.DEBUG, "foo")
    logging.log(logging.INFO, "bar")
    logging.log(logging.WARNING, "baz")
    logging.log(logging.ERROR, "qux")
    
    assert len(caplog.records) == n_logs

If keep_pytest_handlers_during_dict_config is not enabled, len(caplog.records) is always 0.