概要
pythonのプロファイルツールである、cProfile, line_profiler, memory_profilerを使ってみます。
python 2.7.8を使用しています。
下記のフィボナッチ数列のプログラムを使って解説していきます。
import sys
n = int(sys.argv[1])
f = sys.argv[2]
@profile
def fib1(n):
a, b = 0, 1
for i in range(n):
a, b = b, a + b
return b
@profile
def fib2(n):
a, b = 0, 1
for i in xrange(n):
a, b = b, a + b
return b
func = { "fib1": fib1,
"fib2": fib2 }
r = func[f](n)
print(r)
cProfile
関数単位でどこにCPUコストがかかっているか調査できるツールです。
使い方
コマンド実行時にcProfileを指定します
python -m cProfile -s cumulative fib.py 1000000 fib1
結果
以下のようにtottimeを見ると、どの関数で時間がかかっているのかがわかります。
ncalls tottime percall cumtime percall filename:lineno(function)
1 1.045 1.045 13.498 13.498 fib.py:1(<module>)
1 12.432 12.432 12.453 12.453 fib.py:6(fib1)
1 0.022 0.022 0.022 0.022 {range}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
line_profiler
コードの行単位でどこにCPUコストがかかっているか調査できるツールです。
cProfileを使ってもどこに時間がかかっているか分からない場合にline_profilerを使ってみると良いと思います。
ただし、プロファイルを取りたい関数には上のコードにもあるように@profileデコレータを付与する必要があります。
また、line_profilerを使うと通常の実行時より実行時間が長くかかることは注意しておく必要があります。
使い方
まずはpipでインストールを行います。
pip install line_profiler
kernprofコマンドでプロファイルを実行します。
-lは行単位でプロファイルを出力するオプションです。
-vはstdoutと.lprofファイルの両方に結果を出力するオプションです。
kernprof -l -v fib.py 1000000
.lprofファイルを使って以下のように結果を出力できます。
python -m line_profiler fib.py.lprof
結果
以下のように%Timeをみるとコードのどのラインがどれくらいの割合で時間を使っているのかがわかります。
Total time: 13.3281 s
File: fib.py
Function: fib1 at line 6
Line # Hits Time Per Hit % Time Line Contents
==============================================================
6 @profile
7 def fib1(n):
8 1 2.0 2.0 0.0 a, b = 0, 1
9 1000001 466000.0 0.5 3.5 for i in range(n):
10 1000000 12862043.0 12.9 96.5 a, b = b, a + b
11 1 7.0 7.0 0.0 return b
memory_profiler
このツールは上記２つのツールと違いメモリに関するプロファイルツールです。コードのどの部分でどれくらいのメモリを確保しているか確認することができます。
line_profilerと同じで、このツールでもプロファイルを取りたい関数には@profileデコレータを付与する必要があります。
memory_profilerも通常の実行時より実行時間が長くかかることは注意しておく必要があります。
使い方
まずはpipでインストールを行います。
pip install memory_profiler
pythonコマンド実行時にmemory_profilerモジュールを指定して実行します。
python -m memory_profiler fib_profile.py 1000000 fib1
結果
Mem Usageをみると各ラインでどれだけのメモリを使用しているのかがわかります。
特に9行目のrangeで内部的にリストが生成されるのでメモリ使用量が増加していることがわかります。
Line # Mem usage Increment Line Contents
================================================
6 22.617 MiB 22.617 MiB @profile
7 def fib1(n):
8 22.617 MiB 0.000 MiB a, b = 0, 1
9 54.109 MiB 30.594 MiB for i in range(n):
10 54.109 MiB 0.000 MiB a, b = b, a + b
11 46.477 MiB -7.633 MiB return b
上記コードではrangeを使うfib1, xrangeを使うfib2があるのですが、fib2を実行してみるとxrangeはrangeとは違い内部的にリストを生成しないのでメモリを余分に使っていないことがわかります。
Line # Mem usage Increment Line Contents
================================================
14 22.617 MiB 22.617 MiB @profile
15 def fib2(n):
16 22.617 MiB 0.000 MiB a, b = 0, 1
17 23.066 MiB 0.000 MiB for i in xrange(n):
18 23.066 MiB 0.449 MiB a, b = b, a + b
19 23.066 MiB 0.000 MiB return b```