Logging within pytest tests Logging within pytest tests python python

Logging within pytest tests


Since version 3.3, pytest supports live logging, meaning that all the log records emitted in tests will be printed to the terminal immediately. The feature is documented under Live Logs section. Live logging is disabled by default; to enable it, set log_cli = 1 in the pyproject.toml1 or pytest.ini2 config. Live logging supports emitting to terminal and file; the relevant options allow records customizing:

terminal:

  • log_cli_level
  • log_cli_format
  • log_cli_date_format

file:

  • log_file
  • log_file_level
  • log_file_format
  • log_file_date_format

Note: log_cli flag can't be passed from command line and must be set in pytest.ini. All the other options can be both passed from command line or set in the config file. As pointed out by Kévin Barré in this comment, overriding ini options from command line can be done via the -o/--override option. So instead of declaring log_cli in pytest.ini, you can simply call:

$ pytest -o log_cli=true ...

Examples

Simple test file used for demonstrating:

# test_spam.pyimport loggingLOGGER = logging.getLogger(__name__)def test_eggs():    LOGGER.info('eggs info')    LOGGER.warning('eggs warning')    LOGGER.error('eggs error')    LOGGER.critical('eggs critical')    assert True

As you can see, no extra configuration needed; pytest will setup the logger automatically, based on options specified in pytest.ini or passed from command line.

Live logging to terminal, INFO level, fancy output

Configuration in pyproject.toml:

[tool.pytest.ini_options]log_cli = truelog_cli_level = "INFO"log_cli_format = "%(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)"log_cli_date_format = "%Y-%m-%d %H:%M:%S"

The identical configuration in legacy pytest.ini:

[pytest]log_cli = 1log_cli_level = INFOlog_cli_format = %(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)log_cli_date_format=%Y-%m-%d %H:%M:%S

Running the test:

$ pytest test_spam.py=============================== test session starts ================================platform darwin -- Python 3.6.4, pytest-3.7.0, py-1.5.3, pluggy-0.7.1 -- /Users/hoefling/.virtualenvs/stackoverflow/bin/python3.6cachedir: .pytest_cacherootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.inicollected 1 itemtest_spam.py::test_eggs---------------------------------- live log call -----------------------------------2018-08-01 14:33:20 [    INFO] eggs info (test_spam.py:7)2018-08-01 14:33:20 [ WARNING] eggs warning (test_spam.py:8)2018-08-01 14:33:20 [   ERROR] eggs error (test_spam.py:9)2018-08-01 14:33:20 [CRITICAL] eggs critical (test_spam.py:10)PASSED                                                                        [100%]============================= 1 passed in 0.01 seconds =============================

Live logging to terminal and file, only message & CRITICAL level in terminal, fancy output in pytest.log file

Configuration in pyproject.toml:

[tool.pytest.ini_options]log_cli = truelog_cli_level = "CRITICAL"log_cli_format = "%(message)s"log_file = "pytest.log"log_file_level = "DEBUG"log_file_format = "%(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)"log_file_date_format = "%Y-%m-%d %H:%M:%S"

The identical configuration in legacy pytest.ini:

[pytest]log_cli = 1log_cli_level = CRITICALlog_cli_format = %(message)slog_file = pytest.loglog_file_level = DEBUGlog_file_format = %(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)log_file_date_format=%Y-%m-%d %H:%M:%S

Test run:

$ pytest test_spam.py=============================== test session starts ================================platform darwin -- Python 3.6.4, pytest-3.7.0, py-1.5.3, pluggy-0.7.1 -- /Users/hoefling/.virtualenvs/stackoverflow/bin/python3.6cachedir: .pytest_cacherootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.inicollected 1 itemtest_spam.py::test_eggs---------------------------------- live log call -----------------------------------eggs criticalPASSED                                                                        [100%]============================= 1 passed in 0.01 seconds =============================$ cat pytest.log2018-08-01 14:38:09 [    INFO] eggs info (test_spam.py:7)2018-08-01 14:38:09 [ WARNING] eggs warning (test_spam.py:8)2018-08-01 14:38:09 [   ERROR] eggs error (test_spam.py:9)2018-08-01 14:38:09 [CRITICAL] eggs critical (test_spam.py:10)

1 pyproject.toml supported since version 6.0 and is the best option IMO. See PEP 518 for the specs.

2 Although you can also configure pytest in setup.cfg under the [tool:pytest] section, don't be tempted to do that when you want to provide custom live logging format. Other tools reading setup.cfg might treat stuff like %(message)s as string interpolation and fail. The best choice is using pyproject.toml anyway, but if you are forced to use the legacy ini-style format, stick to pytest.ini to avoid errors.


Works for me, here's the output I get: [snip -> example was incorrect]

Edit: It seems that you have to pass the -s option to py.test so it won't capture stdout. Here (py.test not installed), it was enough to use python pytest.py -s pyt.py.

For your code, all you need is to pass -s in args to main:

 pytest.main(args=['-s', os.path.abspath(__file__)])

See the py.test documentation on capturing output.


Using pytest --log-cli-level=DEBUG works fine with pytest-6.2.2