Search code examples
loggingpytesttraceback

Pytest Captures Logfile Even With Logfile Capture Disabled


Running pytest with --capture=sys should capture only stdout/stderr, but if I do --tb=auto --capture=sys the traceback still includes debug statements that should only be routed to a log file. I see the same behavior even with -s.

I have a lot of debug statements being logged to a file that I do NOT want to see on my console. So I have my logging.StreamHandler logger set to logging.INFO and a logging.FileHandler set to logging.DEBUG.

When I run my test, if there is a failure and a traceback is printed, it always prints the Captured log call and Captured stdout call sections if I use --tb=auto and even --tb=short. The only way to stop this from happening is by using --tb=no, but then I lose valuable traceback info.

Minimal example (I called the file test_basic.py):

import logging

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)

fh = logging.FileHandler(filename="log.txt")
fh.setLevel(logging.DEBUG)
logger.addHandler(fh)

sh = logging.StreamHandler()
sh.setLevel(logging.INFO)
logger.addHandler(sh)


def test_one():
    logger = logging.getLogger("test_one")
    logger.info("Logging at INFO level")
    logger.debug("Logging at DEBUG level")
    assert False

Output for python -m pytest --tb=auto --capture=sys:

==================================================== FAILURES ====================================================
____________________________________________________ test_one ____________________________________________________

    def test_one():
        logger = logging.getLogger("test_one")
        logger.info(f"Logging at INFO level")
        logger.debug(f"Logging at DEBUG level")
>       assert False
E       assert False

test_basic.py:19: AssertionError
---------------------------------------------- Captured stderr call ----------------------------------------------
Logging at INFO level
----------------------------------------------- Captured log call ------------------------------------------------
INFO     test_one:test_basic.py:17 Logging at INFO level
DEBUG    test_one:test_basic.py:18 Logging at DEBUG level
============================================ 1 failed in 0.09 seconds ============================================

Desired output:

==================================================== FAILURES ====================================================
____________________________________________________ test_one ____________________________________________________

    def test_one():
        logger = logging.getLogger("test_one")
        logger.info(f"Logging at INFO level")
        logger.debug(f"Logging at DEBUG level")
>       assert False
E       assert False

test_basic.py:19: AssertionError
---------------------------------------------- Captured stderr call ----------------------------------------------
Logging at INFO level
============================================ 1 failed in 0.09 seconds ============================================

If I use --tb=no I get rid of the Captured log call section but also all traceback info:

============================================== test session starts ===============================================

test_basic.py F                                                                                            [100%]

============================================ 1 failed in 0.07 seconds ============================================

How can I achieve my expected behavior?


Solution

  • The answer is --show-capture=stdout.

    It is a little bit confusing that disabling capture does not do this though. I would have liked -s to override --show-capture=all (the default).