背景

UvicornでFastAPIアプリケーションを実行する場合、デフォルトではリクエストごとにログを出力し続けます。

実際に、AWS ECSにデプロイしたFastAPI サービスでCloudwatch へログ出力してみると、ALBがヘルスチェック用のエンドポイントにリクエストを送る度に、"200 OK "と出力されてしまい、ログの可読性がなかなか辛い感じになりました。

そこで、ヘルスチェックに使用するエンドポイントなど、出力したくないログをフィルタリングできないかな？と思い色々調べました。

補足

Uvicornは以下のように起動することができます。

# portryで実行する例
poetry run uvicorn app.api:app --host 0.0.0.0 --port 9010 --reload

この状態でFastAPIの特定エンドポイントにアクセスすると、以下のようなログがデフォルトで出力されます。

INFO:     127.0.0.1:34954 - "GET /ping HTTP/1.1" 200 OK

特定エンドポイントのログをフィルタリングする方法

以下のように、フィルタするクラスを作成します。

import logging


class EndpointFilter(logging.Filter):

    def __init__(self, excluded_endpoints: list[str]) -> None:
        self.excluded_endpoints = excluded_endpoints

    def filter(self, record: logging.LogRecord) -> bool:
        """
        Filter関数
        record.argsには ('127.0.0.1:51632', 'GET', '/ping', '1.1', 200) のような内容が入っています
        """
        return record.args and len(record.args) >= 3 and record.args[2] not in self.excluded_endpoints

あとは、loggerを作成するタイミングで以下のようにフィルタを追加するだけでOKです。
これで /ping にアクセスがあった場合はログ出力されず、 /testへアクセスがあった場合はログ出力されます。

import logging
from fastapi import FastAPI
from log_filters import EndpointFilter

app = FastAPI()

# 除外したいエンドポイントを指定
excluded_endpoints = ["/ping"]

# フィルターを追加
logging.getLogger("uvicorn.access").addFilter(EndpointFilter(excluded_endpoints))

@app.get('/ping')
def ping():
    print('ping endpoint')

@app.get('/test')
def test():
    print('test endpoint')

おまけ

ログ周りで今後使えそうなTipsもついでに残しておきます。

Uvicornのログをjson形式で出力する方法

以下のようにログフォーマットファイルをyamlで定義しておくことで、json形式で出力することができます。
Amazon CloudWatchなどにログ出力する場合、CloudWatchのコンソール上でjsonをいい感じにパースして見ることができるので、（場合にもよりますが）jsonで定義しておくとメリットが大きいと思います。

pythonjsonlogger.jsonlogger.JsonFormatter を使用するには、python-json-logger のインストールが必要なので、あらかじめインストールしておきます。

version: 1
disable_existing_loggers: false

formatters:
  json:
    format: "%(asctime)s %(levelname)s %(message)s %(filename)s %(module)s %(funcName)s %(lineno)d"
    class: pythonjsonlogger.jsonlogger.JsonFormatter

handlers:
  console:
    class: logging.StreamHandler
    level: INFO
    formatter: json

root:
  level: INFO
  handlers: [console]

この状態で--log-configオプションをつけて実行することで、Uvicornのログもjson形式で出力されます。

# portryで実行する例
poetry run uvicorn app.api:app --host 0.0.0.0 --port 9010 --reload --log-config ./app/loggers/logger_config.yaml

エンドポイント毎のレスポンスタイムを計測する方法

FastAPIにはミドルウェアという概念があり、すべてのリクエストに対して、それがあらゆる特定のPath Operationによって処理される前に機能する関数を定義することができます。

これを使い、以下のように記述することで、レスポンスタイムやその他の情報をログに出力しておくことができます。

from fastapi import FastAPI


app = FastAPI()


@app.middleware("http")
async def process_time(request: Request, call_next):
    """リクエストの処理時間などを表示するミドルウェア関数
    /pingエンドポイントは除外している
    """
    start_time = time.time()
    response = await call_next(request)
    request_log = {
        "method": request.method,
        "url": request.url.path,
        "query_params": request.query_params,
        "path_params": request.path_params,
        "status_code": response.status_code,
        "response_time": time.time() - start_time,
        "client": request.client,
    }
    logger.info("Response Log", extra=request_log)
    return response