Skip to content

Conversation

@getzze
Copy link

@getzze getzze commented Nov 12, 2025

Tests using CliRunner run in parallel (with pytest-xdist) sometimes raise an error due to logging messages not being processed correctly because a buffer has been closed. This bug is a due to a regression after #2991.

fixes #3110

Difficult to write a test for it...

@neutrinoceros
Copy link
Contributor

I confirm that this approach does not regress on #2993

Copy link
Contributor

@neutrinoceros neutrinoceros left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think you need to update the docstring for __del__ if del is the agreed upon solution: it's not about closing bytesIO instances in a deterministic order any more

@getzze
Copy link
Author

getzze commented Nov 13, 2025

You're right thanks, I'll change it.

@pjonsson
Copy link
Contributor

Running uv run --python 3.14t pytest t.py -x where t.py contains the test case for #2993 on this branch gives me:

________________________________ test_cmd[598] _________________________________

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

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

src/click/testing.py:80: 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 0x349b37bda40>
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/_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 0x349ae58a090>

    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[598] - pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing...
!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 1 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!
======================== 1 failed, 598 passed in 0.89s =========================

@neutrinoceros
Copy link
Contributor

Interesting, so there is a regression after all ? to be complete, I used a slightly different command to check this earlier. Here it is:

uv run --no-dev -p 3.14t -w typer -w pytest pytest t.py -x

Also note that I multiplied the number of tests by 10, as compared to my reprod in #2993

I also re-ran this just now, and still didn't hit the race. Maybe it's platform specific now ? I'm running macOS 15 on a 10-cores M2 arch for what it's worth (but I originally discovered this race in GHA).

@pjonsson
Copy link
Contributor

I'm running inside a Ubuntu 24.04-based docker container (GDAL 3.10.3) on a 16-core Ryzen 9950X3D running Ubuntu 24.04.

I don't know anything about the race conditions, but I still believe the root cause is multiple objects believing they have ownership over these buffers.

Comment on lines +82 to +83
if not self.copy_to.closed:
self.copy_to.flush()
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

unfortunately this LBYL (Look Before You Leap) approach is infamously inappropriate to guard against races; in a concurrent execution model, self.copy_to.closed could change between the moment the guard clause (if ...) is evaluated, and the rest of the block is, and then you're back to square one, but the code is more complex and the race is potentially harder to reproduce (which isn't necessarily a good thing when you're try to debug it).

@neutrinoceros
Copy link
Contributor

I still believe the root cause is multiple objects believing they have ownership over these buffers.

I agree. That seems like an accurate description of the problem.

@kdeldycke kdeldycke added this to the 8.3.2 milestone Nov 18, 2025
@kdeldycke
Copy link
Collaborator

I am in favor of introducing pytest-xdist to Click. Even better: activate the pytest-randomly plugin.

I am testing the effects of these two in: #3151

@kdeldycke
Copy link
Collaborator

FYI, these changes does not fix the issues uncovered from #3151. It doesn't mean that this PR is not fixing something else! 😅

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

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

4 participants