FastAPI開発者のためのロギング入門

By /

FastAPI開発者のためのロギング入門：実践的なガイド

はじめに：なぜFastAPIアプリケーションでロギングが重要なのか？

現代のWebアプリケーション開発において、ロギングは不可欠な要素です。特にFastAPIのような非同期フレームワークを使用する場合、多数のリクエストが同時に処理されるため、問題が発生した際にその原因を特定するのは容易ではありません。デバッグ実行は開発段階では有効ですが、本番環境で動いているアプリケーションに対して行うことは現実的ではありませんし、パフォーマンスにも影響を与えます。

ここでロギングの出番です。ロギングとは、アプリケーションの実行中に発生した様々なイベントや状態を記録することです。これにより、以下のような多岐にわたる目的を達成できます。

  1. 問題の診断とデバッグ： エラーが発生した場合、ログを見ることで何が起こったのか、どこで、なぜ起こったのかを詳細に把握できます。これは、原因究明と修正の最も基本的なステップです。
  2. アプリケーションの挙動監視： 正常なリクエスト、特定の処理の完了、ユーザーの操作など、アプリケーションが期待通りに動作しているかを確認できます。
  3. セキュリティ監査とトレーサビリティ： 不正アクセス試行、特定のユーザーによる機密情報へのアクセス、システム設定の変更など、セキュリティに関連するイベントを記録できます。これにより、インシデント発生時の追跡や、事後分析が可能になります。
  4. パフォーマンス分析： 特定の処理にかかった時間、リソースの使用状況などをログに記録することで、パフォーマンスのボトルネックを発見できます。
  5. 利用状況の分析： どの機能がよく使われているか、どのようなデータが処理されているかなどを記録し、サービス改善の意思決定に役立てることができます。

FastAPIは非常に高速で効率的なフレームワークですが、それは同時に、問題が発生した際に原因特定の情報が限られている可能性があることを意味します。適切なロギング戦略を導入することで、アプリケーションの信頼性を高め、運用・保守のコストを削減することができます。

この記事では、Python標準のloggingモジュールを中心に、FastAPIアプリケーションにおけるロギングの実装方法、設定、ベストプラクティスについて、初心者から中級者のFastAPI開発者を対象に詳細に解説します。

第1章：Python標準loggingモジュールの基礎

FastAPIアプリケーションでロギングを行う際に、ほとんどの場合Python標準ライブラリに含まれるloggingモジュールを使用します。このモジュールは非常に強力で柔軟性があり、様々な要件に対応できる機能を提供しています。

loggingモジュールを理解するために、いくつかの主要なコンポーネントとその役割を把握する必要があります。

1.1. ログレベル (Log Levels)

ログレベルは、記録するメッセージの重要度を示します。標準で以下のレベルが定義されています。重要度の低い順に並んでいます。

  • logging.DEBUG: デバッグ情報。詳細な情報で、開発中に問題診断のためにのみ通常は使用されます。
  • logging.INFO: 情報メッセージ。アプリケーションが期待通りに進行していることを示します。
  • logging.WARNING: 警告メッセージ。潜在的な問題を示しますが、アプリケーションはまだ正常に動作しています。
  • logging.ERROR: エラーメッセージ。深刻な問題により、一部の機能が動作しなくなりました。
  • logging.CRITICAL: 致命的なエラーメッセージ。アプリケーション全体が停止するなど、非常に深刻な事態を示します。

各ログメッセージはこれらのいずれかのレベルに関連付けられます。ロガーは、設定されたレベル以上の重要度のメッセージのみを処理するように設定できます。これにより、開発中は詳細なDEBUGレベルを有効にし、本番環境ではWARNING以上のレベルのみを記録するといった柔軟な運用が可能になります。

1.2. ロガー (Logger)

ロガーは、ログメッセージを発行するためのエントリーポイントです。アプリケーション内の異なる部分（モジュール、クラスなど）ごとに異なるロガーを持つことが一般的です。ロガーは階層構造になっており、ドット.で区切られた名前で識別されます（例: myapp.database, myapp.api.users）。

ロガーは以下の役割を担います。

  • ログメッセージを受け取り、レベルチェックを行う。
  • 関連付けられたハンドラーにメッセージを渡す。
  • 必要に応じてフィルターを適用する。
  • 設定によっては、親ロガーにメッセージを伝播させる（Propagation）。

ルートロガー (Root Logger) は全てのロガーの親であり、名前を指定せずにlogging.getLogger()を呼び出した場合に取得できます。通常は、logging.getLogger(__name__)のように、現在のモジュール名をロガー名として使用することが推奨されます。これにより、どのモジュールからログが出力されたかを容易に識別できます。

1.3. ハンドラー (Handler)

ハンドラーは、ロガーから受け取ったログレコード（ログメッセージ、レベル、タイムスタンプなどの情報を含むオブジェクト）をどこに、どのように出力するかを決定します。一つのロガーに複数のハンドラーを設定できます。

代表的なハンドラーには以下のようなものがあります。

  • logging.StreamHandler: 標準出力（通常はコンソール）や標準エラー出力にログを出力します。
  • logging.FileHandler: ファイルにログを書き込みます。
  • logging.handlers.RotatingFileHandler: ファイルサイズや時間に基づいてログファイルをローテーション（世代管理）しながら書き込みます。
  • logging.handlers.TimedRotatingFileHandler: 特定の時間間隔や日付に基づいてログファイルをローテーションします。
  • logging.handlers.SMTPHandler: 電子メールでログを送信します。
  • logging.handlers.HTTPHandler: HTTP経由でログを送信します。

FastAPIアプリケーションでは、通常StreamHandlerやFileHandler、またはそのローテーション機能付きのハンドラーを組み合わせて使用することが多いです。

1.4. フォーマッター (Formatter)

フォーマッターは、ログレコードを最終的な出力形式に整形します。タイムスタンプ、ログレベル、ロガー名、メッセージ本体、ファイル名、行番号など、ログレコードに含まれる様々な情報から、人間が読みやすい形式や機械が解析しやすい形式（例: JSON）の文字列を生成します。

フォーマット文字列は、logging.Formatter(fmt=..., datefmt=...)のように指定します。fmtはメッセージ本体のフォーマットを、datefmtはタイムスタンプのフォーマットを指定します。

フォーマット文字列内のプレースホルダー（%(name)s, %(levelname)s, %(message)sなど）を使用して、ログレコードの属性を埋め込みます。

よく使われるプレースホルダーの例：

  • %(asctime)s: ログレコード生成時刻 (通常はdatefmtで指定した形式)
  • %(name)s: ロガー名
  • %(levelname)s: ログレベル名
  • %(message)s: ログメッセージ本体
  • %(pathname)s: ログを記録したソースファイルへのフルパス
  • %(filename)s: ログを記録したソースファイル名
  • %(lineno)d: ログを記録したソースファイルの行番号
  • %(process)d: プロセスID
  • %(thread)d: スレッドID

1.5. フィルター (Filter)

フィルターは、ハンドラーに渡されるログレコードをさらに細かく制御するために使用されます。特定のロガーからのメッセージだけを処理する、特定の文字列を含むメッセージを除外する、ログレコードに特定の情報を追加するといったことが可能です。

フィルターはあまり頻繁には使用されませんが、複雑なロギング要件がある場合に役立ちます。

1.6. コンポーネント間の連携

これらのコンポーネントは以下のように連携して動作します。

  1. アプリケーションコードが特定のロガーに対してlogger.info("..."), logger.error("...")などのメソッドを呼び出します。
  2. ロガーはメッセージを受け取り、そのレベルが自身に設定されたレベル以上であるかを確認します。満たしていなければメッセージは破棄されます。
  3. レベルチェックを通過したメッセージは、ロガーに関連付けられている全てのハンドラーに渡されます。
  4. 各ハンドラーは、自身に関連付けられているフィルターがあればそれを適用します。フィルターを通過しないメッセージは破棄されます。
  5. フィルターを通過したメッセージは、ハンドラーに関連付けられているフォーマッターによって整形されます。
  6. 整形されたログメッセージは、ハンドラーの出力先（コンソール、ファイルなど）に書き込まれます。
  7. ロガーのpropagate属性がTrue（デフォルト）であれば、メッセージは親ロガーにも渡され、同様の処理が繰り返されます。

第2章：基本的なロギング設定と使用法

Pythonでロギングを開始するための最も簡単な方法は、logging.basicConfig()関数を使用することです。この関数は、ルートロガーに対して基本的な設定（ハンドラー、フォーマッター、レベルなど）を一度に行います。

ただし、basicConfig()は一度しか効果がありません。通常、小規模なスクリプトや開発段階での簡単なデバッグには便利ですが、本格的なFastAPIアプリケーションでは、より詳細な設定を行うために後述するlogging.config.dictConfigを使用することが推奨されます。

2.1. basicConfig() を使った基本設定

“`python
import logging

basicConfig() は一度しか効果がない

レベル、フォーマット、出力先などを設定できる

logging.basicConfig(
level=logging.INFO, # デフォルトは WARNING
format=’%(asctime)s – %(name)s – %(levelname)s – %(message)s’,
# filename=’app.log’, # ファイルに出力する場合
# filemode=’w’ # ファイルモード (w:上書き, a:追記)
)

ロガーを取得 (name は現在のモジュール名を返す)

logger = logging.getLogger(name)

ログメッセージを出力

logger.debug(“これはデバッグメッセージです。”) # 設定レベルINFO未満なので出力されない
logger.info(“アプリケーションが開始されました。”)
logger.warning(“設定ファイルが見つかりません。デフォルトを使用します。”)
logger.error(“データベース接続に失敗しました。”)
logger.critical(“システムがシャットダウンしています。”)

別のロガーを取得することも可能

another_logger = logging.getLogger(“my_module”)
another_logger.info(“別のモジュールからの情報です。”)
“`

この例では、basicConfigでログレベルをINFO、フォーマットを指定しています。logger.debug()は設定レベル未満なので出力されませんが、それ以上のレベルのメッセージは標準出力に指定されたフォーマットで出力されます。

出力例:

2023-10-27 10:00:00,123 - __main__ - INFO - アプリケーションが開始されました。
2023-10-27 10:00:00,124 - __main__ - WARNING - 設定ファイルが見つかりません。デフォルトを使用します。
2023-10-27 10:00:00,125 - __main__ - ERROR - データベース接続に失敗しました。
2023-10-27 10:00:00,126 - __main__ - CRITICAL - システムがシャットダウンしています。
2023-10-27 10:00:00,127 - my_module - INFO - 別のモジュールからの情報です。

2.2. FastAPIアプリケーション内での基本的なロギング

FastAPIアプリケーション内でロギングを使用する場合も、基本は同じです。各モジュールでlogging.getLogger(__name__)を使ってロガーを取得し、ログを出力します。

“`python

main.py

import logging
from fastapi import FastAPI

basicConfig はアプリケーションのエントリーポイントで一度だけ呼び出す

本番環境では dictConfig などを使うべきだが、ここでは簡単な例として

logging.basicConfig(level=logging.INFO, format=’%(asctime)s – %(name)s – %(levelname)s – %(message)s’)
logger = logging.getLogger(name)

app = FastAPI()

@app.on_event(“startup”)
async def startup_event():
logger.info(“アプリケーションの起動処理を開始します。”)

@app.on_event(“shutdown”)
async def shutdown_event():
logger.info(“アプリケーションの終了処理を開始します。”)

@app.get(“/”)
async def read_root():
logger.debug(“ルートエンドポイントにアクセスがありました。”) # Debugレベルなので通常は表示されない
logger.info(“ルートエンドポイントへのリクエストを処理しました。”)
return {“Hello”: “World”}

@app.get(“/items/{item_id}”)
async def read_item(item_id: int):
logger.info(f”アイテムエンドポイントにアクセス: item_id={item_id}”)
if item_id == 42:
logger.warning(“特別なアイテムID (42) がリクエストされました。”)
return {“item_id”: item_id}
“`

このコードをmain.pyとして保存し、uvicorn main:app --reloadで実行すると、リクエストに応じてログメッセージがコンソールに出力されます。

デフォルトでは、Uvicorn自体もアクセスログを出力します。上記の例では、Uvicornのログとアプリケーションのログが混ざって表示されます。Uvicornのロギング設定については後述します。

第3章：logging.config.dictConfigによる詳細設定

FastAPIのような複雑なアプリケーションでは、basicConfigでは設定できる内容に限りがあるため、logging.config.dictConfigを使用することが一般的です。この関数は、Pythonの辞書またはYAML/JSONファイルなどで定義された構造的な設定情報を読み込み、ロギングシステム全体を設定します。

dictConfigを使用する最大の利点は、コードの変更なしにロギングの挙動（どのロガーを使うか、どのハンドラーを使うか、どのファイルに書くか、どのレベルから記録するか、フォーマットはどうするかなど）を変更できるようになることです。設定を外部ファイル（例: logging.yaml, logging.json, config.pyなど）に分離すれば、デプロイメント環境ごとに異なる設定を適用することも容易になります。

3.1. dictConfigの設定構造

dictConfigに渡す辞書は、いくつかのキーを持つ必要があります。主要なキーは以下の通りです。

  • version: 設定スキーマのバージョン。現在は1のみがサポートされています。
  • disable_existing_loggers: Trueに設定すると、この設定が適用される前に存在していたロガー（特にルートロガーや、ライブラリによって生成されたロガー）が無効になります。通常はFalseにするか、指定しないでおき、既存のロガーのハンドラーやレベルを引き続き利用できるようにするか、あるいは設定内で明示的に再定義します。Uvicornなどのライブラリのロガーをカスタマイズする場合は、Falseにしておいて、設定内でそれらのロガーを明示的に定義するのが良い方法です。
  • formatters: フォーマッターの定義を保持する辞書。各キーがフォーマッター名、その値がフォーマッターの設定辞書になります。
  • filters: フィルターの定義を保持する辞書。使用頻度は少ないですが、ここに定義します。
  • handlers: ハンドラーの定義を保持する辞書。各キーがハンドラー名、その値がハンドラーの設定辞書になります。
  • loggers: ロガーの定義を保持する辞書。各キーがロガー名（例: myapp, uvicorn), その値がロガーの設定辞書になります。
  • root: ルートロガーの設定を保持する辞書。loggers内のエントリと同様の設定を持ちます。

3.2. dictConfigの具体的な設定例

最も一般的なのは、コンソール出力とファイル出力の両方を行う設定です。

“`python

logging_config.py または app/logging_config.py

import logging
import sys

LOGGING_CONFIG = {
‘version’: 1,
‘disable_existing_loggers’: False, # 既存のロガーを無効にしない (Uvicornなどのログを扱うため)
‘formatters’: {
‘verbose’: {
‘format’: ‘%(asctime)s – %(name)s – %(levelname)s – %(pathname)s:%(lineno)d – %(message)s’
},
‘standard’: {
‘format’: ‘%(asctime)s – %(name)s – %(levelname)s – %(message)s’
},
‘uvicorn_format’: { # Uvicornが出力するようなシンプルなフォーマット
‘()’: ‘uvicorn.logging.DefaultFormatter’, # UvicornのFormatterクラスを使用
‘fmt’: ‘%(levelprefix)s %(asctime)s %(message)s’,
‘use_colors’: True,
}
},
‘handlers’: {
‘console’: {
‘class’: ‘logging.StreamHandler’,
‘formatter’: ‘uvicorn_format’ if sys.stdout.isatty() else ‘standard’, # TTYなら色付き、そうでなければ標準
‘stream’: ‘ext://sys.stdout’ # 標準出力へ
},
‘file’: {
‘class’: ‘logging.handlers.RotatingFileHandler’,
‘formatter’: ‘verbose’,
‘filename’: ‘app.log’,
‘maxBytes’: 1024 * 1024 * 5, # 5 MB
‘backupCount’: 5 # 5世代まで保存
},
‘error_file’: {
‘class’: ‘logging.handlers.RotatingFileHandler’,
‘formatter’: ‘verbose’,
‘filename’: ‘error.log’,
‘maxBytes’: 1024 * 1024 * 10, # 10 MB
‘backupCount’: 3,
‘level’: ‘ERROR’ # ERROR以上のレベルのみこのハンドラーで処理
}
},
‘loggers’: {
”: { # ルートロガー
‘handlers’: [‘console’, ‘file’, ‘error_file’],
‘level’: ‘INFO’,
‘propagate’: False # ルートロガーなので通常はFalse
},
‘uvicorn’: { # Uvicornのロガー
‘handlers’: [‘console’],
‘level’: ‘INFO’,
‘propagate’: False
},
‘uvicorn.error’: { # Uvicornのエラーロガー
‘level’: ‘ERROR’,
‘handlers’: [‘console’], # エラーはコンソールにも出す
‘propagate’: False
},
‘uvicorn.access’: { # Uvicornのアクセスロガー
‘handlers’: [‘console’],
‘level’: ‘INFO’,
‘propagate’: False
},
‘myapp’: { # アプリケーション固有のロガー (例: myapp.*)
‘handlers’: [‘console’, ‘file’],
‘level’: ‘DEBUG’, # 開発中はDEBUGに設定
‘propagate’: False # 親ロガー(ルートロガー)に伝播させない
}
},
‘root’: { # ルートロガーの別名として定義することも多い
‘handlers’: [‘console’, ‘file’, ‘error_file’],
‘level’: ‘INFO’,
‘propagate’: False
}
}
“`

解説：

  • version: 1 は必須です。
  • disable_existing_loggers: False とすることで、Uvicornなどが生成するロガーの設定を上書きしたり、それらのログをキャプチャしたりできます。
  • formatters では、verbose, standard, uvicorn_formatという名前で3つのフォーマッターを定義しています。uvicorn_formatではUvicornが提供する色付き出力に対応したフォーマッタークラスを直接指定しています。
  • handlers では、console, file, error_fileという名前で3つのハンドラーを定義しています。
    • console: 標準出力へのハンドラー。TTYかどうかで異なるフォーマッターを使い分けます。
    • file: app.logというファイルに書き込むローテーション機能付きハンドラー。最大5MBで5世代まで保存します。verboseフォーマッターを使用します。
    • error_file: error.logというファイルに書き込むローテーション機能付きハンドラー。こちらはレベルをERRORに設定しているため、ERROR以上のメッセージのみが記録されます。
  • loggers では、特定のロガーに対して設定を行います。
    • '': これはルートロガーを指します。rootキーと同じ設定を持つことが多いですが、どちらか一方で設定します。ここではルートロガーにconsole, file, error_fileの3つのハンドラー全てを関連付け、レベルをINFOにしています。propagate: Falseは、これ以上親ロガー（ルートロガーには親はいません）に伝播させないことを明示しています。
    • uvicorn, uvicorn.error, uvicorn.access: Uvicornが出力する様々なログに対するロガー設定です。これらを明示的に定義することで、Uvicornのデフォルトのハンドラーを置き換えたり、独自のハンドラーを追加したりできます。ここでは、アクセスログとエラーログをコンソールに、INFOレベル以上で出力するように設定しています。propagate: Falseにしないと、Uvicornのログがルートロガーにも伝播して二重に出力される可能性があるため注意が必要です。
    • myapp: 例として、アプリケーションコード内でlogging.getLogger("myapp")やlogging.getLogger("myapp.database")のように取得するロガーの親として設定しています。このロガーはconsoleとfileハンドラーを使用し、レベルはDEBUGに設定しています。これにより、myapp名前空間のロガーはDEBUG以上の詳細なログをコンソールとファイルの両方に出力します。
  • root: ルートロガーの設定です。loggersの''キーと意味的には同じですが、こちらで定義するのが一般的です。

3.3. dictConfigの設定をアプリケーションに適用する

この設定をアプリケーションに適用するには、FastAPIアプリケーションの起動時にlogging.config.dictConfig()を呼び出します。

“`python

main.py

import logging
import logging.config
from fastapi import FastAPI

ロギング設定をインポート

from logging_config import LOGGING_CONFIG # 前述の辞書を定義したファイル

アプリケーション起動前にロギング設定を適用

logging.config.dictConfig(LOGGING_CONFIG)

ロガーを取得 (name が “main” になる)

logger = logging.getLogger(name)

アプリケーション固有のロガーを取得 (上記設定の ‘myapp’ ロガーにマッチする)

app_logger = logging.getLogger(“myapp”)

app = FastAPI()

@app.on_event(“startup”)
async def startup_event():
logger.info(“メインモジュールのstartupイベント.”) # main ロガーから出力
app_logger.info(“myapp ロガーからのstartupイベント.”) # myapp ロガーから出力

@app.on_event(“shutdown”)
async def shutdown_event():
logger.info(“メインモジュールのshutdownイベント.”)
app_logger.info(“myapp ロガーからのshutdownイベント.”)

@app.get(“/”)
async def read_root():
logger.debug(“メインモジュールのルートデバッグ.”) # main ロガー (レベル INFO) なので出力されない
app_logger.debug(“myapp ロガーのルートデバッグ.”) # myapp ロガー (レベル DEBUG) なので出力される
app_logger.info(“myapp ロガーのルート情報.”)
return {“Hello”: “World”}

@app.get(“/items/{item_id}”)
async def read_item(item_id: int):
app_logger.info(f”myapp ロガー: アイテムアクセス item_id={item_id}”)
if item_id == 500:
app_logger.error(“myapp ロガー: アイテム取得エラーをシミュレート.”) # error.log にも出力される
return {“item_id”: item_id}
“`

この構成では、mainモジュールのロガー（logger変数）はルートロガーの設定（レベルINFO）に従い、myappという名前で取得したロガー（app_logger変数）はloggersセクションで定義したmyappの設定（レベルDEBUG）に従います。

uvicorn main:app --reloadで実行し、/や/items/123、/items/500にアクセスしてみてください。コンソール出力、app.log、error.logにそれぞれ異なるログが出力されることが確認できます。

注意: Uvicornをuvicorn main:app --log-config logging_config.pyのように起動することも可能ですが、これはUvicorn自身のロギング設定をロードするためのものであり、FastAPIアプリケーションコード内でlogging.config.dictConfigを呼び出す方が、アプリケーション全体のロギング設定を一元管理する上で推奨されます。FastAPIアプリケーションの起動イベント（@app.on_event("startup")）内でdictConfigを呼び出す方法もありますが、ロガーの取得はモジュールのグローバルスコープで行われるため、イベントハンドラーよりもモジュールトップレベルで設定を適用するのが一般的です。

3.4. YAMLやJSONファイルからの設定読み込み

dictConfigは辞書を受け取るため、設定を直接Pythonコードに書く代わりに、YAMLやJSONファイルに記述してそれを読み込むこともよく行われます。これにより、設定とコードを完全に分離できます。

まず、YAMLファイルを作成します (例: logging_config.yaml)。内容は基本的に上記の辞書をYAML形式に変換したものです。

“`yaml
version: 1
disable_existing_loggers: False

formatters:
verbose:
format: ‘%(asctime)s – %(name)s – %(levelname)s – %(pathname)s:%(lineno)d – %(message)s’
standard:
format: ‘%(asctime)s – %(name)s – %(levelname)s – %(message)s’
uvicorn_format:
‘()’: uvicorn.logging.DefaultFormatter
fmt: ‘%(levelprefix)s %(asctime)s %(message)s’
use_colors: True

handlers:
console:
class: logging.StreamHandler
formatter: uvicorn_format # YAMLでは条件分岐が難しいので固定するか、コード側で読み込み後に修正
stream: ext://sys.stdout
file:
class: logging.handlers.RotatingFileHandler
formatter: verbose
filename: app.log
maxBytes: 5242880 # 5 MB
backupCount: 5
error_file:
class: logging.handlers.RotatingFileHandler
formatter: verbose
filename: error.log
maxBytes: 10485760 # 10 MB
backupCount: 3
level: ERROR

loggers:
”: # root logger
handlers: [console, file, error_file]
level: INFO
propagate: False
uvicorn:
handlers: [console]
level: INFO
propagate: False
uvicorn.error:
level: ERROR
handlers: [console]
propagate: False
uvicorn.access:
handlers: [console]
level: INFO
propagate: False
myapp:
handlers: [console, file]
level: DEBUG # 開発中はDEBUGに設定
propagate: False

root: # Alias for ”
handlers: [console, file, error_file]
level: INFO
propagate: False
“`

そして、アプリケーションコードでこのYAMLファイルを読み込んでdictConfigに渡します。PyYAMLライブラリが必要です (pip install PyYAML)。

“`python

main.py

import logging
import logging.config
import yaml # PyYAMLが必要

from fastapi import FastAPI

YAMLファイルから設定を読み込む

with open(‘logging_config.yaml’, ‘rt’) as f:
logging_config_dict = yaml.safe_load(f)

ロギング設定を適用

logging.config.dictConfig(logging_config_dict)

ロガーを取得

logger = logging.getLogger(name)
app_logger = logging.getLogger(“myapp”)

app = FastAPI()

@app.on_event(“startup”)
async def startup_event():
logger.info(“メインモジュールのstartupイベント (YAML設定).”)
app_logger.info(“myapp ロガーからのstartupイベント (YAML設定).”)

… (以降のエンドポイントなどは前述の例と同じ)

@app.get(“/”)
async def read_root():
app_logger.debug(“myapp ロガーのルートデバッグ (YAML設定).”)
app_logger.info(“myapp ロガーのルート情報 (YAML設定).”)
return {“Hello”: “World”}

… 他のエンドポイント

“`

JSONファイルを使用する場合も同様に、jsonモジュールで読み込みます。

第4章：FastAPI特有のロギングと高度なテクニック

FastAPIアプリケーションでは、一般的なアプリケーションロギングに加えて、Webフレームワーク特有の考慮事項があります。

4.1. Uvicornのロギング制御

前述の通り、Uvicornはデフォルトでアクセスログやエラーログをコンソールに出力します。dictConfigでuvicorn, uvicorn.error, uvicorn.accessなどのロガーを定義することで、これらのUvicornが出力するログのレベルやハンドラーを完全に制御できます。

例えば、UvicornのアクセスログをINFOレベルでコンソールに出力しつつ、アプリケーションのエラーログはERRORレベルでファイルにも出力するという設定は、前述のlogging_config.pyの例で実現されています。

もしUvicornのアクセスログが不要な場合は、uvicorn.accessロガーのレベルをWARNINGやERRORに設定するか、ハンドラーを空にすることで非表示にできます。

“`python

logging_config.py (一部抜粋)

LOGGING_CONFIG = {
# … formatters, handlers …
‘loggers’: {
# … その他のロガー …
‘uvicorn.access’: {
‘handlers’: [], # ハンドラーを空にする
‘level’: ‘INFO’, # または ‘WARNING’, ‘ERROR’ にレベルを上げる
‘propagate’: False
}
},
# … root …
}
“`

4.2. ロギングコンテキスト（コンテキスト変数）の追加

単にメッセージを記録するだけでなく、ログにリクエストID、ユーザーID、セッションIDなどの追加情報を付加すると、後からログを検索・分析する際に非常に役立ちます。これをロギングコンテキストと呼びます。

Pythonのloggingモジュールでコンテキストを追加する一般的な方法として、logging.Logger.with_context() (Python 3.10+) や logging.Filter、または後述の構造化ロギングライブラリを使用する方法があります。

FastAPIでは、リクエストごとに固有の情報を付加することが多いです。これはミドルウェアで処理するのが自然です。

4.2.1. logging.Filter を使用したコンテキスト追加

カスタムフィルターを作成し、ログレコードに情報を追加する例です。このフィルターをハンドラーまたはロガーに関連付けます。

“`python
import logging
import contextvars # 非同期処理でコンテキストを維持するためのモジュール

リクエストIDを保持するためのContextVar

request_id_var = contextvars.ContextVar(‘request_id’, default=None)

class ContextFilter(logging.Filter):
def filter(self, record):
# ログレコードにリクエストIDを追加
record.request_id = request_id_var.get()
return True # Trueを返すとメッセージは処理される

dictConfig の formatters に request_id を表示するよう追加

formatters:

verbose:

format: ‘%(asctime)s – %(name)s – %(levelname)s – req_id=%(request_id)s – %(pathname)s:%(lineno)d – %(message)s’

standard:

format: ‘%(asctime)s – %(name)s – %(levelname)s – req_id=%(request_id)s – %(message)s’

dictConfig の handlers に filter を追加

handlers:

console:

class: logging.StreamHandler

formatter: verbose

stream: ext://sys.stdout

filters: [context_filter] # ここでフィルターを適用

file:

class: logging.handlers.RotatingFileHandler

formatter: verbose

filename: app.log

maxBytes: 5242880

backupCount: 5

filters: [context_filter] # ここでフィルターを適用

dictConfig の filters にフィルターの定義を追加

filters:

context_filter:

‘()’: main.ContextFilter # またはフィルタークラスが定義されているモジュール名を指定

ミドルウェアで request_id を ContextVar にセット

from fastapi import FastAPI, Request
import uuid
import time

app = FastAPI()

@app.middleware(“http”)
async def logging_middleware(request: Request, call_next):
req_id = str(uuid.uuid4())
# ContextVar にリクエストIDをセットし、コンテキストを実行
token = request_id_var.set(req_id)
start_time = time.time()

# リクエスト情報のログ (処理前)
app_logger.info(f"リクエスト開始: method={request.method} path={request.url.path}")

try:
    response = await call_next(request)
    process_time = time.time() - start_time
    # レスポンス情報のログ (処理後)
    app_logger.info(f"リクエスト完了: status={response.status_code} time={process_time:.4f}s")
    return response
except Exception as e:
    # エラー発生時のログ
    app_logger.error(f"リクエスト処理中にエラーが発生: {e}", exc_info=True)
    raise e
finally:
    # ContextVar の値をリセット
    request_id_var.reset(token)

ロギング設定 (dictConfig) は別途読み込む必要がある

例: logging.config.dictConfig(…)

ロガーを取得

app_logger = logging.getLogger(“myapp”)

エンドポイントの例

@app.get(“/hello”)
async def hello():
app_logger.info(“Helloエンドポイント内で処理中.”)
return {“message”: “Hello”}

@app.get(“/error”)
async def simulate_error():
app_logger.error(“エラーエンドポイント内でエラーをシミュレート.”)
raise RuntimeError(“Intentional error”)

実行例: uvicorn main:app –reload

ログ出力にリクエストIDが含まれるようになる

“`

この例では、logging.Filterを継承したContextFilterを作成し、contextvars.ContextVarに保存されたrequest_idをログレコードに追加しています。ミドルウェアで各リクエストに対して一意のリクエストIDを生成し、ContextVarにセットしています。これにより、そのリクエストを処理する間に出力される全てのログに同じリクエストIDが付加されます。ContextVarは非同期コンテキストを正しく扱うために重要です。

dictConfigの設定で、フォーマットに%(request_id)sを追加し、ハンドラーにこのカスタムフィルターを関連付ける必要があります。

4.2.2. LoggerAdapter を使用したコンテキスト追加

logging.LoggerAdapterを使用すると、ロガーのメソッド呼び出し時に自動的に追加情報をログレコードに付加できます。これもリクエストコンテキストを扱うのに適した方法です。

“`python
import logging
import uuid
from starlette.requests import Request # FastAPIRoutesからアクセスする場合など Request が必要

class RequestIdAdapter(logging.LoggerAdapter):
def process(self, msg, kwargs):
# extra にリクエストIDを追加
extra = kwargs.get(‘extra’, {})
# ContextVar または Request オブジェクトからリクエストIDを取得するロジック
req_id = request_id_var.get() # ContextVar を使用する場合
# あるいは、Request オブジェクトを引数などで渡すように設計
# req_id = getattr(self, ‘_request_id’, ‘N/A’) # Adapter に Request を保持させる場合など
if req_id:
extra[‘request_id’] = req_id
kwargs[‘extra’] = extra
return msg, kwargs

dictConfig の formatters に request_id を表示するよう追加 (%(request_id)s)

handlers に filter を追加する必要はない。Formatterだけで良い。

アプリケーションコードでの使用

logging.config.dictConfig(…) でロギング設定を読み込んだ後

app_logger = logging.getLogger(“myapp”)

request_aware_logger = RequestIdAdapter(app_logger, {}) # extra引数はここでは空でOK

ミドルウェアで request_id を ContextVar にセットするのは ContextFilter の例と同じ

エンドポイントの例

@app.get(“/hello”)
async def hello():
# ここで request_aware_logger を使用すると、自動的に request_id が付加される
# ロガーの取得を Adapter 経由にする必要がある
# request_aware_logger.info(“Helloエンドポイント内で処理中.”)
# これは、各リクエストで Adapter を取得・使用する必要があり、少し面倒になる場合がある

# ContextVar + Filter/Formatter の方が、既存ロガーをそのまま使えるので楽なことが多い
app_logger.info("Helloエンドポイント内で処理中 (ContextVar+Filter方式).") # ContextVar+Filter が適用される

return {"message": "Hello"}

“`

LoggerAdapterは柔軟ですが、FastAPIの各エンドポイントや依存関数でAdapter経由でロガーを取得・使用するコードが必要になり、少し冗長になる場合があります。ContextVarとカスタムフィルター/フォーマッターを組み合わせる方が、既存のlogging.getLogger(__name__)で取得したロガーをそのまま使用できるため、FastAPIアプリケーションでは好まれる傾向にあります。

4.3. ロギングのパフォーマンスに関する考慮事項

ロギングはI/O操作（ファイルへの書き込み、ネットワーク送信など）を伴うため、パフォーマンスに影響を与える可能性があります。特に高負荷なアプリケーションでは注意が必要です。

  • ログレベルの適切な設定: 本番環境ではDEBUGレベルを無効にし、必要な情報量に絞ることで、ログ出力の量を減らし、パフォーマンスへの影響を最小限に抑えられます。
  • ハンドラーの選択: リモートサービスへの送信など、ブロッキングの可能性があるハンドラーを使用する場合は、logging.handlers.QueueHandlerとlogging.handlers.QueueListenerを使用して、ログ処理を別スレッドや別プロセスにオフロードすることを検討してください。
  • メッセージ生成コスト: ログレベルによっては出力されないメッセージであっても、そのメッセージ文字列や引数の評価（例: f-stringの生成）は常に行われます。コストの高い処理を含むログメッセージは、ログレベルのガードを追加することで評価を遅延させることができます。

“`python

高コストな処理を含むログメッセージ

このままだと、DEBUGレベルがOFFでも item.calculate_complex_property() が実行されてしまう

logger.debug(f”アイテムの詳細プロパティ: {item.calculate_complex_property()}”)

レベルチェックによるガード

if logger.isEnabledFor(logging.DEBUG):
logger.debug(f”アイテムの詳細プロパティ: {item.calculate_complex_property()}”)

または、loggingメソッドの extra 引数で遅延評価可能なオブジェクトを渡す方法もあるが、一般的ではない。

ロギング処理自体がメッセージ整形前にレベルチェックするため、上記ガードが最もシンプルで効果的。

“`

4.4. 非同期処理とロギング

FastAPIは非同期フレームワークであり、複数のコルーチンが同時に実行されます。loggingモジュール自体はスレッドセーフですが、ContextVarのような非同期コンテキスト管理ツールを使用しない場合、リクエスト固有のコンテキスト情報（例: リクエストID）が異なるリクエストのログメッセージに混ざってしまう可能性があります。

前述のContextVarを使用したコンテキスト追加の方法は、非同期処理においてもリクエストコンテキストを正しく維持するために有効です。

第5章：構造化ロギング (Structured Logging)

テキスト形式のログは人間にとっては読みやすいですが、機械による解析や集計には向きません。近年、ログをJSONなどの構造化された形式で出力する構造化ロギングが一般的になっています。

構造化ログの利点：

  • 検索と集計の容易さ: キー-バリュー形式のため、特定のフィールド（例: status_code, user_id, request_id）で簡単に検索、フィルタリング、集計ができます。
  • ログ管理システムとの連携: ELK Stack (Elasticsearch, Logstash, Kibana), Splunk, Datadog, AWS CloudWatch Logsなど、多くのログ管理システムは構造化ログの取り込みと解析に最適化されています。
  • 一貫性: ログメッセージのフォーマットが一貫するため、解析処理を簡素化できます。

Pythonで構造化ロギングを実現するためのライブラリがいくつかあります。代表的なものにpython-json-loggerとstructlogがあります。

5.1. python-json-logger を使用した構造化ロギング

python-json-loggerは、標準のlogging.Formatterを置き換える形で機能します。既存のloggingコードを変更することなく、出力形式をJSONに変更できるのが利点です。

インストール: pip install python-json-logger

使用方法: dictConfigのformattersセクションで、Formatterクラスとしてpythonjsonlogger.jsonlogger.JsonFormatterを指定します。

“`python

logging_config_json.py

import logging
import sys
from pythonjsonlogger import jsonlogger # インストールが必要

LOGGING_CONFIG_JSON = {
‘version’: 1,
‘disable_existing_loggers’: False,
‘formatters’: {
‘json_formatter’: {
‘()’: jsonlogger.JsonFormatter,
‘fmt’: ‘%(asctime)s %(levelname)s %(name)s %(message)s %(request_id)s’ # 含めたい属性を指定
}
},
‘handlers’: {
‘console’: {
‘class’: ‘logging.StreamHandler’,
‘formatter’: ‘json_formatter’, # JSONフォーマッターを使用
‘stream’: ‘ext://sys.stdout’
},
‘file’: {
‘class’: ‘logging.handlers.RotatingFileHandler’,
‘formatter’: ‘json_formatter’, # JSONフォーマッターを使用
‘filename’: ‘app.log.json’, # ファイル名に拡張子を付けると分かりやすい
‘maxBytes’: 1024 * 1024 * 5,
‘backupCount’: 5
}
},
‘loggers’: {
”: { # ルートロガー
‘handlers’: [‘console’, ‘file’],
‘level’: ‘INFO’,
‘propagate’: False
},
‘myapp’: { # アプリケーション固有のロガー
‘handlers’: [‘console’, ‘file’],
‘level’: ‘DEBUG’,
‘propagate’: False
}
}
}
“`

ContextVarで追加したrequest_idのようなカスタム属性も、Formatterのfmtに%(request_id)sのように含めることでJSON出力に追加できます。（ただし、ContextVar + Filter の例で示されたように、Filterでログレコードに属性を追加する必要があります。）

アプリケーションコードでの使い方：

“`python

main.py

import logging
import logging.config
from fastapi import FastAPI
import uuid
import time
import contextvars

from logging_config_json import LOGGING_CONFIG_JSON # JSON設定をインポート

ContextVar と Filter (ContextFilter) は前述の例と同じものを使用

ContextFilter を dictConfig に追加する必要がある

LOGGING_CONFIG_JSON[‘filters’] = {
‘context_filter’: {
‘()’: ‘main.ContextFilter’ # または適切なモジュールパス
}
}

console ハンドラーと file ハンドラーに context_filter を関連付ける必要がある

LOGGING_CONFIG_JSON[‘handlers’][‘console’][‘filters’] = [‘context_filter’]
LOGGING_CONFIG_JSON[‘handlers’][‘file’][‘filters’] = [‘context_filter’]

アプリケーション起動前にロギング設定を適用

logging.config.dictConfig(LOGGING_CONFIG_JSON)

ロガーを取得

app_logger = logging.getLogger(“myapp”)

FastAPI アプリとミドルウェア (ContextVar をセットする部分) は前述の例と同じ

app = FastAPI()

request_id_var = contextvars.ContextVar(‘request_id’, default=None) # ContextVar も定義

@app.middleware(“http”)
async def logging_middleware(request: Request, call_next):
req_id = str(uuid.uuid4())
token = request_id_var.set(req_id)
start_time = time.time()

app_logger.info(f"リクエスト開始: method={request.method} path={request.url.path}", extra={'custom_key': 'custom_value'}) # extra で追加情報を渡す例

try:
    response = await call_next(request)
    process_time = time.time() - start_time
    app_logger.info(f"リクエスト完了: status={response.status_code} time={process_time:.4f}s")
    return response
except Exception as e:
    app_logger.error(f"リクエスト処理中にエラーが発生: {e}", exc_info=True)
    raise e
finally:
    request_id_var.reset(token)

エンドポイントの例

@app.get(“/hello”)
async def hello():
app_logger.info(“Helloエンドポイント内で処理中.”)
return {“message”: “Hello”}

@app.get(“/error”)
async def simulate_error():
app_logger.error(“エラーエンドポイント内でエラーをシミュレート.”)
raise RuntimeError(“Intentional error”)

ContextFilter クラスの定義も必要 (前述の例を参照)

class ContextFilter(logging.Filter):
def filter(self, record):
record.request_id = request_id_var.get()
return True
“`

python-json-loggerはextra引数で渡された辞書の内容も自動的にJSONに含めてくれます。ContextVar+Filterでログレコードに付加した情報も、Formatterで指定すれば出力に含まれます。

出力例 (JSON形式):

json
{"asctime": "2023-10-27 10:30:00,123", "levelname": "INFO", "name": "myapp", "message": "リクエスト開始: method=GET path=/", "request_id": "abcdef12-3456-7890-abcd-ef1234567890", "custom_key": "custom_value"}
{"asctime": "2023-10-27 10:30:00,456", "levelname": "INFO", "name": "myapp", "message": "Helloエンドポイント内で処理中.", "request_id": "abcdef12-3456-7890-abcd-ef1234567890"}
{"asctime": "2023-10-27 10:30:00,789", "levelname": "INFO", "name": "myapp", "message": "リクエスト完了: status=200 time=0.6660s", "request_id": "abcdef12-3456-7890-abcd-ef1234567890"}

5.2. structlog を使用した構造化ロギング

structlogは、標準のloggingモジュールとは異なるアプローチをとるライブラリです。より柔軟で強力な構造化ロギング機能を提供しますが、既存のloggingコードからの移行には変更が必要になる場合があります。

structlogは、イベント処理パイプラインを通じてログイベントを処理します。各ステップでログレコードに情報を追加・変更・整形し、最終的にハンドラー（標準loggingのハンドラーを利用することも可能）に渡します。

インストール: pip install structlog

使用方法:

“`python

main.py

import structlog
import logging
import sys
import contextvars # 非同期処理のコンテキスト用
import uuid
import time

from fastapi import FastAPI, Request

ContextVar: リクエストIDを保持

request_id_var = contextvars.ContextVar(‘request_id’, default=None)

structlog の設定

ContextVar から request_id を取得してログに追加するプロセッサー

def add_request_id(logger, method_name, event_dict):
request_id = request_id_var.get()
if request_id:
event_dict[‘request_id’] = request_id
return event_dict

標準loggingとの連携を設定

structlog.configure(
processors=[
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt=”iso”), # タイムスタンプを追加
add_request_id, # カスタムプロセッサーを挿入
structlog.processors.StackInfoRenderer(), # 例外発生時にスタックトレースを追加
structlog.processors.format_exc_info, # 例外情報を整形
structlog.stdlib.ProcessorFormatter.wrap_for_formatter, # 標準Formatter向けにラップ
],
logger_factory=structlog.stdlib.LoggerFactory(), # 標準loggingのロガーファクトリを使用
wrapper_class=structlog.stdlib.BoundLogger, # 標準loggingのロガーをラップ
cache_size=1000 # structlogロガーをキャッシュ
)

標準loggingの dictConfig 設定 (structlogからの出力先を定義)

LOGGING_CONFIG_STRUCTLOG = {
‘version’: 1,
‘disable_existing_loggers’: False,
‘formatters’: {
‘json_formatter’: {
‘()’: structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
‘processor’: structlog.processors.JSONRenderer(), # JSONRenderer を使用
# fmt は不要、processor が整形を担当
},
‘colored_console’: {
‘()’: structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
‘processor’: structlog.dev.ConsoleRenderer(colors=True), # 開発用色付きコンソール出力
# fmt は不要
}
},
‘handlers’: {
‘console’: {
‘class’: ‘logging.StreamHandler’,
‘formatter’: ‘colored_console’, # structlog のコンソール用Formatterを使用
‘stream’: ‘ext://sys.stdout’
},
‘file’: {
‘class’: ‘logging.handlers.RotatingFileHandler’,
‘formatter’: ‘json_formatter’, # structlog のJSON用Formatterを使用
‘filename’: ‘app.log.json’,
‘maxBytes’: 1024 * 1024 * 5,
‘backupCount’: 5
}
},
‘loggers’: {
”: { # ルートロガー
‘handlers’: [‘console’, ‘file’],
‘level’: ‘INFO’,
‘propagate’: False
},
‘myapp’: { # アプリケーション固有のロガー
‘handlers’: [‘console’, ‘file’],
‘level’: ‘DEBUG’,
‘propagate’: False
},
# Uvicorn ロガーなども必要に応じて定義
}
}

標準loggingの設定を適用

logging.config.dictConfig(LOGGING_CONFIG_STRUCTLOG)

structlog のロガーを取得 (標準loggingのロガーをラップしたものになる)

app_logger = structlog.get_logger(“myapp”)

app = FastAPI()

ミドルウェア (ContextVar をセットする部分は同じ)

@app.middleware(“http”)
async def logging_middleware(request: Request, call_next):
req_id = str(uuid.uuid4())
token = request_id_var.set(req_id)
start_time = time.time()

# structlog では キーワード引数で追加情報を渡すのが一般的
app_logger.info("リクエスト開始", method=request.method, path=request.url.path)

try:
    response = await call_next(request)
    process_time = time.time() - start_time
    app_logger.info("リクエスト完了", status=response.status_code, time_seconds=process_time)
    return response
except Exception as e:
    # exc_info=True は標準loggingの機能だが、structlogもサポート
    app_logger.error("リクエスト処理中にエラーが発生", exc_info=True)
    raise e
finally:
    request_id_var.reset(token)

エンドポイントの例

@app.get(“/hello”)
async def hello():
# structlog ではメッセージと追加情報を分けて渡すスタイルが推奨
app_logger.info(“Helloエンドポイント内で処理中”, status=”processing”)
return {“message”: “Hello”}

@app.get(“/error”)
async def simulate_error():
app_logger.error(“エラーエンドポイント内でエラーをシミュレート.”)
# exc_info=True を渡すとスタックトレースが付加される
raise RuntimeError(“Intentional error”)
“`

structlogは標準loggingよりも設定や使い方が独特ですが、プロセッサーチェーンによる柔軟な処理や、キーワード引数で構造化された情報を渡しやすいため、よりリッチなロギングを求める場合に有力な選択肢となります。

structlogとpython-json-loggerのどちらを選ぶかは、プロジェクトの要件、既存コードとの親和性、チームの慣れなどによって異なります。python-json-loggerは既存のloggingモジュールへの影響が少なく導入が容易ですが、structlogはより高度なカスタマイズや処理が可能です。

第6章：ロギングのベストプラクティスとヒント

  • 適切なログレベルの使用: 各ログレベルには明確な意図があります。これらを適切に使い分けることで、ログの重要度を素早く判断できます。
    • DEBUG: 開発/デバッグ時のみ有効にする詳細情報。変数の中身など。
    • INFO: アプリケーションの正常な流れを示す情報。リクエストの開始/完了、重要な処理の成功など。
    • WARNING: 潜在的な問題、回復可能なエラー、推奨されない状況など。設定ファイルの不足、非推奨機能の使用など。
    • ERROR: 期待通りに処理が続行できない問題。データベース接続エラー、外部APIの失敗など。
    • CRITICAL: アプリケーションの停止など、壊滅的な問題。メモリ不足、ディスクフルなど。
  • ログメッセージにコンテキストを含める: ログメッセージだけでは状況が把握できないことがよくあります。ユーザーID、リクエストID、注文ID、関連するデータベースレコードのIDなど、問題特定に役立つ情報を構造化されたデータとして含めるように心がけましょう。
  • 例外情報は必ず記録する: エラーログを記録する際は、例外オブジェクトをlogger.error("...", exc_info=True)のように渡すことで、スタックトレースなどの詳細情報がログに含まれるようになります。これは問題の原因特定に不可欠です。
  • 機密情報をログに含めない: パスワード、クレジットカード番号、個人情報など、機密性の高い情報はログに絶対に含めないでください。リクエストやレスポンス全体をログに記録する場合、これらの情報をマスクまたは削除する処理が必要です。
  • ログの量を管理する: 過剰なロギングはストレージを圧迫し、パフォーマンスに影響を与え、ノイズが多くて重要なログを見つけにくくします。必要な情報を必要なレベルで記録するように調整しましょう。
  • 本番環境と開発環境で設定を分ける: 開発環境ではDEBUGレベルでコンソールに出力し、本番環境ではINFO以上をファイルや集中ログ管理システムに送るなど、環境に応じた設定を行いましょう。dictConfigと設定ファイルを組み合わせるのが効果的です。
  • 集中ログ管理システムの導入: アプリケーションが複数になったり、スケールしたりする場合、各サーバーのログファイルを個別に確認するのは非効率です。Elasticsearch/Logstash/Kibana (ELK), Splunk, Datadog, Grafana Loki, AWS CloudWatch Logs, Google Cloud Logging, Azure Monitor Logsなどの集中ログ管理システムを導入し、ログの収集、保存、検索、分析、可視化を効率化しましょう。構造化ロギングはこれらのシステムとの連携を強力にサポートします。
  • ログのレビュー習慣: 定期的にログを確認し、警告やエラーが発生していないかをチェックする習慣をつけましょう。異常を早期に発見することが、大きな問題への発展を防ぎます。
  • ロギング設定のテスト: ロギング設定は意図した通りに機能しているか（適切なファイルに書かれているか、レベルは正しいか、フォーマットは期待通りかなど）をテストすることが重要です。

第7章：よくある問題とトラブルシューティング

  • ログが出力されない:
    • ロガーのレベルが低すぎる可能性があります。設定されたレベル以上のメッセージのみが出力されます。
    • ハンドラーがロガーに関連付けられていない可能性があります。dictConfigでロガーに適切なハンドラーが指定されているか確認してください。
    • ハンドラーのレベルが低すぎる可能性があります。ハンドラーにもレベルを設定できます。
    • disable_existing_loggers: True になっていると、既存のロガー（特にルートロガー）が無効になっている可能性があります。
    • ファイルハンドラーの場合、ファイルへの書き込み権限がない可能性があります。
  • ログが二重に出力される:
    • ロガーのpropagate属性がTrue（デフォルト）になっていて、かつ親ロガー（特にルートロガー）にも同じハンドラーが関連付けられている可能性があります。propagate: Falseを設定して伝播を止めます。
    • 同じハンドラーが複数のロガーやルートロガーに重複して追加されている可能性があります。dictConfigを使用している場合、設定辞書を確認してください。
  • Uvicornのログが表示されない/カスタム設定が適用されない:
    • disable_existing_loggers: True になっていると、Uvicornのロガーが無効になります。Falseに設定してください。
    • loggersセクションでuvicorn, uvicorn.error, uvicorn.accessなどのロガーを適切に定義し、ハンドラーを関連付けているか確認してください。
  • カスタムフィルターやフォーマッターが機能しない:
    • dictConfigのfiltersやformattersセクションで正しく定義されているか確認してください。
    • ハンドラーにフィルターやフォーマッターが正しく関連付けられているか確認してください。
    • カスタムクラスのモジュールパスが正しいか確認してください（__main__.MyFilterなど）。
  • 非同期処理でコンテキスト情報が混ざる:
    • ContextVarのような非同期コンテキスト管理ツールを使用せずにリクエスト固有の情報を扱おうとしている可能性があります。ContextVarの使用を検討してください。
    • ContextVarのset/resetが正しくペアで行われているか確認してください。特にエラーハンドリングでresetを忘れやすいので注意が必要です（finallyブロックでの実行が推奨されます）。

これらの問題のほとんどは、dictConfigの設定辞書を注意深く確認することで解決できます。

結論：より堅牢なFastAPIアプリケーションのために

FastAPIアプリケーションにおけるロギングは、単にエラーメッセージを表示する以上のものです。それは、アプリケーションの挙動を理解し、問題を迅速に診断し、パフォーマンスを最適化し、セキュリティを維持するための強力なツールです。

Python標準のloggingモジュールは非常に柔軟であり、logging.config.dictConfigを使用することで、複雑な要件を持つアプリケーションにも対応できる堅牢なロギングシステムを構築できます。コンソール出力、ファイル出力、ローテーション、異なるレベルでのハンドリング、そしてリクエストコンテキストのような情報の付加が可能です。

さらに、構造化ロギングライブラリ（python-json-logger, structlogなど）や集中ログ管理システムを導入することで、ログの収集、分析、活用を次のレベルに引き上げることができます。

FastAPI開発者として、アプリケーションコードを書く際には、どのような情報がログとして価値を持つかを常に意識し、適切なレベルとコンテキストでログを出力する習慣をつけましょう。これにより、あなた自身や運用チームが、自信を持ってアプリケーションを本番環境で実行し、管理できるようになります。

この記事で紹介したテクニックや設定例が、あなたのFastAPIアプリケーションにおける効果的なロギング実装の一助となれば幸いです。実践を重ね、あなたのプロジェクトに最適なロギング戦略を確立してください。

コメントする

メールアドレスが公開されることはありません。 ※ が付いている欄は必須項目です

上部へスクロール