Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RuntimeError after ctrl-C interrupt when asyncio is closing the threadpool #96827

Labels
3.10 only security fixes 3.11 only security fixes 3.12 bugs and security fixes topic-asyncio type-bug An unexpected behavior, bug, or error

Comments

Copy link

Test program based on a SO question; press Ctrl-C after "coro stop" and before "thread stop":

import asyncio
import time

async def main():
    print("coro start")
    loop = asyncio.get_running_loop()
    loop.run_in_executor(None, blocking)
    await asyncio.sleep(1.0)
    print("coro stop")

def blocking():
    print("thread start")
    time.sleep(3.0)
    print("thread stop")

try:
    asyncio.run(main())
except KeyboardInterrupt:
    print("interrupted!")

The output is as expected:

coro start
thread start
coro stop
^Cinterrupted!
thread stop

but a stack trace is printed to stderr:

exception calling callback for <Future at 0x7fb3e38bc0a0 state=finished returned NoneType>
Traceback (most recent call last):
  File "/usr/lib64/python3.10/concurrent/futures/_base.py", line 342, in _invoke_callbacks
    callback(self)
  File "/usr/lib64/python3.10/asyncio/futures.py", line 399, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 795, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 515, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception in thread Thread-1 (_do_shutdown):
Traceback (most recent call last):
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 576, in _do_shutdown
    self.call_soon_threadsafe(future.set_result, None)
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 795, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 515, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib64/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib64/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 578, in _do_shutdown
    self.call_soon_threadsafe(future.set_exception, ex)
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 795, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib64/python3.10/asyncio/base_events.py", line 515, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

The interrupt occurs in asyncio.run at line 49 in the file asyncio/runners.py

 39     loop = events.new_event_loop()
 40     try:
 41         events.set_event_loop(loop)
 42         if debug is not None:
 43             loop.set_debug(debug)
 44         return loop.run_until_complete(main)
 45     finally:
 46         try:
 47             _cancel_all_tasks(loop)
 48             loop.run_until_complete(loop.shutdown_asyncgens())
 49             loop.run_until_complete(loop.shutdown_default_executor())
 50         finally:
 51             events.set_event_loop(None)
 52             loop.close()

The control returns to the main program (except KeyboardInterrupt), but the cleanup waits
until the spawned thread terminates and at that time the event loop is closed and the RuntimeError
occurs.

In my opinion, no RuntimeError should happen. Given that the entire user's program is guarded by
try-except which successfully catches the KeyboardInterrupt, there is very little a programmer
can do to avoid this situation maybe except suppressing the output by redirecting the stderr to /dev/null.

Your environment

Python 3.10

type-bug An unexpected behavior, bug, or error label Sep 14, 2022
@AlexWaygood AlexWaygood moved this to Todo in asyncio Sep 14, 2022
@gvanrossum
Copy link
Member

What does it do in Python 3.11 (e.g. 3.11rc2, now available from python.org)?

@gvanrossum
Copy link
Member

I tried, and it seems to give a similar traceback.

~/3.11$ ./python.exe intr.py 
coro start
thread start
coro stop
^Cinterrupted!
thread stop
exception calling callback for <Future at 0x10d283450 state=finished returned NoneType>
Traceback (most recent call last):
  File "/Users/guido/3.11/Lib/concurrent/futures/_base.py", line 340, in _invoke_callbacks
    callback(self)
  File "/Users/guido/3.11/Lib/asyncio/futures.py", line 407, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception in thread Thread-1 (_do_shutdown):
Traceback (most recent call last):
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 580, in _do_shutdown
    self.call_soon_threadsafe(future.set_result, None)
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/guido/3.11/Lib/threading.py", line 1038, in _bootstrap_inner
    self.run()
  File "/Users/guido/3.11/Lib/threading.py", line 975, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 582, in _do_shutdown
    self.call_soon_threadsafe(future.set_exception, ex)
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "/Users/guido/3.11/Lib/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
~/3.11$ 

@gvanrossum
Copy link
Member

Ouch, this is tricky.

I think I understand the last part of the traceback. When a loop is closed, it tries to shut down its default executor. This is done by creating a helper thread (in shutdown_default_executor())) that runs _do_shutdown(). The helper thread blocks until the executor is actually shut down, and then uses call_soon_threadsafe() to report back to the event loop that it's done. Because the thread sleeps for 3 seconds, the by the time this happens the loop's _closed flag has already been set, and call_soon_threadsafe() raises an exception because of this.

Interestingly, the traceback has the form

<traceback 1>
<traceback 2> 

During handling of the above exception, another exception occurred:

<traceback 3>

Now both traceback 2 and traceback 3 are reporting an error in _do_shutdown(). The line numbers suggest that the first call_soon_tnreadsafe() call fails, its exception is caught, and then the second call fails in a similar manner.

So what about traceback 1? This is happening in _call_set_state(), an inner function of _chain_future() which is used to chain the executor's Future (which is not an asyncio.Future but a concurrent.futures.Future) to the future that wraps the run_in_executor() call.

Still with me? It looks like _call_set_state() could simply check whether the destination loop isn't closed, which it does a few lines earlier when it finds the destination future is cancelled.

I'll try to come up with a repro that doesn't require one to hit ^C, and take it from there.

@kumaraditya303
Copy link
Contributor

That sounds right, you might be able to create reproducer with _thread.interrupt_main.

@kumaraditya303 kumaraditya303 added 3.11 only security fixes 3.10 only security fixes 3.12 bugs and security fixes labels Sep 17, 2022
@kumaraditya303 kumaraditya303 moved this from Todo to In Progress in asyncio Sep 24, 2022
@gvanrossum
Copy link
Member

I have a fix, but not yet a test.

I spent 30-60 minutes trying to come up with a test case, but I'm pretty unhappy with it. The key thing is that we need to aim the keyboard interrupt to happen once shutdown_default_executor() has entered the await future line. I tried various ways to do this but wasn't very successful. The best thing I can think of is to have a loop in the executor thread that sleeps 1 msec at a time and then checks if the loop._executor_shutdown_called flag is set yet. Once that is set, sleep a little longer (another msec?) and then call _thread.interrupt_main(), in the hope that the extra bit of sleeping is enough to make us reach the await future.

However, when I try this, it doesn't always trigger the bug with Python 3.11rc2 or Python 3.10.

```py import asyncio import _thread import time

async def main():
print("coro start")
loop = asyncio.get_running_loop()
loop.run_in_executor(None, blocking, loop)
print("coro stop")

def blocking(loop):
print("thread start")
while not loop._executor_shutdown_called:
time.sleep(0.001)
print("Got it")
time.sleep(0.001)
_thread.interrupt_main()
print("thread stop")

try:
asyncio.run(main())
except KeyboardInterrupt:
print("interrupted!")

</details>

gvanrossum added a commit that referenced this issue Sep 30, 2022
* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
miss-islington pushed a commit to miss-islington/cpython that referenced this issue Sep 30, 2022
…nGH-96837)

* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
(cherry picked from commit e9d6376)

Co-authored-by: Guido van Rossum <[email protected]>
miss-islington pushed a commit to miss-islington/cpython that referenced this issue Sep 30, 2022
…nGH-96837)

* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
(cherry picked from commit e9d6376)

Co-authored-by: Guido van Rossum <[email protected]>
Repository owner moved this from In Progress to Done in asyncio Sep 30, 2022
miss-islington added a commit that referenced this issue Sep 30, 2022
* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
(cherry picked from commit e9d6376)

Co-authored-by: Guido van Rossum <[email protected]>
miss-islington added a commit that referenced this issue Sep 30, 2022
* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
(cherry picked from commit e9d6376)

Co-authored-by: Guido van Rossum <[email protected]>
serhiy-storchaka pushed a commit to serhiy-storchaka/cpython that referenced this issue Oct 2, 2022
…n#96837)

* When chaining futures, skip callback if loop closed.
* When shutting down an executor, don't wake a closed loop.
@pfmoore
Copy link
Member

pfmoore commented Nov 14, 2022

I'm still seeing this issue on Python 3.11.0 on Windows. That is, if I run the test program in the original comment here and hit Ctrl-C after "coro stop" is printed, I get the same exception traceback:

❯ py .\bug.py
coro start
thread start
coro stop
interrupted!
thread stop
exception calling callback for <Future at 0x250844fd1d0 state=finished returned NoneType>
Traceback (most recent call last):
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\concurrent\futures\_base.py", line 340, in _invoke_callbacks
    callback(self)
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\futures.py", line 401, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception in thread Thread-1 (_do_shutdown):
Traceback (most recent call last):
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 580, in _do_shutdown
    self.call_soon_threadsafe(future.set_result, None)
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\threading.py", line 1038, in _bootstrap_inner
    self.run()
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\threading.py", line 975, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 582, in _do_shutdown
    self.call_soon_threadsafe(future.set_exception, ex)
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 803, in call_soon_threadsafe
    self._check_closed()
  File "C:\Users\Gustav\AppData\Local\Programs\Python\Python311\Lib\asyncio\base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

Did the fix make it into the 3.11.0 release?

(I found this issue when trying to debug the same error in a program running a subprocess - I assume that create_subprocess_exec uses the threadpool in the background).

@gvanrossum
Copy link
Member

I guess we'll have to reopen this. It definitely made it into 3.11 (based on the date it was committed). I am out of bandwidth to personally research this -- do you have time to look into it more? Maybe we only fixed it for Selector event loops and not for the Proactor event loop?

@gvanrossum gvanrossum reopened this Nov 14, 2022
Repository owner moved this from Done to In Progress in asyncio Nov 14, 2022
@pfmoore
Copy link
Member

pfmoore commented Nov 14, 2022

I'm happy to help, but I don't understand enough about asyncio in general, or the proactor/process implementation in particular, to diagnose what the issue might be.

Copy link
Author

I checked on Linux. It appears fixed on 3.10, but not on 3.11. I will try to find out what makes the difference.

Copy link
Author

I can't believe. I have installed Python 3.11.0 on Fedora 35 from the Fedora RPMs and the patch for this issue is missing! At least on the asyncio/base_events.py file.

On Github:
https://github.com/python/cpython/blob/3.11/Lib/asyncio/base_events.py#L577

   def _do_shutdown(self, future):
        try:
            self._default_executor.shutdown(wait=True)
            if not self.is_closed():
                self.call_soon_threadsafe(future.set_result, None)
        except Exception as ex:
            if not self.is_closed():
                self.call_soon_threadsafe(future.set_exception, ex)

On Fedora, RPM python3.11-libs-3.11.0-1.fc35.x86_64:

    def _do_shutdown(self, future):
        try: 
            self._default_executor.shutdown(wait=True)
            self.call_soon_threadsafe(future.set_result, None)
        except Exception as ex:
            self.call_soon_threadsafe(future.set_exception, ex)

Copy link
Author

The people from Fedora/Redhat used the source tarball to build their RPMs. Here's the thing: I do not see the patched asyncio code in the source tarballs (both xz and gz) on the official download page https://www.python.org/downloads/release/python-3110/ !!

Could somebody please check and confirm that, because I still can't believe it. But if I'm not wrong, it explains the report from @pfmoore.

@pfmoore
Copy link
Member

pfmoore commented Nov 15, 2022

I have checked that code in my installed copy of Python 3.11.0 on Windows, and I see

    def _do_shutdown(self, future):
        try:
            self._default_executor.shutdown(wait=True)
            self.call_soon_threadsafe(future.set_result, None)
        except Exception as ex:
            self.call_soon_threadsafe(future.set_exception, ex)

So it looks like the patch didn't make it into the Windows 3.11.0 release either 🙁

@pablogsal @zooba is there any possibility that the 3.11 Windows release was done from somewhere other than what's currently on the 3.11 branch?

Edit: Never mind, the fix is not on the 3.11.0 tag - see https://github.com/python/cpython/blob/v3.11.0/Lib/asyncio/base_events.py#L577

Copy link
Author

I checked the changelog. The assumption that 3.11.0 (released Oct 24) contains the fix for this issue (patch from Sep 30) is false indeed, thanks @pfmoore for pointing that out.

@pfmoore
Copy link
Member

pfmoore commented Nov 15, 2022

So this should be fixed in 3.11.1. That's cool, thanks for the investigation!

@pfmoore pfmoore closed this as completed Nov 15, 2022
Repository owner moved this from In Progress to Done in asyncio Nov 15, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
3.10 only security fixes 3.11 only security fixes 3.12 bugs and security fixes topic-asyncio type-bug An unexpected behavior, bug, or error
Projects
Status: Done
Development

No branches or pull requests

5 participants