We are using Quart (Flask+asyncio) Python web framework. Every time the request is processed and the response is sent to a client, this (or similar) message is logged:
WARNING:asyncio:Executing <Task pending name='Task-11' coro=<ASGIHTTPConnection.handle_request() running at /usr/local/lib/python3.8/site-packages/quart/asgi.py:102> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f742ba41ee0>()] created at /usr/local/lib/python3.8/asyncio/base_events.py:422> cb=[_wait.._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:518] created at /usr/local/lib/python3.8/site-packages/quart/asgi.py:46> took 2.700 seconds
Since it is WARNING, we are kind of worried about what this could be. Does anyone have any idea why a log like this appears?
Also, I have seen more logs starting <Task pending name... before. Does anyone know what these logs are?
To replicate a similar log message, it is enough just to do this:
import time
from quart import Quart
app = Quart(__name__)
@app.route('/', methods=['POST'])
async def endpoint():
time.sleep(0.5)
return '', 200
If I set sleep() to a lower value (e.g. 0.05), the log message is not printed out.
asyncio and other event loops require the tasks to yield control back to the event loop periodically so that it can switch to another task and execute tasks concurrently. This warning is indicating that a task is taking a long time between yields, thereby 'blocking' the event loop.
It is likely this is happening as your code is either doing something CPU intensive, or more likely is using non-asyncio IO e.g. using requests. You should investigate this as it will degrade your servers ability to serve multiple requests concurrently.