pytest-dev / pytest-dev/pytest
`LogCaptureHandler` can be garbage collected when `caplog` fixture is in use
Nobody has claimed this yet.
- Dominant language
- Python
- Stars
- 14.5k
- Forks
- 3.4k
- Avg merge
- 2d 9h
- Merged PRs (30d)
- 35
Description
- a detailed description of the bug or problem you are having
In our tests we have had issues with the caplog fixture not correctly saving every log into caplog.messages and caplog.records. From what I can tell, the underlying issue is that in some circumstances the LogCaptureHandlers that caplog relies on can get garbage collected.
There seem to be a lot of issues in this area (#5160, #8977, #7335 etc.), but I'm not sure if any of them are the specific case that I have experienced.
- minimal example if possible
Some debugging has got me to the stage where I have a MWE that reproduces the problem:
test.py:
import gc
import logging
import sys
import pytest
logging.basicConfig()
logger = logging.getLogger()
# No idea why this test must be an xfail, but we do not hit the error if this is an empty pass
@pytest.mark.xfail
def test_other_test():
assert False
def test_a_test_with_caplog(caplog):
print(logging.root.handlers)
gc.collect()
print(logging.root.handlers)
logger.error("TEST")
assert caplog.messages[0] == "TEST", caplog.messages
conftest.py:
# It is unclear if this makes a difference (as the number of objects is so small we would be
# unlikely to hit a GC anyway)
# import gc
# gc.disable()
import pytest
# Despite this being a noop, it is required to hit the issue
@pytest.hookimpl(hookwrapper=True)
def pytest_runtest_call(item):
outcome = yield
outcome.get_result()
If you run pytest test.py, then it fails with the following:
❯ pytest test.py
======================================================== test session starts ========================================================
platform darwin -- Python 3.8.3, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: /Users/james/code/pytest_example
collected 2 items
test.py xF [100%]
============================================================= FAILURES ==============================================================
______________________________________________________ test_a_test_with_caplog ______________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x1024ebc10>
def test_a_test_with_caplog(caplog):
print(logging.root.handlers)
gc.collect()
print(logging.root.handlers)
logger.error("TEST")
> assert caplog.messages[0] == "TEST", caplog.messages
E IndexError: list index out of range
test.py:22: IndexError
------------------------------------------------------- Captured stdout call --------------------------------------------------------
[<_LiveLoggingNullHandler (NOTSET)>, <_FileHandler /dev/null (NOTSET)>, <LogCaptureHandler (NOTSET)>, <LogCaptureHandler (NOTSET)>]
[<_LiveLoggingNullHandler (NOTSET)>, <_FileHandler /dev/null (NOTSET)>]
====================================================== short test summary info ======================================================
FAILED test.py::test_a_test_with_caplog - IndexError: list index out of range
=================================================== 1 failed, 1 xfailed in 0.04s ====================================================
However, if you remove the gc.collect() call from the test, it passes:
❯ pytest test.py
======================================================== test session starts ========================================================
platform darwin -- Python 3.8.3, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: /Users/james/code/pytest_example
collected 2 items
test.py x. [100%]
=================================================== 1 passed, 1 xfailed in 0.04s ====================================================
- output of
pip listfrom the virtual environment you are using
❯ pip list
Package Version
--------------------------------- ---------
appdirs 1.4.4
attrs 21.2.0
backports.entry-points-selectable 1.1.0
CacheControl 0.12.6
cachy 0.3.0
certifi 2021.10.8
charset-normalizer 2.0.7
cleo 0.8.1
clikit 0.6.2
crashtest 0.3.1
distlib 0.3.3
filelock 3.0.12
html5lib 1.1
idna 3.2
iniconfig 1.1.1
keyring 21.8.0
lockfile 0.12.2
msgpack 1.0.2
packaging 20.9
pastel 0.2.1
pbr 5.4.5
pexpect 4.8.0
pip 19.2.3
pkginfo 1.7.1
platformdirs 2.4.0
pluggy 1.0.0
poetry 1.1.11
poetry-core 1.0.7
ptyprocess 0.7.0
py 1.10.0
pylev 1.4.0
pyparsing 2.4.7
pytest 6.2.5
requests 2.26.0
requests-toolbelt 0.9.1
setuptools 41.2.0
shellingham 1.4.0
six 1.15.0
stevedore 2.0.0
toml 0.10.2
tomlkit 0.7.2
urllib3 1.26.7
virtualenv 20.8.1
virtualenv-clone 0.5.4
virtualenvwrapper 4.8.4
webencodings 0.5.1
WARNING: You are using pip version 19.2.3, however version 21.3.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
- pytest and operating system versions
pytest 6.2.5 and MacOS BigSur 11.6.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by running the reported test.py and conftest.py reproducer, then inspect pytest's caplog fixture and LogCaptureHandler implementation. Trace why gc.collect() removes handlers from logging.root.handlers, and add a regression test demonstrating that captured messages and records remain available after collection. Done means the reproducer passes and the relevant logging tests pass.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- testing-qa
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100