【初心者向け】Pythonで行うデバック、パフォーマンス測定、ロギング

プログラミングにおいて、効率的なデバッグ、パフォーマンス分析、そして適切なログ管理は、高品質なソフトウェア開発に欠かせない重要なスキルです。本記事では、Pythonの標準ライブラリが提供する強力なツール群（pdb、timeit、logging）を使用して、開発プロセスを最適化する方法を詳しく解説します。初心者から中級者まで、プログラミングスキルを一段階引き上げるテクニックを学んでいきましょう
。

pdb、breakpoint
timeit
logging
- logging
- logger

pdb、breakpoint

・Pdb.set_trace()やbreakpoint()関数でデバック時のブレークポイントを作成することができます。スクリプトを実行すると、対話側モードでデバックが開始します。
・コマンド「l」で周囲のソースコードを表示したり、「c」で次のブレークポイントに進みます。「p 変数名」で変数の値を表示でき、デバックを終了したい場合は、「q」で終了します。

import pdb


def calc():
    result = 10 / 1
    # pdb.set_trace()  # ブレークポイント
    return result


num = calc()
breakpoint()  # ブレークポイント
print(num)

実行結果

-> print(num)
(Pdb) l
  7         return result
  8  
  9  
 10     num = calc()
 11     breakpoint()  # ブレークポイント
 12  -> print(num)
[EOF]
(Pdb) c
10.0

また、コマンドでスクリプト実行時に、「python -m pdb」で実行すると、エラーが発生した際に自動でデバックが開始します。エラーを確認する場合は、「c」コマンドを実行します。

timeit

timeitではコードの実行時間を計測します。
・コマンドラインから実行する場合は、「python -m timeit “statement”」で100万回処理を繰り返した場合の実行時間を返します。
・Pythonのコード内で計測する場合は、timeit.timeit(stmt,setup)とrepeat(stmt,setup)を使用します。

import timeit

random_num = timeit.timeit(stmt="random.random()", setup="import random")
# >>> 0.054082999999991443

repeat_num = timeit.repeat(stmt="random.random()", setup="import random")
# >>> [0.04132569999978841, 0.044903799999929106, 0.06555869999988317, 0.04658389999985957, 0.03975379999997131]

logging

・ロギングでは、「critical」「error」「warning」「info」「debug」のレベルごとのログ、メッセージを出力できます。デフォルトでは、「warning」以上を出力しますが、basicConfig()でlebelやformatを変更できます。
・ログメッセージに変数を使用する場合は、%演算子を使用します。

import logging

logging.basicConfig(level="INFO",
                    format='%(asctime)s %(filename)s %(levelname)s %(message)s',)

logging.critical('critcal')
logging.error("error")
logging.warning("warning")
logging.info("info")
logging.debug("debug")

# >>> 2024-12-05 20:43:52,644 3.logging.py CRITICAL critcal
# >>> 2024-12-05 20:43:52,645 3.logging.py ERROR error
# >>> 2024-12-05 20:43:52,645 3.logging.py WARNING warning
# >>> 2024-12-05 20:43:52,646 3.logging.py INFO info

# %演算子
name='Taro'
logging.info('My name is %s',name)
# >>> 2024-12-05 20:44:33,288 3.logging.py INFO My name is Taro

logger

・logging.getLogger(__name__)で名前付きロガーを作成し、ハンドラを複数追加できます。ハンドラは出力先と出力方法を定義する機能です。
・fileterは、ログメッセージの内容に基づいて、ログの出力を制御・フィルタリングします。

# logger/handrler
logger = logging.getLogger(__name__)
h = logging.FileHandler(filename="test2.log")
logger.setLevel("INFO")
logger.addHandler(h)
logger.info("from logger")


# filter
class NoPassFilter(logging.Filter):
    def filter(self, record):
        log_message = record.getMessage()
        return "password" not in log_message


logger.addFilter(NoPassFilter())
logger.info("from main passwor==XXXX")

実行結果（test2.log）

from logger
from main passwor==XXXX