BUG/Question: a race condition seen in `click` against free-threading interpreters

[neutrinoceros]

Bug report

Bug description:

I hit a flaky error in an actual application neutrinoceros/inifix#421, which only seems to happen with free-threaded interpreters (at least 3.13.5t and 3.14.0b3t, seen on ubuntu and macOS). I got the reproducer down to a few lines of typer (which extends on click). I'm aware that it's not appropriate to report bugs in third-party libraries to CPython, and I apologize for bringing it here in its current state, but before I attempt to reduce it further, I'd like to start the discussion here if it's not too much of a bother, because I do not know enough yet to state for sure that the actual bug is downstream, and not in the interpreter itself.

# t.py
from concurrent.futures import ThreadPoolExecutor

import pytest
from typer import Exit, Typer
from typer.testing import CliRunner

app = Typer()


@app.command()
def cmd(_: list[str]) -> None:
    with ThreadPoolExecutor() as executor:
        executor.submit(lambda: None).result()

    raise Exit(code=1)

runner = CliRunner()

@pytest.mark.parametrize("_", range(10_000))
def test_cmd(_):
    runner.invoke(app, ["cmd"])

I run the following command

❯ pytest t.py -x

And get the following output (number of passing tests varies)

warning: Using incompatible environment (`.venv`) due to `--no-sync` (The project environment's Python version does not satisfy the request: `Python >=3.11`)
========================================== test session starts ===========================================
platform darwin -- Python 3.14.0b3, pytest-8.4.1, pluggy-1.6.0
rootdir: /Users/clm/dev/inifix
configfile: pyproject.toml
plugins: hypothesis-6.135.11
collected 10000 items                                                                                    

t.py ............................................................................................. [  0%]
.................................................................................................. [  1%]
.................................................................................................. [  2%]
.................................................................................................. [  3%]
.................................................................................................. [  4%]
.................................................................................................. [  5%]
.................................................................................................. [  6%]
.................................................................................................. [  7%]
.................................................................................................. [  8%]
.................................................................................................. [  9%]
.................................................................................................. [ 10%]
.................................................................................................. [ 11%]
.................................................................................................. [ 12%]
.................................................................................................. [ 13%]
.................................................................................................. [ 14%]
.................................................................................................. [ 15%]
.................................................................................................. [ 16%]
.................................................................................................. [ 17%]
.................................................................................................. [ 18%]
.................................................................................................. [ 19%]
.................................................................................................. [ 20%]
.................................................................................................. [ 21%]
.................................................................................................. [ 22%]
.................................................................................................. [ 23%]
.................................................................................................. [ 24%]
.................................................................................................. [ 25%]
.................................................................................................. [ 26%]
.................................................................................................. [ 27%]
.................................................................................................. [ 28%]
.................................................................................................. [ 29%]
.................................................................................................. [ 30%]
.................................................................................................. [ 31%]
.................................................................................................. [ 32%]
.................................................................................................. [ 33%]
.................................................................................................. [ 34%]
.................................................................................................. [ 35%]
.................................................................................................. [ 36%]
.................................................................................................. [ 37%]
.................................................................................................. [ 38%]
.................................................................................................. [ 39%]
.................................................................................................. [ 40%]
.................................................................................................. [ 41%]
.................................................................................................. [ 42%]
.................................................................................................. [ 43%]
.................................................................................................. [ 44%]
.................................................................................................. [ 45%]
.................................................................................................. [ 46%]
.................................................................................................. [ 46%]
.................................................................................................. [ 47%]
.................................................................................................. [ 48%]
.................................................................................................. [ 49%]
.................................................................................................. [ 50%]
.................................................................................................. [ 51%]
.................................................................................................. [ 52%]
.................................................................................................. [ 53%]
.................................................................................................. [ 54%]
.................................................................................................. [ 55%]
.................................................................................................. [ 56%]
.................................................................................................. [ 57%]
.................................................................................................. [ 58%]
.................................................................................................. [ 59%]
.................................................................................................. [ 60%]
.................................................................................................. [ 61%]
.................................................................................................. [ 62%]
.................................................................................................. [ 63%]
.................................................................................................. [ 64%]
.................................................................................................. [ 65%]
.................................................................................................. [ 66%]
.................................................................................................. [ 67%]
............................................F

================================================ FAILURES ================================================
_____________________________________________ test_cmd[6801] _____________________________________________

item = <Option help>

    def sort_key(item: Parameter) -> tuple[bool, float]:
        try:
>           idx: float = invocation_order.index(item)
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
E           ValueError: list.index(x): x not in list

_click/src/click/core.py:133: ValueError

During handling of the above exception, another exception occurred:

self = <click.testing.BytesIOCopy object at 0x498c711ff00>

    def flush(self) -> None:
        super().flush()
>       self.copy_to.flush()
E       ValueError: I/O operation on closed file.

_click/src/click/testing.py:82: ValueError

The above exception was the direct cause of the following exception:

cls = <class '_pytest.runner.CallInfo'>
func = <function call_and_report.<locals>.<lambda> at 0x498c9a760c0>, when = 'call'
reraise = (<class '_pytest.outcomes.Exit'>, <class 'KeyboardInterrupt'>)

    @classmethod
    def from_call(
        cls,
        func: Callable[[], TResult],
        when: Literal["collect", "setup", "call", "teardown"],
        reraise: type[BaseException] | tuple[type[BaseException], ...] | None = None,
    ) -> CallInfo[TResult]:
        """Call func, wrapping the result in a CallInfo.
    
        :param func:
            The function to call. Called without arguments.
        :type func: Callable[[], _pytest.runner.TResult]
        :param when:
            The phase in which the function is called.
        :param reraise:
            Exception or exceptions that shall propagate if raised by the
            function, instead of being wrapped in the CallInfo.
        """
        excinfo = None
        instant = timing.Instant()
        try:
>           result: TResult | None = func()
                                     ^^^^^^

.venv/lib/python3.14t/site-packages/_pytest/runner.py:344: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
.venv/lib/python3.14t/site-packages/_pytest/runner.py:246: in <lambda>
    lambda: runtest_hook(item=item, **kwds), when=when, reraise=reraise
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
.venv/lib/python3.14t/site-packages/pluggy/_hooks.py:512: in __call__
    return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
.venv/lib/python3.14t/site-packages/pluggy/_manager.py:120: in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
.venv/lib/python3.14t/site-packages/_pytest/logging.py:850: in pytest_runtest_call
    yield
.venv/lib/python3.14t/site-packages/_pytest/capture.py:900: in pytest_runtest_call
    return (yield)
            ^^^^^
.venv/lib/python3.14t/site-packages/pluggy/_callers.py:53: in run_old_style_hookwrapper
    return result.get_result()
           ^^^^^^^^^^^^^^^^^^^
.venv/lib/python3.14t/site-packages/pluggy/_callers.py:38: in run_old_style_hookwrapper
    res = yield
          ^^^^^
.venv/lib/python3.14t/site-packages/_pytest/skipping.py:263: in pytest_runtest_call
    return (yield)
            ^^^^^
.venv/lib/python3.14t/site-packages/_pytest/unraisableexception.py:158: in pytest_runtest_call
    collect_unraisable(item.config)
.venv/lib/python3.14t/site-packages/_pytest/unraisableexception.py:79: in collect_unraisable
    raise errors[0]
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

config = <_pytest.config.Config object at 0x498bc589f10>

    def collect_unraisable(config: Config) -> None:
        pop_unraisable = config.stash[unraisable_exceptions].pop
        errors: list[pytest.PytestUnraisableExceptionWarning | RuntimeError] = []
        meta = None
        hook_error = None
        try:
            while True:
                try:
                    meta = pop_unraisable()
                except IndexError:
                    break
    
                if isinstance(meta, BaseException):
                    hook_error = RuntimeError("Failed to process unraisable exception")
                    hook_error.__cause__ = meta
                    errors.append(hook_error)
                    continue
    
                msg = meta.msg
                try:
>                   warnings.warn(pytest.PytestUnraisableExceptionWarning(msg))
E                   pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing file <_NamedTextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>: None

.venv/lib/python3.14t/site-packages/_pytest/unraisableexception.py:67: PytestUnraisableExceptionWarning
======================================== short test summary info =========================================
FAILED t.py::test_cmd[6801] - pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing file <_NamedTextIOWrapper...
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 1 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
===================================== 1 failed, 6801 passed in 6.13s =====================================

Assuming the details do not matter too much (this is a big if), the exception appears to be raised within click.testing.BytesIOCopy, which is small enough that I can reproduce it entirely here:

import io
from typing import TYPE_CHECKING

if TYPE_CHECKING:
    from _typeshed import ReadableBuffer

class BytesIOCopy(io.BytesIO):
    def __init__(self, copy_to: io.BytesIO) -> None:
        super().__init__()
        self.copy_to = copy_to

    def flush(self) -> None:
        super().flush()
        self.copy_to.flush()

    def write(self, b: ReadableBuffer) -> int:
        self.copy_to.write(b)
        return super().write(b)

This is used within another small class, StreamMixer, which is how click combines stdin, stdout and stderr in its testing framework

import io

class StreamMixer:
    def __init__(self) -> None:
        self.output: io.BytesIO = io.BytesIO()
        self.stdout: io.BytesIO = BytesIOCopy(copy_to=self.output)
        self.stderr: io.BytesIO = BytesIOCopy(copy_to=self.output)

So it looks like BytesIOCopy can race with the io.BytesIO object it references, as the former may flush after the latter is already closed. I searched click and typer for explicit close() calls and didn't find anything relevant, so I'm assuming that the interpreter (or garbage collector ?) may be doing it under the hood.
I guess at this point my questions are:

• what's the lifetime of io.BytesIO instances in a multi-threaded context ?
• is click.testing.BytesIOCopy's implementation obviously not thread-safe ?

CPython versions tested on:

3.13

Operating systems tested on:

macOS

[picnixz]

cc @ZeroIntensity (I can't answer quickly on this one so I'm delegating :))

[ZeroIntensity]

At a quick glance:

1. The lifetime is the same as all other objects, it's just that we only guarantee memory-safety for BytesIO, not thread-safety, so you can sometimes see weird things like this. The GC is executing the object's finalizer, and at the same time, a thread is trying to flush it.
2. Yeah, BytesIOCopy doesn't look thread-safe. For calls like write, you need a lock around it to ensure that super().write() and copy_to.write() are called in the same order; right now, a thread can do whatever it wants during those calls. This is also true on the GIL-enabled build, but you probably aren't noticing it because the switch interval is too high.

You might be interested in the "Threading" category on DPO for questions like this.

[neutrinoceros]

BytesIOCopy doesn't look thread-safe. For calls like write, you need a lock around it to ensure that super().write() and copy_to.write() are called in the same order

I'm not sure I understand what you mean here. I tried wrapping all calls to write and flush into with lock: contexts (using a unique, global threading.Lock instance) and it doesn't seem to change anything, but I also don't see why it should: it doesn't stop other threads from finalizing the objects (does it ?). I also don't understand how execution order can possibly change between two lines that live in the same function.
I must be missing something important...

[ZeroIntensity]

Are you also locking over calls to self.output?

I also don't understand how execution order can possibly change between two lines that live in the same function.

Because you aren't doing anything to synchronize it. For example:

def write(self, b: ReadableBuffer) -> int:
        self.copy_to.write(b)
        # Another thread can call write() to completion right here, so there's a mismatch between
        # what's written in copy_to and the superclass
        return super().write(b)

You need a lock over that to prevent torn writes. This is also true when the GIL is enabled, because the thread can yield the GIL at any time.

---

I'm not entirely sure why the object is getting finalized, I'd have to see what code is calling it. But, it's worth noting that objects can be finalized without having a reference count of zero. In C, the GC calls the tp_finalize slot, not tp_dealloc (see PEP 442). tp_finalize can "resurrect" the object by storing a reference to it, and threads are free to execute concurrently.

[neutrinoceros]

Are you also locking over calls to self.output?

yes

I'm not entirely sure why the object is getting finalized, I'd have to see what code is calling it.

I think this happens because StreamMixer instances are only created within a specific context manager, so I'd expect their ref count to drop to 0 when the context exits ?
see https://github.com/pallets/click/blob/91ac02718af3a0b88dbe282501c06642da0785fe/src/click/testing.py#L276

Actually, scratch that. I'm also seeing the exception sometimes propagate from this line, which is run within the context (i.e. before it gets a chance to exit)

https://github.com/pallets/click/blob/91ac02718af3a0b88dbe282501c06642da0785fe/src/click/testing.py#L521

[cmaloney]

Re: this particular part of the stack trace:

    def flush(self) -> None:
        super().flush()
>       self.copy_to.flush()
E       ValueError: I/O operation on closed file.

There's some thread consistency things here, but it looks like is self.output (a io.BytesIO) is closed before self.stdout a BytesIOCopy which references self.output?

file-like objects have .flush() called before doing the underlying stream .close(), and __del__ calls .close() if the file isn't closed (it tries to not lose data when file-like aren't closed and there are buffers). Reading through the isolation function there are a number of _NamedTextIOWrapper and BytesIO created (which are file-like), but none of them are explicitly closed. On delete they implicitly try to flush and close the file. I strongly suspect there's a "unlcosed file-like object" warning, or a buffering file-like object which shold have one added.... My guess is a reference loop or similar which is making it so self.stdout gets closed first.

[neutrinoceros]

Excellent, this gave me the idea of implementing __del__ on StreamMixer as follows:

diff --git a/src/click/testing.py b/src/click/testing.py
index 7c0e874..c0610ee 100644
--- a/src/click/testing.py
+++ b/src/click/testing.py
@@ -99,6 +99,13 @@ class StreamMixer:
         self.stdout: io.BytesIO = BytesIOCopy(copy_to=self.output)
         self.stderr: io.BytesIO = BytesIOCopy(copy_to=self.output)
 
+    def __del__(self) -> None:
+       # guarantee that embedded file-like objects are closed in a
+       # predictable order, protecting against races between
+       # self.output being closed and other streams being flushed on close
+       self.stderr.close()
+       self.stdout.close()
+       self.output.close()
 
 class _NamedTextIOWrapper(io.TextIOWrapper):
     def __init__(

which appears to fix my issue: the race happened about once in 10k runs with click 8.2.1, and I couldn't hit it a single time in over 1M runs with my patch.

Anyway, many thanks to all for your invaluable insight ! I'll now close this and move the discussion to click as it's now clear this isn't a CPython bug.