Task was destroyed but it is pending!

[micahdlamb]

I'm running a pretty simple quart app with hypercorn on a RHEL7 linux server.
quart = 0.10.0
hypercorn = 0.9.0

I keep seeing these messages printed to standard out randomly every couple requests.

Task was destroyed but it is pending!
task: <Task pending coro=<ProtocolWrapper.send_task() done, defined at /root/.local/share/virtualenvs/atomix-Zh2dG3yU/lib/python3.7/site-packages/hypercorn/protocol/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f08fc3db1d0>()]>>
Task was destroyed but it is pending!
task: <Task pending coro=<ProtocolWrapper.send_task() done, defined at /root/.local/share/virtualenvs/atomix-Zh2dG3yU/lib/python3.7/site-packages/hypercorn/protocol/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f08f55188d0>()]>>

I'm pretty sure it has to do with hypercorn because I don't see the messages when I run the app using app.run(...). I'm having trouble narrowing down the problem anymore than that... Is anyone else seeing these messages?

Every once in a while I have a json request fail. The response body is mysteriously empty. The content-length is set to the correct non 0 value but nothing is in the body. I'm not sure if its related to this or not.

[pgjones]

Sorry, I missed this issue.

I think this will happen if the client disconnects whilst the server is sending a response. These messages shouldn't be shown though, so this is a bug in Hypercorn.

When you see this happen, is there any evidence to prove/disprove that it is the client disconnecting?

[micahdlamb]

I don't see any requests getting cancelled in the chrome dev tools. I still haven't been able to figure out what causes the messages. It just seems to happen randomly every couple requests.

[svenstaro]

I get the exact same problem. I can reproduce this every few requests using http or curl. I'm using hypercorn 0.9.0 with fastapi 0.43.0. Just curling a route will sometimes emit those errors in the console. I'm not sure whether these errors indicate that something harmful is going on or whether they are safe to ignore.

[pgjones]

I think this is fixed in the 0.9.2 release, could you check?

[thewhaleking]

Still seeing this as of 0.9.2

[pgjones]

The send_task, which sends the HTTP/2 data according to the prioritization could get blocked when the connection closed - leading to this warning. It should be fixed with 1e350e4, could you check?

[thewhaleking]

Testing this out today. Will update by EOD with results.

[thewhaleking]

Well, that didn't take long:

2020-03-03 08:00:03,542 :: ERROR :: Task was destroyed but it is pending!
task: <Task pending name='Task-40' coro=<ProtocolWrapper.send_task() done, defined at /home/bhimes/Gits/hardware-tooling/venvhypercorn/lib/python3.8/site-packages/hypercorn/protocol/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f33554e5eb0>()]>>

Started up the hypercorn server (running Quart), clicked around a few of the links in my web app, was working fine. Walked away from my computer and made myself coffee. Came back, clicked another link (same session, browser, window, etc.), instantly this. Note that the page still loaded fine (they really always do), but yet still getting that error in the log.

EDIT: Confirmed that this dev version does include 1e350e4. From /home/bhimes/Gits/hardware-tooling/venvhypercorn/lib/python3.8/site-packages/hypercorn/protocol/h2.py

    async def _close_stream(self, stream_id: int) -> None:
        if stream_id in self.streams:
            stream = self.streams.pop(stream_id)
            await stream.handle(StreamClosed(stream_id=stream_id))
            await self.has_data.set()

These are all h2 in Chrome btw.

[pgjones]

Ok, so I'm now confident that 0.9.3 has fixed this.

[thewhaleking]

Bumped to 0.9.3, testing today, will report results.

[thewhaleking]

I've seen no errors in the last day. I think you may have indeed solved it.