Hi - would someone know how to profile async SQLAlchemy operations with this?

This works in the sense that I get to see something, but the timing is always ~1ms, maybe because that's how quickly the initial call to the coroutine returns?

  "db_async_exec": (sqlalchemy.ext.asyncio.AsyncSession.execute,),

I also tried to add equivalents to the ResultProxy examples, but these are not correct, don't show up in the timings at all, probably these are just wrong functions.

  "db_async_fetch": (
      sqlalchemy.ext.asyncio.AsyncResult.fetchone,
      sqlalchemy.ext.asyncio.AsyncResult.fetchmany,
  )```

In the README, it says to use fastapi.routing.ModelField.validate in order to profile how long it takes to validate the response.

No matter which function calls I ask it to profile I'm able to get yappi to return a profile for the 3valid step.

    "3valid": (
        fastapi.routing.BaseModel.validate,
        fastapi.routing.ModelField.validate,
        pydantic.fields.BaseModel.validate,
        pydantic.fields.ModelField.validate
    ),

I can confirm by entering a debugger that these functions are being called, it's just that yappi isn't profiling them. I'm not entirely sure why.

I know you haven't looked in this in a while and you did so much research. to get this working in the first place. It's greatly appreciated!

Here's a repro:

import fastapi
import pydantic


from contextvars import ContextVar
from typing import Dict, List, Tuple, Callable
import re

import yappi
from fastapi import FastAPI
from yappi import YFuncStats

_yappi_ctx_tag: ContextVar[int] = ContextVar("_yappi_ctx_tag", default=-1)


def _get_context_tag() -> int:
    return _yappi_ctx_tag.get()


class ServerTimingMiddleware:
    """Timing middleware for ASGI HTTP applications

    The resulting profiler data will be returned through the standard
    `Server-Timing` header for all requests.

    Args:
        app (ASGI v3 callable): An ASGI application

        calls_to_track (Dict[str,Tuple[Callable]]): A dict of functions
            keyed by desired output metric name.

            Metric names must consist of a single rfc7230 token

        max_profiler_mem (int): Memory threshold (in bytes) at which yappi's
            profiler memory gets cleared.

    .. _Server-Timing sepcification:
        https://w3c.github.io/server-timing/#the-server-timing-header-field
    """

    def __init__(
        self, app, calls_to_track: Dict[str, Tuple[Callable]], max_profiler_mem: int = 50_000_000
    ):
        for metric_name, profiled_functions in calls_to_track.items():
            if len(metric_name) == 0:
                raise ValueError("A Server-Timing metric name cannot be empty")

            # https://httpwg.org/specs/rfc7230.html#rule.token.separators
            # USASCII (7 bits), only visible characters (no non-printables or space), no double-quote or delimiter
            if (
                not metric_name.isascii()
                or not metric_name.isprintable()
                or re.search(r'[ "(),/:;<=>?@\[\\\]{}]', metric_name) is not None
            ):
                raise ValueError(
                    '"{}" contains an invalid character for a Server-Timing metric name'.format(
                        metric_name
                    )
                )

            if not all(callable(profiled) for profiled in profiled_functions):
                raise TypeError(
                    'One of the targeted functions for key "{}" is not a function'.format(
                        metric_name
                    )
                )

        self.app = app
        self.calls_to_track = {
            name: list(tracked_funcs) for name, tracked_funcs in calls_to_track.items()
        }
        self.max_profiler_mem = max_profiler_mem

        yappi.set_tag_callback(_get_context_tag)
        yappi.set_clock_type("wall")
        yappi.set_context_backend("greenlet")
        yappi.start()

    async def __call__(self, scope, receive, send):
        ctx_tag = id(scope)
        _yappi_ctx_tag.set(ctx_tag)

        def wrapped_send(response):
            if response["type"] == "http.response.start":
                tracked_stats: Dict[str, YFuncStats] = {
                    name: yappi.get_func_stats(
                        filter=dict(tag=ctx_tag),
                        filter_callback=lambda x: yappi.func_matches(x, tracked_funcs),
                    )
                    for name, tracked_funcs in self.calls_to_track.items()
                }

                # NOTE (sm15): Might need to be altered to account for various edge-cases
                timing_ms = {
                    name: sum(x.ttot for x in stats) * 1000
                    for name, stats in tracked_stats.items()
                    if not stats.empty()
                }

                server_timing = ",".join(
                    [f"{name};dur={duration_ms:.3f}" for name, duration_ms in timing_ms.items()]
                ).encode("ascii")

                if server_timing:
                    # FIXME: Doesn't check if a server-timing header is already set
                    response["headers"].append([b"server-timing", server_timing])

                if yappi.get_mem_usage() >= self.max_profiler_mem:
                    yappi.clear_stats()

            return send(response)

        await self.app(scope, receive, wrapped_send)



track: Dict[str, Tuple[Callable, ...]] = {
    "1deps": (fastapi.routing.solve_dependencies,),
    "2main": (fastapi.routing.run_endpoint_function,),
    "3valid": (
        fastapi.routing.BaseModel.validate,
        fastapi.routing.ModelField.validate,
        pydantic.main.BaseModel.validate,
        pydantic.fields.ModelField.validate
    ),
    "4encode": (fastapi.encoders.jsonable_encoder,),
    "5render": (
        fastapi.responses.JSONResponse.render,
        fastapi.responses.ORJSONResponse.render,
    ),
}
app = FastAPI()
app.add_middleware(ServerTimingMiddleware, calls_to_track=track)


class Item(pydantic.main.BaseModel):
    name: int = pydantic.Field(description="name")
    val: int = pydantic.Field(description="val")


@app.get("/", response_model=List[Item])
def test():
    resp = [{"name": x, "val": x} for x in range(10000)]
    return resp

And here's the result from hitting localhost:8000/

inspect.isfunction returns False for Cython functions (see this discussion).

As a result, tracking pydantic.fields.ModelField.validate for pydantic==1.7.3 is impossible.

I don't really have much experience in the way of packaging and publishing python modules, but that's probably something I should get around doing if I want people to be able to use this.