概要
DjangoのLOGGINGの設定について、今までは割と適当に書いていたが、今回、ちゃんと調べて意味を理解しながら設定を書いたので、経緯を記事にしてみたいと思う。
結論
最終的なsettings.pyのLOGGINGの設定は以下のようになった。
#ログ出力先のディレクトリを設定する LOG_BASE_DIR = os.path.join("/var", "log", "app") LOGGING = { "version": 1, "disable_existing_loggers": False, "formatters": {"simple": {"format": "%(asctime)s [%(levelname)s] %(message)s"}}, "handlers": { "info": { "level": "INFO", "class": "logging.FileHandler", "filename": os.path.join(LOG_BASE_DIR, "info.log"), "formatter": "simple", }, "warning": { "level": "WARNING", "class": "logging.FileHandler", "filename": os.path.join(LOG_BASE_DIR, "warning.log"), "formatter": "simple", }, "error": { "level": "ERROR", "class": "logging.FileHandler", "filename": os.path.join(LOG_BASE_DIR, "error.log"), "formatter": "simple", }, }, "root": { "handlers": ["info", "warning", "error"], "level": "INFO", }, }
上記の設定に至るまでの考え方・調べたこと・ハマったことなど
DjangoのLOGGING = ほぼPython標準のlogging
大前提となる考え方として、DjangoのLOGGINGは、内部ではほぼPython標準のloggingを使っているだけである。
従って、Django特有のロギング機能があるとは考えなくてよいし、公式ドキュメントもdocs.python.org上のloggingの公式ドキュメントを読めばよい。
このことはDjangoの公式ドキュメントにも
Django uses Python’s builtin logging module to perform system logging. The usage of this module is discussed in detail in Python’s own documentation.
と記載されているし、以下のDjango本体のlog.pyのソースコードを読んでもわかる。
django/log.py at master · django/django · GitHub
【注意】"ValueError: Unable to configure handler"というエラーについて
LOGGINGの設定を編集していると、Djangoでrunserverを実行した時に、以下のようなエラーメッセージが出ることがある。
config.py", line 799, in dictConfig
dictConfigClass(config).configure()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/config.py", line 570, in configure
'%r' % name) from e
ValueError: Unable to configure handler 'django'エラーメッセージを読むとLOGGINGのhandlerの設定周りに誤りがあるように読めるが、このエラーメッセージは
にも出力されるややミスリーディングなエラーメッセージである。
(handlerに定義されているファイルの作成に失敗した結果、handlerを設定できなかったという意味だと思うので、間違ってはいないが)
これを知らずにLOGGINGの設定におかしな箇所がないかという方向で調べてしまうと、本質ではないところに時間を使ってしまうので、覚えておいた方が良い。
私もこれにハマって、以下の記事を参照させて頂いて解決した。
DjangoのLOGGINGで採用されている設定方式について
公式ドキュメントによると、Python標準のloggingには以下の2種類の設定方式が存在する。
dictConfigの方が新しいAPIらしく、DjangoもdictConfigによる設定方式を採用している。
従って、設定に関しては以下の公式ドキュメントのdictConfigの各設定値の説明を読めばよい。
以下、各設定値の説明をしていく。
version
公式ドキュメントに記載がある通り、必須項目であり、かつ「現在有効な値は 1 だけ」とのことなので、お約束として1をセットする。
disable_existing_loggers
まだ完全には理解していないが、この値がTrueだと、LOGGINGの設定を読み込む前に初期化されたloggerが無効になってしまい、ログが出力されなくなる場合があるらしい。
公式ドキュメントはFalseにすることを推奨しているので、Falseに設定する。
デフォルト値はTrueなので、明示的にFalseを設定する必要がある。
formatters
ログに出力したいメッセージのフォーマットを定義する。
使用可能な変数は以下に定義されている。
docs.python.org
この記事の設定では"simple"1つしか定義していないが、例えばERRORレベルではより多くの項目を出力したいというような要件がある場合は、複数定義する必要がある。
handlers
ログハンドラーを定義する。
よく見るサンプルコードでは以下のような設定になっていることが多い。
'handlers': { 'file': { 'level': 'DEBUG', 'class': 'logging.FileHandler', 'filename': '/path/to/django/debug.log', }, },
しかし、実運用を考えたprodutionコードの場合は、ログレベルによって出力先のログファイルを出し分けることが多いと思うので、本記事の例のように"FileHandler"を複数定義することになると思う。
本記事の例では、
- [INFO]レベル以上 → info.log
- [WARNING]レベル以上 → warning.log
- [ERROR]レベル以上 → error.log
と分けて出力する設定にしている。
なお、 巷のサンプルコードではキー名がほぼ決まって
- classが"FileHandler"の場合 → "file"
- classが"StreamHandler"の場合 → "console"
となっているが、このキーはただのhandlerの名前なので、任意の名前を設定してよい。(むしろ"file"と付けてしまうと、FileHandlerを複数定義する時に命名に困る。)
loggers
ここが一番理解が難しかったところなので、ちゃんと書きたいと思う。
loggerの名前解決の仕組み
そもそもの前提として、Pythonのloggerの名前解決の仕組みを理解しておく必要がある。
公式ドキュメントでは以下にて説明されているが、具体例を挙げて説明してみる。
docs.python.org
例えば、以下のようなloggerの設定があったとする。
※ "propagate"はデフォルトTrueだが、分かりやすいように明示している。
"loggers": { "aaa.bbb": { "propagate": True, # 他の設定は省略 }, "aaa": { "propagate": True, # 他の設定は省略 }, }, "root": { # 他の設定は省略 },
loggerには親子関係を持たせることができ、ドットで区切って表現される。
例えば、上記の設定においては、"aaa"のloggerは"aaa.bbb"のloggerの親という関係になる。
この設定の状態で、
logger = logging.getLogger("aaa.bbb") logger.info("hoge")
というコードを実行すると、以下のように伝播して、"aaa.bbb"のlogger、"aaa"のlogger、ルートloggerそれぞれのhandlerの設定に基づいてログが出力される。
①"aaa.bbb"のloggerにイベントが渡される。
②"aaa.bbb"のloggerは"propagate=True"なので、親の"aaa"のloggerにイベントが渡される。
③"aaa"のloggerは"propagate=True"なので、ルートloggerにイベントが渡される。
次に、"aaa.bbb"のloggerの"propagate"をFalseに変更して再度実行してみる。
同様にコードを実行すると、今度は"aaa.bbb"のloggerで伝播が止まるので、"aaa.bbb"のloggerのみのhandlerの設定に基づいてログが出力される。
以上が、Pythonのloggerの名前解決の仕組みである。
なぜlogger = logging.getLogger(__name__)と宣言するのか？
上記の名前解決の仕組みを踏まえた上で、なぜloggerを宣言するときは
logger = logging.getLogger(__name__)
とするのが良いプラクティスだということになっているのかを考えてみる。
仮に、Djangoのpolls.views.pyとpolls.forms.pyで上記の一文を宣言したとする。
この場合、__name__には自身のモジュール名が入っているので、それぞれ以下のコードと等しくなる。
logger = logging.getLogger("polls.views")
logger = logging.getLogger("polls.forms")
なので、以下のようなloggerの設定をするだけで、Djangoのapplication単位で共通のloggerを使うことができる。
"loggers": { "polls": { # 設定は省略 }, }
もしapplication単位でloggerを分ける必要がないのであれば、ルートloggerを設定するだけで良い。
(本記事の例ではルートloggerしか設定していない。)
このようにloggerの設定をアプリケーションの名前空間の構造に寄せて集約することができるのが、
logger = logging.getLogger(__name__)
と宣言するメリットだと考えられる。
DjangoのLOGGINGにはどのように設定するのがよいか？
上にも書いたように、特にapplicationごとにloggerを分けたいという要件がないのであれば、以下のように"loggers"には何も定義せずにルートloggerを1つ定義するのがよいと思う。
"root": { "handlers": ["info", "warning", "error"], "level": "INFO", }
【注意】ルートloggerの定義はdictの最上位階層に定義する。
私は最初、以下のように"loggers"配下にルートloggerの定義を書いてしまい、何もログが出力されずに少しハマっていた。
"loggers": { "root": { "handlers": ["info", "warning", "error"], "level": "INFO", } }
ルートloggerもloggerの一つなので、直観的には"loggers"配下に定義したくなるが、ルートloggerの定義はLOGGING設定のdictの最上位階層(="loggers"と同じ階層)に定義する必要がある。
確かに公式ドキュメントを読むと、"root"は"loggers"とは異なる独立した項目として定義されていた。
ルートloggerとキー名が空文字のloggerの違い
他には、よくみるサンプルコードで、ルートloggerを定義する代わりに、以下のようにloggers配下にキー名が空文字のloggerを定義している場合もある。
"loggers": { "": { "handlers": ["info", "warning", "error"], "level": "INFO", } }
検証したところ、確かにこのように定義しても、ルートloggerを定義した場合と同じ挙動になった。
この定義方法については、公式ドキュメントには記載がなかったが、理由は恐らく以下だと思う。(polls.viewsを例とする。)
①"polls.views"という名前のloggerを探す。→ 見つからない。
②"polls"という名前のloggerを探す。→ 見つからない。
③""という名前のloggerを探す。→ 見つかる。
以上のように、全てのloggerが最終的には空文字のloggerに伝播するというのが理由なのかな？と思った(検証はしていない)。
ただ、仮にそうだった場合、あくまで名前解決のロジックを実行した結果として、ルートloggerを定義した場合と同じ挙動になるというだけである。
公式ドキュメントを確認した限りでは「キー名に空文字を定義する」ということに設定上の特別な意味があるというような記述は見当たらなかった。
それであれば、ルートloggerを定義するやり方の方が公式ドキュメントに記載があるのでベターなのかなと、個人的には思った。
(参考)Django本体のソースコードのログを別のファイルに出力する。
handlersとloggersにそれぞれ以下のように定義すると、Django本体のソースコードのログを別のファイル(django.log)に出力することができる。
(仕組みは、上で説明したloggerの名前解決の仕組みを理解していれば説明不要かと思う。)
"handlers": { # 他の定義は省略 "django": { "level": "INFO", "class": "logging.FileHandler", "filename": os.path.join(LOG_BASE_DIR, "django.log"), "formatter": "simple", }, },
"loggers": { # 他の定義は省略 "django": { "handlers": ["django"], "level": "INFO", }, },
これもサンプルコードで割とよく見かける設定である。
この場合の注意点は、誤って"propagate"をFalseに設定してしまうと、Django本体のソースコードが出力したエラーログが「error.log」に出力されなくなってしまい、エラー検知ができなくなるので、"propagate"は必ずTrue(デフォルト値)に設定する必要がある。
ただ、個人的には、フレームワーク本体のログを分けて出力するメリットがあるケースをあまり想像できないので、特別な理由がなければこの設定はいらないのではないかと思う。
本記事で触れていないこと
ログファイルのローテーションについては、大事なトピックだと思うが、本記事では触れられなかった。
ちょっと調べたところ、TimedRotatingFileHandlerというものを使うとPython側でローテーションできるらしい。
ただ、使ったことがないので落とし穴があるかもしれないのと、logrotateとかでサーバー側で管理する方法もあると思うので、どういう実現方法があるのかはこれから勉強したい。
