結論:進捗・注意・失敗をレベルで分け、例外には履歴を残す
後から実行状況を調べたい処理では、printを増やす代わりにloggingを使う。通常の進捗をINFO、注意して確認したい状態をWARNING、失敗をERRORとして分けると、必要な情報だけを表示しやすい。例外を捕まえた場所でlogger.exceptionを使えば、メッセージに加えてトレースバックも記録できる。失敗したという一言だけで終わらせないのがポイントである。
ログのレベルは色分けのためだけではない。調査時は詳細を出し、通常運用では要点だけにする、といった出力方針を処理内容から分離できる。計算結果を標準出力へ流すCLIでは、ログを標準エラー出力やファイルへ分けることで結果の機械読込を壊しにくくなる。ログをどこへ出すかと、何を記録するかを別々に決めたい。
そのまま動かせる例
例は標準ライブラリだけで動き、ログをStringIOへ集めて最後に表示する。実際のログファイルを作らず、レベルの選別と例外情報を観察するための構成である。ZeroDivisionErrorは意図的に発生させる。コードをexample.pyとして保存し実行すると、INFO・WARNING・ERRORと実際の例外履歴を確認できる。
出力中のソースパスだけは、コード内でファイル名へ短縮している。トレースバックを一から作ったり、エラーメッセージを想像で記載したりしたものではない。保存したコードの行位置によって行番号が変わる点に注意してほしい。DEBUGはINFOより低いレベルなので、この設定では出力されない。
import io
import logging
from pathlib import Path
buffer = io.StringIO()
handler = logging.StreamHandler(buffer)
handler.setFormatter(logging.Formatter("%(levelname)s %(name)s %(message)s"))
logger = logging.getLogger("analysis.demo")
logger.setLevel(logging.INFO)
logger.propagate = False
logger.addHandler(handler)
try:
logger.debug("detail hidden")
logger.info("start sample=%s", "A")
logger.warning("missing points=%d", 2)
try:
ratio = 1 / 0
except ZeroDivisionError:
logger.exception("calculation failed sample=%s", "A")
logger.info("done")
finally:
logger.removeHandler(handler)
handler.close()
text = buffer.getvalue()
assert "detail hidden" not in text
assert text.count("start sample=A") == 1
assert text.count("calculation failed") == 1
assert "Traceback" in text and "ZeroDivisionError" in text
# Shorten only the source path in the captured traceback.
text = text.replace(str(Path(__file__).resolve()), Path(__file__).name)
print(text, end="")
実行結果
INFO analysis.demo start sample=A
WARNING analysis.demo missing points=2
ERROR analysis.demo calculation failed sample=A
Traceback (most recent call last):
File "example.py", line 17, in <module>
ratio = 1 / 0
~~^~~
ZeroDivisionError: division by zero
INFO analysis.demo done
logger・handler・formatterの役割
loggerは記録を発生させる入口、handlerは出力先、formatterは表示形式を受け持つ。同じ名前のgetLoggerは同じloggerを返すので、関数を呼ぶたびにhandlerを追加すると重複出力の原因になる。通常のアプリケーションでは入口で一度設定し、各モジュールではgetLogger(__name__)で取得して使う構成が分かりやすい。
loggerには親子関係があり、通常は記録が上位のhandlerへ伝播する。この例は自前のhandlerだけを使うためpropagateをFalseにしている。親と子の両方へhandlerを付けたまま伝播させれば、同じ記録が二重に表示されることがある。重複を見つけたらprintの回数だけでなく、handlerの配置と伝播経路も確認しよう。
例外を記録した後の方針も決める
logger.exceptionは例外処理中に使うと、現在扱っている例外の情報をERRORレベルで残す。logger.errorへ文字列だけを渡した場合とは違い、どの経路で失敗したかを追える。ログを残すことと例外を解決することは別であり、その後に継続するのか、再送出して停止するのかは処理の契約に合わせて決める必要がある。
今回の例は動作確認なので失敗後にdoneを記録して終了する。実際の解析で結果が不完全になった場合は、doneだけを成功の印にしないようにする。入力ID、成功件数、失敗件数、再試行可能かなどを記録し、呼び出し元へも状態を伝える。例外をログへ書いて握りつぶすだけでは、自動処理が正常終了と誤認する危険がある。
必要な情報だけを安全に残す
logger.info("...%s", value)のように値を別引数で渡すと、メッセージの整形をloggingへ任せられる。ただしvalueを作る高価な関数呼び出しまで遅延されるわけではない。大量のデータ全体を毎回文字列化するより、対象ID、件数、shapeなど原因調査に必要な要約を記録する方が扱いやすい。
パスワード、APIキー、認証ヘッダー、個人データを不用意にログへ出さないようにする。例外の本文にも入力やURLが含まれる場合がある。ファイルへ保存するなら文字コード、保管先、容量上限やローテーションも考えたい。またbasicConfigは既に設定がある環境では期待どおり再設定されない場合がある。ノートブックの重複や未反映を、何度もhandlerを足すことで解決しようとしないのが基本である。
確認環境と参考資料
例はLinux・CPython 3.12.14で実行した。掲載した出力はこの環境での結果である。公式資料のstable版や最新版は更新されるため、手元のバージョンと対応する仕様も確認してほしい。
- Python公式:logging(2026年10月2日参照)
関連項目:argparseでヘルプ付きの使いやすいコマンドを作る / subprocess.runで外部コマンドの失敗・出力・時間切れを扱う / 解析をやり直せる実行記録を残す:条件・入力ハッシュ・環境情報
