Testing logging output with pytest
Asked Answered
D

4

103

I am trying to write a test, using pytest, that would check that a specific function is writing out a warning to the log when needed. For example:

In module.py:

import logging
LOGGER = logging.getLogger(__name__)

def run_function():
    if something_bad_happens:
        LOGGER.warning('Something bad happened!')

In test_module.py:

import logging
from module import run_function

LOGGER = logging.getLogger(__name__)

def test_func():
    LOGGER.info('Testing now.')
    run_function()
    ~ somehow get the stdout/log of run_function() ~
    assert 'Something bad happened!' in output

I have seen that you can supposedly get the log or the stdout/stderr with pytest by passing capsys or caplog as an argument to the test, and then using either capsus.readouterr() or caplog.records to access the output.

However, when I try those methods, I only see "Testing now.", and not "Something bad happened!". It seems like the logging output that is happening within the call to run_function() is not accessible from test_func()?

The same thing happens if I try a more direct method, such as sys.stdout.getvalue(). Which is confusing, because run_function() is writing to the terminal, so I would think that would be accessible from stdout...?

Basically, does anyone know how I can access that 'Something bad happened!' from within test_func()?

Demount answered 2/11, 2018 at 20:17 Comment(1)
docs.pytest.org/en/latest/how-to/logging.htmlUnmeaning
D
73

I don't know why this didn't work when I tried it before, but this solution works for me now:

In test_module.py:

import logging
from module import run_function

LOGGER = logging.getLogger(__name__)

def test_func(caplog):
    LOGGER.info('Testing now.')
    run_function()
    assert 'Something bad happened!' in caplog.text
Demount answered 5/11, 2018 at 20:40 Comment(6)
I think it might work for Python 3.5, but not 3.6 or 3.7.Demount
Maybe I don't get what you're trying but I'm using python3.7 and my caplog.text contained what I expected it to contain.Sheep
I am doing nearly the same thing and it is not working - meaning that caplog.text is empty. The only difference is that run_function() is method in a pytest.fixture in my case, but that shouldnt matter, right?Nur
@Sheep It's not working for me. See this question.Hazan
As mentioned correctly in @ssoler's answer , in your logger setup, make sure is logger.propagate=TrueCauseuse
What if my run_function() takes an argument record? How should I pass the record? @DemountDiplomacy
R
70

test_module.py should look like this:

import logging
from module import run_function

LOGGER = logging.getLogger(__name__)

def test_func(caplog):
    with caplog.at_level(logging.WARNING):
        run_function()
    assert 'Something bad happened!' in caplog.text

or, alternatively:

import logging
from module import run_function

LOGGER = logging.getLogger(__name__)

def test_func(caplog):
    caplog.set_level(logging.WARNING)
    run_function()
    assert 'Something bad happened!' in caplog.text

Documentation for pytest capture logging is here

Reportorial answered 4/3, 2020 at 9:12 Comment(1)
As mentioned correctly in @ssoler's answer , in your logger setup, make sure is logger.propagate=TrueCauseuse
P
10

In your logging set up, check propagate is set to True, otherwise caplog handler is not able to see the logging message.

Potence answered 19/10, 2020 at 9:8 Comment(0)
S
0

I had the same issue. I just explicitly mentioned the name of the module instead of name inside the test function And set the propagate attribute to True.

Note: module should be the directory in which you have scripts to be test.

def test_func():

    LOGGER = logging.getLogger("module")
    LOGGER.propagate = True
    run_function()
    ~ somehow get the stdout/log of run_function() ~
    assert 'Something bad happened!' in output
Selinaselinda answered 25/11, 2022 at 9:45 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.