loguru: Pytest's caplog fixture doesn't seem to work

Summary

Pytest’s caplog fixture is a critical part of testing. I’d love to move to loguru, but loguru doesn’t seem to work with caplog.

I’m not sure if this is user error (perhaps it’s documented somewhere? I haven’t been able to find it.), if it is some design oversight/choice, or if the problem is actually on pytest’s end.

Expected Result

Users should be able to use loguru as a drop-in replacement for the stdlib logging package and have tests that use the caplog fixture still work.

Actual Result

Drop-in replacement causes tests that use the caplog pytest fixture to fail.

Steps to Reproduce

Base test file

# test_demo.py
import pytest
import logging
logger = logging.getLogger()
logger.addHandler(logging.StreamHandler())
# from loguru import logger

def some_func(a, b):
    if a < 1:
        logger.warning("Oh no!")
    return a + b

def test_some_func_logs_warning(caplog):
    assert some_func(-1, 2) == 1
    assert "Oh no!" in caplog.text

if __name__ == "__main__":
    some_func(-1, 1)
    print("end")

Without Loguru:

$ python test_demo.py
Oh no!
end
(.venv) Previous Dir: /home/dthor
09:59:56 dthor@Thorium /home/dthor/temp/loguru
$ pytest
========================== test session starts ==========================
platform linux -- Python 3.6.7, pytest-4.3.0, py-1.8.0, pluggy-0.8.1
rootdir: /home/dthor/temp/loguru, inifile:
collected 1 item

test_demo.py .                                                    [100%]

======================= 1 passed in 0.03 seconds ========================

With Loguru:

Adjust test_demo.py by commenting out stdlib logging and uncommenting loguru:

...
# import logging
# logger = logging.getLogger()
# logger.addHandler(logging.StreamHandler())
from loguru import logger
...
$ python test_demo.py
2019-02-22 10:02:35.551 | WARNING  | __main__:some_func:9 - Oh no!
end
(.venv) Previous Dir: /home/dthor
10:02:35 dthor@Thorium /home/dthor/temp/loguru
$ pytest
========================== test session starts ==========================
platform linux -- Python 3.6.7, pytest-4.3.0, py-1.8.0, pluggy-0.8.1
rootdir: /home/dthor/temp/loguru, inifile:
collected 1 item

test_demo.py F                                                    [100%]

=============================== FAILURES ================================
______________________ test_some_func_logs_warning ______________________

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

    def test_some_func_logs_warning(caplog):
        assert some_func(-1, 2) == 1
>       assert "Oh no!" in caplog.text
E       AssertionError: assert 'Oh no!' in ''
E        +  where '' = <_pytest.logging.LogCaptureFixture object at 0x7f8e8b620438>.text

test_demo.py:14: AssertionError
------------------------- Captured stderr call --------------------------
2019-02-22 10:02:37.708 | WARNING  | test_demo:some_func:9 - Oh no!
======================= 1 failed in 0.20 seconds ========================

Version information

$ python --version
Python 3.6.7
(.venv) Previous Dir: /home/dthor
10:10:03 dthor@Thorium /home/dthor/temp/loguru
$ pip list
Package                Version
---------------------- -----------
ansimarkup             1.4.0
atomicwrites           1.3.0
attrs                  18.2.0
better-exceptions-fork 0.2.1.post6
colorama               0.4.1
loguru                 0.2.5
more-itertools         6.0.0
pip                    19.0.3
pkg-resources          0.0.0
pluggy                 0.8.1
py                     1.8.0
Pygments               2.3.1
pytest                 4.3.0
setuptools             40.8.0
six                    1.12.0
(.venv) Previous Dir: /home/dthor
10:10:07 dthor@Thorium /home/dthor/temp/loguru
$ uname -a
Linux Thorium 4.4.0-17763-Microsoft #253-Microsoft Mon Dec 31 17:49:00 PST 2018 x86_64 x86_64 x86_64 GNU/Linux
(.venv) Previous Dir: /home/dthor
10:11:33 dthor@Thorium /home/dthor/temp/loguru
$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 18.04.2 LTS
Release:        18.04
Codename:       bionic

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 1
  • Comments: 31 (19 by maintainers)

Most upvoted comments

Please, note the documentation has been updated. The recommended way to integrate Loguru with pytest is to override the caplog fixture this way:

@pytest.fixture
def caplog(caplog):
    handler_id = logger.add(caplog.handler, format="{message}")
    yield caplog
    logger.remove(handler_id)

Using PropagateHandler could result in dead-lock if inadvertently combined with InterceptHandler see #474.

Thank you all for code samples, they’re incredibly useful. I just want to share my own, in case any of you find it useful:

# conftest.py
import logging

import pytest
from loguru import logger

@pytest.fixture
def caplog(caplog):
    """
    override and wrap the caplog fixture with one of our own
    """
    logger.remove() # remove default handler, if it exists
    logger.enable("") # enable all logs from all modules
    logging.addLevelName(5, "TRACE") # tell python logging how to interpret TRACE logs
    class PropogateHandler(logging.Handler):
        def emit(self, record):
            logging.getLogger(record.name).handle(record)
    logger.add(PropogateHandler(), format="{message} {extra}", level="TRACE") # shunt logs into the standard python logging machinery
    caplog.set_level(0) # Tell logging to handle all log levels
    yield caplog

Ah, I wasn’t aware the loguru didn’t use the stdlib logging module. I guess I could have checked that first…

Well, this is actually not stated explicitly anywhere as far as I know. Good catch, I should add a word about this.

Anyway, between the 3 I’m thinking the easiest one would be the 3rd option. I’ll see what I can come up with and, if I find something, submit a PR to update docs with the results.

Would fit pretty well in the documentation page about migrating from logging to loguru I think.

Do you think using the sample in the Readme would work for your tests?

class PropagateHandler(logging.Handler):
    def emit(self, record):
        logging.getLogger(record.name).handle(record)

logger.add(PropagateHandler(), format="{message}")

Please, note the documentation has been updated. The recommended way to integrate Loguru with pytest is to override the caplog fixture this way:

@pytest.fixture
def caplog(caplog):
    handler_id = logger.add(caplog.handler, format="{message}")
    yield caplog
    logger.remove(handler_id)

Using PropagateHandler could result in dead-lock if inadvertently combined with InterceptHandler see #474.

@Delgan Thank you so much! Your snippet helped me avoid deadlock!

Looks like adding this to conftest.py works:

import logging

import pytest
from _pytest.logging import caplog as _caplog

from loguru import logger

@pytest.fixture
def caplog(_caplog):
    class PropogateHandler(logging.Handler):
        def emit(self, record):
            logging.getLogger(record.name).handle(record)
    logger.add(PropogateHandler(), format="{message}")
    yield _caplog

Technically you don’t even need to add from _pytest.logging import caplog as _caplog and can just:

@pytest.fixture
def caplog(caplog):

but I really don’t like that naming collision.

I’ll write up some docs for it come Monday or Tuesday and submit the PR. Discussion can continue there.

What am I even trying to achieve?

It sounds like you’re just interested in having pytest capture log output on failures. Is that correct? If so, none of this PropogateHandler mumbo jumbo needs to be done - pytest will already capture loguru output for tests. The “Captured stderr call” section might not be formatted the same way, but I don’t know if that matters to you.

from loguru import logger

def test_foo():
    print("hallo")
    logger.debug("foo")
    assert False
$ pytest test_foo.py
============================================ test session starts =============================================
platform linux -- Python 3.6.8, pytest-6.1.2, py-1.9.0, pluggy-0.13.1
rootdir: /home/dthor/temp/loguru-pytest
collected 1 item

test_foo.py F                                                                                          [100%]

================================================== FAILURES ==================================================
__________________________________________________ test_foo __________________________________________________

    def test_foo():
        print("hallo")
        logger.debug("foo")
>       assert False
E       assert False

test_foo.py:6: AssertionError
-------------------------------------------- Captured stdout call --------------------------------------------
hallo
-------------------------------------------- Captured stderr call --------------------------------------------
2020-11-10 14:32:31.733 | DEBUG    | test_foo:test_foo:5 - foo
========================================== short test summary info ===========================================
FAILED test_foo.py::test_foo - assert False
============================================= 1 failed in 0.14s ==============================================

The core of this issue is specific to pytest’s caplog fixture, which you only need if you want to assert what’s being logged. Meaning, you need the PropogateHandler if you want to do this:

from loguru import logger

def test_foo(caplog):
    print("hallo")
    logger.debug("foo")
    assert "foo" in caplog.text"     # This won't work without the PropogateHandler hack

@glass-ships Please open a new issue with fully reproducible example if possible.

Hi @SomeAkk.

The catch() decorator does not propagate exceptions by default. It will simply create a logging record and send it to the handlers as any other logged message. You need to specify reraise=True if you want to be able to explicitly catch it with try / except or with pytest.raises().

However, a little hack is possible to achieve what you want. That is, having a behavior similar to reraise=False in production but being able to switch to reraise=True during testing. Since the message is sent to each configured handler, you can add an error_handler() sink that will be in charge of re-raising the error. Be careful, it must also be added with the parameter catch=False parameter because Loguru prevents otherwise the propagation of the error.

def error_handler(message):
    exc = message.record["exception"]
    if exc is not None:
        _, val, _ = exc
        raise val

# Add this during testing
logger.add(error_handler, catch=False)

Hi @blueyed.

Do you think it makes sense for loguru to ship a pytest plugin that would do this?

(I just came here from the docs, have not read up on it, but think it is possible, and would be willing to do it)

Thanks for your proposition. However, I don’t wish for Loguru to expose such plugin, the code snippet in the documentation is sufficient enough as a workaround.

That’s great, thanks @dougthor42!

I think you should maybe remove() the added sink at the end of each test. Based on your snippet, I’m wondering if this is not addind a new sink each time you run a test.

handler_id = logger.add(PropogateHandler(), format="{message}")
yield _caplog
logger.remove(handler_id)