Fastapi: [BUG] Getting request body in a sync path operation

[Hedingber]

Describe the bug

I have a route operation that is running some sync code, therefore, as the docs says, I'm defining it as def (and not async def) which causes it to run in an awaited threadpool.
In my route I need to get the request JSON body as is, according to the docs I should use reuqest.json(), the problem is that this is an async function, and since my route operation is not async I can't use await.
After googling it (I think it would be very helpful to add docs about what's the right way to do it), it seems like the way to go is to do asyncio.run(request.json()) - since we're on a different thread, there is no running event loop, asyncio.run will handle creating running and terminating the event loop.
This solution seemed to be working, but suddenly I saw this error in production when there was high load on the endpoint:

 [2020-05-25 02:13:07 +0000] [8] [ERROR] Exception in ASGI application
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 385, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  File "/usr/local/lib/python3.7/site-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "/usr/local/lib/python3.7/site-packages/fastapi/applications.py", line 149, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.7/site-packages/starlette/applications.py", line 102, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.7/site-packages/starlette/middleware/errors.py", line 181, in __call__
    raise exc from None
  File "/usr/local/lib/python3.7/site-packages/starlette/middleware/errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "/usr/local/lib/python3.7/site-packages/starlette/exceptions.py", line 82, in __call__
    raise exc from None
  File "/usr/local/lib/python3.7/site-packages/starlette/exceptions.py", line 71, in __call__
    await self.app(scope, receive, sender)
  File "/usr/local/lib/python3.7/site-packages/starlette/routing.py", line 550, in __call__
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.7/site-packages/starlette/routing.py", line 227, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.7/site-packages/starlette/routing.py", line 41, in app
    response = await func(request)
  File "/usr/local/lib/python3.7/site-packages/fastapi/routing.py", line 197, in app
    dependant=dependant, values=values, is_coroutine=is_coroutine
  File "/usr/local/lib/python3.7/site-packages/fastapi/routing.py", line 150, in run_endpoint_function
    return await run_in_threadpool(dependant.call, **values)
  File "/usr/local/lib/python3.7/site-packages/starlette/concurrency.py", line 34, in run_in_threadpool
    return await loop.run_in_executor(None, func, *args)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/app/main.py", line 11, in store_log
    body = asyncio.run(request.body())
  File "/usr/local/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "uvloop/loop.pyx", line 1456, in uvloop.loop.Loop.run_until_complete
  File "/usr/local/lib/python3.7/site-packages/starlette/requests.py", line 194, in body
    async for chunk in self.stream():
  File "/usr/local/lib/python3.7/site-packages/starlette/requests.py", line 179, in stream
    message = await self._receive()
  File "/usr/local/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 533, in receive
    await self.message_event.wait()
  File "/usr/local/lib/python3.7/asyncio/locks.py", line 293, in wait
    await fut
RuntimeError: Task <Task pending coro=<Request.body() running at /usr/local/lib/python3.7/site-packages/starlette/requests.py:194> cb=[run_until_complete.<locals>.<lambda>()]> got Future <Future pending> attached to a different loop

Googling it showed that this occurs when people mistakenly bring up two event loops and not reusing the same one, I wonder how could it happened in my case if each request is running in a different thread with a different event loop

To Reproduce

Steps to reproduce the behavior with a minimum self-contained file.

see https://github.com/Hedingber/fastapi-bug

Expected behavior

All requests should return 200 status code

Environment

• OS: macOS 10.14.2
• FastAPI 0.54.1
• Python 3.7.7

[phy25]

asyncio.run will start a separate event loop rather than using the existing loop I guess..? Refer to #1066.

[Hedingber]

@phy25 Thanks a lot for the fast response !
tl;dr changed to run_in_threadpool inside async def - worked !

After reading https://github.com/tiangolo/fastapi/issues/1066, https://github.com/tiangolo/fastapi/issues/825 and this post looks like the right way to go is to change the path operation to be async (async def) and use run_in_threadpool for the sync code.
I've verified it to be working both for the minified example, and for my production system.

Indeed my use of asyncio.run starts a separate loop, TBH my first try was to do asyncio.get_running_loop() but I got an exception claiming there's no running loop, so I thought that since I'm in a different thread I need to start a new loop.
I can't say I fully understand what's going on under the hood here that causes this to work most of the time, but fail in high load scenarios (probably some kind of race).

Anyways I suggest to add to the async related docs explanation on what's the way to go when you have both sync and async code in your path operation

[tiangolo]

Thanks for the help here @phy25 ! :bow:

Thanks for reporting back and closing the issue @Hedingber :+1: