pyinstrument icon indicating copy to clipboard operation
pyinstrument copied to clipboard

Better support for sync routes in FastAPI

Open joerick opened this issue 2 years ago • 6 comments

FastAPI profiling is complicated by the fact that-

If you use def instead of async def, FastAPI runs the request asynchronously on a separate default execution thread to not block IO. So it essentially runs everything async for you under the hood whether you want it or not. Adding async def to the app signals FastAPI to not use that separate default execution thread, which ironically WILL block IO unless the application uses await somewhere down line to free up the thread for handling another request.

Originally posted by @coneybeare in https://github.com/joerick/pyinstrument/issues/219#issuecomment-1291239186

This means that non-async routes in FastAPI don't show up in the profile output. Async routes work fine. Perhaps there's a way we could create a first-party middleware for this? I'm not a FastAPI user, so PRs would be welcome.

joerick avatar Jul 22 '23 18:07 joerick

Perhaps there's a way we could create a first-party middleware for this?

would really love to see this

spolloni avatar Dec 06 '23 00:12 spolloni

Hi~ IMO a broader request is to support tracking "sync-to-async" function execution in general (not limited to sync routes), which would be tremendously useful to profile FastAPI services that use a mix of asyncio/coroutines and thread(s)/threadpool(s) to execute synchronous IO functions. Currently, when async code executes a sync function in a separate thread/threadpool:

def blocking_io_fn(param):
   # do some IO work

async def api_route():
   ...
   await asyncio.to_thread(blocking_io_fn, arg)
   ...
   # or we can execute concurrent blocking operations in threadpool
   corotines = [
      asyncio.get_event_loop().run_in_executor(None, blocking_io_fn, i) for i in range(5)
   ]
   await asyncio.gather(*corotines)

the profiling result completely loses any info about blocking_io_fn, the result would contain something like [await] or epoll.poll which is not useful at all...

lambyqq avatar Feb 28 '24 04:02 lambyqq

here's a dummy example (I'm using asgiref.sync.SyncToAsync as convenient helper to execute sync func in threadpool while propagating context, noticing that loop.run_in_executor() does not propagate context by default):

from asgiref.sync import SyncToAsync

async def api_route():
        def _dummy_fn():
            sleep(random.uniform(1.0, 2.0))

        await asyncio.gather(
            *[SyncToAsync(_dummy_fn, thread_sensitive=False)() for _ in range(8)])

Then profiling result looks like: image which isn't useful at all (except that it indicates we are gathering & awaiting 8 futures), but it doesn't show any information about _dummy_fn

lambyqq avatar Feb 28 '24 17:02 lambyqq