Python講座 / トレースバック・デバッガー・loggingで問題を調べる

デバッグは、トレースバック末尾の例外と、関係するファイル・行番号を読み、入力を再現するところから始めます。デバッガーは実行状態の観察、loggingは選んだ出来事をレベル付きで記録するために使います。

再現できる小さな問題へ絞る

末尾の例外の種類とメッセージを読み、呼び出しの列から自分のコードを探します。ライブラリーの内部を変更する前に、そこへどんな入力や設定を渡したかを確認してください。最小の再現例にすると、関係しない条件を減らせます。

VS Codeのブレークポイントで変数、呼び出し履歴、次の実行文を確認します。失敗後へprintを増やし続けるより、失敗前の状態を観察する方が原因を見つけやすいことがあります。

例外伝播と失敗の自動確認は、try・except・else・finally・raiseで例外を扱うで扱う規則とつながります。

ログを伴う計算を実行する

logging_demo.pyを保存し、仮想環境でpython logging_demo.pyを実行します。

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s:%(message)s")
logger = logging.getLogger(__name__)

def calculate(amounts):
    logger.debug("count=%s", len(amounts))
    if any(x < 0 for x in amounts):
        raise ValueError("negative amount")
    return sum(amounts)

try:
    total = calculate([3500, 8000, 2500])
except ValueError:
    logger.exception("calculation failed")
    raise SystemExit(1)
else:
    logger.info("total=%s", total)
print("finished")

次は標準出力だけの予想結果です。

finished

ログにはINFO:total=14000も記録され、通常は標準エラーへ出ます。二つの出力先を混ぜて読む場合には、画面上の順序が違って見えることがあります。

レベルと出力先を選ぶ

アプリケーションの方針に沿ってレベルを一貫させます。INFOの設定ではDEBUGのcountメッセージは表示されません。ファイルへ残す場合は、保存先、ローテーション、保存期間、権限も決める必要があります。

意図した失敗と通常動作の復旧を試す

一つの金額を-1へ変え、失敗のログとトレースバックを確認します。ログレベルをDEBUGへ替えてcount=3が出ることを確かめ、最後に値とレベルを元へ戻して正常な結果を再確認します。

広い例外を空のハンドラーで隠さず、呼び出し元が対処すべき失敗は伝えます。パスワード、認証ヘッダー、個人情報の記録全体をログへ残さないでください。大きなオブジェクトの反復記録は時間と保存領域も使います。利用者への案内と開発者の診断は読み手が異なります。期待する動作が決まった再現例は、自動テストとして繰り返し確認できます。

loggingは記録するだけで失敗終了にはしません。修正版は回復できないValueErrorを記録して SystemExit(1) で終了するため、負数の実験ではfinishedを表示しません。正常入力はINFOとfinishedを出し、終了値は0です。直後にPowerShellの $LASTEXITCODE、macOS・Ubuntuの echo $? で確認します。stdoutとstderrを別々に収集すると、見える順序が異なることがあります。

動作と適用条件の公式説明：Python: sys.exit

関連する公式リファレンス

• Python: logging