FastAPI のパフォーマンス分析
FastAPI で作った WebAPI について、どの処理に時間がかかっているかをプロファイリングで調べる方法を紹介します。私は WebAPI の開発で FastAPI をよく使っており、何度かパフォーマンスを改善したい場面があったので調べました。
プロファイリングの方法
私が観測している範囲では、次のようなツールでプロファイリングできます。
今回メインで取り上げるのはfastapi_profilerです。他の 2 つの概要は次のとおりです。
| ツール | 概要 | 連携 |
logfire | Pydantic チームが開発するサービス。OpenTelemetry でデータを送信し、リクエストをトレースする | Pydantic、FastAPI、OpenAI のフレームワーク |
OpenTelemetry | 分散トレーシングのためのプロジェクトで、FastAPI にも導入できる | 各クラウドプロバイダーのサービス |
logfireは 2024/05/03 時点ではベータ版で、無料で利用できます。続く節では、メインで使うfastapi_profilerのインストール方法と使い方を説明します。
fastapi_profiler
fastapi_profilerは FastAPI のミドルウェアとして動作するプロファイリングツールで、FastAPI のリクエストに対してプロファイリングできます。内部ではpyinstrumentを使っており、リクエストごとの処理時間や、各 Python コードの処理時間を計測できます。
インストール
| pip install fastapi_profiler
|
使い方
FastAPI のミドルウェアとしてPyInstrumentProfilerMiddlewareを追加するだけで利用できます。
| import time
import uvicorn
from fastapi import FastAPI
from fastapi.responses import JSONResponse
from fastapi_profiler import PyInstrumentProfilerMiddleware
app = FastAPI()
app.add_middleware(PyInstrumentProfilerMiddleware)
@app.get("/test")
async def normal_request():
time.sleep(1)
return JSONResponse({"retMsg": "Hello World!"})
if __name__ == '__main__':
uvicorn.run(app=app, host="0.0.0.0", port=8080, workers=1)
|
/testにリクエストを送信すると、次のようなログが出力されます。
| INFO: 127.0.0.1:54872 - "GET /test HTTP/1.1" 200 OK
Method: GET, Path: /test, Duration: 1.0088946190662682, Status: 200
_ ._ __/__ _ _ _ _ _/_ Recorded: 07:11:39 Samples: 83
/_//_/// /_\ / //_// / //_'/ // Duration: 1.009 CPU time: 0.009
/ _/ v4.6.2
Program: /tmp/pants-sandbox-ETDYpC/sandbox/fastapi-profiler/app.py
1.009 PyInstrumentProfilerMiddleware.__call__ fastapi_profiler/profiler.py:66
`- 1.009 ExceptionMiddleware.__call__ starlette/middleware/exceptions.py:49
[10 frames hidden] starlette, fastapi
1.001 run_endpoint_function fastapi/routing.py:183
`- 1.001 normal_request sandbox/fastapi-profiler/app.py:14
`- 1.000 sleep <built-in>
|
今回の例は単純ですが、複雑な処理を行うコードでも各関数や行レベルで計測してくれるので、ボトルネックを特定するのに便利です。fastapi_profiler の設定例のように設定すれば、HTML や JSON でも出力できます。
利用時の注意
私が試した環境では、このミドルウェアを有効にしたままリクエストを繰り返すと、徐々に処理が遅くなりました。継続して使う場合は、リクエストを繰り返したときの処理時間も確認してください。