はじめに
ういっす✌️ nikkieです。
先日、Pythonのloggingモジュールを完全に理解しました。
深まった理解をもとに、ドキュメントの「もっとも単純な例」を説明してみます。
目次
- はじめに
- 目次
- もっとも単純な例
- logging.warningはlogging.basicConfigを呼び出す
- logging.basicConfigはルートロガーにフォーマッタとハンドラを設定する
- まとめ:もっとも単純な例でやっていること
- 終わりに
もっとも単純な例
ドキュメントの冒頭にあります。
>>> import logging >>> logging.warning('Watch out!') WARNING:root:Watch out!
※Python 3.10.9で動作確認しました
この例が何をしているかを説明していきます。
説明するのはlogging.warning('Watch out!')
です。
なぜ「WARNING:root:Watch out!」と出力されているか、今の理解をダンプします。
logging.warning
はlogging.basicConfig
を呼び出す
https://docs.python.org/ja/3/library/logging.html#logging.warning
logging.debug
のドキュメントにまとめられています:
https://docs.python.org/ja/3/library/logging.html#logging.debug
ルートロガーにハンドラが接続されていない場合、この関数 (および info(), warning(), error() そして critical()) は basicConfig() を呼び出します。
「もっとも単純な例」では、ルートロガーにハンドラを接続するようなコードを書いていませんから、logging.basicConfig
が引数無しで呼び出されています1。
logging.basicConfig
はルートロガーにフォーマッタとハンドラを設定する
https://docs.python.org/ja/3/library/logging.html#logging.basicConfig
デフォルトの Formatter を持つ StreamHandler を生成してルートロガーに追加し、ロギングシステムの基本的な環境設定を行います。
デフォルトのFormatter
により、ログメッセージは「WARNING:root:Watch out!」という書式となり、
StreamHandler
によりログが画面に出力されます。
ルートロガー
ルートロガーはログレベルがWARNING
に設定されています。
>>> import logging >>> logging.warning('Watch out!') WARNING:root:Watch out! >>> logging.getLogger() # ルートロガーを取得 <RootLogger root (WARNING)>
「basicConfigの中で設定したのだろうか?」と実装を追ったところ、ログレベルWARNING
で初期化していました。
https://github.com/python/cpython/blob/v3.10.9/Lib/logging/__init__.py#L1935
root = RootLogger(WARNING)
logging.Formatter
https://docs.python.org/ja/3/library/logging.html#logging.Formatter
fmt が指定されない場合、 '%(message)s' が使われます。
logging.basicConfig
ではfmt
引数を指定しています。
basicConfig
を引数無しで呼び出したときの、Formatter
呼び出しイメージです。
# https://github.com/python/cpython/blob/v3.10.9/Lib/logging/__init__.py#L516-L520 _STYLES = { '%': (PercentStyle, BASIC_FORMAT), '{': (StrFormatStyle, '{levelname}:{name}:{message}'), '$': (StringTemplateStyle, '${levelname}:${name}:${message}'), } # https://github.com/python/cpython/blob/v3.10.9/Lib/logging/__init__.py#L2046-L2052 dfs = kwargs.pop("datefmt", None) style = kwargs.pop("style", '%') fs = kwargs.pop("format", _STYLES[style][1]) fmt = Formatter(fs, dfs, style)
basicConfig
を引数無しで呼び出したとき、style
は'%'
を指します。
このとき_STYLES[style]
は(PercentStyle, BASIC_FORMAT)
となるので、_STYLES[style][1]
はBASIC_FORMAT
です。
https://github.com/python/cpython/blob/v3.10.9/Lib/logging/__init__.py#L514
BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s"
LogRecord 属性を参照すると
%(levelname)s
メッセージのための文字のロギングレベル ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')。
%(name)s
ロギングに使われたロガーの名前。
%(message)s
msg % args として求められた、ログメッセージ。
です。
これで「WARNING:root:Watch out!」となる理由が分かりましたね。
basicConfig()
という引数なしの呼び出しでは、Formatter
にBASIC_FORMAT
(ロギングレベル:ロガーの名:ログメッセージ)が設定されるのです!
logging.StreamHandler
https://docs.python.org/ja/3/library/logging.handlers.html#logging.StreamHandler
stream が指定された場合、インスタンスはログ出力先として指定されたストリームを使います; そうでない場合、 sys.stderr が使われます。
basicConfig
を引数無しで呼び出したときの、StreamHandler
呼び出しイメージです。
# https://github.com/python/cpython/blob/v3.10.9/Lib/logging/__init__.py#L2043-L2044 stream = kwargs.pop("stream", None) h = StreamHandler(stream)
basicConfig
を引数無しで呼び出したとき、StreamHandler(None)
なのでsys.stderr
(標準エラー出力)が使われるのですね!
ログが標準エラー出力に出力される理由がようやく分かりました。
ルートロガーに設定されたStreamHandler
を見てみると
>>> import logging >>> logging.warning('Watch out!') WARNING:root:Watch out! >>> logging.getLogger().handlers [<StreamHandler <stderr> (NOTSET)>]
ハンドラのレベルはNOTSET
です。
https://docs.python.org/ja/3/library/logging.html#logging.Handler.setLevel
ハンドラが生成された際、レベルは NOTSET (すべてのメッセージが処理される) に設定されます。
ということで、NOTSET
になっているようです。
まとめ:もっとも単純な例でやっていること
logging.warning
でメッセージを出力する裏ではlogging.basicConfig()
が(引数無しで)呼び出されている
- ルートロガーのログレベルは
WARNING
Formatter
とStreamHandler
を生成して、ルートロガーに追加Formatter
はBASIC_FORMAT
("%(levelname)s:%(name)s:%(message)s"
)で初期化されるStreamHandler
は標準エラー出力、レベルNOTSET
で初期化される
終わりに
logging.warning
と呼んだだけですが、裏ではルートロガーにフォーマッタやハンドラが設定されているんですね!
仕組みが分からなくてもlogging.warning
は使えますが、仕組みが分かると解像度が上がった感じがします。
魔法でなくなった感じです。
Pythonのloggingはlogging.warning
から、ロガー・フォーマッタ・ハンドラ(などなど)の登場人物を理解して使えるようになるまでに大きな溝があるように感じます。
logging.warning
でルートロガーを無自覚で使っていたのに、いきなりロガーとかフォーマッタとかハンドラとか登場人物増やされてもワケワカンナイヨー!
そこの架け橋となるかなと考えているのが、今回説明したようなlogging.warning
の裏側の理解です。
裏側を覗くとフォーマッタやハンドラがいました。
この理解があると、いきなり登場人物が増えたと感じずに、それらを組み合わせてloggingを使える一歩目が踏み出しやすいのではないかと今の私は考えています。