CliRunner.invoke raises a "ValueError: I/O operation on closed file"

[getzze]

Hi,
I am a maintainer of subliminal that uses click for its CLI. Some tests for the CLI are failing since the upgrade to click 8.3.0.
I tracked the failures to a regression in click 8.3.0 due to #2991. Reverting this commit makes my tests pass with click 8.3.0.

The failing pytest tests are of the following form:

def test_cli_download(tmp_path: os.PathLike[str]) -> None:
    runner = CliRunner()

    result = runner.invoke(subliminal_cli, ['download', '-l', 'en', '-p', 'podnapisi', 'video.mkv'])

    # Curiously this test is not failing, subtitle is even downloaded
    assert result.exit_code == 0

    # The following two asserts are failing because `result.output` show a long error message.
    assert result.output.startswith('Collecting videos')
    assert result.output.endswith('Downloaded 1 subtitle\n')

When I only run this test function with pytest, all the assertions pass, but when I run the whole file that has plenty of test functions with the same structure, all the functions fail at the result.output assert (although not consistently...)

The error message in result.output is like this:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.13/logging/__init__.py", line 1154, in emit
    stream.write(msg + self.terminator)
    ~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
ValueError: I/O operation on closed file.
[...]
  File "src/subliminal/score.py", line 157, in compute_score
    logger.debug('Found matches %r', matches)
Message: 'Found matches %r'
Arguments: ({'country', 'episode', 'season', 'series', 'year'},)

It seems the logging files are closed after one CliRunner.invoke call and its giving rise to failures in the other tests.

[edgarrmondragon]

I'm seeing similar output in some projects. I think that ironically #2991 introduced a different race condition, because the stream is closed by the time logging tries to write a message to it.

cc @neutrinoceros

[neutrinoceros]

Thanks for the ping. I'm not an expert here, so please take everything I say with a grain of salt, but I do notice there was a test that needed updating for click's own CI to survive my patch. Could you try using the CliRunner.isolation context manager in your tests, see if it resolves the new race ?

[getzze]

I didn't try but the docs say that the invoke method uses the isolation context, so there would be nested contexts, not sure it would help.

[getzze]

I was thinking, would it solve your problem if your patch would delete the BytesIO attributes instead of calling their close method?

[neutrinoceros]

I checked, and I can confirm that it wouldn't.

[neutrinoceros]

I didn't try but the docs say that the invoke method uses the isolation context, so there would be nested contexts, not sure it would help.

Indeed, but to be clear, I'm suggesting to replace runner.invoke with a runner.isolation context. See for instance

click/tests/test_testing.py

Lines 443 to 451 in 309ce91

	def test_isolation_stderr_errors():
	"""Writing to stderr should escape invalid characters instead of
	raising a UnicodeEncodeError.
	"""
	runner = CliRunner()
	with runner.isolation() as (_, err, _):
	click.echo("\udce2", err=True, nl=False)
	assert err.getvalue() == b"\\udce2"

[getzze]

I've been looking at the code in testing.py, instead of overloading StreamMixer.__del__, it would be cleaner to modify BytesIOCopy to handle properly the fact that the copy_to stream can be closed or dereferenced.

Edit: maybe allowing copy_to to be None and checking for that possibility in the methods would be enough.

[pjonsson]

@neutrinoceros I tried your reproducer from #2993 with Python 3.14 (via uv) on click 8.2.1 and after a dozen runs I still haven't been able to hit the exception. Or do you mean you run that ~9 second reproducer 10 000 times, so it takes upwards of 25 hours of constant hammering to reproduce the problem once?

Even Python's own documentation seem pretty keen on not using __del__(): https://docs.python.org/3.14/reference/datamodel.html#object.__del__

If it takes you 9 seconds to reproduce the problem, could you please see if the following also avoids the problem you were fixing?

diff --git a/src/click/testing.py b/src/click/testing.py
index f6f60b8..16c021c 100644
--- a/src/click/testing.py
+++ b/src/click/testing.py
@@ -77,8 +77,8 @@ class BytesIOCopy(io.BytesIO):
         self.copy_to = copy_to
 
     def flush(self) -> None:
-        super().flush()
         self.copy_to.flush()
+        super().flush()
 
     def write(self, b: ReadableBuffer) -> int:
         self.copy_to.write(b)
@@ -98,7 +98,7 @@ class StreamMixer:
         self.stdout: io.BytesIO = BytesIOCopy(copy_to=self.output)
         self.stderr: io.BytesIO = BytesIOCopy(copy_to=self.output)
 
-    def __del__(self) -> None:
+    def close(self) -> None:
         """
         Guarantee that embedded file-like objects are closed in a
         predictable order, protecting against races between
@@ -106,8 +106,8 @@ class StreamMixer:
 
         .. versionadded:: 8.2.2
         """
-        self.stderr.close()
         self.stdout.close()
+        self.stderr.close()
         self.output.close()
 
 
@@ -429,6 +429,7 @@ class CliRunner:
             utils.should_strip_ansi = old_should_strip_ansi  # type: ignore
             _compat.should_strip_ansi = old__compat_should_strip_ansi
             formatting.FORCED_WIDTH = old_forced_width
+            stream_mixer.close()
 
     def invoke(
         self,

[neutrinoceros]

@neutrinoceros I tried your reproducer from #2993 with Python 3.14 (via uv) on click 8.2.1 and after a dozen runs I still haven't been able to hit the exception. Or do you mean you run that ~9 second reproducer 10 000 times, so it takes upwards of 25 hours of constant hammering to reproduce the problem once?

No, I can reliably reproduce it under 10min. It is much easier to hit with a free-threaded interpreter. Is that what you did ?

[neutrinoceros]

If it takes you 9 seconds to reproduce the problem, could you please see if the following also avoids the problem you were fixing?

I'll try this in a couple minutes, thanks !

[neutrinoceros]

Warmup: I could still reliably reproduce this race (got 6 hits in 70s of crunching) with Python 3.14.0t + click 8.2.0

Pièce de résistance: I just tried your patch. Happy to report I didn't hit the race a single time with an equal amount of effort¹

Footnotes

1. just for security fun, I also tried 10x harder, and ... 🥁 ... still no hit 🎉 ↩

[getzze]

@pjonsson thanks for the patch, but it is still giving an error with subliminal.

Removing the call to BytesIO.close() fixes it though:

@@ -106,8 +106,8 @@ class StreamMixer:
 
         .. versionadded:: 8.2.2
         """
-        self.stdout.close()
-        self.stderr.close()
-        self.output.close()
+        self.stdout = None
+        self.stderr = None
+        self.output = None

@neutrinoceros, does it also fix the race condition in your case?