pythonの関数の処理時間計測デコレータ
pythonで実行時間を測定するためにはtime ライブラリ、jupyter上では%time などの使用が有名だと思います。コードの中に余計な処理を書き込みたくない人向けに、decoratorを使って関数の定義部分で宣言するだけで、実行後に処理時間を出力するようにかえる方法を紹介します。 また、少し分かりにくいdecoratorを解説します。
実行時間の計測
関数の処理時間を出力します。 入力された整数の大きさ分だけ1を足し、合計を返す関数を用意して計測してみます
処理時間の出力をデコレータで宣言
本記事で紹介する方法です。デコレータの定義は後述
# （後述）stop_watchというdecoratorを定義しておく # decoratorを置く @stop_watch def example_func_deco(num): res = 0 for i in range(num): res += 1 return res # 実行すると処理時間がprintされる summ = example_func_deco(1000) # >>> 0.0122 ms in example_func
関数定義に書くだけなのでメインアルゴリズムに何の影響も及ぼさず計測できます。また、計測を外すときには関数上部のデコレータをコメントアウトするだけなので見落としにくいと思います。
上記と同じ処理で、decoratorのない関数に対する有名な処理時間計測法も紹介します。
def example_func(num): res = 0 for i in range(num): res += 1 return res
有名な書き方.1: time moduleで時間取得
よくある有名な計測法は以下の様にtime モジュールを使って処理開始前の時間を取得し、関数実行後に時間を取得し、差分を計算することで処理時間を求めるというものです。
import time # 処理開始前の時間取得 start = time.time() # 計測したい処理 summ = example_func(100) # 処理開始後の時間取得・処理時間をプリント elapsed_time = time.time() - start print("{:.03} ms in {}".format(elapsed_time * 1000, 'example_func'))
有名な書き方.2: jupyterの%time
以下の様に書きます。ただし、jupyter notebookからしか使えません。
%time sample_func(100) # >>> CPU times: user 7 µs, sys: 1 µs, total: 8 µs # >>> Wall time: 10 µs
また、以下では複数回関数を実行して実行時間を計測することでより正確な測定ができます。
%timeit example_func(100) # >>> 3.74 µs ± 62.3 ns per loop (mean ± std. dev. of 7 runs, 100000 loops each)
利点・欠点
これらの手法には以下の様にメリットとデメリットがあります。 使用したいケースに応じて使い分けていくのがいいと思います。
| 手法 | 記述箇所 | 利点 | 欠点 |
|---|---|---|---|
| デコレータ | 関数定義の上部 | 記述量が少ない | 関数にしか使えない |
| time module | 処理の前後 | いつでも使える | 記述量が多い |
| %time | 関数実行部の先頭 | 記述量が少ない | jupyter でしか使えない |
stop_watch decoratorの中身
本記事で紹介する、関数の処理時間の計測用デコレータの中身を解説していきます。 まず、こちらがstop_watch decoratorの定義です。この関数を定義して (or 別ファイルからimportして)@stop_watchすると処理時間が計測できます。 つまる所、time moduleの方法をdecorator化しただけです。
from functools import wraps import time def stop_watch(func): @wraps(func) def wrapper(*args, **kargs): # 処理開始直前の時間 start = time.time() # 処理実行 result = func(*args, **kargs) # 処理終了直後の時間から処理時間を算出 elapsed_time = time.time() - start # 処理時間を出力 print("{} ms in {}".format(elapsed_time * 1000, func.__name__)) return result return wrapper
decorator
どのように動いているの理解するためにdecoratorの処理を確認していきます。
# decorator関数の定義 def deco(func): @wraps(func) def _deco(*args, **kwargs): print('before main') func(*args, **kwargs) print('after main') return _deco # docoratorを適用した関数 @deco def main(*args, **kwargs): print('main function')
main() # >>> before main # >>> main function # >>> after main
decoratorは関数の前後に処理を追加していることがわかります。
部分適用
decoratorは関数型プログラミング言語で言うところの部分適用のシンタックスシュガーにあたります。 部分適用では関数内変数 (引数) の一部にだけ値を代入して、引数の数を減らすことに相当します。
# 実質、引数が2つの関数 def curry(x): def _curry(y): return x + y return _curry
_curry関数内のxはcurry関数の引数を参照するため、
curried = curry(1) # xに1を代入
は部分適用に相当しており、引数の一部xに値を代入して、引数がyだけのcurried関数をつくったことになります。 すなわち、curried関数は部分適用されて、以下のような関数になっています。
def curried(y): return 1 + y
decoratorの働き
では、decoratorでやっていた処理を部分適用で書いてみます。
# decoratorとして使う関数 def deco(func): @wraps(func) def _deco(*args, **kwargs): print('before main') func(*args, **kwargs) print('after main') return _deco def main(*args, **kwargs): print('main function') # _deco関数のfuncにmain関数を代入 (部分適用) # よって、_deco関数はmain関数の前後に処理を追加したものになる # そして、_deco関数を新ためてmain関数とする main = deco(main)
以上の処理がdecoをmain 関数のdecoratorとして使うのと同等であることがわかるかと思います。 この処理をわかりやすくするためにdecoratorというシンタックスシュガーがあります。状況にもよりますが、decoratorのほうが直感的な気がします。
functools.wraps
decorator内のwraps decoratorは部分適用をdecoratorとして使う時に、入力した親の関数名やdocstringを引き継ぐためのものです。 つけなくとも動きますが、doctestが使えなくなってしまいます。
def deco(func): @wraps(func) def _deco(*args, **kwargs): pass return _deco def deco_no_wraps(func): def _deco(*args, **kwargs): pass return _deco # decorateされる関数 main # >>> <function __main__.main(*args, **kwargs)> # wrapsをいれるとmainを引き継ぐ deco(main) # >>> <function __main__.main(*args, **kwargs)> # wrapsをいれないと別の関数名をもつ deco_no_wraps(main) # >>> <function __main__.deco_no_wraps.<locals>._deco(*args, **kwargs)>
おわりに
以上がpythonの関数の処理時間の計測用デコレータの紹介になります！ (半分ぐらいdecoratorの説明になってしましましたが) よければ使ってみて下さい！
