St_Hakky’s blog

Data Science / Human Resources / Web Applicationについて書きます

【Python】実行時間を測定する方法まとめ

こんにちは。

実行時間(処理時間)を計測したいことはよくあると思いますが、今回はPythonで実行時間を測りたいなってなった時の方法を、自分用にまとめておきたいと思います。

※なんか章立ての粒度がばらばらになってしまった気がするが、細かいことは気にしない。。。

Pythonコード上

Pythonのコード上(という表現がいいのかはわかりませんが汗)で実行時間を計測するための方法が以下。

timeモジュールを使う

これが一番最初にパッと思いつく方法かなと思います。

import time

start = time.time()
func()
process_time = time.time() - start

print(process_time)

デコレーターを用いる方法

こちらの記事で紹介されていたんですが、これは確かに便利だなと思いました(作者の方ありがとうございます)。

自作のデコレーターを作って、それで処理時間を計測したい関数にそのデコレーターを使ってあげれば、実現することが可能です。

以下のコードは、その記事にあったものほぼそのままです(詳細な解説は、元記事にされているので、そちらを参照ください)。

from functools import wraps
import time
def stop_watch(func) :
    @wraps(func)
    def wrapper(*args, **kargs) :
        start = time.time()
        result = func(*args,**kargs)
        process_time =  time.time() - start
        print(f"{func.__name__}は{process_time}秒かかりました")
        return result
    return wrapper

使う時は、処理時間を計測したい関数に、以下のようにしてデコレートしてあげればオッケーです。

@stop_watch
def func() :
    ~~何かの処理を書く~~~

# 使う時は普通に使うだけ。
func()

ただ、私はやっていないのですが、こちらの記事によると、再帰呼び出しや複数関数を同時に計測しようとすると、ハマるらしいので、注意が必要とのことです。

Jupyter Notebook

Jupyter Notebookで実行時間を計測するためには、Pythonファイル上でごねごねやっていた方法を取る必要がなく、簡単に処理時間を計測することができます。

%%timeit

Jupyter Notebookを使っている場合は、簡単に処理時間を計測できるtimeitマジックがあります。

使い方は、%%timeitを実行時間を計測したい処理が書かれているcellにいれるだけです。

%%timeit
func()

そうすると、その処理を何回か繰り返して、処理時間を計測してくれます。以下のような感じの出力が返ってきます。

The slowest run took 7.18 times longer than the fastest. This could mean that an intermediate result is being cached.
100000 loops, best of 3: 7.56 µs per loop

10万回も実行して、処理時間に関する情報をくれています。実際に何回か実行するとわかるんですが、一回一回の実行では処理時間に結構ばらつきがありますので、より正確に実行時間を知りたい場合にはこちらを使うといいかな、っておもいます。

%%time

%%timeでも処理時間を計測できます。

%%time
func()

こうすると、以下のような出力が返ってきます。

CPU times: user 5 µs, sys: 0 ns, total: 5 µs
Wall time: 10 µs

CPU timesってのが何なのかはいまいちよくわかっていませんが*1、とりあえず、Wall timeってのが実行時間のことなので、これで処理にかかった時間をしれます。

さっきの%%timeitは、10万回も実行していましたが、今回は1回の実行時間しか計測していません。ので、実行時間にはばらつきはでますが、だいたいの処理時間を知りたい時には便利かなと思います。

IPython

%timeit

IPythonでは、1行でかける場合に限定されてしまうっぽいのですが、以下のようにかけます。%timeitの意味は、Jupyter で説明したのと同じく、複数回実行して処理時間を返してくれます。

%timeit func()

これも関数の実行時間とか知る分には充分ですよね。

%time

当然、%timeも用意されていて、これもJupyterで説明したのと同じ意味で使われます。

使い方は、以下の通りです。

%time func()

コマンドライン

Linuxのtimeコマンドを利用する

script全体の時間を計りたい時に使うと便利なのが、これです。以下のようにすることで、script全体の実行時間を計測することができます。

$ time python file.py

timeitを使用して実行時間を測る

以下のような方法でも処理時間を測ることができます。

$ python -m timeit "[i for i in range(100)]"
100000 loops, best of 3: 4.88 usec per loop

デフォルトでは10万回処理時間を計測してくれるみたいです(やりすぎでは笑)。これは内包表記の時間を計っていますが、ファイル中の処理の実行時間も計測できて、

$ python -m timeit -s "import file_name" "file_name.func_name()"

みたいな感じでできます。-sは、その後の処理を一度だけ実行するということを指定できるやつです。これしないと、10万回回す必要がないものまで回ってしまうので、危険です。

cProfile

Pythonには、cProfileというものがあります。詳細はドキュメントをみればわかりますが、一応まとめておこうかなと思います。

# -s をつけることで、実行時間をソートして出力を返してくれる
python -m cProfile -s file_name.py

# 更にcumulative をつけることで、関数が消費した累計時間でソートして、表示してくれます
python -m cProfile -s cumulative file_name.py

コマンドライン以外からでも使うことができますが、詳細はドキュメントを。

cProfileの使い所

例えばscript内で複数の関数を使用して処理を実行する際に、「何がボトルネックになっているか」を特定するのに使うと良いそうです。

このcProfileでは、複数の関数が何回呼び出されたかや、その処理にかかった時間を返してくれるので、どこの処理にどれくらいの時間がかかっているかがわかります。

処理の時間を計測してパフォーマンスを改善したい場合がほとんどだと思うので、これは便利ですね。

出力結果の見方

出力がちょっと特殊なので、ドキュメントに書いてある通りですが、メモがわりに記載しておきます。

ncalls 呼び出し回数
tottime 与えられた関数に消費された合計時間 (sub-function の呼び出しで消費された時間は除外されています)
percall tottime を ncalls で割った値
cumtime この関数と全ての subfunction に消費された累積時間 (起動から終了まで)。この数字は再帰関数に ついても 正確です。
percall cumtime をプリミティブな呼び出し回数で割った値
filename:lineno(function) その関数のファイル名、行番号、関数名
■参考


こんな感じでしょうか。。。他に方法を知っている方がいれば教えてください。

それでは。

*1:わかる方だれか教えてください