プロファイラ
- cProfile
- プログラムが、どの関数でどれぐらい時間がかかっているかをプロファイリングしてくれます。
- ざっくり関数レベルでのプロファイルを調べるのに使います。
参考：https://docs.python.jp/3/library/profile.html
- line_profile
- 行ごとにどの程度の時間がかかっているのかを調べます。
- cProfileであたりをつけた関数のプロファイルを調べるのに使います。
- 全体(main)に使うことも可能ですが、行ごとに結果が出てきます。
参考：https://github.com/rkern/line_profiler
以下では、それぞれについて、
- 実行する方法：コマンドラインから行う場合とコードに組み込んで実行する場合
- 確認する方法：標準出力とファイル出力の場合
について説明します。
cProfile
プログラムが、どの関数でどれぐらい時間がかかっているかをプロファイリングしてくれます。ざっくり関数レベルでのプロファイルを調べるのに使います。
出力情報
197 function calls (192 primitive calls) in 0.002 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.001 0.001 <string>:1(<module>)
1 0.000 0.000 0.001 0.001 re.py:212(compile)
1 0.000 0.000 0.001 0.001 re.py:268(_compile)
1 0.000 0.000 0.000 0.000 sre_compile.py:172(_compile_charset)
1 0.000 0.000 0.000 0.000 sre_compile.py:201(_optimize_charset)
4 0.000 0.000 0.000 0.000 sre_compile.py:25(_identityfunction)
3/1 0.000 0.000 0.000 0.000 sre_compile.py:33(_compile)
- 1行目：呼び出した関数の数と実行時間
- Ordered by: 出力のソート方法
- ncalls: 呼び出し回数
- tottime: subfunctionの実行時間を除いた時間
- percall: tottimeをncallsで割った値
- cumtime: この関数とそのsubfuntionに消費された累積時間
- percall: cumtimeを呼び出し回数で割った値
使い方
1. コマンドラインから実行する場合
以下のように -m cProfileを指定して実行します。
python -m cProfile [-o output_file] [-s sort_order] myscript.py
なお、コマンドラインから実行した場合、プログラム内の全関数のプロファイルが出力されます。
1.1 標準出力する場合
-o オプションを指定しないで実行します。 -sで結果のソート方法を指定します。デフォルトでのソート方法 standard nameになります。
- ソート方法の一覧
| 有効な引数 | 意味 |
|---|---|
| 'calls' | 呼び出し数 |
| 'cumulative' | 累積時間 |
| 'cumtime' | 累積時間 |
| 'file' | ファイル名 |
| 'filename' | ファイル名 |
| 'module' | ファイル名 |
| 'ncalls' | 呼び出し数 |
| 'pcalls' | プリミティブな呼び出し回数 |
| 'line' | 行番号 |
| 'name' | 関数名 |
| 'nfl' | 関数名/ファイル名/行番号 |
| 'stdname' | 標準名 |
| 'time' | 内部時間 |
| 'tottime' | 内部時間 |
1.2 ファイル出力する場合
-o オプションを指定して実行します。
$ python -m cProfile -o main.prof myscript.py
出力ファイルはバイナリになっているので、pythonから呼び出して可視化します。
$ python
>> import pstats
>> sts = pstats.Stats('main.prof')
>> sts.strip_dirs().sort_stats(-1).print_stats()
2. コードに組み込む場合
コードに組み込むことで、特定の関数のprofileのみ出力することができます。
2.1 標準出力する場合
ざっと調べた感じ、なさそう。
2.2 ファイル出力する場合
例えば、以下のように記載することで、ファイルにプロファイル結果を出力します。
import cProfile
if __name__ == '__main__':
cProfile.run('main()', filename='main.prof')
なお、runをする関数を限定させる場合は、以下のようにします
(runは、mainで実行する場合のみになるため)
import cProfile
def main():
cProfile.runctx('hoge()', globals(), locals(), filename='hoge.prof')
line_profile
行ごとにどの程度の時間がかかっているのかを調べます。cProfileであたりをつけた関数のプロファイルを調べるのに使います。全体(main)に使うことも可能ですが、行ごとに結果が出てきます。
出力情報
ある関数について、 行ごとにどれくらい時間がかかっているのか・ その割合はどうなのか を出力します。
Pystone(1.1) time for 50000 passes = 2.48
This machine benchmarks at 20161.3 pystones/second
Wrote profile results to pystone.py.lprof
Timer unit: 1e-06 s
File: pystone.py
Function: Proc2 at line 149
Total time: 0.606656 s
Line # Hits Time Per Hit % Time Line Contents
==============================================================
149 @profile
150 def Proc2(IntParIO):
151 50000 82003 1.6 13.5 IntLoc = IntParIO + 10
152 50000 63162 1.3 10.4 while 1:
153 50000 69065 1.4 11.4 if Char1Glob == 'A':
154 50000 66354 1.3 10.9 IntLoc = IntLoc - 1
155 50000 67263 1.3 11.1 IntParIO = IntLoc - IntGlob
156 50000 65494 1.3 10.8 EnumLoc = Ident1
157 50000 68001 1.4 11.2 if EnumLoc == Ident1:
158 50000 63739 1.3 10.5 break
159 50000 61575 1.2 10.1 return IntParIO
- Line: 全体の中の行数
- Hits: 呼び出し回数
- Time: かかった時間
- Per Hit: １呼び出しあたりにかかった時間
- % Time: その関数内でかかった時間の割合
- Line Contents: その行の内容
使い方
1. コマンドラインから実行する場合
まず、@profileデコレータを関数につけます。(クラス内の関数にも適用できます）
@profile
def hoge():
hogehoge
そして、以下のように実行します
$ kernprof -l script_to_profile.py
1.1 標準出力する場合
ざっと調べた感じ、なさそう。
1.2 ファイル出力する場合
script_to_profile.py.lprof というファイルが作られます。これを以下の通り実行すると、プロファイル結果が出力されます。
$ python -m line_profiler script_to_profile.py.lprof
2. コードに組み込む場合
以下のように記載することで、標準出力で、プロファイリング結果を出力することができます。
if __name__ == "__main__":
prf = LineProfiler()
prf.add_module(hoge_class)
prf.add_function(main)
prf.runcall(main)
add_function(hoge)によって、プロファイリングする関数を追加できます。クラス内の関数も add_function(hoge_class.hoge) で追加できます。また、 add_module(hoge_class) によって、クラス全体のプロファイルを追加できます。
また、以下のように記載することで、特定の関数についてプロファイリング結果を出力することができます。
from line_profiler import LineProfiler
def main():
prf = LineProfiler()
prf.add_module(hoge_class)
prf.add_function(hoge)
prf.runctx('hoge()', globals(), locals())
2.1 標準出力する場合
標準出力する場合は、上記に加えて、LineProfiler().print_stats() を使用すると、と標準出力されます。
例）
from line_profiler import LineProfiler
if __name__ == "__main__":
prf = LineProfiler()
prf.add_module(hoge_class)
prf.add_function(main)
prf.runcall(main)
prf.print_stats()
2.2 ファイル出力する場合
ファイル出力する場合は、上記に加えて、LineProfiler().dump_stats() を使用すると、と標準出力されます。
例）
from line_profiler import LineProfiler
if __name__ == "__main__":
prf = LineProfiler()
prf.add_module(hoge_class)
prf.add_function(main)
prf.runcall(main)
prf.dump_stats('line_profiler.prof')