[Python]デコレータで時間計測処理を共通化する
はじめに
Pythonでは、「デコレータ」を使うことで、既存の関数のコードに変更を加えることなく、関数実行時の処理を変更することができます。
その性質を利用して、プログラムの処理にかかる時間を計測する機能を、サクッと使えるようにしてみます。
デコレータとは？
「関数を引数として受け取り、別の関数を返す関数」です。
Pythonでは関数もオブジェクトとして扱われます。
例えば、関数Aを引数として渡すと、関数Bを返してくれる関数を作ることもできます。これがデコレータです。
もう少し具体的な例をあげます。
- intを渡すと2倍にして返す関数double_int()があるとします。
- 関数の結果を3倍にするデコレータtriple_func()を作成します。
- triple_func()にdouble_int()を引数として渡します。
- triple_func()の戻り値として、double_int()の結果を3倍にした結果を得る関数が得られます。
上記をサンプルコードに落としてみます。
サンプルコード
1. intを渡すと2倍にして返す関数double_int()があるとします。
def double_int(a):
return a * 2
2. 関数の結果を3倍にするデコレータtriple_func()を作成します。
def triple_func(func): # 引数として関数を受け付ける
def new_function(*args, **kwargs):
result = func(*args, **kwargs)
return result * 3 # 引数として渡された関数の結果を3倍にする
return new_function # 定義したnew_functionを戻り値として返す
3. triple_func()にdouble_int()を引数として渡します。
six_times_int = triple_func(double_int)
4. triple_func()の戻り値として、double_int()の結果を3倍にした結果を得る関数が得られます。
print(double_int(3)) # 結果 : 6
six_times_int = triple_func(double_int)
print(six_times_int(3)) # 結果 : 18
デコレータに関数を渡して別の関数を得る、を@で簡単に書く
前項の
six_times_int = triple_func(double_int)
は、以下のように書くことで同様の結果を得ることができます。
@triple_func
def double_int(a):
return a * 2
留意点として、以下があります。
- デコレータ関数は
@で宣言されるより前に定義されている必要があります @でデコレータを複数設定することができますが、その場合は関数名定義(defの行)から近い順に処理が実行されます
時間計測処理をデコレータで作る
本題です。時間計測処理をデコレータで作ります。
ベースとなる時間計測処理を書く
まずはシンプルに時間計測処理を書きます。
やっていることは以下です。
- time.time()で処理前の時刻(UNIXTIME)を取得し、処理後のtime.time()から引いて処理時間を計算
- 時刻はdatetime.strftimeで見やすく変換して出力
- 処理時間も桁数を見やすく変換して出力
import time
from datetime import datetime
def wait_method(sec):
"""サンプルメソッド。引数の間待ち、「Done!」をprintする"""
time.sleep(sec)
print('Done!')
# wait_methodの前後で時間を計測する
##############
# 時間計測処理
##############
start_at = time.time()
start_str = datetime.fromtimestamp(start_at).strftime('%Y-%m-%d %H:%I:%S')
print('Started:', '[' + start_str + ']')
wait_method(3)
end_at = time.time()
end_str = datetime.fromtimestamp(end_at).strftime('%Y-%m-%d %H:%I:%S')
time_taken = end_at - start_at
print('Finished: took', '{:.3f}'.format(time_taken), 'sec[' + end_str + ']')
実行結果
$ python time_recorder.py
Started: [2020-05-24 17:05:37]
Done!
Finished: took 3.005 sec[2020-05-24 17:05:40]
処理内容をデコレータにする
上記の# 時間計測処理以降をデコレータ関数にします。
time_recorder.py
import time
from datetime import datetime
from functools import wraps
def time_recorder(func):
@wraps(func)
def new_function(*args, **kwargs):
start_at = time.time()
start_str = datetime.fromtimestamp(start_at).strftime('%Y-%m-%d %H:%I:%S')
print('Started func:', func.__name__, '[' + start_str + ']')
result = func(*args, **kwargs)
end_at = time.time()
end_str = datetime.fromtimestamp(end_at).strftime('%Y-%m-%d %H:%I:%S')
time_taken = end_at - start_at
print('Finished func:', func.__name__, 'took', '{:.3f}'.format(time_taken), 'sec[' + end_str + ']')
return result
return new_function
@time_recorder
def wait_method(sec):
"""サンプルメソッド。引数の間待ち、「Done!」をprintする"""
time.sleep(sec)
print('Done!')
if __name__ == '__main__':
wait_method(3)
- どの関数の時間かわかりやすいよう、
func.__name__で関数名を表示するようにしています。 - 与えられた関数の性質を引き継ぐように、
@wraps(func)を付けています。(こちらの記事が詳しいですので参照ください)
実行結果
Started func: wait_method [2020-05-24 17:05:20]
Done!
Finished func: wait_method took 3.001 sec[2020-05-24 17:05:23]
同様の結果が得られました。
これで、計測したい関数に@time_recorderをつければ簡単に時間を計測できるようになりました。
デコレータ関数を別ファイルから呼び出す
実際に使う上では、このデコレータ関数を都度書くわけにもいきません。
time_recorder.pyのtime_recorder関数を、別のファイルから呼び出したくなります。
another_file.py
import time_recorder
@time_recorder
def sample_method():
print('Sample!')
上記の書き方では、以下のようなエラーになります。
@time_recorder
TypeError: 'module' object is not callable
別ファイルから使う場合は、普通に別ファイルのメソッドを呼び出すときと同様、time_recorder.time_recorderと書く必要があります。
@time_recorder.time_recorder
def sample_method():
print('Sample!')
実行結果
Started func: print_multiple_result [2020-05-24 18:06:44]
Sample!
Finished func: print_multiple_result took 0.000 sec[2020-05-24 18:06:44]
まとめ
時間計測したい場合は、import time_recorderして、@time_recorder.time_recorderと書けば良くなりました。
上記ソースは以下で公開しています。
tsoshiro/time_recorder: Time record decorator
デコレータは一見複雑ですが、使いこなせると便利です。