Pythonのtraceモジュールでプログラムの実行をトレースする方法

traceモジュールとは

Python標準ライブラリのtraceモジュールは、プログラムの実行過程をトレース（追跡）したり、注釈付きのステートメントカバレッジ（実行網羅率）を生成したりするための機能を提供します。さらに、実行時に呼び出された関数の一覧表示や、呼び出し元と呼び出し先の関係（コールグラフ）の出力にも対応しています。

ここでは、以下の2つのPythonスクリプトを例として、traceモジュールの各機能を紹介します。

#myfunctions.py
import math

def area(x):
    a = math.pi * math.pow(x, 2)
    return a

def factorial(x):
    if x == 1:
        return 1
    else:
        return x * factorial(x - 1)

#mymain.py
import myfunctions

def main():
    x = 5
    print('area=', myfunctions.area(x))
    print('factorial=', myfunctions.factorial(x))

if __name__ == '__main__':
    main()

--traceオプション：実行された行を表示する

traceモジュールにはコマンドラインインターフェースが用意されており、すべての機能をコマンドラインのスイッチから利用できます。最も重要なのが--traceオプションで、プログラムの各行が実行されるたびにその内容を表示します。次の例では、標準ライブラリのディレクトリをトレース対象から除外するため、--ignore-dirオプションも併用しています。

E:\python37>python -m trace --ignore-dir=../lib --trace mymain.py

出力例

mymain.py(2): def main():
mymain.py(7): if __name__=='__main__':
mymain.py(8): main()
--- modulename: mymain, funcname: main
mymain.py(3): x=5
mymain.py(4): print ('area=',myfunctions.area(x))
--- modulename: myfunctions, funcname: area
myfunctions.py(3): a=math.pi*math.pow(x,2)
myfunctions.py(4): return a
area= 78.53981633974483
mymain.py(5): print ('factorial=',myfunctions.factorial(x))
--- modulename: myfunctions, funcname: factorial
myfunctions.py(6): if x==1:
myfunctions.py(9): return x*factorial(x-1)
--- modulename: myfunctions, funcname: factorial
myfunctions.py(6): if x==1:
myfunctions.py(9): return x*factorial(x-1)
--- modulename: myfunctions, funcname: factorial
myfunctions.py(6): if x==1:
myfunctions.py(9): return x*factorial(x-1)
--- modulename: myfunctions, funcname: factorial
myfunctions.py(6): if x==1:
myfunctions.py(9): return x*factorial(x-1)
--- modulename: myfunctions, funcname: factorial
myfunctions.py(6): if x==1:
myfunctions.py(7): return 1
factorial= 120

--countオプション：行ごとの実行回数をカウントする

--countオプションを使用すると、読み込まれた各モジュールごとに「.cover」拡張子のファイルが生成され、各行が何回実行されたかを確認できます。

E:\python37>python -m trace --count mymain.py
area= 78.53981633974483
factorial = 120

生成されたmyfunctions.coverの内容：

1: import math
1: def area(x):
1:     a = math.pi*math.pow(x,2)
1:     return a
1: def factorial(x):
5:    if x==1:
1:       return 1
   else:
4:    return x*factorial(x-1)

生成されたmymain.coverの内容：

1: import myfunctions
1: def main():
1:    x = 5
1:    print ('area=',myfunctions.area(x))
1:    print ('factorial=',myfunctions.factorial(x))

1: if __name__=='__main__':
1:    main()

行頭の数字がその行の実行回数を表します。この例では、再帰呼び出しによってif x==1:の行が5回、return x*factorial(x-1)の行が4回実行されていることがわかります。

--summaryオプション：カバレッジのサマリーを表示する

--summaryオプションは、--countオプションと組み合わせて使用すると、モジュールごとの実行行数とカバレッジ率の概要を表示します。

E:\python37>python -m trace --count --summary mymain.py
area = 78.53981633974483
factorial = 120
lines cov% module (path)
   8 100% myfunctions (E:\python37\myfunctions.py)
   7 100% mymain (mymain.py)

--fileオプション：カウント結果をファイルに蓄積する

--fileオプションを指定すると、複数回のトレース実行にわたってカウント結果を指定したファイルに蓄積できます。

E:\python37>python -m trace --count --file report.txt mymain.py
area = 78.53981633974483
factorial = 120
Skipping counts file 'report.txt': [Errno 2] No such file or directory: 'report.txt'

E:\python37>python -m trace --count --file report.txt mymain.py
area= 78.53981633974483
factorial= 120

初回実行時にはファイルが存在しないためスキップされますが、2回目以降は既存のreport.txtにカウントが累積されます。

--listfuncsオプション：呼び出された関数の一覧を表示する

--listfuncsオプションを使用すると、プログラムの実行中に呼び出された関数の一覧を確認できます。

E:\python37>python -m trace --listfunc mymain.py | findstr -v importlib
area= 78.53981633974483
factorial= 120

functions called:
filename: E:\python37\lib\encodings\cp1252.py, modulename: cp1252, funcname: IncrementalEncoder.encode
filename: E:\python37\myfunctions.py, modulename: myfunctions, funcname: <module>
filename: E:\python37\myfunctions.py, modulename: myfunctions, funcname: area
filename: E:\python37\myfunctions.py, modulename: myfunctions, funcname: factorial
filename: mymain.py, modulename: mymain, funcname: <module>
filename: mymain.py, modulename: mymain, funcname: main

--trackcallsオプション：関数の呼び出し関係を表示する

--trackcallsオプションは、--listfuncsオプションと組み合わせて使用します。「どの関数がどの関数を呼び出したか」という呼び出し関係（コールグラフ）を出力できます。

E:\python37>python -m trace --listfunc --trackcalls mymain.py | findstr -v importlib
area= 78.53981633974483
factorial= 120

calling relationships:

--> E:\python37\myfunctions.py


*** E:\python37\lib\trace.py ***
--> mymain.py
trace.Trace.runctx -> mymain.<module>

*** E:\python37\myfunctions.py ***
myfunctions.factorial -> myfunctions.factorial

*** mymain.py ***
mymain.<module> -> mymain.main
--> E:\python37\lib\encodings\cp1252.py
mymain.main -> cp1252.IncrementalEncoder.encode
--> E:\python37\myfunctions.py
mymain.main -> myfunctions.area
mymain.main -> myfunctions.factorial

まとめ

traceモジュールを活用すれば、プログラムのどの行が実際に実行されているかを可視化でき、デバッグやテストカバレッジの確認、関数間の依存関係の把握に役立ちます。特に大規模なコードベースでは、--countと--summaryによるカバレッジ計測や、--trackcallsによる呼び出し関係の分析が効果的です。