--log-cli may cause some unrelated printed messages to be swallowed #7148
Description
See #7148 (comment) for a description of the issue.
Original report:
Question
Why do print statements get captured once there is a logging call (less than or equal) to the --log-cli-level on macOS, but not Windows?
Tested with
- platform darwin -- Python 3.6.6, pytest-5.4.1, py-1.8.1, pluggy-0.13.1. (macOS 10.14.6)
- platform darwin -- Python 3.7.6, pytest-5.4.1, py-1.8.0, pluggy-0.12.0. (macOS 10.14.6)
- platform win32 -- Python 3.6.6, pytest-5.4.1, py-1.8.1, pluggy-0.13.1. (Win10 Pro 1909)
pip list
Package Version
------------------ -------
attrs 19.3.0
bcrypt 3.1.7
cffi 1.14.0
cryptography 2.8
importlib-metadata 1.4.0
more-itertools 8.1.0
packaging 20.0
paramiko 2.7.1
pip 10.0.1
pluggy 0.13.1
py 1.8.1
pycparser 2.20
PyNaCl 1.3.0
pyparsing 2.4.6
pysftp 0.2.9
pytest 5.4.1
setuptools 39.0.1
six 1.14.0
wcwidth 0.1.8
zipp 1.0.0
Repro Sample
Sample conftest.py to repro
import logging
import platform
"""
Question: Why do print statements get captured once there is a logging call (less than or equal)
to the --log-cli-level on macOS, but not Windows?
Example: collection_modifyitems executes before report_collectionfinish
1. $ python -m pytest --log-cli-level=critical
***HOOK gets printed in the terminal because the --log-cli-level is greater than the first
logging call (which is warning)
2. $ python -m pytest --log-cli-level=warning
***HOOK is no longer printed because there was a logging call that was (less than or equal)
to the --log-cli-level
3. $ python -m pytest
***HOOK is printed since there is no --log-cli-level
Tested with:
platform darwin -- Python 3.6.6, pytest-5.4.1, py-1.8.1, pluggy-0.13.1
"""
def pytest_sessionstart(session):
print(session.config.invocation_params.args)
current_os = platform.system()
print(platform.platform())
if current_os == 'Darwin':
print(platform.mac_ver())
elif current_os == 'Windows':
print(platform.win32_ver())
def pytest_collection_modifyitems(session, config, items):
logging.warning("\n***LOG MSG")
def pytest_report_collectionfinish(config, startdir, items):
print("XXXXXXXX")
return "\n***HOOK"Sample test
def test_1():
print("hello")
assert TruePytest output
--log-cli-level=critical --> HOOK is printed
$ python -m pytest --log-cli-level=critical
('--log-cli-level=critical',)
Darwin-18.7.0-x86_64-i386-64bit
('10.14.6', ('', '', ''), 'x86_64')
============================= test session starts ==============================
platform darwin -- Python 3.6.6, pytest-5.4.1, py-1.8.1, pluggy-0.13.1
rootdir: /Users/x/Downloads/temp_stuff
collected 1 item
XXXXXXXX
***HOOK
test_thing.py::test_1 PASSED [100%]
============================== 1 passed in 0.01s ===============================
--log-cli-level=warning --> HOOK is not printed
$ python -m pytest --log-cli-level=warning
('--log-cli-level=warning',)
Darwin-18.7.0-x86_64-i386-64bit
('10.14.6', ('', '', ''), 'x86_64')
============================= test session starts ==============================
platform darwin -- Python 3.6.6, pytest-5.4.1, py-1.8.1, pluggy-0.13.1
rootdir: /Users/x/Downloads/temp_stuff
collecting ...
----------------------------- live log collection ------------------------------
WARNING root:conftest.py:37
***LOG MSG
PASSED [100%]
============================== 1 passed in 0.01s ===============================