The Challenges of Async Python Observability: Blackfire to the Rescue 3/3

By Sümer Cip, on Jan 27, 2022

Blog post series index:

Introduction to FastAPI and asyncio
Profiling Asynchronous Code
Blackfire to the Rescue (you are here)

Let’s run the same application with the latest version of Blackfire that supports asynchronous profiling by first taking a look at its call graph:

Blackfire Profile call-graph of an asyncio / FastAPI application

The information provided looks more accurate now. Coroutine suspends are not treated as separate function calls anymore. Wall-Time includes while CPU and Memory excludes information when a coroutine is suspended. In other words, when a coroutine suspends, e.g, starts waiting for any I/O task in the event loop, the CPU time does not get aggregated to the current coroutine. When it resumes back, we start aggregating CPU time again. Memory works in the same way. This accurately shows how much Wall/CPU time is spent inside the coroutine, like any regular function call.

In summary, Blackfire allows you to profile wall-time of the coroutines properly. The Wall-Time dimension shows you the exact time spent within the coroutine, including suspends. The CPU time shows you exactly how much CPU time is spent inside the coroutine, and the Memory dimension will show you the exact amount of memory the coroutine consumed/peaked.

What about FastAPI?

So far, we have talked about how Blackfire measures coroutines and asynchronous tasks. How does it fit with ASGI applications?

Blackfire only profiles single HTTP requests. This is to ensure that it could be used on production servers as it is only enabled on demand. Therefore, the overhead only affects the single HTTP request being profiled. Once the profiling process ends, the profiler hooks are removed.

With FastAPI, we need to profile a single HTTP request out of many concurrent ones. On a typical server, there are many requests being run concurrently. And we need to be able to isolate the one for which we started the profiler. 

In order to accomplish this, we used contextvars library. A Blackfire specific context var is set before starting the probe so that we only profile the requests/coroutines/asyncio.Tasks that have this Blackfire specific context variable set.

In summary, HTTP request profiling in ASGI works in the same way as we do in WSGI frameworks. You do not need to do anything special other than running your preferred ASGI capable web server using the blackfire-python command. And the first ASGI framework we support, without question, is FastAPI. The minimum supported version is 0.51.0.

Here is an example command to run an ASGI application via uvicorn with Blackfire:

blackfire-python uvicorn app.main:app

Subscribe to Blackfire Monitoring

Start a Blackfire Monitoring subscription today and set up the Continous Observability of your Python applications.

Happy Performance Optimization!

Sümer Cip

Sümer Cip is currently a Senior Software Engineer at Blackfire. He has been coding for nearly 20 years and contributed to many open source projects in his career. He has a deep love for Python and obsession with code performance and low-level stuff.