L14 ch03 — ログミドルウェア

L14 ch03 — ログミドルウェア

リクエスト/レスポンスを記録して「動いた・落ちた」を可視化する

ゴール

• logging モジュールの最小設定ができる
• リクエスト毎にログを出すミドルウェアを書ける
• ステータスコード・処理時間を記録できる

なぜログが必要か

print で済むのは開発初期だけ:

• 時刻 が付かない
• 重要度 (INFO / WARNING / ERROR) を区別できない
• 本番では ファイル or 集約基盤 に流したい

→ Python 標準の logging モジュールを使う

logging 最小例

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s",
)
logger = logging.getLogger(__name__)

logger.info("server started")
# → 2026-06-24 10:00:00,123 INFO server started

ログレベル

basicConfig(level=...) で出力閾値を変えられる。

FastAPI のミドルウェアとは

リクエスト処理の 前後 に共通処理を挟む仕組み。

[ Request ]
    ↓
[ Middleware (前処理) ]
    ↓
[ Route handler ]
    ↓
[ Middleware (後処理) ]
    ↓
[ Response ]

ログ・認証・CORS・計測などで使う。

最小のログミドルウェア

import time
import logging
from fastapi import FastAPI, Request

logging.basicConfig(level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s")
logger = logging.getLogger(__name__)

app = FastAPI()

@app.middleware("http")
async def log_requests(request: Request, call_next):
    start = time.time()
    response = await call_next(request)
    elapsed = (time.time() - start) * 1000
    logger.info(
        f"{request.method} {request.url.path} "
        f"-> {response.status_code} ({elapsed:.1f}ms)"
    )
    return response

動作イメージ

uv run uvicorn main:app --reload

別ターミナルで:

curl http://localhost:8000/hello

サーバー側ログ:

2026-06-24 10:00:00,123 INFO GET /hello -> 200 (1.2ms)

ポイント解説

1. @app.middleware("http") で HTTP リクエスト全体をフック
2. await call_next(request) で本来のルートを実行
3. その前後で time.time() を測って差分 = 処理時間
4. request.method / request.url.path / response.status_code が取れる

エラー時のログ

例外発生時もログに残したい:

@app.middleware("http")
async def log_requests(request: Request, call_next):
    start = time.time()
    try:
        response = await call_next(request)
    except Exception as e:
        logger.exception(f"{request.method} {request.url.path} failed")
        raise
    elapsed = (time.time() - start) * 1000
    logger.info(f"... -> {response.status_code} ({elapsed:.1f}ms)")
    return response

logger.exception はスタックトレースも自動で記録。

print vs logger

→ サーバーコードでは 必ず logger を使う

drill

drill/ — ログミドルウェアの空欄を埋める

拡張課題

1. ログをファイルに書く: logging.FileHandler("app.log") を追加
2. JSON ログ: python-json-logger で構造化ログ
3. request ID: uuid.uuid4() を生成してログに含め、リクエスト追跡可能に

よくある詰まり

次に学ぶ領域