Task was destroyed but it is pending! about hypercorn

[jonathanslenders]

We are facing the same issue and I think I have a fix. Read along. ;-)

Some analysis.

• It seems to happen only on OS X, not on Linux (same Python version, both latest Hypercorn).
• In our case, it's only when TLS is enabled.
• Indeed it's only when HTTP/2.0 is used, not with HTTP/1.1.

The GeneratorExit and "Task was destroyed but it is pending" error indicate that there's an asyncio Task that was spawned, but we don't await it. At some point it gets garbage collected before it's completed. (Where completed could potentially be "completed the cancellation").

I was tracing the code, trying to understand what's going wrong. Several observations:

1. _server_callback is async, but spawned not within a task group.

See this line: https://github.com/pgjones/hypercorn/blob/main/src/hypercorn/asyncio/run.py#L94
It's spawned in asyncio.streams.StreamReaderProtocol.connection_made.
There is no await in here. The obvious fix would be to open a TaskGroup in hypercorn.asyncio.run.worker_serve, then pass a synchronous callback to asyncio.start_server and spawn the current async function in the task group that we created. This is easy to fix, but seems insufficient to fix the issue.

2. hypercorn.asyncio.tcp_server.TCPServer.run() creates a H2Protocol instance, passing along the TaskGroup. In there, H2Protocol spawns send_task(). When the client (curl) terminates, the _read_data() in TCPServer is done, but this send_task() in H2Protocol is still waiting in .wait(). So, the has_data Event in there sometimes doesn't get set when the TLS connection terminates.

3. I wonder whether or not adoption of anyio would be desirable, instead of reinventing TaskGroups for Trio and Asyncio, but without cancellation features. This is a different discussion, but maybe could have prevented the issue. I'm not sure.

Fix:

The bug is in TCPServer.read_data:
https://github.com/pgjones/hypercorn/blob/main/src/hypercorn/asyncio/tcp_server.py#L93

When the TLS connection terminates, we don't get a ConnectionError, but rather an empty data chunk. Possibly, this is due to the complexity of shutting down a TLS stream. The stream has to remain open because of the possibility of TLS key renegotiation. So, sending an end-of-file within a TLS stream is tricky. (I don't remember all the details, so my explanation is maybe not 100% accurate.)

What happens is that we feed RawData(b'') into self.protocol, which is an H2Protocol in our case. Then, after that self.reader.at_eof() becomes False and we don't feed a Closed() into H2Protocol. Because of that, the _send_task that is spawned in H2Protocol will keep blocking on self.has_data.wait(). This will keep the TaskGroup in which this was spawned open, until at some point there's no reference anymore, and the garbage collector kicks in.

The fix would be this:

class TCPServer:
    ...
    
    async def _read_data(self) -> None:
        closed_send = False

        while not self.reader.at_eof():
            try:
                print('before _read_data wait for')
                data = await asyncio.wait_for(self.reader.read(MAX_RECV), self.config.read_timeout)
                print('after _read_data wait for')
            except (
                ConnectionError,
                OSError,
                asyncio.TimeoutError,
                TimeoutError,
                SSLError,
            ) as e:
                await self.protocol.handle(Closed())
                closed_send = True
                break
            else:
                await self.protocol.handle(RawData(data))

        # It happens with TLS connections that we don't got a
        # `ConnectionError`, but the connection gets closed at some point. We
        # want to make sure that a `Closed()` got fed into the protocol, so
        # that protocol handlers will be unblocked.
        # See: https://github.com/pgjones/hypercorn/issues/50
        if not closed_send:
            await self.protocol.handle(Closed())

[XChikuX]

Similar issue. Only happens on https://

ERROR    [<->] 2023-12-11 05:52:55 -0800 |26349| Task exception was never retrieved                                                                                    base_events.py:1758
                              future: <Task finished name='Task-11' coro=<worker_serve.<locals>._server_callback() done, defined at                                                                            
                              /root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/run.py:90> exception=ExceptionGroup('unhandled errors in a TaskGroup', [KeyError(1)])>                         
                                + Exception Group Traceback (most recent call last):                                                                                                                           
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/run.py", line 96, in _server_callback                                                              
                                |     await TCPServer(app, loop, config, context, reader, writer)                                                                                                              
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 56, in run                                                                    
                                |     async with TaskGroup(self.loop) as task_group:                                                                                                                           
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/task_group.py", line 74, in __aexit__                                                              
                                |     await self._task_group.__aexit__(exc_type, exc_value, tb)                                                                                                                
                                |   File "/root/backend/.env/lib/python3.10/site-packages/taskgroup/taskgroups.py", line 139, in __aexit__                                                                     
                                |     raise me from None                                                                                                                                                       
                                | exceptiongroup.ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)                                                                                             
                                +-+---------------- 1 ----------------                                                                                                                                         
                                  | Traceback (most recent call last):                                                                                                                                         
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 70, in run                                                                  
                                  |     await self._read_data()                                                                                                                                                
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 105, in _read_data                                                          
                                  |     await self.protocol.handle(RawData(data))                                                                                                                              
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/__init__.py", line 62, in handle                                                                
                                  |     return await self.protocol.handle(event)                                                                                                                               
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/h2.py", line 188, in handle                                                                     
                                  |     await self._handle_events(events)                                                                                                                                      
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/h2.py", line 248, in _handle_events                                                             
                                  |     await self.streams[event.stream_id].handle(                                                                                                                            
                                  | KeyError: 1                                                                                                                                                                
                                  +------------------------------------                                                                                                                                        
                     ERROR    [<->] 2023-12-11 05:52:55 -0800 |26349| Task exception was never retrieved                                                                                    base_events.py:1758
                              future: <Task finished name='Task-17' coro=<worker_serve.<locals>._server_callback() done, defined at                                                                            
                              /root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/run.py:90> exception=ExceptionGroup('unhandled errors in a TaskGroup', [KeyError(1)])>                         
                                + Exception Group Traceback (most recent call last):                                                                                                                           
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/run.py", line 96, in _server_callback                                                              
                                |     await TCPServer(app, loop, config, context, reader, writer)                                                                                                              
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 56, in run                                                                    
                                |     async with TaskGroup(self.loop) as task_group:                                                                                                                           
                                |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/task_group.py", line 74, in __aexit__                                                              
                                |     await self._task_group.__aexit__(exc_type, exc_value, tb)                                                                                                                
                                |   File "/root/backend/.env/lib/python3.10/site-packages/taskgroup/taskgroups.py", line 139, in __aexit__                                                                     
                                |     raise me from None                                                                                                                                                       
                                | exceptiongroup.ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)                                                                                             
                                +-+---------------- 1 ----------------                                                                                                                                         
                                  | Traceback (most recent call last):                                                                                                                                         
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 70, in run                                                                  
                                  |     await self._read_data()                                                                                                                                                
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/asyncio/tcp_server.py", line 105, in _read_data                                                          
                                  |     await self.protocol.handle(RawData(data))                                                                                                                              
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/__init__.py", line 62, in handle                                                                
                                  |     return await self.protocol.handle(event)                                                                                                                               
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/h2.py", line 188, in handle                                                                     
                                  |     await self._handle_events(events)                                                                                                                                      
                                  |   File "/root/backend/.env/lib/python3.10/site-packages/hypercorn/protocol/h2.py", line 248, in _handle_events                                                             
                                  |     await self.streams[event.stream_id].handle(                                                                                                                            
                                  | KeyError: 1                                                                                                                                                                
                                  +------------------------------------                    

[dimaqq]

Python 3.9.5
hypercorn 0.13.2
fastapi 0.73.0
curl 7.68.0

Formal MRE: https://github.com/dimaqq/repro-task-destroyed

[hasanmuzak]

Any update?

[dimaqq]

Given that a fix landed in main, can this issue be closed?
Or is there more to it?

[hdante]

Hello, I believe I'm having a similar problem in Linux. I'm using Debian 12 packaged python3-hypercorn 0.13.2-3.

[2023-10-17 02:22:09 +0000] [734] [WARNING] ASGI Framework Lifespan error, continuing without Lifespan support
[2023-10-17 02:22:09 +0000] [734] [INFO] Running on https://[::]:9077 (CTRL + C to quit)
/home/django/.local/lib/python3.11/site-packages/django/http/response.py:517: Warning: StreamingHttpResponse must consume synchronous iterators in order to serve them asynchronously. Use an asynchronous iterator instead.
  warnings.warn(
Not Found: /favicon.ico
Task was destroyed but it is pending!
task: <Task pending name='Task-106' coro=<worker_serve.<locals>._server_callback() running at /usr/lib/python3/dist-packages/hypercorn/asyncio/run.py:100> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()]>>
Exception ignored in: <coroutine object worker_serve.<locals>._server_callback at 0x7fcba2504160>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/run.py", line 100, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 70, in run
    async with TaskGroup(self.loop) as task_group:
RuntimeError: coroutine ignored GeneratorExit
Task was destroyed but it is pending!
task: <Task cancelling name='Task-107' coro=<H2Protocol.send_task() running at /usr/lib/python3/dist-packages/hypercorn/protocol/h2.py:148> wait_for=<Future cancelled> cb=[gather.<locals>._done_callback() at /usr/lib/python3.11/asyncio/tasks.py:754]>
Task exception was never retrieved
future: <Task finished name='Task-146' coro=<worker_serve.<locals>._server_callback() done, defined at /usr/lib/python3/dist-packages/hypercorn/asyncio/run.py:98> exception=TimeoutError('SSL shutdown timed out')>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/run.py", line 100, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 88, in run
    await self._close()
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 131, in _close
    await self.writer.wait_closed()
  File "/usr/lib/python3.11/asyncio/streams.py", line 350, in wait_closed
    await self._protocol._get_close_waiter(self)
TimeoutError: SSL shutdown timed out
Task was destroyed but it is pending!
task: <Task pending name='Task-5' coro=<worker_serve.<locals>._server_callback() running at /usr/lib/python3/dist-packages/hypercorn/asyncio/run.py:100> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()]>>
Exception ignored in: <coroutine object worker_serve.<locals>._server_callback at 0x7fcba504a200>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/run.py", line 100, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 70, in run
    async with TaskGroup(self.loop) as task_group:
RuntimeError: coroutine ignored GeneratorExit
Task was destroyed but it is pending!
task: <Task cancelling name='Task-6' coro=<H2Protocol.send_task() running at /usr/lib/python3/dist-packages/hypercorn/protocol/h2.py:148> wait_for=<Future cancelled> cb=[gather.<locals>._done_callback() at /usr/lib/python3.11/asyncio/tasks.py:754]>
Not Found: /
Exception ignored in: <coroutine object worker_serve.<locals>._server_callback at 0x7fcba504a200>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/run.py", line 100, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 70, in run
    async with TaskGroup(self.loop) as task_group:
RuntimeError: coroutine ignored GeneratorExit
Task was destroyed but it is pending!
task: <Task pending name='Task-163' coro=<worker_serve.<locals>._server_callback() done, defined at /usr/lib/python3/dist-packages/hypercorn/asyncio/run.py:98> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()]>>
Task was destroyed but it is pending!
task: <Task cancelling name='Task-164' coro=<H2Protocol.send_task() done, defined at /usr/lib/python3/dist-packages/hypercorn/protocol/h2.py:140> wait_for=<Future cancelled> cb=[gather.<locals>._done_callback() at /usr/lib/python3.11/asyncio/tasks.py:754]>
Not Found: /
Not Found: /favicon.ico
Task exception was never retrieved
future: <Task finished name='Task-195' coro=<worker_serve.<locals>._server_callback() done, defined at /usr/lib/python3/dist-packages/hypercorn/asyncio/run.py:98> exception=TimeoutError('SSL shutdown timed out')>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/run.py", line 100, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 88, in run
    await self._close()
  File "/usr/lib/python3/dist-packages/hypercorn/asyncio/tcp_server.py", line 131, in _close
    await self.writer.wait_closed()
  File "/usr/lib/python3.11/asyncio/streams.py", line 350, in wait_closed
    await self._protocol._get_close_waiter(self)
TimeoutError: SSL shutdown timed out
(...)

[rroque6428]

Similar issue. Only happens on https://
..._handle_events
| await self.streams[event.stream_id].handle(
| KeyError: 1
+------------------------------------

Yes. This is a very annoying error, but apparently it didn't cause any trouble to the clients. I'd love to see the above correction (suggested by @jonathanslenders) applied to the source code in near future.