Pythonコードの実行速度を計測する

Pythonコードの実行に時間がかかるときに、コード全体ではなくコード内のどの箇所で時間がかかっているか確認したいときがある。Pythonモジュールのline_profilerを使うと、1行単位で実行速度を計測できる。今回はline_profilerで関数内のコード1行ごとの実行時間を計測してみる。

環境

Windows10(1903)のWSL(Ubuntu 18.04)とJupyter Notebookを使用。
$ lsb_release -dr Description: Ubuntu 18.04.3 LTS Release: 18.04 $ python3 -V Python 3.6.8 $ pip3 show numpy Name: numpy Version: 1.17.0 ... $ jupyter --version 4.4.0

line_profilerのインストール

line_profilerはバージョン2.1.2の時点ではpipでインストールできないらしいので、gitでクローンしてインストールする。
$ git clone https://github.com/rkern/line_profiler.git $ find line_profiler -name '*.pyx' -exec cython {} \; $ cd line_profiler $ pip3 install . --user $ pip3 show line_profiler Name: line-profiler Version: 2.1.1

line_profilerでコードの実行速度を計測する

テスト用の関数を定義して、その実行速度を計測してみる。

import numpy as np
from line_profiler import LineProfiler

def test(loop):
    arr1 = np.random.rand(500,500,500)
    for i in range(loop):
        arr2 = np.random.rand(500,500,500)
    arr3 = np.random.rand(500,500,500)
    
    return 0

# インスタンス作成
lp = LineProfiler()

# 計測する関数を追加
lp.add_function(test)

# 計測する関数の実行
# 2は関数の引数、resultは返値
result = lp.runcall(test, 2)
print('result =', result)

# 計測結果の出力（単位をミリ秒に指定）
lp.print_stats(output_unit=1e-3)

以下のように行単位の実行時間が出力される。
result = 0 Timer unit: 0.001 s Total time: 6.08212 s File: lp_test.py Function: test at line 4 Line # Hits Time Per Hit % Time Line Contents ============================================================== 4 def test(loop): 5 1 1499.8 1499.8 24.7 arr1 = np.random.rand(500,500,500) 6 3 0.0 0.0 0.0 for i in range(loop): 7 2 3084.3 1542.2 50.7 arr2 = np.random.rand(500,500,500) 8 1 1498.0 1498.0 24.6 arr3 = np.random.rand(500,500,500) 9 10 1 0.0 0.0 0.0 return 0

出力結果の項目は以下の通り。

• Line: ファイル内の行数
• Hits: 実行回数
• Time: 実行回数分の合計時間
• Per Hit: 平均（1回分の）実行時間
• % Time: 関数内での実行時間の割合
• Line Contents: コード

Jupyter Notebookでの時間計測

Jupyter Notebookではもっと簡単に計測できる。

%load_ext line_profiler
import numpy as np

def test(loop):
    arr1 = np.random.rand(500,500,500)
    for i in range(loop):
        arr2 = np.random.rand(500,500,500)
    arr3 = np.random.rand(500,500,500)
    
    return 0

# 計測の実行
# オプションuで出力する時間の単位を指定し、fで計測する関数を指定
%lprun -u 1e-3 -f test result = test(2)
print('result =', result)

先のLineProfilerインスタンスを作成したコードと同様の結果が得られる。