Logging within pytest tests
Solution 1
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.
Solution 2
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.toml
1 or pytest.ini
2 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
As pointed out by Kévin Barré in this comment, overriding ini
options from command line can be done via:
-o OVERRIDE_INI, --override-ini=OVERRIDE_INI
override ini option with "option=value" style, e.g.
-o xfail_strict=True -o cache_dir=cache
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.py
import logging
LOGGER = 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 = true
log_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 = 1
log_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
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.6
cachedir: .pytest_cache
rootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.ini
collected 1 item
test_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 = true
log_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 = 1
log_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
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.6
cachedir: .pytest_cache
rootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.ini
collected 1 item
test_spam.py::test_eggs
---------------------------------- live log call -----------------------------------
eggs critical
PASSED [100%]
============================= 1 passed in 0.01 seconds =============================
$ cat pytest.log
2018-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.
Solution 3
Using pytest --log-cli-level=DEBUG
works fine with pytest (tested from 6.2.2 to 7.1.1)
Using pytest --log-cli-level=DEBUG --capture=tee-sys
will also print stdtout
.
Solution 4
To turn logger output on use send --capture=no
flag from command line.
--capture=no
will show all outputs from logger and print statements. If you would like to capture outputs from logger and not print statements use --capture=sys
pytest --capture=no tests/system/test_backoffice.py
Here is more information about "Capturing of the stdout/stderr output"
By default logger output level is "WARNING"
To change log output level use --log-cli-level
flag.
pytest --capture=no --log-cli-level=DEBUG tests/system/test_backoffice.py
Solution 5
If you want to filter logs with the command line, you can pass --log-cli-level (pytest --log-cli-level) and logs will be shown from the level you specified and above
(e.g. pytest --log-cli-level=INFO will show INFO and above logs(WARNING, ERROR, CRITICAL))
note that: default --log-cli-level is a WARNING if you don't specify it (https://docs.pytest.org/en/6.2.x/logging.html)
But if you dont want to use --log-cli-level every time use pytest, you can set log-level in your pytest config file (pytest.ini/tox.ini/setup.cfg)
e.g.
put log-level=INFO in pytest.ini (or other config files i mentioned)
when you run pytest, you only see INFO and above logs
Related videos on Youtube
superselector
Updated on April 26, 2022Comments
-
superselector about 2 years
I would like to put some logging statements within test function to examine some state variables.
I have the following code snippet:
import pytest,os import logging logging.basicConfig(level=logging.DEBUG) mylogger = logging.getLogger() ############################################################################# def setup_module(module): ''' Setup for the entire module ''' mylogger.info('Inside Setup') # Do the actual setup stuff here pass def setup_function(func): ''' Setup for test functions ''' if func == test_one: mylogger.info(' Hurray !!') def test_one(): ''' Test One ''' mylogger.info('Inside Test 1') #assert 0 == 1 pass def test_two(): ''' Test Two ''' mylogger.info('Inside Test 2') pass if __name__ == '__main__': mylogger.info(' About to start the tests ') pytest.main(args=[os.path.abspath(__file__)]) mylogger.info(' Done executing the tests ')
I get the following output:
[bmaryada-mbp:/Users/bmaryada/dev/platform/main/proto/tests/tpch $]python minitest.py INFO:root: About to start the tests ======================================================== test session starts ========================================================= platform darwin -- Python 2.6.2 -- pytest-2.0.0 collected 2 items minitest.py .. ====================================================== 2 passed in 0.01 seconds ====================================================== INFO:root: Done executing the tests
Notice that only the logging messages from the
'__name__ == __main__'
block get transmitted to the console.Is there a way to force
pytest
to emit logging to console from test methods as well?-
chb almost 11 yearsYou might take a look at this answer, posted by py.test's creator. He suggests a pytest plugin that provides a high degree of versatility.
-
-
superselector over 13 yearsSorry. I pasted the code in haste. Please remove the 'assert 0 == 1' from the 'test_one' function to notice the 'problem'. Only when there is some failure (which I forced by having a false assert), py.test seems to print the logging information.
-
TryPyPy over 13 yearsNo problem, I found out how to fix on the command line, looking for a programmatic way.
-
hpk42 over 13 yearsyou could also redirect the logging output to some file instead of the default implicit stderr.
-
TryPyPy over 13 years@superselector hpk42 is the py.test guy, do listen. IIUC, in your code it'd be
logging.basicConfig(filename="somelog.txt", level=logging.DEBUG)
. -
Kévin Barré over 5 yearsAbout the note that
log_cli
must be in pytest.ini, it seems you can use-o
option to override value from command line.pytest -o log_cli=true --log-cli-level=DEBUG
works for me. -
hoefling over 5 years@KévinBarré very nice comment and a very useful hint in general, thanks! Updated the answer.
-
CMCDragonkai about 5 yearsThis is definitely the correct answer when using logging. Although I like to differentiate logs that are inside the tests, and logs that are inside the system under test which should be considered separately.
-
hoefling almost 5 years@CMCDragonkai unfortunately,
pytest
is somewhat limited in that matter. However, this should be doable with special logging configuration for tests in your app; turn off propagation in your loggers and add a "test handler" that logs to a specified file. This way,pytest
only logs records coming from tests, while the custom handler takes care about the SuT logs. -
Ofek Agmon about 4 yearsHi, thanks for this great answer. One small question - I run my tests with the pytest.ini file and my log messages go to the file, which is great. What still doesn't go to the file in the actual result line of each test
test.py:test_method [None] PASSED
- how can I make those lines go to the file also? -
hoefling about 4 years@OfekAgmon if you want to store
pytest
output, you can use the--result-log
argument (although note it is deprecated, here are the alternatives). You can't storepytest
output and live logging output in the same file, though. -
andrea over 3 yearsHi @hoefling, is there a way to dynamically change the filename pytest.log to include date and time in the filename, so that successive test runs logs will be kept in separate file as opposed to being overwritten?
-
hoefling over 3 years@andrea yes, you can change the options programmatically; I can't post snippets in the comments, so check out the answer I gave to a similar issue (link). The option to adjust is
log_file
instead ofhtmlpath
; should you have any difficulties with that, write a new question and ping me here again, I will add a working example. -
osacognitive almost 3 yearsI'm seeing logs for my app, but I'm not seeing any of the logs from packages I am using, is there possibly a reason package logs don't get printed out? The package logs are at the debug level. The package I'm using is flask_oidc just in case you'd like to see how logs are used in the package.