Go to Qiita Advent Calendar Top
LoginSignup
0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

@sho5330(sho)

【FastAPI】リクエスト毎にIDを発行してログに使う

Last updated at Posted at 2025-12-20

この記事で紹介すること

  • FastAPI, Uvicorn のインストール
  • FastAPIのミドルウェアを使用してエンドポイント処理の前後にコードを仕込む
    • デコレータ @app.middleware('http') を使ったミドルウェア関数定義
    • BaseHTTPMiddleware を継承したミドルウェアクラス定義
    • 複数のミドルウェアを実装した場合の処理順序

FastAPI, Uvicorn のインストール

FastAPI 本体とこれを動かすためのASGIサーバをインストールする。

  • FastAPI: Python製のWebフレームワーク。データ検証ライブラリの Pydantic や 軽量ASGIフレームワークの Starlette が含まれている
  • Uvicorn: ASGIサーバー。FastAPIアプリを実行するために使う
# pipを使ってFastAPIとUvicornをインストール
$ pip install fastapi uvicorn

# または、uvを使ってFastAPIとUvicornをインストール
$ uv add fastapi uvicorn

最小FastAPIアプリの作成

まずは、以下のエンドポイントを持つ最小構成の FastAPI アプリを作る。
ついでに logging モジュールを使ったログ出力も行う。

  • /ping: パラメータは受け取らず、{"message":"pong"} を返す疎通確認用エンドポイント
main.py
import logging

from fastapi import FastAPI


# logging設定
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)


# FastAPIアプリケーションの作成
app = FastAPI()


@app.get('/ping')
async def ping():
    """pingエンドポイント"""
    logging.info('`/ping` が呼ばれました')
    return {'message': 'pong'}

Uvicorn で FastAPI アプリを実行する。--reload オプションを付けると、コード変更時 (保存時) に自動で再起動してくれる。開発時には便利。

$ uvicorn main:app --reload
INFO:     Will watch for changes in these directories: ['/path/to/your/project']
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [25168] using StatReload
INFO:     Started server process [30948]
INFO:     Waiting for application startup.
INFO:     Application startup complete.

別のターミナルで /ping エンドポイントにアクセスする。

$ curl -v http://127.0.0.1:8000/ping
{"message":"pong"}

一方、Uvicorn を実行しているターミナルでは、pingエンドポイントが呼ばれたというログとUvicornが出力するアクセスログを確認できる。

2025-12-20 17:16:16.048 INFO `/ping` が呼ばれました
INFO:     127.0.0.1:49220 - "GET /ping HTTP/1.1" 200 OK

ミドルウェア を使ってエンドポイント処理の前後にコードを実行する

API処理の前後に何かコードを仕込むためには、Middleware を使う。Middleware - FastAPI

処理の流れは以下の通り。

  1. リクエストを受け取る
  2. ミドルウェアに渡す
    1. 前処理を実施 (IDの生成など)
    2. 次の ミドルウェア or エンドポイント に渡す
    3. 後処理を実施 (ログの出力など)
  3. レスポンスを返す

デコレータ @app.middleware('http') を使ったミドルウェアの定義

@app.middleware('http') デコレータを使ってミドルウェアを定義する。
今回はUUIDv4でランダムな値を発行しリクエストIDとして使用する。
エンドポイントの前後やエンドポイント内でログを仕込み、挙動を確認する。

Request / Response インスタンスでは、state 属性に任意の値を保存することができるため、request.state.id = request_id のようにしてリクエストIDを埋め込む。
Applications - Starlette

main.py
import logging
from uuid import uuid4

from fastapi import FastAPI, Request, Response


# logging設定
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)


# FastAPIアプリケーションの作成
app = FastAPI()


@app.middleware('http')
async def add_request_id(request: Request, call_next) -> Response:
    """リクエストID付与ミドルウェア"""
    # リクエストIDを生成
    request_id = str(uuid4())
    # リクエストオブジェクトにリクエストIDを追加
    request.state.id = request_id
    # ログにリクエストIDを出力
    logging.info(f'リクエストID付与(リクエスト): {request.state.id}')

    # 次のミドルウェアまたはエンドポイントを呼び出す
    response = await call_next(request)

    # ログにレスポンスのステータスコードを出力
    logging.info(
        f'リクエストID付与(レスポンス): {request.state.id}'
        f' {response.status_code}'
    )
    # レスポンスを返す
    return response


@app.get('/ping')
async def ping(request: Request):
    """pingエンドポイント"""
    # リクエストID付きでログ出力
    logging.info(
        f'`/ping` が呼ばれました: {request.state.id}'
    )
    return {'message': 'pong'}

再度 /ping エンドポイントにアクセスする。

$ curl -v http://127.0.0.1:8000/ping
{"message":"pong"}

uvicorn コマンドで --reload オプションを指定していると、自動的にコードが再読み込みされる。もし実行結果が変化しない場合は再度 uvicorn コマンドを実行してみること。

そのころ、Uvicorn 側では、各地点でのログが出力されている。

2025-12-20 17:16:52.568 INFO リクエストID付与(リクエスト): c8d67e05-bbcb-4d5a-8cc2-f25e77088d75
2025-12-20 17:16:52.569 INFO `/ping` が呼ばれました: c8d67e05-bbcb-4d5a-8cc2-f25e77088d75
2025-12-20 17:16:52.569 INFO リクエストID付与(レスポンス): c8d67e05-bbcb-4d5a-8cc2-f25e77088d75 200
INFO:     127.0.0.1:55537 - "GET /ping HTTP/1.1" 200 OK

BaseHTTPMiddleware クラスを継承したミドルウェアクラスの定義

今度は、前項と同様の操作をクラスで定義する。

クラスとしてミドルウェアを定義する場合は、BaseHttpMiddleware を継承し async def dispatch(request, call_next) メソッドをオーバーライドする。Middleware - Starlette

main.py
import logging
from uuid import uuid4

from fastapi import FastAPI, Request, Response
from starlette.middleware.base import BaseHTTPMiddleware


# logging設定
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)


class RequestIDMiddleware(BaseHTTPMiddleware):
    """リクエストIDを付与するミドルウェアクラス"""
    async def dispatch(self, request: Request, call_next) -> Response:
        # リクエストIDを生成
        request_id = str(uuid4())
        # リクエストオブジェクトにリクエストIDを追加
        request.state.id = request_id
        # ログにリクエストIDを出力
        logging.info(f'リクエストID付与(リクエスト): {request.state.id}')

        # 次のミドルウェアまたはエンドポイントを呼び出す
        response = await call_next(request)

        # ログにレスポンスのステータスコードを出力
        logging.info(
            f'リクエストID付与(レスポンス): {request.state.id}'
            f' {response.status_code}'
        )
        # レスポンスを返す
        return response


# FastAPIアプリケーションの作成
app = FastAPI()
# ミドルウェアの追加
app.add_middleware(RequestIDMiddleware)


@app.get('/ping')
async def ping(request: Request):
    """pingエンドポイント"""
    # リクエストID付きでログ出力
    logging.info(
        f'`/ping` が呼ばれました: {request.state.id}'
    )
    return {'message': 'pong'}

エンドポイントへアクセスしてみると、先ほどと同様の結果を確認できる。
もちろんリクエストIDは異なる。

$curl http://127.0.0.1:8000/ping
{"message":"pong"}

2025-12-20 17:17:14.292 INFO リクエストID付与(リクエスト): 62e07f33-8ee1-4012-8a55-b9cc2b22f42e
2025-12-20 17:17:14.293 INFO `/ping` が呼ばれました: 62e07f33-8ee1-4012-8a55-b9cc2b22f42e
2025-12-20 17:17:14.293 INFO リクエストID付与(レスポンス): 62e07f33-8ee1-4012-8a55-b9cc2b22f42e 200
INFO:     127.0.0.1:61139 - "GET /ping HTTP/1.1" 200 OK

複数のミドルウェアを追加したときは先に追加したものを後で追加したものでラップする

今度は、ログを出力する部分とリクエストIDを発行する部分に分割する。

処理の流れは以下の通り。

  1. リクエストを受け取る
  2. ミドルウェア1に渡す
    1. 前処理を実施 (IDの生成など)
    2. ミドルウェア2に渡す
      1. 前処理を実施 (リクエストログの出力など)
      2. 次の ミドルウェア or エンドポイント に渡す
      3. 後処理を実施 (レスポンスログの出力など)
    3. 後処理を実施 (ログの出力など)
  3. レスポンスを返す

デコレータを使った複数のミドルウェア定義

レスポンスを受けたら、まずリクエストIDを生成してからリクエストログを出力するようなミドルウェアを定義する。

リクエストID付与ミドルウェアはそのままに、リクエスト・レスポンスログ出力ミドルウェアを追加する。
内側の処理を先に書き、外側の処理を後に記述していく。

main.py
import logging
from uuid import uuid4

from fastapi import FastAPI, Request, Response


# logging設定
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)


# FastAPIアプリケーションの作成
app = FastAPI()


@app.middleware('http')
async def log_request_response(request: Request, call_next) -> Response:
    """リクエスト・レスポンスログ出力ミドルウェア"""
    # リクエスト情報をログ出力
    logging.info(
        f'ログ出力(リクエスト): {request.method} {request.url.path}'
        f' - {request.state.id}'
    )

    # 次のミドルウェアまたはエンドポイントを呼び出す
    response = await call_next(request)

    # レスポンス情報をログ出力
    logging.info(
        f'ログ出力(レスポンス): {request.method} {request.url.path} {response.status_code}'
        f' - {request.state.id}'
    )
    # レスポンスを返す
    return response


@app.middleware('http')
async def add_request_id(request: Request, call_next) -> Response:
    """リクエストID付与ミドルウェア"""
    # リクエストIDを生成
    request_id = str(uuid4())
    # リクエストオブジェクトにリクエストIDを追加
    request.state.id = request_id
    # ログにリクエストIDを出力
    logging.info(f'リクエストID: {request.state.id}')

    # 次のミドルウェアまたはエンドポイントを呼び出す
    response = await call_next(request)

    # ログにレスポンスのステータスコードを出力
    logging.info(
        f'リクエストID: {request.state.id}'
        f' ステータスコード: {response.status_code}'
    )
    # レスポンスを返す
    return response


@app.get('/ping')
async def ping(request: Request):
    """pingエンドポイント"""
    # リクエストID付きでログ出力
    logging.info(
        f'`/ping` が呼ばれました'
        f' リクエストID: {request.state.id}'
    )
    return {'message': 'pong'}

/ping エンドポイントにアクセスする。

$ curl -v http://127.0.0.1:8000/ping
{"message":"pong"}

Uvicorn 側のログで、リクエストID作成 -> ログ出力 -> エンドポイント -> ログ出力 -> リクエストID作成 の順番で実行されていることが確認できる。

2025-12-20 17:17:38.575 INFO リクエストID: bd69ab82-a6eb-4e82-8c11-bb5b3d6c454d
2025-12-20 17:17:38.575 INFO ログ出力(リクエスト): GET /ping - bd69ab82-a6eb-4e82-8c11-bb5b3d6c454d
2025-12-20 17:17:38.576 INFO `/ping` が呼ばれました リクエストID: bd69ab82-a6eb-4e82-8c11-bb5b3d6c454d
2025-12-20 17:17:38.576 INFO ログ出力(レスポンス): GET /ping 200 - bd69ab82-a6eb-4e82-8c11-bb5b3d6c454d
2025-12-20 17:17:38.577 INFO リクエストID: bd69ab82-a6eb-4e82-8c11-bb5b3d6c454d ステータスコード: 200
INFO:     127.0.0.1:61165 - "GET /ping HTTP/1.1" 200 OK

BaseHTTPMiddleware クラスを継承した複数のミドルウェア定義

クラス定義の場合は、app.add_middleware(<クラス>) の実行順でミドルウェアの順番が決定する。クラス定義の時点では順序を気にしなくて良い。

main.py
import logging
from uuid import uuid4

from fastapi import FastAPI, Request, Response
from starlette.middleware.base import BaseHTTPMiddleware


# logging設定
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)


class RequestIDMiddleware(BaseHTTPMiddleware):
    """リクエストIDを付与するミドルウェアクラス"""
    async def dispatch(self, request: Request, call_next) -> Response:
        # リクエストIDを生成
        request_id = str(uuid4())
        # リクエストオブジェクトにリクエストIDを追加
        request.state.id = request_id
        # ログにリクエストIDを出力
        logging.info(f'リクエストID付与(リクエスト): {request.state.id}')

        # 次のミドルウェアまたはエンドポイントを呼び出す
        response = await call_next(request)

        # ログにレスポンスのステータスコードを出力
        logging.info(
            f'リクエストID付与(レスポンス): {request.state.id}'
            f' {response.status_code}'
        )
        # レスポンスを返す
        return response


class LoggingMiddleware(BaseHTTPMiddleware):
    """リクエスト・レスポンスログ出力ミドルウェアクラス"""
    async def dispatch(self, request: Request, call_next) -> Response:
        # リクエスト情報をログ出力
        logging.info(
            f'ログ出力(リクエスト): {request.method} {request.url.path}'
            f' - {request.state.id}'
        )

        # 次のミドルウェアまたはエンドポイントを呼び出す
        response = await call_next(request)

        # レスポンス情報をログ出力
        logging.info(
            f'ログ出力(レスポンス): {request.method} {request.url.path} {response.status_code}'
            f' - {request.state.id}'
        )
        # レスポンスを返す
        return response


# FastAPIアプリケーションの作成
app = FastAPI()
# ミドルウェアの追加
app.add_middleware(LoggingMiddleware)
app.add_middleware(RequestIDMiddleware)


@app.get('/ping')
async def ping(request: Request):
    """pingエンドポイント"""
    # リクエストID付きでログ出力
    logging.info(
        f'`/ping` が呼ばれました: {request.state.id}'
    )
    return {'message': 'pong'}

/ping エンドポイントにアクセスする。

$ curl -v http://127.0.0.1:8000/ping
{"message":"pong"}

Uvicorn 側のログで、リクエストID作成 -> ログ出力 -> エンドポイント -> ログ出力 -> リクエストID作成 の順番で実行されていることが確認できる。

2025-12-20 17:17:57.412 INFO リクエストID付与(リクエスト): a657a626-1004-41f0-93db-dd3bf37a9ef2
2025-12-20 17:17:57.412 INFO ログ出力(リクエスト): GET /ping - a657a626-1004-41f0-93db-dd3bf37a9ef2
2025-12-20 17:17:57.413 INFO `/ping` が呼ばれました: a657a626-1004-41f0-93db-dd3bf37a9ef2
2025-12-20 17:17:57.413 INFO ログ出力(レスポンス): GET /ping 200 - a657a626-1004-41f0-93db-dd3bf37a9ef2
2025-12-20 17:17:57.413 INFO リクエストID付与(レスポンス): a657a626-1004-41f0-93db-dd3bf37a9ef2 200
INFO:     127.0.0.1:65343 - "GET /ping HTTP/1.1" 200 OK

まとめ

  • FastAPIアプリケーションにミドルウェアを追加することで、エンドポイント処理の前後にコードを仕込むことができる
  • ミドルウェアはデコレータ @app.middleware('http') を使って関数として定義する方法と、BaseHTTPMiddleware クラスを継承してクラスとして定義する方法がある
  • 複数のミドルウェアを追加した場合、デコレータの場合は内側の処理を先に書き、外側の処理を後に記述する。クラス定義の場合は app.add_middleware(<クラス>) の実行順でミドルウェアの順番が決定する

参考

0
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?