背景

デバッグログとかで、

log.debug('foo = {}'.format(foo))

と書くことがあると思う。これについて Pylint が

W1202: Use % formatting in logging functions and pass the % parameters as arguments

と警告(Conventionではない)を出してくるのが気になっていた。このStackoverflow によれば、

log.debug('foo = %s', foo)

と書けば良いようだが¹、なぜ警告を出してまでこれに統一したいのかがわからない。ので調べた。

.format() と % フォーマットの違い

Pylint にこの Warning が追加されたときのプルリクエスト を見ると²、

Because the message will be evaluated (interpolated), even if the message will not be logged, due to a different warning level set. For instance, the following is always better than using .format.

とある。たとえば、 INFO 以上のレベルのログを表示する設定をしていたとき、 DEBUG レベルのログは「文字列の評価をするが表示はしない」という処理をする。ここで、

log.debug('foo = {}'.format(foo))

のケースだと、

• "foo = ${foo}" という文字列を作成
• ログレベルが低いので表示はしない

という処理の順番になる。これが % formatting: すなわち

log.debug('foo = %s', foo)

のケースの場合は

• “foo = %s” という文字列のまま一旦放置
• ログレベルが低いので表示しない
• 文字列は評価しないまま次の行に行く

という処理になる。

今の場合、単に foo という変数を評価するだけなのでコストは低いが、これが "foo = {}".format(too_expensive_func()) だと表示しない文字列を作るのに大きなコストを払ってしまう、というわけ。

結論

• logging で文字列をフォーマットするときは % フォーマットを使用するのが基本正しい
  • ただし .format() の functional な部分は使えない
• とはいっても PEP とかに明示的に書いてあるわけではない