Preventing logging file IO during test execution

Question

I want to test a class that does logging when initialised and save logs to local file. Therefore, I'm mocking the logging piece of logic in order to avoid file IO when testing. This is pseudo-code representing how I've structured the tests

class TestClass:
    def test_1(self, monkeypatch):
        monkeypatch.setattr('dotted.path.to.logger', lambda *args: '')
        assert True

    def test_2(self, monkeypatch):
        monkeypatch.setattr('dotted.path.to.logger', lambda *args: '')
        assert True

    def test_3(self, monkeypatch):
        monkeypatch.setattr('dotted.path.to.logger', lambda *args: '')
        assert True

Note how monkeypatch.setattr() is copy-pasted across all methods. Considering that:

we know a priori that all call methods will need to be monkey-patched in the same way, and
one might forget to monkeypatch new methods,

I think that monkey-patching should be abstracted at class level. How do we abstract monkeypatching at class level? I would expect the solution to be something similar to what follows:

import pytest
class TestClass:
    pytest.monkeypatch.setattr('dotted.path.to.logger', lambda *args: '')

    def test_1(self):
        assert True

    def test_2(self):
        assert True

    def test_3(self):
        assert True

This is where loggers are configured.

def initialise_logger(session_dir: str):
    """If missing, initialise folder "log" to store .log files. Verbosity:
    CRITICAL, ERROR, WARNING, INFO, DEBUG, NOTSET."""
    os.makedirs(session_dir, exist_ok=True)
    logging.basicConfig(filename=os.path.join(session_dir, 'session.log'),
                        filemode='a',
                        level=logging.INFO,
                        datefmt='%Y-%m-%d %H:%M:%S',
                        format='|'.join(['(%(threadName)s)',
                                         '%(asctime)s.%(msecs)03d',
                                         '%(levelname)s',
                                         '%(filename)s:%(lineno)d',
                                         '%(message)s']))

    # Adopt NYSE time zone (aka EST aka UTC -0500 aka US/Eastern). Source:
    # https://stackoverflow.com/questions/32402502/how-to-change-the-time-zone-in-python-logging
    logging.Formatter.converter = lambda *args: get_now().timetuple()

    # Set verbosity in console. Verbosity above logging level is ignored.
    console = logging.StreamHandler()
    console.setLevel(logging.ERROR)
    console.setFormatter(logging.Formatter('|'.join(['(%(threadName)s)',
                                                     '%(asctime)s',
                                                     '%(levelname)s',
                                                     '%(filename)s:%(lineno)d',
                                                     '%(message)s'])))
    logger = logging.getLogger()
    logger.addHandler(console)


class TwsApp:
    def __init__(self):
        initialise_logger(<directory>)

Please edit your post to add the section of the code where loggers are configured. Ping me once you've done so, and I'll add an answer. — wim, Feb 20 '18 at 20:58
@wim Updated question with code. I've ended up using a python.fixture with scope='class' and using MonkeyPatch() form _pytest.monkeypatch import MonkeyPatch. I've posted my solution, but I'm happy to accept your if it's more elegant! — MLguy, Feb 21 '18 at 09:53
You were on the right track, but you are not really using the monkeypatch fixture correctly (it should not be instantiated manually like that). I've added an answer. — wim, Feb 21 '18 at 19:33

score 1 · Answer 1 · answered Feb 21 '18 at 19:32

1

A cleaner implementation:

# conftest.py
import pytest

@pytest.fixture(autouse=True)
def dont_configure_logging(monkeypatch):
    monkeypatch.setattr('twsapp.client.initialise_logger', lambda x: None)

You don't need to mark individual tests with the fixture, nor inject it, this will be applied regardless.

Inject the caplog fixture if you need to assert on records logged. Note that you don't need to configure loggers in order to make logging assertions - the caplog fixture will inject the necessary handlers it needs in order to work correctly. If you want to customise the logging format used for tests, do that in pytest.ini or under a [tool:pytest] section of setup.cfg.

answered Feb 21 '18 at 19:32

wim

338,267
99
616
750

I see your point, but I think that there could exist situations where `autouse=True` is sub-optimal with respect to `scope=class`, so I tend to think that your answer is relying on the (too much) strong assumption that we always want to monkeypatch all classes. How to we monkeypatch a single class? The last paragraph is very informative. – MLguy Feb 27 '18 at 15:20
@MLguy Ideally, you should move away from class-based thinking when working with pytest. If you don't want to patch all classes, then you can use multiple `conftest.py` files, or even just define the fixture directly in the .py module with just the tests that need it. Grouping tests into classes is no longer needed nor desirable, when the module/filesystem already provides some sensible structure. – wim May 01 '18 at 00:22
Using classes improve readability because they allow to wrap tests according to the tested class. So if `module.py` defines classes `A` and `B`, then `test_module.y` will define `TestA` and `TestB`. If `module.py` defines a single class, then I might agree that test classes are superfluous. See EDIT in my answer to see what I'm currently using (which has been inspired by your answer with great readability). – MLguy May 01 '18 at 10:00
I see your edit but I still think it's over-complicating things. It is not necessary to patch out logger *calls* during test (logger.error, logger.warning, logger.debug, logger.info). You only need to patch out logging *configuration*. Pytest will by default capture all the logging anyway, so suppressing the logger calls is superfluous. Using test classes are perhaps just a matter of preference (I see it as old-fashioned xunit style, and in pytest it's just adding an extra layer of unnecessary nesting, but opinions differ). – wim May 01 '18 at 15:39

MLguy · Answer 2 · 2018-05-01T09:53:21.050

In practice, I've put the fixture in /test/conftest.py. In fact, pytest automatically load fixture from files named conftest.py and can be applied in any module during the testing session.

from _pytest.monkeypatch import MonkeyPatch


@pytest.fixture(scope="class")
def suppress_logger(request):
    """Source: https://github.com/pytest-dev/pytest/issues/363"""
    # BEFORE running the test.
    monkeypatch = MonkeyPatch()
    # Provide dotted path to method or function to be mocked.
    monkeypatch.setattr('twsapp.client.initialise_logger', lambda x: None)
    # DURING the test.
    yield monkeypatch
    # AFTER running the test.
    monkeypatch.undo()



import pytest
@pytest.mark.usefixtures("suppress_logger")
class TestClass:
    def test_1(self):
        assert True

    def test_2(self):
        assert True

    def test_3(self):
        assert True

EDIT: I ended up using the following in conftest.py

@pytest.fixture(autouse=True)
def suppress_logger(mocker, request):
    if 'no_suppress_logging' not in request.keywords:
        # If not decorated with: @pytest.mark.no_suppress_logging_error
        mocker.patch('logging.error')
        mocker.patch('logging.warning')
        mocker.patch('logging.debug')
        mocker.patch('logging.info')

Preventing logging file IO during test execution

2 Answers2