ProactorEventLoop raises unhandled ConnectionResetError

[JonathanSlenders]

BPO	39010
Nosy	@db3l, @asvetlov, @cjrh, @bdarnell, @1st1, @zooba, @cmeyer, @segevfiner, @miss-islington, @robbiecares
PRs	bpo-39010: Ignore error on cancelled future after end of loop. #20525 bpo-39010: Fix errors logged on proactor loop restart #22017 [3.9] bpo-39010: Fix errors logged on proactor loop restart (GH-22017) #22034 [3.8] bpo-39010: Fix errors logged on proactor loop restart (GH-22017) #22035 bpo-39010: Improve test shutdown #22066 [3.9] bpo-39010: Improve test shutdown (GH-22066) #22082 [3.8] bpo-39010: Improve test shutdown (GH-22066) #22083

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = None
created_at = <Date 2019-12-09.20:47:38.611>
labels = ['3.8', '3.9', '3.10', 'expert-asyncio']
title = 'ProactorEventLoop raises unhandled ConnectionResetError'
updated_at = <Date 2021-01-29.11:59:02.884>
user = 'https://bugs.python.org/JonathanSlenders'

bugs.python.org fields:

activity = <Date 2021-01-29.11:59:02.884>
actor = 'robbiecares'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['asyncio']
creation = <Date 2019-12-09.20:47:38.611>
creator = 'Jonathan Slenders'
dependencies = []
files = []
hgrepos = []
issue_num = 39010
keywords = ['patch']
message_count = 22.0
messages = ['358140', '358141', '358144', '358199', '358208', '358226', '362076', '366002', '368692', '375861', '376108', '376166', '376173', '376212', '376213', '376215', '376247', '376284', '376314', '376315', '376321', '376322']
nosy_count = 14.0
nosy_names = ['db3l', 'asvetlov', 'cjrh', 'Ben.Darnell', 'yselivanov', 'steve.dower', 'cmeyer', 'Segev Finer', 'miss-islington', 'PeterL777', 'Jonathan Slenders', 'Rustam S.', 'Burak Yi\xc4\x9fit Kaya', 'robbiecares']
pr_nums = ['20525', '22017', '22034', '22035', '22066', '22082', '22083']
priority = 'normal'
resolution = None
stage = 'patch review'
status = 'open'
superseder = None
type = None
url = 'https://bugs.python.org/issue39010'
versions = ['Python 3.8', 'Python 3.9', 'Python 3.10']

[JonathanSlenders]

We have a snippet of code that runs perfectly fine using the SelectorEventLoop, but crashes sometimes using the ProactorEventLoop.

The traceback is the following. The exception cannot be caught within the asyncio application itself (e.g., it is not attached to any Future or propagated in a coroutine). It probably propagates in run_until_complete().

File "C:\Python38\lib\asyncio\proactor_events.py", line 768, in _loop_self_reading
f.result() # may raise
File "C:\Python38\lib\asyncio\windows_events.py", line 808, in _poll
value = callback(transferred, key, ov)
File "C:\Python38\lib\asyncio\windows_events.py", line 457, in finish_recv
raise ConnectionResetError(*exc.args)

I can see that in IocpProactor._poll, OSError is caught and attached to the future, but not ConnectionResetError. I would expect that ConnectionResetError too will be attached to the future.

In order to reproduce, run the following snippet on Python 3.8:

from prompt_toolkit import prompt  # pip install prompt_toolkit
while 1:
    prompt('>')

Hold down the enter key, and it'll trigger quickly.

See also: prompt-toolkit/python-prompt-toolkit#1023

[JonathanSlenders]

Suppressing ConnectionResetError in BaseProactorEventLoop._loop_self_reading, like we do with CancelledError seems to fix it.

Although I'm not sure what it causing the error, and whether we need to handle it somehow.

[vstinner]

ConnectionResetError means that the pipe socket is closed. Was the event loop closed? Can you provide a reproducer? Can you try to get debug logs to see what's going on?
https://docs.python.org/dev/library/asyncio-dev.html#debug-mode

[JonathanSlenders]

Thanks Victor for the reply.

It looks like it's the self-socket in the BaseProactorEventLoop that gets closed. It's exactly this FD for which the exception is raised.

We don't close the event loop anywhere. I also don't see _close_self_pipe being called anywhere.

Debug logs don't provide any help. I'm looking into a reproducer.

[JonathanSlenders]

It looks like the following code will reproduce the issue:

import asyncio
import threading

loop = asyncio.get_event_loop()

while True:
    def test():
        loop.call_soon_threadsafe(loop.stop)

    threading.Thread(target=test).start()
    loop.run_forever()

Leave it running on Windows, in Python 3.8 for a few seconds, then it starts spawning ConnectionResetErrors.

[JonathanSlenders]

Even simpler, the following code will crash after so many iterations:

import asyncio
loop = asyncio.get_event_loop()

while True:
    loop.call_soon_threadsafe(loop.stop)
    loop.run_forever()

Adding a little sleep of 0.01s after run_forever() prevents the issue.

So, to me it looks like the cancellation of the _OverlappedFuture that wraps around the _recv() call from the self-pipe did not complete before we start _recv() again in the next run_forever() call. No idea if that makes sense...

[bdarnell]

I just spent some time digging into this. Each call to run_forever starts a call to _loop_self_reading, then attempts to cancel it before returning:

cpython/Lib/asyncio/windows_events.py

Lines 312 to 325 in 1ed6161

	def run_forever(self):
	try:
	assert self._self_reading_future is None
	self.call_soon(self._loop_self_reading)
	super().run_forever()
	finally:
	if self._self_reading_future is not None:
	ov = self._self_reading_future._ov
	self._self_reading_future.cancel()
	# self_reading_future was just cancelled so it will never be signalled
	# Unregister it otherwise IocpProactor.close will wait for it forever
	if ov is not None:
	self._proactor._unregister(ov)
	self._self_reading_future = None

The comment at line 321 is not entirely accurate: the future will not resolve in the future, but it may have already resolved, and added its callback to the call_soon queue. This callback will run if the event loop is restarted again. Since _loop_self_reading calls itself, this results in two copies of the "loop" running concurrently and stepping on each other's _self_reading_futures.

This appears to be fairly harmless except for noise in the logs when only one of the loops is stopped cleanly.

I believe the simplest fix is for _loop_self_reading to compare its argument to self._self_reading_future to determine if it is the "current" loop and if not, don't reschedule anything.

[RustamS]

Please take a look at this as well:
(ipython bpo-12049 'Unhandled exception in event loop' (WinError 995))
ipython/ipython#12049 (comment) and below

[cmeyer]

Here is another way to reproduce this (or an extremely similar) error without a loop. Since may be a race condition, I'm not sure this works 100% of the time on all machines - but it did on several machines I tried.

import asyncio

loop = asyncio.get_event_loop()

def func():
    pass

f = loop.run_in_executor(None, func)
loop.stop()
loop.run_forever()
loop.stop()
loop.run_forever()
loop.stop()
loop.run_forever()

Error on reading from the event loop self pipe
loop: <ProactorEventLoop running=True closed=False debug=False>
Traceback (most recent call last):
  File "C:\Miniconda3\envs\py38\lib\asyncio\windows_events.py", line 453, in finish_recv
    return ov.getresult()
OSError: [WinError 995] The I/O operation has been aborted because of either a thread exit or an application request

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Miniconda3\envs\py38\lib\asyncio\proactor_events.py", line 768, in _loop_self_reading
    f.result()  # may raise
  File "C:\Miniconda3\envs\py38\lib\asyncio\windows_events.py", line 808, in _poll
    value = callback(transferred, key, ov)
  File "C:\Miniconda3\envs\py38\lib\asyncio\windows_events.py", line 457, in finish_recv
    raise ConnectionResetError(*exc.args)
ConnectionResetError: [WinError 995] The I/O operation has been aborted because of either a thread exit or an application request

[zooba]

Any input from the asyncio experts?

I don't have an issue with handling the exception in this case, and hopefully when someone is up to the task of dealing with the range of edge cases throughout this loop implementation, hopefully they can get the ordering of waits right.