Python｜出力内容を調整可能なプロファイリング用デコレータ
Pythonでプロファイリングする場合、標準ライブラリのcProfileを使うことが多いのではないでしょうか。
この記事では、そのcProfileを使ったプロファイリング時に活用できる、既存の処理を邪魔せず、使いまわしやすいデコレータについて説明します。
さらに、大きな処理をプロファイリングしようとすると、出力が多すぎて見づらくなってしまうことがありますが、紹介するデコレータは出力内容を調整可能です。
プロファイリング用デコレータのコード
cProfileを使ったプロファイリング用デコレータのコードは下の通りです。一度実装しておけば、プロファイリングしたい関数にデコレータを付けるだけで、プロファイルの統計情報が取得できるようになります。
import cProfile
import pstats
from functools import wraps
def profile(
sort_key=pstats.SortKey.CUMULATIVE, # 累積時間が多い順に出力する
file_name_regex=None, # file_nameの条件なし
output_line=10 # 10件分出力する
):
"""
関数プロファイリング用デコレータ。
"""
def _profile(func):
@wraps(func)
def _wrapper(*args, **kwargs):
# プロファイルデータを収集
with cProfile.Profile() as pr:
ret = func(*args, **kwargs)
# Statsクラスに変換して、プロファイルデータを解析
p = pstats.Stats(pr)
p = p.sort_stats(sort_key)
# file_name_regex, output_lineを条件として抽出した結果を出力
p.print_stats(file_name_regex, output_line)
return ret
return _wrapper
return _profile使用方法
下の関数をプロファイリング対象とする場合を例として、使用方法を説明します。
import re
def test_profile(string):
""" プロファイリング対象の関数 """
re.compile(string)
return "done"
if __name__ == "__main__":
ret = test_profile("foo|bar")
print(f"return: {ret}")デフォルトの使い方
デコレータがあるモジュールをインポートし、プロファイリングしたい関数の上に@profile()を付けるだけです。
import re
from profile_util import profile # 追加
@profile() # 追加
def test_profile(string):
""" プロファイリング対象の関数 """
re.compile(string)
return "done"
if __name__ == "__main__":
ret = test_profile("foo|bar")
print(f"return: {ret}")実行結果は下の様なフォーマットで標準出力されます。デフォルトでは、累積時間が多い順に10件分出力します。
218 function calls (211 primitive calls) in 0.000 seconds
Ordered by: cumulative time
List reduced from 43 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 /home/user1/python/test_profile.py:5(test_profile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:225(compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:272(_compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:738(compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_parser.py:970(parse)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:571(_code)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_parser.py:447(_parse_sub)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:509(_compile_info)
2 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_parser.py:507(_parse)
3/1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:37(_compile)
return: donereturn: doneが出力されていることから、test_profile関数に引数、返値があっても問題なく動作することが分かります。
プロファイリングが完了したら、そのままだと処理が遅くなりますので、デコレータを削除、もしくはコメントアウトしてください。
出力件数を調整したい場合の使い方
@profile()の引数output_lineに出力したい件数を設定してください。5件出力したい場合は@profile(output_line=5)となり、出力結果はこのようになります。
218 function calls (211 primitive calls) in 0.000 seconds
Ordered by: cumulative time
List reduced from 43 to 5 due to restriction <5>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 /home/user1/python/test_profile.py:5(test_profile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:225(compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:272(_compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:738(compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_parser.py:970(parse)
return: done出力したいfilenameに条件を付ける場合の使い方
@profile()の引数file_name_regexに条件を正規表現で指定してください。filenameにはパッケージ名やモジュール名、関数名が含まれるため、条件指定したこれらのみを出力させることができます。__init__.pyモジュール、またはcompile関数を出力したい場合は@profile(file_name_regex="__init__.py|\(compile\)")となり、出力結果はこのようになります。
218 function calls (211 primitive calls) in 0.000 seconds
Ordered by: cumulative time
List reduced from 43 to 3 due to restriction <'__init__.py|\\(compile\\)'>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:225(compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/__init__.py:272(_compile)
1 0.000 0.000 0.000 0.000 /usr/lib/python3.11/re/_compiler.py:738(compile)
return: done出力順を変える場合の使い方
@profile()の引数sort_keyに、pstats.SortKeyの変数、もしくは該当する文字列を設定してください。詳細はこちらを参照ください。
関連タグの記事
