pytest-xdist icon indicating copy to clipboard operation
pytest-xdist copied to clipboard

`ValueError: I/O operation on closed file.` when using `conftest.py` with `xdist`

Open mkmoisen opened this issue 1 year ago • 2 comments

I have a regression test suite that I run in parallel with xdist.

My application has permanent threads that poll and log every 5 seconds for the life time of the application.

If I create an empty conftest.py file, and run pytest -n 16 to run under xdist, the tests will eventually start logging ValueError: I/O operation on closed file. each time that these permanent thread calls logger.debug.

It appears that these error messages don't start until an xdist worker finally stops, and each xdist worker once stopped will start contributing these error messages. Usually when the tests are around 90% completed is when these error messages start to occur.

If I add the -s flag when calling pytests (pytest -n16 -s), this issue doesn't occur. Or if I remove the conftest.py file the issue does not occur.

It seems like the mere existence of a conftest.py file is enough to trigger this issue. I'm trying to write a custom plugin, but even if I remove all the code and just leave an empty conftest.py, this issue occurs.

Unfortunately I cannot reproduce this issue outside of my application. For example creating a small test file with a permanent thread that logs every second doesn't reproduce the issue.

Has anyone encountered this issue, or can offer insight into why the presence of conftest.py affects logging in this way? Any suggestions for workarounds or fixes would be greatly appreciated.

Here is the logging error that I see over and over again when running the tests:

--- Logging error ---
Traceback (most recent call last):
  File "/app/Python-3.12.1/Lib/logging/__init__.py", line 1163, in emit
    stream.write(msg + self.terminator)
Call stack:
  File "/app/Python-3.12.1/Lib/threading.py", line 1030, in _bootstrap
    self._bootstrap_inner()
  File "/app/Python-3.12.1/Lib/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/app/Python-3.12.1/Lib/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  ... [logs abridged]
  File "/app/src/engine/poll/__init__.py", line 76, in _poll
    logger.info('polling message')
Message: 'polling message'
Arguments: ()

I'm using Pytest==8.0.0 and pytest-xdist==3.5.0

mkmoisen avatar Feb 07 '24 20:02 mkmoisen

Do you configure logging while io capture is active?

RonnyPfannschmidt avatar Feb 07 '24 20:02 RonnyPfannschmidt