Structlog configuration is not restored to its previous state after test

[olii]

I have noticed this unexpected behavior. I managed to create a single test file that illustrates what is wrong:

import structlog

logger: structlog.stdlib.BoundLogger = structlog.get_logger('some logger')

def test_first():
    structlog.configure(
        processors=[
            structlog.stdlib.filter_by_level,
            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
        ],
        context_class=dict,
        logger_factory=structlog.stdlib.LoggerFactory(),
        wrapper_class=structlog.stdlib.BoundLogger,
        cache_logger_on_first_use=False,
    )
    logger.warning('test')

def test_second(log):
    logger.warning('test')
    assert log.has('test')

def test_third():
    logger.warning('test')

Each test passes when executed separately, yet the last test fails if they are executed together. The reason is that here we reset the configuration: https://github.com/wimglenn/pytest-structlog/blob/c31f23ffeeef36e1dccb4f52ae56eb37e08c16f7/pytest_structlog.py#L76 The default configuration sets the logger_factory to PrintLoggerFactory. Once the test is finished the whole configuration should be restored but only processors are restored. Restored processors are incompatible with the PrintLogger object. Thus the last test fails with:

AttributeError: 'PrintLogger' object has no attribute 'isEnabledFor'

I think we shouldn't reset the configuration globally. Is there a reason to do so? The code in the structlog distribution replaces only processors: https://github.com/hynek/structlog/blob/main/src/structlog/testing.py#L50

The code with more context: https://github.com/wimglenn/pytest-structlog/blob/c31f23ffeeef36e1dccb4f52ae56eb37e08c16f7/pytest_structlog.py#L76-L83

[wimglenn]

Hmm, reset_defaults was added in v0.3 to address an issue related to cache_logger_on_first_use - does v0.2 work as expected for you? See https://github.com/wimglenn/pytest-structlog/issues/10 for the details.

I wonder if we can address both this issue and the other one without regressing .. will take a look

[olii]

I forgot to link this page that recommends disabling the caching in tests: https://www.structlog.org/en/stable/testing.html

capture_logs() relies on changing the configuration. If you have cache_logger_on_first_use enabled for performance, any cached loggers will not be affected, so it’s recommended you do not enable it during tests.

I didn't downgrade the library but commented out structlog.reset_defaults() and the test now works as expected.

[wimglenn]

Yep, I got it, but the issue was that if cache_logger_on_first_use was set in some library code at import time (e.g. in a Django settings module), then some cached loggers can hang around and mess with the test suite. To reset defaults entirely is a bit of a sledgehammer for removing all global mutable state- but perhaps something more nuanced is needed here.

[olii]

I did some experiments. There is no way of resetting the cached logger after first use even if you use reset_defaults(). There are some hacky ways of replacing the processors in cached instances but I consider them too brittle.

[wimglenn]

Thanks for the reproducer. I've added it to the test suite in https://github.com/wimglenn/pytest-structlog/pull/17

This should be resolved in v0.4