IOError: close() called during concurrent operation on the same file object.

[blockjon]

Occasionally, I get IOError: close() called during concurrent operation on the same file object. when my tests run. I'm not sure what I should do to resolve this.

PIP LIST:
https://gist.github.com/blockjon/787895c8f5aab3b2587051b919e4e037

PYTEST:
pytest (3.0.5)

OS:
Debian Jessie running Docker Container

TRACE:

00:03:04.535 Traceback (most recent call last):
00:03:04.535   File "runtests.py", line 107, in <module>
00:03:04.535     main()
00:03:04.535   File "runtests.py", line 99, in main
00:03:04.535     status = pytest.main(pytest_args)
00:03:04.535   File "/usr/local/lib/python2.7/dist-packages/_pytest/config.py", line 57, in main
00:03:04.549     return config.hook.pytest_cmdline_main(config=config)
00:03:04.551   File "/usr/local/lib/python2.7/dist-packages/_pytest/vendored_packages/pluggy.py", line 745, in __call__
00:03:04.564     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
00:03:04.565   File "/usr/local/lib/python2.7/dist-packages/_pytest/vendored_packages/pluggy.py", line 339, in _hookexec
00:03:04.565     return self._inner_hookexec(hook, methods, kwargs)
00:03:04.566   File "/usr/local/lib/python2.7/dist-packages/_pytest/vendored_packages/pluggy.py", line 334, in <lambda>
00:03:04.566     _MultiCall(methods, kwargs, hook.spec_opts).execute()
00:03:04.566   File "/usr/local/lib/python2.7/dist-packages/_pytest/vendored_packages/pluggy.py", line 614, in execute
00:03:04.566     res = hook_impl.function(*args)
00:03:04.566   File "/usr/local/lib/python2.7/dist-packages/_pytest/main.py", line 127, in pytest_cmdline_main
00:03:04.574     return wrap_session(config, _main)
00:03:04.574   File "/usr/local/lib/python2.7/dist-packages/_pytest/main.py", line 123, in wrap_session
00:03:04.574     config._ensure_unconfigure()
00:03:04.575   File "/usr/local/lib/python2.7/dist-packages/_pytest/config.py", line 897, in _ensure_unconfigure
00:03:04.577     fin()
00:03:04.577   File "/usr/local/lib/python2.7/dist-packages/_pytest/capture.py", line 82, in reset_capturings
00:03:04.577     cap.stop_capturing()
00:03:04.578   File "/usr/local/lib/python2.7/dist-packages/_pytest/capture.py", line 306, in stop_capturing
00:03:04.578     self.out.done()
00:03:04.578   File "/usr/local/lib/python2.7/dist-packages/_pytest/capture.py", line 378, in done
00:03:04.578     self.syscapture.done()
00:03:04.578   File "/usr/local/lib/python2.7/dist-packages/_pytest/capture.py", line 421, in done
00:03:04.578     self.tmpfile.close()
00:03:04.578 IOError: close() called during concurrent operation on the same file object.

[nicoddemus]

I think some code under test is closing sys.stdout or sys.stderr.

If you pass -s in the command-line, the error goes away?

pytest by default captures sys.stdout and sys.stderr to a temporary file to capture it.

[nicoddemus]

Closing for now due to lack of feedback, but we can reopen this later if new information comes along.

[blockjon]

@nicoddemus I'm seeing this issue again. If I pass -s, it will create a lot of output and overwhelm my CI logs. This is hard to nail down since I have thousands of tests and its not deterministic. Can some defensive logic be added around the file close statement to avoid this?

[nicoddemus]

Hi @blockjon,

Can some defensive logic be added around the file close statement to avoid this?

I would be OK if we could reproduce the problem and understand what's happening but just adding some defensive logic in there, without knowing why, is problematic in the long term as it might be hiding some bug.

I suggest we investigate more.

I can see from the traceback that the error happens here:

pytest/_pytest/capture.py

Lines 530 to 533 in 9fcbf57

	def done(self):
	setattr(sys, self.name, self._old)
	del self._old
	self.tmpfile.close()

A quick search suggests that threads are somehow involved:

• https://stackoverflow.com/questions/29890603/ioerror-close-called-during-concurrent-operation-on-the-same-file-object
• https://github.com/Nextdoor/kingpin/pull/32/files

But pytest itself does not use threads internally at all, so I'm puzzled as to how this is happening.

Some questions:

• Can you try to use a more recent pytest version? You are using 3.0.7 which is somewhat old.
• Can you try using --capture=sys instead of --capture=fd?
• Is there a chance that some of your tests are using multi-threading and writing to stdout/stderr from multiple threads?

[benjaminp]

Here's a test file that reproduces it for me 100% of the time:

from __future__ import print_function
import time
import threading
import sys

def spam():
    f = sys.stderr
    while True:
        print('.', end='', file=f)

def test_silly():
    t = threading.Thread(target=spam)
    t.daemon = True
    t.start()
    time.sleep(.5)

While this example is silly, the error can come up in practice if there's a background thread logging something at an inopportune moment during shutdown.

[nicoddemus]

Thanks a lot @benjaminp! Using this sample I can also reproduce this on latest pytest on Windows, Python 2.7 (but not on 3.6).

Opened #3305 with a fix.

[benjaminp]

On Tue, Mar 13, 2018, at 13:43, Bruno Oliveira wrote: Thanks a lot @benjaminp! Using this sample I can also reproduce this on latest pytest on Windows, Python 2.7 (but not on 3.6).

Yeah, the Python 3 IO stack does not share this quirk.