asgi-server-timing-middleware
asgi-server-timing-middleware copied to clipboard
`pydantic.fields.ModelField.validate` doesn't work anymore
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/

I wonder if the validate option is only for request validation and not for response validation.
I'm just confirming what I believe is the same problem. I get an error with Pydantic 1.8.2:
"3valid": (pydantic.fields.ModelField.validate,),
TypeError: One of the targeted functions for key "3valid" is not a function
Edit: Ah-ha.
In[1]: type(pydantic.fields.ModelField.validate)
Out[1]: cython_function_or_method
inspect.isfunction() will therefore not recognize pydantic.fields.ModelField.validate.
I have forked this repository to implement a fix.
IIUC, this issue is same as #3. Please do not hesitate to open a PR against yappi as well. I will happily merge.
Thank you!