Pythonのlogging.exceptionには例外ではなく説明を入れるべき

エラー時のログを出したい

logging モジュールにはログを出す方法がいくつかあります。

logging.debug()
logging.info()
logging.warning()
logging.error()
logging.critical()

これらの違いはログレベル(log level)によるもので、緊急度などに応じて設定しておけば「開発時は debug も含めて出力」「本番では warn 以上（または info 以上）」のように出力するレベルを変更できます。

これと並んでもう一つ、 logging.exception() があり、ライブラリのリファレンスには次のように書いてあります。

レベル ERROR のメッセージをこのロガーで記録します。引数は debug() と同じように解釈されます。例外情報がログメッセージに追加されます。このメソッドは例外ハンドラからのみ呼び出されるべきです。
https://docs.python.org/ja/3/library/logging.html#logging.Logger.exception

その名の通り、例外処理時に except: の中で利用することを想定しています。
しかし、実装するときに勘違いしている例をよく見かけます。（私もしょっちゅうやってました）

勘違い

よくある勘違いとは「キャッチした例外を引数に入れる」というものです。

try:
    int("aaa")
except Exception as e:
    logging.exception(e)

これで出力されるログはこのようになります。

ERROR:root:invalid literal for int() with base 10: 'aaa'
Traceback (most recent call last):
  File "main.py", line 6, in hoge
    int("aaa")
ValueError: invalid literal for int() with base 10: 'aaa'

invalid literal for int() with base 10: 'aaa' というメッセージが2回重複しているのがわかるでしょうか。
ERROR:root: となっている部分が引数から生成されたもので、 Traceback 以降は自動的に付加された例外情報です。
リファレンスにあったのはこの部分ですね。

例外情報がログメッセージに追加されます。

引数に例外オブジェクトを渡した場合、文字列化した値 str(e) が出力されるだけなので同じエラーメッセージが重複してしまいます。
例外情報は自動的に取得される¹ので、実際には例外オブジェクトのコード上の取得は不要です。

try:
    int("aaa")
except:
    logging.exception("What is doing when exception happens.")

ERROR:root:What is doing when exception happens.
Traceback (most recent call last):
  File "main.py", line 6, in hoge
    int("aaa")
ValueError: invalid literal for int() with base 10: 'aaa'

例外だけを出力するのではなく、開発者が理解しやすいメッセージを付与するとよいでしょう。

• ログで状況を伝える
  • ログメッセージを読むときに、何をしていたときに発生した例外なのか読み取れるようにする
• 再現性のための情報
  • try: に入るときの事前条件（変数の値など）の出力をしてテストで再現できるようにする

1. 「except または finally 節内で例外を送出 (または再送出) するとき、__context__ は自動的に最後に捕まった例外に設定されます。」 https://docs.python.org/ja/3/library/exceptions.html ↩