pythonの標準プロファイラであるcProfileの使い方を簡単に説明します
cProfileを使用することでプログラムのボトルネックを簡単に特定することができます
この記事を読むとわかること・・
- cProfileの使い方
- snakevizの使い方
- cProfileとProfileの違い
cProfileの使い方
さっそくcProfileの使い方を説明していきます
まず、cProfileの主な使い方は以下の２つです
- プログラムファイル（.py）のコードの中にcProfileを書き込む方法
- ターミナル（コマンドプロンプト）でプログラムを実行するときにcProfileを使用する方法
プログラム全体の処理時間を計測したい場合は、ターミナルでcProfileを使用する方法が適しています
1.cProfileの使い方手順
まず、以下のようなsample.pyファイルがあったとします
# coding: UTF-8
import time
def main():
print(1)
time.sleep(1) # １秒待機
print("----------")
print(2)
time.sleep(2) # 2秒待機
print("----------")
print(3)
time.sleep(3) # 3秒待機
print("----------")
if __name__ == '__main__':
main()
これをターミナルで普通に実行するときは
$ python sample.py（実行結果）
1
----------
2
----------
3
----------cProfileを使用して実行するときは
$ python -m cProfile sample.py（実行結果）
1
----------
2
----------
3
----------
13 function calls in 6.009 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 6.009 6.009 sample.py:3(<module>)
1 0.000 0.000 6.009 6.009 sample.py:6(main)
1 0.000 0.000 6.009 6.009 {built-in method builtins.exec}
6 0.000 0.000 0.000 0.000 {built-in method builtins.print}
3 6.009 2.003 6.009 2.003 {built-in method time.sleep}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}このようにファイルを実行するコードを少し変えるだけでcProfileを使用することができます
一度普通にプログラムが実行されて、その後処理にかかった時間などが表示されます
cProfileを使用してプログラムを実行すると
- プログラム実行時間
- 関数呼び出し回数・関数ごとの処理時間
を簡単に把握することができます
それぞれの項目の意味は
- ncalls : 呼び出された回数
- tottime : 関数処理にかかった合計時間(subfunctionの呼び出しにかかった時間は除く)
- percall : tottime ➗ ncalls
- cumtime : 関数処理と全てのsubfunctionに消費された累積時間
- percall : cumtimeを呼び出し回数で割った値
- filename : 関数のファイル名、行番号、関数名
となっています
2.cProfileのオプションについて
cProfileは実行する際にオプションを設定することができます
$ python -m cProfile [-o output_file] [-s sort_order] myscript.py- -o : cProfile結果をファイルに書き出すときに使用する（cProfile結果がターミナルに標準出力されない）
- -s : 出力をソートする値を指定できる（-o を使用していない場合に有効）
各オプションを使用するときの例をみてみましょう
-o オプションを使用する場合（例）
# coding: UTF-8
import time
def main():
print(1)
time.sleep(1) # １秒待機
print("----------")
print(2)
time.sleep(2) # 2秒待機
print("----------")
print(3)
time.sleep(3) # 3秒待機
print("----------")
if __name__ == '__main__':
main()
$ python -m cProfile -o sample.profile sample.py（実行結果）
1
----------
2
----------
3
----------出力結果が格納されているsample.profileはsample.pyが格納されているディレクトリに書き出されます
-s オプションを使用する場合 （例）
$ python -m cProfile -s tottime sample.py（実行結果）
1
----------
2
----------
3
----------
13 function calls in 6.013 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
3 6.013 2.004 6.013 2.004 {built-in method time.sleep}
6 0.000 0.000 0.000 0.000 {built-in method builtins.print}
1 0.000 0.000 6.013 6.013 sample.py:6(main)
1 0.000 0.000 6.013 6.013 sample.py:3(<module>)
1 0.000 0.000 6.013 6.013 {built-in method builtins.exec}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}tottimeを指定しているからtottimeの値が大きい順に並べられている
ソートできる項目は以下のとおり（公式の表より）
snakevizの使い方
snakevizはcProfileの出力結果を図で表示することができます
- cProfileの出力結果が書き出されたファイルが必要（-o オプションにより書き出しておく必要がある）
- インストールが必要
標準ライブラリではないため別途インストールする
$ pip install snakeviz先ほど上で書き出したsample.profileをsnakevizで表示してみる
$ snakeviz sample.profile（実行結果）
- カーソルを図の上に移動すると、それぞれの関数の処理時間などが表示される
- ページしたのnacallsやtottimeはクリックすることで、昇順・降順に並べ替えることができる
sample.pyは単純なプログラムのため、より複雑なプログラムの出力結果は
みればわかる複雑なやつやーん笑 って感じになります。（失礼しました）
cProfileとProfileの違いについて
ボトルネックを特定する方法としてよくProfileとcProfileが挙げられます
どちらもpythonの標準プロファイリングツールであり
プログラムの処理時間等を計測するためのツールです
これらの違いを超ざっくりまとめると
１０ファイル程度両方を使用して試してみましたが
全てのファイルにおいてcProfileの方が処理が早く終わりました
内部的な仕組み等は詳しくはわかりませんが 、cProfileを使用しておけば、問題なさそうです
まとめ
cProfileとは
- プログラムのボトルネックを特定できる便利なツール
snakevizを使うと
- cProfileの出力結果を可視化できる
cProfileとProfileの違い
cProfile（c言語）・Profile(python)
基本的にcProfileが処理速度が速い
- cProfileを使用しておけば問題ない
cProfileについて理解できたでしょうか？
今回は紹介しませんでしたが、行ごとに処理時間を計測できるline_profilerや
リアルタイムで計測結果を確認できるpy_spyなどのプロファイラもありますので
そちらも使って自分に合うプロファイラを使用することをオススメします
ohenziblogはプログラミングを独学で始めるための徹底ガイドを目指しています
