Provide timing data for things FastAPI does outside of user code

[sm-Fifteen]

Is your feature request related to a problem? Please describe.
I currently find myself using FastAPI as an API frontend for a database running queries of varying levels of complexity that usually return fairly large quantities of data. The problem I have is that, when attempting to figure out why an API request is taking time to respond, there's a lot going on outside of what fencing the code inside your route with the usual time_start = time.time(), time_delta = time.time() - time_start won't tell you.

In your average FastAPI application, there's 4 main causes for slowdowns:

• Endpoint code running (app)
• Waiting for the database (io)
• Data validation (pydantic)
• Data serialization (json/ujson)

Of those 4, only the first two are actually part of the user code, the other two are handled behind the scenes by FastAPI. If I'm testing a route that's returning 50MBs of JSON (for whatever reason), it's actually rather tricky to determine whether switching from json to ujson or orjson will have any performance benefit or if the slowdown is coming from Pydantic choking on the sheer amount of data being fed to it or the database being slow.

Describe the solution you'd like
Given FastAPI is performing operations outside of what the user can observe or measure, it should probably expose timing data for those things in some way (especially validation and serialization, since I doubt routing is going to factor a lot in the processing time). I don't know how the implementation should go, though, given any middleware is only going to receive a Starlette Response object and FastAPI probably shouldn't be doing this sort of thing automatically anymore than it does with CORS. The Response object could probably be extended in some way to contain some sort of timing dict, though that's sure to cause all sorts of compatibility issues, so I don't know whether that can be done without some upstream work with Starlette.

Describe alternatives you've considered
I was initially trying to write a middleware for this, but python's own cProfile is limited to text file export, so processing the data in Python becomes an extra hurdle, if the format is even stable enough for that. Without using a profiler, ASGI middlewares simply don't have access to timing information for the app besides the total time spent awaiting the callable.

Additional context
The recently introduced Server-Timing HTTP header seems like a perfect way to push coarse profiling information to make debugging those cases somewhat easier, especially given how it's supported in the Chrome devtools and that Firefox support for it is just around the corner. That's probably beyond the scope of that issue, though.

[dmontagu]

A couple tangential profiling-related notes that may be of interest to anyone working with "50MBs of JSON"-sized payloads:

Click to expand

• Serialization may also involve two (potentially very costly!) steps: 1) if specifying a response_model, where the returned data is parsed into the response_model, and 2) in all cases unless you return a Response directly, where fastapi.encoders.jsonable_encoder is used to convert your output to json.
  • For payloads with long lists or dicts with many keys this function call is not cheap, and unless you return a Response or one of its subclasses from your endpoint, in most cases, the cost of jsonable_encoder will probably dwarf the call to json.dumps or faster alternatives from other packages.
• For faster creation of pydantic model instances, consider using BaseModel.construct if you know the input data doesn't require parsing (e.g., whenever you perform the instantiation yourself in a type-safe way, rather than relying on fastapi's parsing machinery).
  • I profiled this method at ~30-40x faster than calls to BaseModel.__init__, even for relatively small payloads.
  • The API is a little awkward in pydantic v0.32.2 since you have to pass the values as a dict (and have to specify the fields set), but starting in v1 it has the same API as the __init__ calls and is even type-checked by the pydantic mypy plugin (a good reason for FastAPI to update to pydantic v1 as soon as possible!).

---

Addressing the main point brought up in this issue, I think it might be worth looking into yappi -- if you look at the docs for the get_func_stats function and the YFuncStat class, it looks like it should be relatively easy to package up the profiling results inside an ASGI middleware. (Also, for what it's worth, it has built-in support in PyCharm.)

I'm not very familiar with the Server-Timing header, but based on a quick skim of the linked docs, it seems that such a yappi ASGI middleware could return Server-Timing headers for each of its YFuncStat instances, presumably with some (configurable) filtering and formatting. (Obviously it could also just log the results to the console.)

[sm-Fifteen]

A couple tangential profiling-related notes that may be of interest to anyone working with "50MBs of JSON"-sized payloads:

Ah, that's interesting, I'd usually just build my own RawJSONResponse class and handle json conversion on my own so I could bypass Pydantic entirely, but this is certainly much cleaner if you trust your input source.

Addressing the main point brought up in this issue, I think it might be worth looking into yappi -- if you look at the docs for the get_func_stats function and the YFuncStat class, it looks like it should be relatively easy to package up the profiling results inside an ASGI middleware. (Also, for what it's worth, it has built-in support in PyCharm.)

I'm not very familiar with the Server-Timing header, but based on a quick skim of the linked docs, it seems that such a yappi ASGI middleware could return Server-Timing headers for each of its YFuncStat instances, presumably with some (configurable) filtering and formatting. (Obviously it could also just log the results to the console.)

Thanks for pointing out yappi. I've tried the middleware solution with it, and while it's working well enough, it runs into the issue where, since profiling is global, if a route is called while another one is running, the profiler gets confused and the resulting profiling data will be incorrect or missing.

from starlette.middleware.base import BaseHTTPMiddleware
from starlette.responses import Response
from starlette.requests import Request

import fastapi
import json
import sqlalchemy

import yappi

class BenchMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next) -> Response:
        yappi.start()
        response = await call_next(request)
        yappi.stop()

        #yappi.get_func_stats().sort('ttot', sort_order="desc").print_all() # All time

        db_exec_time = yappi.get_func_stats(dict(name=sqlalchemy.engine.base.Engine.execute.__qualname__))
        #db_fetch_time = yappi.get_func_stats(dict(name=sqlalchemy.engine.result.ResultProxy.fetchone.__qualname__))
        pydantic_time = yappi.get_func_stats(dict(name=fastapi.routing.serialize_response.__qualname__))
        render_time = yappi.get_func_stats(dict(name=response.render.__qualname__))

        server_timing = []

        if not db_exec_time.empty():
            server_timing.append(f"db_exec;dur={(db_exec_time.pop().ttot * 1000):.3f}")

        if not pydantic_time.empty():
            server_timing.append(f"pydantic;dur={(pydantic_time.pop().ttot * 1000):.3f}")

        if not render_time.empty():
            server_timing.append(f"render;dur={(render_time.pop().ttot * 1000):.3f}")

        yappi.clear_stats()
        response.headers["Server-Timing"] = ','.join(server_timing)
        return response

Because of that, I doubt that can be "correctly realized" on an async framework like FastAPI using a regular profiler, since I'd ideally want to leave this sort of performance collection online to facilitate performance analysis in real-world use cases.

Server-Timing is working as I'd hoped, though.

[dmontagu]

Haha, that's some heavy pydantic!

Yappi is able to track threads appropriately; I'm wondering if there is a way to use async contextvars in python 3.7 to achieve similar functionality. I'll look into it.

[dmontagu]

Aha! It looks like you can override the context id callback with yappi!

See here: https://github.com/sumerc/yappi/blob/master/yappi.py#L938

I think we could use a contextvar for this and should be able to get proper per-request profiling! (In Python >=3.7)

[sm-Fifteen]

Haha, that's some heavy pydantic!

Seems like it's actually half jsonable_encoder and half Field.validate. But yeah, it's 6 or so sets of 9600 datapoints each, separated in arrays of 100 floats keyed by ISO8601 datetime. It's a good stress test, I'd say, even if common sense would advise to just return this as a CSV instead.

Aha! It looks like you can override the context id callback with yappi!

See here: https://github.com/sumerc/yappi/blob/master/yappi.py#L938

I think we could use a contextvar for this and should be able to get proper per-request profiling! (In Python >=3.7)

You seem to have a pretty clear idea of how that could be done. I haven't had the occasion to use contextvars yet, so could you show me how you would go about doing that?

[sm-Fifteen]

I looked into it a little, and I'm assuming you mean something along those lines?

import contextvars

profiler_ctx_id = contextvars.ContextVar('profiler_ctx_id')

yappi.set_context_id_callback(lambda: profiler_ctx_id.get())

class BenchMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next) -> Response:
        ctx_token = profiler_ctx_id.set(id(asyncio.current_task())) # Set unique id in context

        yappi.start()
        response = await call_next(request)
        yappi.stop()

(Guess I should update to python 3.7 or 3.8, since the contextvars backport for 3.6 doesn't work with asyncio)

[dmontagu]

I think there is a package called aiocontextvars which works with python 3.6.

This is what I have in mind:

from contextvars import ContextVar
from typing import Dict

import yappi
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
from starlette.responses import Response
from starlette.types import ASGIApp
from yappi import YFuncStats

yappi_request_id = ContextVar('yappi_request_id')
yappi_request_id.set(-1)


def get_context_id() -> int:
    try:
        return yappi_request_id.get()
    except LookupError:
        return -2


yappi.set_context_id_callback(get_context_id)


class BenchMiddleware(BaseHTTPMiddleware):
    def __init__(self, app: ASGIApp, calls_to_track: Dict[str, str]) -> None:
        self.calls_to_track = calls_to_track
        super().__init__(app, None)

    async def dispatch(self, request: Request, call_next) -> Response:
        ctx_id = id(request)
        yappi_request_id.set(ctx_id)
        response = await call_next(request)

        tracked_stats: Dict[str, YFuncStats] = {}
        for name, call_to_track in self.calls_to_track.items():
            tracked_stats[name] = yappi.get_func_stats({"name": call_to_track, "ctx_id": ctx_id})

        server_timing = []
        for name, stats in tracked_stats.items():
            if not stats.empty():
                server_timing.append(f"{name};dur={(stats.pop().ttot * 1000):.3f}")
        if server_timing:
            response.headers["Server-Timing"] = ','.join(server_timing)
        return response


# ######################
# ##### Usage test #####
# ######################
import asyncio

import fastapi
import sqlalchemy
from httpx import AsyncClient
from fastapi import FastAPI

yappi.start()  # If you don't start yappi, stats.empty() will always be true
app = FastAPI()


@app.get("/")
async def context_id_endpoint() -> int:
    await asyncio.sleep(1)
    return get_context_id()


track: Dict[str, str] = {
    "db_exec": sqlalchemy.engine.base.Engine.execute.__qualname__,
    "pydantic": fastapi.routing.serialize_response.__qualname__,
    "render": Response.render.__qualname__,
    "endpoint": context_id_endpoint.__qualname__
}
app.add_middleware(BenchMiddleware, calls_to_track=track)


async def main():
    client = AsyncClient(app=app, )
    tasks = [client.get("http://www.example.org/") for _ in range(5)]
    resps = await asyncio.gather(*tasks)
    for resp in resps:
        print(f"Request ID: {resp.json()}")
        print(f"Server Timing: {resp.headers.get('server-timing')}")
        print("-----")


if __name__ == '__main__':
    asyncio.run(main())

"""
Request ID: 4451087568
Server Timing: pydantic;dur=0.980,render;dur=0.003,endpoint;dur=0.248
-----
Request ID: 4451120784
Server Timing: pydantic;dur=0.083,render;dur=0.003,endpoint;dur=0.227
-----
Request ID: 4451140944
Server Timing: pydantic;dur=0.057,render;dur=0.002,endpoint;dur=0.296
-----
Request ID: 4451161168
Server Timing: pydantic;dur=0.048,render;dur=0.003,endpoint;dur=0.196
-----
Request ID: 4451169104
Server Timing: pydantic;dur=0.047,render;dur=0.004,endpoint;dur=0.192
-----
"""

There is a little more tweaking to do here, but I wanted to share progress now.

[dmontagu]

Potential problems:

1. I can't figure out how to track time spent awaiting async calls -- clearly that isn't showing up in the printouts of the endpoint duration. Using yappi.set_clock_type("wall") also doesn't help with await calls.

   This shouldn't matter too much if the goal is just to find cpu bottlenecks (e.g., related to serialization), and it shouldn't be a problem if you use def endpoints to achieve non-blocking IO, but it means that you can't get wall-time profiling for asyncio-based io. This seems kind of unfortunate for an ASGI middleware.

2. It would be nice if there was an easier way to track stats by module and function name; there is a way to filter by the "full_name", and to strip dirs from the filenames, but it annoyingly includes line numbers. Maybe that's fine for now, or maybe there is an easy way to just pass the callable itself to the middleware, and use the yappi function directly to determine the full_name.

[sm-Fifteen]

1. I can't figure out how to track time spent awaiting async calls -- clearly that isn't showing up in the printouts of the endpoint duration. Using `yappi.set_clock_type("wall")` also doesn't help with `await` calls.

Yeah, that's going to be tricky, since you'd probably have to monitor something like Task._step() or whatever the event loop stays parked in when it has nothing to do (if that's even possible). I looked it up and asyncio doesn't offer any sort of hook to keep track of how much time a task has spent running or suspended (or blocked from resuming because the event loop is busy). A lot of existing profilers "work" with async, but they don't neccesarily make it easy to get that sort of metric.

2\. It would be nice if there was an easier way to track stats by module and function name; there is a way to filter by the "full_name", and to strip dirs from the filenames, but it annoyingly includes line numbers. Maybe that's fine for now, or maybe there is an easy way to just pass the _callable itself_ to the middleware, and use the yappi function directly to determine the full_name.

I've seen a dir-stripping method in their doc, so that part shouldn't be an issue. Regarding gearing the middleware to take callables as parameters... yeah, that's not a bad idea. Those functions have enough introspection data to make it possible to derive what to feed the profiler to get info on them. Your other concerns would probably only affect the result of printing the complete output, though, not the headers I was planning to use, so that shouldn't be too much of a problem (although that could also be logged somewhere else, I don't know).

[sm-Fifteen]

Also, I can't seem to get your version running properly, I only get the following error message.

[*] [yappi-err] context id callback returned non-integer
Request ID: 2466563236480
Server Timing: None
-----
Request ID: 2466563267168
Server Timing: None
-----
Request ID: 2466563273776
Server Timing: None
-----
Request ID: 2466563274736
Server Timing: None
-----
Request ID: 2466563275696
Server Timing: None
-----

https://github.com/sumerc/yappi/blob/afb2cffa815bae84c649fee43ea2b63419716a7a/_yappi.c#L227-L242

I'm not entirely sure what's causing this, no exception seems to even be thrown and debugging C modules is not as straightforward as pure Python.

[sumerc]

Hello everyone, I am the author of yappi and as I said in the issue opened by @dmontagu sumerc/yappi#21 , I would be more than happy to try my best helping you guys regarding profiling async. code.

I have not been able to digest all the information in this thread but if you need help please do not hesitate.

For the last question:
[*] [yappi-err] context id callback returned non-integer
This error means the context_id_callback returns a value that fails PyLong_AsLong() like you have suggested. Is it possible you return None or any other object other than an integer in that function somehow?

[sumerc]

And regarding the other problem(wall time is not being correct). IIRC, this was something we have solved for gevent library. See this code here: https://github.com/ajdavis/GreenletProfiler/blob/700349864a4f368a8a73a2a60f048c2e818d7cea/_vendorized_yappi/_yappi.c#L577

_pause_ctx()
_resume_ctx()

So, every time a ctx switch occurs, meaning context_id returned a different value, we simply pause_ctx and when it is resumed we call _resume_ctx which updates the internal call_stack time values by the factor of pause duration which should probably give correct results.

Please tell me this was your problem. I might have misunderstood the root of the problem here.

[dmontagu]

@sumerc Thanks for all the help! This may well solve the problem; I'll try it out.

@sm-Fifteen I'm running it in Python 3.7; is that a difference? Maybe try using aiocontextvars instead of contextvars in python 3.6?

[sm-Fifteen]

Hello everyone, I am the author of yappi and as I said in the issue opened by dmontagu sumerc/yappi#21 , I would be more than happy to try my best helping you guys regarding profiling async. code.

I have not been able to digest all the information in this thread but if you need help please do not hesitate.

Don't worry about the FastAPI and other web-framework specifics, the main thing you should know is that we're trying to get profiling results (mainly just total runtime) for specific functions and coroutines, and having multiple concurrent but unrelated async Tasks running on the same thread is leading to some interesting issues.

[*] [yappi-err] context id callback returned non-integer
This error means the context_id_callback returns a value that fails PyLong_AsLong() like you have suggested. Is it possible you return None or any other object other than an integer in that function somehow?

I'm running it in Python 3.7; is that a difference? Maybe try using aiocontextvars instead of contextvars in python 3.6?

Disregard that, it's most likely related to how I upgraded my venv from Python36 to Python38; I did some more tests and I have a number of other libraries that are now complaining about version mismatches.

Traceback (most recent call last):
    from pyexpat import *
ImportError: Module use of python36.dll conflicts with this version of Python.

I'll try again with a fresh venv when I get time. If not, it's probably just my environment variables being misconfigured.

[sumerc]

I am also writing here for reference: (along with sumerc/yappi#21)

I have done few experiments on python 3.7 for coroutine wall-time profiling. It is in very alpha stage(far from production ready) but seems to work on cases I had thrown. It would be great if you guys would like to play with it.

The test branch name is coroutine-profiling.

Please send your valuable feedback.

[sumerc]

what is the total pit count ?

It was a typo left for debugging something...

Ok. I think you can also continue testing in parallel and I will be informing you after implementing the filtering. Maybe also do CPU time testing...etc.. not sure about use cases.

Then before release: I need to make sure all code works for all Python versions and write more and more tests. But meanwhile hopefully you can start integrating yappi into your workflow :)

Thanks again guys!

[sumerc]

Ok. This will hopefully be my final update:
I have done few changes related to get_func_stats() again: implemented filtering on C side and moved same tags into same hashtables. With these improvements, now 1000 concurrent requests is being done in ~3.7 secs! which seems to indicate 10x improvement. I think we no more need filtering on clear_stats() as the number of tags does not affect performance anymore while filtering on tag.(as we use a hashtable underneath.)

Anyway, I will be finalizing the tests and hopefully will be releasing a new version which includes lots of new, exciting stuff. Looking forward to your latest feedback and use cases in FastAPI, too, of course.

[euri10]

looking forward to test your latest improvments but so far even before the hashtable it was perfect ! thanks a lot @sumerc

[sm-Fifteen]

I think we no more need filtering on clear_stats() as the number of tags does not affect performance anymore while filtering on tag.(as we use a hashtable underneath.)

What if I were to leave the profiler running on a test server for several days or weeks, wouldn't the inability to "garbage collect" old profiling data cause memory or performance issues?

[sumerc]

What if I were to leave the profiler running on a test server for several days or weeks, wouldn't the inability to "garbage collect" old profiling data cause memory or performance issues?

I am not expecting performance issues, but we sure might have some memory issues. Maybe it would be better to implement this, but let's postpone as currently there is lots of code written for this feature and I really do not want to complicate things more.

And for your scenario: you can always call clear_stats() at 10000 request or in some specific interval like per-day. If the server is running several days/weeks I think having a few invalid profile calculations for couple of requests might not be so important after all.

[sumerc]

Guys!

Thank you for all your help on this. Today, I have released a new version of Yappi(1.2.1). You can hopefully use it via installing from pip. I have updated the docs as well and written a bit more about coroutine profiling here: https://github.com/sumerc/yappi/blob/coroutine-profiling/doc/coroutine-profiling.md.

Please send me if you find any problems/inconsistencies with the new release. And for the future: I am open to any new suggestions on profiling async. code. Please do not hesitate to discuss/ask anything you think might help you making the code faster.

I will be adding your names on THANKS, that is all I can do at this time:)

[sm-Fifteen]

This is fantastic! Way to set Yappi appart from any other python profiler, even the official ones. I also need to thank you for all the time and effort you've put into supporting this idea I was just throwing out there as a possible feature to integrate into the framework. I didn't even think it was possible to profile coroutines in Python, and as it turns out, I was right...

...but now, only a month later, thanks to you, it's now possible. So thank you, @sumerc! And here's to yappi becoming the go-to profiler for all async programs!

[sm-Fifteen]

So I'm getting pretty good results with this test middleware and the following config for FastAPI:

from fastapi import FastAPI
app = FastAPI(debug=DEBUG, openapi_prefix=PATH_PREFIX)

import fastapi
import starlette.responses
import sqlalchemy.engine.base
app.add_middleware(ServerTimingMiddleware, calls_to_track={
    # All steps of the generated fastapi.routing.get_request_handler app
    "1deps": fastapi.routing.solve_dependencies.__qualname__, # `Depends` execution
    #"2endpoint": fastapi.routing.get_request_handler.?????.__qualname__,
    "3valid": fastapi.routing.ModelField.validate.__qualname__, # Pydantic model validation
    "4encode": fastapi.encoders.jsonable_encoder.__qualname__, # JSON encoding
    #"5render": starlette.responses.Response.render.__qualname__, # Respnse (JSON) rendering

    # Extra measurements
    "db_exec": sqlalchemy.engine.base.Engine.execute.__qualname__,
    #"db_fetch": sqlalchemy.engine.ResultProxy.fetchone.__qualname__,
})

I still can't figure how (generically) to get timing for the endpoint and response rendering execution. Response rendering is a problem because there's no easy way to connect starlette.responses.Response.render with starlette.responses.JSONResponse.render since they're two different functions (even though as methods they override each other).

Meanwhile, endpoint duration is a problem because the endpoint executor doesn't have a qualified name, it's executed as part of the app closure inside get_request_handler:

https://github.com/tiangolo/fastapi/blob/8d3dcbcd1bb93bc0563eea5e98688d9dc4867e00/fastapi/routing.py#L125-L129

That means there's no single named function I can profile to get the endpoint execution time. Unless we extract those lines into some async def execute_endpoint(dependant) at the root of the module, I don't know if that one is going to be possible.

[tiangolo]

Thanks everyone for all the conversation here! 👏 🤓

I'm amazed by the value I see you generated here with your combinations of ideas. 😮 ✨

Thanks a lot @sumerc for all the effort you put into adding support for these async tools. 🚀 💪 🎉

Did anyone of you publish the middleware as a package? I see @dmontagu 's fastapi-utils Timing middleware is quite similar, but doesn't use yappi, right? https://fastapi-utils.davidmontague.xyz/user-guide/timing-middleware/

I tried @sm-Fifteen 's implementation from the comment there and I got stats in the developer tools in the browser. That's awesome! 🚀

I think that deserves existing as a published ASGI middleware package.

Maybe@sm-Fifteen could publish it, or @dmontagu could include it in fastapi-utils?

Also, trying it locally I had to change the line:

response['headers'].append(["server-timing", b','.join(server_timing)])

to

response['headers'].append([b"server-timing", b','.join(server_timing)])

(b"server-timing" as bytes).

---

@sm-Fifteen about timing the endpoint alone, I see the value in this and in being able to time just the endpoint duration. Would you like to send a PR putting that in a separate function?

[sm-Fifteen]

I tried @sm-Fifteen 's implementation from the comment there and I got stats in the developer tools in the browser. That's awesome! 🚀

Thanks! 😄 I'm a bit impressed myself at how well this all turned out.

I think that deserves existing as a published ASGI middleware package.

Maybe @sm-Fifteen could publish it, or dmontagu could include it in fastapi-utils?

Also, trying it locally I had to change the line:

response['headers'].append(["server-timing", b','.join(server_timing)])

to

response['headers'].append([b"server-timing", b','.join(server_timing)])

(b"server-timing" as bytes).

Yeah, I probably missed a few things here or there. Like I said in that other post, this was more meant as a WIP proof-of-concept, and I was worried about a few remaining yappi issues (namely: "How should the profiler free memory?", "What's a reliable way to tell yappi to profile a specific function?") (also raised by dmontagu) causing problems so I haven't touched it much since. I can probably just polish up what's there, add a memory threshold where the middleware just wipes the profiler memory so it doesn't inflate until Python goes OOM, add a README listing the caveats and publish it.

@sm-Fifteen about timing the endpoint alone, I see the value in this and in being able to time just the endpoint duration. Would you like to send a PR putting that in a separate function?

Well,, if you're open to it, then I might as well. It's certainly going to be easier than the crazy solution I was considering, where I somehow time get_request_handler.<locals>.app and substract the duration of everything else.

[tiangolo]

I think that we now have a clear way to solve this and all the pieces in place on the FastAPI side.

The only piece missing is a third-party middleware (or just these snippets properly configured).

But as that would be on a third-party package, I think we can close this issue on the FastAPI side, right @sm-Fifteen ?

[sm-Fifteen]

@tiangolo: Pretty much. I'm going to release this as a proper middleware in the near future; I've mainly been holding off on it because the current way of determining if a function in the profiler's data matches one of the targeted ones is currently incorrect (see sumerc/yappi#22) due to a few implementation details in CPython that I wouldn't want to couple a simple ASGI middleware with.

The next release of Yappi addresses this by letting users match functions by their descriptors instead of their name (see sumerc/yappi#41), so once that lands, I'll probably make PR to add it in the FastAPI documentation or something like that. Whether you would rather keep this issue open until then, or consider the problem generally solved is up to you.

[acnebs]

Is it possible to use this solution to time Starlette middlewares themselves, given that this is itself a middleware?

I am currently evaluating APM solutions (and their respective middlewares), and it would be very helpful if I could get some idea of the performance impact each one is having.

[sm-Fifteen]

@acnebs: As long as they're registered to run after the profiling middleware (because the context variables wouldn't be registered otherwise), maybe, although making sure that only the target middleware gets timed and not the rest of the application (since middleware have to call the next ASGI callable with the scope as part of their activity, meaninng they are always part of the application's callstack) might prove a bit tricky. The middleware I have right now can only return the end-to-end execution duration for the functions specified and I don't really know how complex I want to make that middleware.

[antoniogamizbadger]

Any updates on this?

[sm-Fifteen]

To my knowledge, there weren't any such explicit performance hooks added to FastAPI. The middleware on my Github still mostly works, although it would need some tweaks to be able to recognize Pydantic V2 and orjson's native functions. The required changes would be fairly minor, but I've just not taken the time to go back to that project yet.