Pytest: Print traceback immediately in live log, not at the end in summary

Question

Given test.py

import logging
log = logging.getLogger("mylogger")

def test():
    log.info("Do thing 1")
    log.info("Do thing 2")
    raise Exception("This is deeply nested in the code")
    log.info("Do thing 3")
    assert True

def test_2():
    log.info("Nothing interesting here")

When I run pytest --log-cli-level NOTSET test.py I get the output

======================= test session starts ========================
platform win32 -- Python 3.9.4, pytest-6.2.5, py-1.11.0, pluggy-1.0.0

rootdir: C:\work\scraps\python-test-scraps
collected 2 items                                                   

test.py::test_1
-------------------------- live log call ---------------------------
INFO     mylogger:test.py:6 Do thing 1
INFO     mylogger:test.py:7 Do thing 2
FAILED                                                        [ 50%]
test.py::test_2
-------------------------- live log call ---------------------------
INFO     mylogger:test.py:13 Nothing interesting here
PASSED                                                        [100%]

============================= FAILURES =============================
______________________________ test_1 ______________________________

    def test_1():
        log.info("Do thing 1")
        log.info("Do thing 2")
>       raise Exception("This is deeply nested in the code")
E       Exception: This is deeply nested in the code

test.py:8: Exception
------------------------ Captured log call -------------------------
INFO     mylogger:test.py:6 Do thing 1
INFO     mylogger:test.py:7 Do thing 2
===================== short test summary info ======================
FAILED test.py::test_1 - Exception: This is deeply nested in the code

=================== 1 failed, 1 passed in 0.07s ====================

I find this output format very confusing, especially for bigger tests suits. When I follow the log and see FAILED, then I have to jump to the second half of the log and search for the corresponding FAILURE or ERROR.

I'd like to alter pytest's output, so that the (so called) summary at the end is printed immediately when the according events happen, so that the output can be read chronologically without having to jump around.

So far, I only found a way to disable the summary. pytest --log-cli-level NOTSET --no-summary test.py prints ...

======================= test session starts ========================
platform win32 -- Python 3.9.4, pytest-6.2.5, py-1.11.0, pluggy-1.0.0

rootdir: C:\work\scraps\python-test-scraps
collected 2 items                                                   

test.py::test_1
-------------------------- live log call ---------------------------
INFO     mylogger:test.py:6 Do thing 1
INFO     mylogger:test.py:7 Do thing 2
FAILED                                                        [ 50%]
test.py::test_2
-------------------------- live log call ---------------------------
INFO     mylogger:test.py:13 Nothing interesting here
PASSED                                                        [100%]

=================== 1 failed, 1 passed in 0.06s ====================

This is somewhat better, but also worse, because the trace is missing.
Is there an official way to print the trace inside the live log call?

Answer 1

I don't know if it's "official" or not, but I did find this answer in the Pytest dev forums, recommending the use of pytest-instafail. It's a maintained plugin, so it might do what you're looking to do. It met my needs; now I can see tracebacks in the live-log output, and not have to wait till the end of a test suite to see what went wrong.

To print logs, fails and errors only once and in the original order, run ...

pytest --log-cli-level NOTSET --instafail --show-capture no --no-summary

• --instafail enables the plugin.
  pytest loads it by default, but the plugin itself is written to do nothing by default.
• --show-capture no disables printing the logs after an error occurred.
  Without this, you would print the logs twice in case of errors: Once before the error (because of --log-cli-level NOTSET) and once after the error (like pytest usually does).

That the plugin still prints the traceback first, and captured logs after that, goes against your goals to print everything in the original order. But since you were already using --log-cli, the combination with --show-capture no should be sufficient for your use-case.