当サイトは、アフィリエイト広告を利用しています
fastapi製のアプリケーションを動かす際によく使われる
ASGI(Synchronous Server Gateway Interface)サーバのUvicornで
ログの出力をカスタマイズする方法を調べたので忘備録として残す。
uvicornは内部でPython標準のloggingモジュールのdictConfigを使って
デフォルトでロガーが設定されている
LOGGING_CONFIG: dict[str, Any] = {# ロギングの設定バージョン (固定で 1 を指定)"version": 1,# 既存のロガーを無効にしない (他のロガー設定を保持する)"disable_existing_loggers": False,# 【フォーマッターの設定】ログの出力フォーマットを定義"formatters": {# デフォルトのフォーマット (主に uvicorn.error で使用)"default": {"()": "uvicorn.logging.DefaultFormatter","fmt": "%(levelprefix)s %(message)s", # ログレベルとメッセージのみ出力"use_colors": False, # ANSI カラー出力 (ターミナルによって自動調整)},# アクセスログのフォーマット (HTTP リクエスト情報を含む)"access": {"()": "uvicorn.logging.AccessFormatter","fmt": '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s', # クライアントIP、リクエスト、ステータスコードを表示},},# 【ハンドラーの設定】ログの出力先を定義"handlers": {# 標準ログの出力先 (uvicorn.error など)"default": {"formatter": "default", # 上記の "default" フォーマッターを使用"class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stderr", # 出力先を標準エラー (stderr) に指定},# アクセスログの出力先 (uvicorn.access 用)"access": {"formatter": "access", # 上記の "access" フォーマッターを使用"class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stdout", # 出力先を標準出力 (stdout) に指定},},# 【ロガーの設定】各ロガーが使用するハンドラーとログレベルを定義"loggers": {# メインの Uvicorn ロガー (デフォルトでは出力されない)"uvicorn": {"handlers": ["default"], # 標準ログのハンドラーを使用"level": "INFO", # INFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},# エラーログ (起動メッセージや例外ログを出力)"uvicorn.error": {"level": "INFO", # INFO レベル以上を出力 (ハンドラーは root logger に委任)},# アクセスログ (HTTP リクエストログを出力)"uvicorn.access": {"handlers": ["access"], # アクセスログ専用のハンドラーを使用"level": "INFO", # INFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},},}
「formatters」、「handlers」、「loggers」などの項目については下記記事で詳しくまとめている
上記の通り、uvicornはデフォルトでは
3つのロガーが設定してある
汎用的に使用されるロガー。
設定はしてあるが、、Uvicorn のコード内部で logging.getLogger("uvicorn") に対してログが送られていないため、何も出力されない。
つまり、デフォルトでは 「uvicorn ロガーは設定されているけど、何も出力しない」 という状態になっている。
uvicornロガーを有効にするには、明示的に
logging.getLogger("uvicorn")
をして使う必要がある
サーバー起動メッセージや例外に使用されるロガー。
# エラーログ (起動メッセージや例外ログを出力)"uvicorn.error": {"level": "INFO", # INFO レベル以上を出力 (ハンドラーは root logger に委任)},
のようにログレベルしか明示されていないので
はルートロガーを設定を継承する
つまり、ログレベルINFO以上のログがsys.stderr(標準エラー出力)に下記のフォーマットで出力される
%(asctime)s - %(name)s - %(levelname)s - %(message)s
uvicorn起動時にログ出力されている
INFO: Will watch for changes in these directories: ['/workspace']INFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)INFO: Started reloader process [1] using WatchFilesINFO: Started server process [8]INFO: Waiting for application startup.INFO: Application startup complete.
はuvicorn.errorロガーが出している
HTTPリクエストのアクセスを記録するログ。
ログレベルINFO以上のログがsys.stdout(標準出力)に下記のフォーマットで出力される
%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s
REST APIのエンドポイントにアクセスした時に出力される
INFO: 172.28.0.1:50100 - "GET / HTTP/1.1" 211
はuvicorn.accessロガーが出している
特に何も設定せずにUvicornを動かしたとしても基本的なログは
uvicorn.errorロガーとuvicorn.errorロガーがコンソールに出力してくれる
Uvicornに対してデフォルトではなく、ログ出力をカスタマイズしたい場合、方法としては
の2つがある
Pythonスクリプトからuvicornを起動する場合は
uvicorn.runメソッドの引数「log_config」にuvicorn設定辞書を渡すことで
カスタマイズをすることができる
uvicorn.run("asgi:app",host=config["host"],port=config["port"],reload=config["reload"],# log_level=config["log_level"],access_log=True,log_config=custom_logging_config)
簡単なfastapiのREST APIを上記の方法でログ設定をカスタマイズした
uvicornで動作させて確認する
カスタマイズは下記にする
.|-- app| |-- __init__.py| |-- asgi.py| |-- endpoints.py| `-- main.py|-- docker-compose.yml|-- dockerfile|-- requirements.txt|-- start_uvicorn.py`-- uvicorn_config.py
dockerコンテナ上でfastapiのREST APIをuvicornで動かす
FROM python:3.12# PYTHONPATHの設定ENV PYTHONPATH=/workspace/app# workspaceディレクトリ作成、移動WORKDIR /workspace# プロジェクトディレクトリにコピーCOPY requirements.txt /workspace# 必要パッケージのインストールRUN pip install --upgrade pipRUN pip install -r requirements.txt
fastapi==0.115.6uvicorn[standard]==0.34.0
version: "3"services:uvicorn-log:container_name: "uvicorn-log"build:context: .dockerfile: Dockerfilevolumes:- .:/workspacetty: trueports:- 8000:8000entrypoint: ["python", "start_uvicorn.py"]
from fastapi import FastAPIimport loggingimport endpoints as endpoints# from logger import logger_initdef create_app():# アプリケーションインスタンスの作成app = FastAPI()# ルーティング設定app.include_router(endpoints.router)return app
from main import create_appapp = create_app()
import loggingfrom fastapi import APIRouter, HTTPExceptionfrom fastapi.responses import JSONResponse# uvicornロガーを取得logger = logging.getLogger("uvicorn")router = APIRouter()# ディクショナリusers = [{"user_id": "1", "name": "Tujimura", "age": 11},{"user_id": "2", "name": "mori", "age": 20},{"user_id": "3", "name": "shimada", "age": 501},{"user_id": "4", "name": "kyogoku", "age": 70}]# ユーザー一覧を取得@router.get("/")async def get_users():# ログ出力logger.error("error")logger.critical("critical")return JSONResponse(status_code=211, content=users)
import os# ログディレクトリの作成log_dir = "/workspace/log"os.makedirs(log_dir, exist_ok=True)# uvicornログ設定custom_logging_config = {# ロギングの設定バージョン (固定で 1 を指定)"version": 1,# 既存のロガーを無効にしない (他のロガー設定を保持する)"disable_existing_loggers": False,# 【フォーマッターの設定】ログの出力フォーマットを定義"formatters": {# デフォルトのフォーマット (主に uvicorn.error で使用)"default": {"()": "uvicorn.logging.DefaultFormatter","fmt": "%(levelprefix)s %(message)s", # ログレベルとメッセージのみ出力"use_colors": False, # ANSI カラー出力 (ターミナルによって自動調整)},# アクセスログのフォーマット (HTTP リクエスト情報を含む)"access": {"()": "uvicorn.logging.AccessFormatter","fmt": '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s', # クライアントIP、リクエスト、ステータスコードを表示"use_colors": False, # ANSI カラー出力 (ターミナルによって自動調整)},},# 【ハンドラーの設定】ログの出力先を定義"handlers": {# 標準ログの出力先"default": {"formatter": "default", # 上記の "default" フォーマッターを使用"level": "INFO","class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stderr", # 出力先を標準エラー (stderr) に指定},# クリティカルログファイル出力"critical_file": {"formatter": "default","level": "CRITICAL","class": "logging.FileHandler","filename": os.path.join(log_dir, "critical_logfile"),},# エラーログファイル出力"error_file": {"formatter": "default","level": "INFO","class": "logging.FileHandler","filename": os.path.join(log_dir, "error_logfile"),},# アクセスログファイル出力"access_file": {"formatter": "access","level": "INFO","class": "logging.FileHandler","filename": os.path.join(log_dir, "access_logfile"),},},# 【ロガーの設定】各ロガーが使用するハンドラーとログレベルを定義"loggers": {# メインの Uvicorn ロガー (デフォルトでは出力されない)"uvicorn": {"handlers": ["default","critical_file"], # 標準ログのハンドラーを使用"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},# エラーログ (起動メッセージや例外ログを出力)"uvicorn.error": {"handlers": ["default","error_file"], # コンソールとエラーログファイルに出力"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},# アクセスログロガー"uvicorn.access": {"handlers": ["default","access_file"], # コンソールとアクセスログファイルに出力"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},},}# uvicorn起動config = {"host": "0.0.0.0","port": 8000,"reload": True,"log_level": "info","log_config": custom_logging_config,}
import uvicornfrom uvicorn_config import config # uvicornの設定if __name__ == "__main__":# uvicorn起動uvicorn.run("asgi:app",host=config["host"],port=config["port"],reload=config["reload"],access_log=True,log_config=config["log_config"] # uviconrのlog設定)
カスタマイズしたロガー
の動作を確認する。
uvicornロガーの設定は
"uvicorn": {"handlers": ["default","critical_file"], # 標準ログのハンドラーを使用"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},
で、ログレベルが「INFO」以上なっている
そして、ハンドラーに
"handlers": {# 標準ログの出力先"default": {"formatter": "default", # 上記の "default" フォーマッターを使用"level": "INFO","class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stderr", # 出力先を標準エラー (stderr) に指定},# クリティカルログファイル出力"critical_file": {"formatter": "default","level": "CRITICAL","class": "logging.FileHandler","filename": os.path.join(log_dir, "critical_logfile"),},
"default"と"critical_file"が設定されている
まとめるとuvicornロガーのログ出力は
となる。
uvicornロガーで出力しているのは
import loggingfrom fastapi import APIRouter, HTTPExceptionfrom fastapi.responses import JSONResponse# uvicornロガーを取得logger = logging.getLogger("uvicorn")router = APIRouter()# ディクショナリusers = [{"user_id": "1", "name": "Tujimura", "age": 11},{"user_id": "2", "name": "mori", "age": 20},{"user_id": "3", "name": "shimada", "age": 501},{"user_id": "4", "name": "kyogoku", "age": 70}]# ユーザー一覧を取得@router.get("/")async def get_users():# ログ出力logger.error("error")logger.critical("critical")return JSONResponse(status_code=211, content=users)
の部分になる
下記のようにREST APIのGETリクエストを実行して
$ curl -i -X GET http://localhost:8000HTTP/1.1 211date: Fri, 14 Feb 2025 13:20:22 GMTserver: uvicorncontent-length: 168content-type: application/json[{"user_id":"1","name":"Tujimura","age":11},{"user_id":"2","name":"mori","age":20},{"user_id":"3","name":"shimada","age":501},{"user_id":"4","name":"kyogoku","age":70}]
コンテナのログを確認すると
$ docker logs uvicorn-logINFO: Will watch for changes in these directories: ['/workspace'] # uvicorn.errorロガーのログINFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit) # uvicorn.errorロガーのログINFO: Started reloader process [1] using WatchFiles # uvicorn.errorロガーのログINFO: Started server process [8] # uvicorn.errorロガーのログINFO: Waiting for application startup. # uvicorn.errorロガーのログINFO: Application startup complete. # uvicorn.errorロガーのログERROR: errorCRITICAL: criticalINFO: 172.18.0.1:32804 - "GET / HTTP/1.1" 211 # uvicorn.accessロガーのログ
のようにuvicornロガーのログが出力されている
※他のロガーのログも混在している
critical_logfileには
CRITICAL: critical
のようにログレベルが「critical」のログのみが記録される
uvicorn.errorロガーの設定は
# エラーログ (起動メッセージや例外ログを出力)"uvicorn.error": {"handlers": ["default","error_file"], # コンソールとエラーログファイルに出力"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},
で、ログレベルが「INFO」以上なっている
そして、ハンドラーに
# 【ハンドラーの設定】ログの出力先を定義"handlers": {# 標準ログの出力先"default": {"formatter": "default", # 上記の "default" フォーマッターを使用"level": "INFO","class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stderr", # 出力先を標準エラー (stderr) に指定},# # クリティカルログファイル出力# "critical_file": {# "formatter": "default",# "level": "CRITICAL",# "class": "logging.FileHandler",# "filename": os.path.join(log_dir, "critical_logfile"),},# エラーログファイル出力"error_file": {"formatter": "default","level": "INFO","class": "logging.FileHandler","filename": os.path.join(log_dir, "error_logfile"),},
"default"と"error_file"が設定されているので
まとめるとuvicorn.errorロガーのログ出力は
となる。
uvicorn.errorロガーはサーバー起動時や例外時に出力されるように
デフォルトで設定されているので特にREST APIのプログラム上ではロガーを取得しない。
コンテナ起動時のログを見ると
$ docker logs uvicorn-logINFO: Will watch for changes in these directories: ['/workspace']INFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)INFO: Started reloader process [1] using WatchFilesINFO: Started server process [8]INFO: Waiting for application startup.INFO: Application startup complete.ERROR: error # uvicornロガーのログCRITICAL: critical # uvicornロガーのログINFO: 172.18.0.1:32804 - "GET / HTTP/1.1" 211 # uvicorn.accessロガーのログ
uvicorn.errorロガーのログが出力されている
※他のロガーのログも混在している
同様の内容がerror_logfileにも出力されている
INFO: Will watch for changes in these directories: ['/workspace']INFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)INFO: Started reloader process [1] using WatchFilesINFO: Started server process [8]INFO: Waiting for application startup.INFO: Application startup complete.
uvicorn.accessロガーの設定は
# アクセスログロガー"uvicorn.access": {"handlers": ["default","access_file"], # コンソールとアクセスログファイルに出力"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},
で、ログレベルが「INFO」以上なっている
そして、ハンドラーに
"handlers": {# 標準ログの出力先"default": {"formatter": "default", # 上記の "default" フォーマッターを使用"level": "INFO","class": "logging.StreamHandler", # 標準出力に送るストリームハンドラー"stream": "ext://sys.stderr", # 出力先を標準エラー (stderr) に指定},# # クリティカルログファイル出力# "critical_file": {# "formatter": "default",# "level": "CRITICAL",# "class": "logging.FileHandler",# "filename": os.path.join(log_dir, "critical_logfile"),# },# # エラーログファイル出力# "error_file": {# "formatter": "default",# "level": "INFO",# "class": "logging.FileHandler",# "filename": os.path.join(log_dir, "error_logfile"),# },# アクセスログファイル出力"access_file": {"formatter": "access","level": "INFO","class": "logging.FileHandler","filename": os.path.join(log_dir, "access_logfile"),},
"default"と"access_file"が設定されている
まとめるとuvicorn.accessロガーのログ出力は
となる。
uvicorn.accessロガーはアクセス時に出力されるように
デフォルトで設定されているので特にREST APIのプログラム上ではロガーを取得しない。
コンテナ起動時→GETリクエストのログを見ると
$ docker logs uvicorn-logINFO: Will watch for changes in these directories: ['/workspace'] # uvicorn.errorロガーのログINFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit) # uvicorn.errorロガーのログINFO: Started reloader process [1] using WatchFiles # uvicorn.errorロガーのログINFO: Started server process [8] # uvicorn.errorロガーのログINFO: Waiting for application startup. # uvicorn.errorロガーのログINFO: Application startup complete. # uvicorn.errorロガーのログERROR: error # uvicornロガーのログCRITICAL: critical # uvicornロガーのログINFO: 172.18.0.1:32804 - "GET / HTTP/1.1" 211
uvicorn.accessロガーのログが出力されている ※他のロガーのログも混在している
同様の内容がaccess_logfileにも出力されている
INFO: 172.18.0.1:32804 - "GET / HTTP/1.1" 211
dictConfigを使ってuvicornのログ設定をする際に
ハマったポイントがあったのでまとめておく。
dictConfigを使ってuvicornのログ設定をする時は
ロガーのログレベルを設定する箇所が
"uvicorn": {"handlers": ["default","critical_file"], # 標準ログのハンドラーを使用"level": "INFO", # ロガーではINFO レベル以上を出力"propagate": False, # 他のロガーにログを伝播させない},
と
import uvicornfrom uvicorn_config import configif __name__ == "__main__":# uvicorn起動uvicorn.run("asgi:app",host=config["host"],port=config["port"],reload=config["reload"],log_level=config["log_level"],access_log=True,log_config=config["log_config"])
の箇所ある。
上記の二つともに設定をした場合、ロガーのログレベルは
「uvicorn_config.py」のloggerで設定したログレベルは無視され
「start_uvicorn.py」のuvicorn.runの引数「log_level」で設定した
ログレベルが優先される
※ハンドラーは別
上記ではuvicornをpythonスクリプトから起動する際に、uvicorn.runメソッドの
引数としてuvicornのログ設定のdictを渡したが、こちらは
uvicornをコマンド起動する際にログ設定をしたymlファイルを渡す。
uviconrnのログ設定ymlファイルを作成する
version: 1disable_existing_loggers: Falseformatters:default:"()": "uvicorn.logging.DefaultFormatter"fmt: "%(levelprefix)s %(message)s"use_colors: Falseaccess:"()": "uvicorn.logging.AccessFormatter"fmt: '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s'handlers:default:formatter: "default"class: "logging.StreamHandler"stream: "ext://sys.stderr"access:formatter: "access"class: "logging.StreamHandler"stream: "ext://sys.stdout"loggers:uvicorn:handlers: ["default"]level: "INFO"propagate: Falseuvicorn.error:level: "INFO"uvicorn.access:handlers: ["access"]level: "INFO"propagate: False
Uvicorn内部のdictConfig(デフォルトのロガー設定)をyamlファイル化したものを載せておく。
これはデフォルトの設定なので、カスタマイズしたいときをこれに対して行う。
version: 1disable_existing_loggers: Falseformatters:default:"()": "uvicorn.logging.DefaultFormatter"fmt: "%(levelprefix)s %(message)s"use_colors: Falseaccess:"()": "uvicorn.logging.AccessFormatter"fmt: '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s'use_colors: Falsehandlers:default:class: logging.StreamHandlerlevel: INFOformatter: defaultstream: ext://sys.stderrcritical_file:class: logging.FileHandlerlevel: CRITICALformatter: defaultfilename: /workspace/log/critical_logfileerror_file:class: logging.FileHandlerlevel: INFOformatter: defaultfilename: /workspace/log/error_logfileaccess_file:class: logging.FileHandlerlevel: INFOformatter: accessfilename: /workspace/log/access_logfileloggers:uvicorn:handlers: [default, critical_file]level: INFOpropagate: falseuvicorn.error:handlers: [default, error_file]level: INFOpropagate: falseuvicorn.access:handlers: [default, access_file]level: INFOpropagate: false
デフォルト設定ymlに対して
でしたのと同様のカスタマイズをしたyamlファイル
pythonスクリプトでのuvicorn起動から、コマンドでの起動に変更する
version: "3"services:uvicorn-log:container_name: "uvicorn-log"build:context: .dockerfile: Dockerfilevolumes:- .:/workspace- ./log:/workspace/log # ローカルの log/ をコンテナの /workspace/log にマウントtty: trueports:- 8000:8000 # ホストマシンのポート8000を、docker内のポート8000に接続する# entrypoint: ["python", "start_uvicorn.py"]command:["uvicorn","asgi:app","--reload","--host","0.0.0.0","--port","8000","--log-config","logging_config_custom.yml",]