LoginSignup
7

More than 5 years have passed since last update.

[Python3] 関数の実行時間を計測するデコレータの定義

Posted at

関数の実行時間の計測がデコレータ足すだけでできそうな気がしたのでやってみたメモ
(パッケージとかですでにありそうな気はしますけど)

実装例

地味にf-string使っているので、Python3.6以上がいりますが、若干修正すれば2.7でも動くと思います。

関数の実行時間を計測するデコレータの定義
import time

def calc_time(message='', parser=None):
    def _calc_time(func):
        import functools

        @functools.wraps(func)
        def wrapper(*args, **kargs):
            start = time.time()
            ret = func(*args, **kargs)
            if parser:
                parsed_message = parser(message, *args, **kargs)
                print(
                    f'end time : {time.time() - start:0.4} sec : {parsed_message}')
            else:
                print(f'end time : {time.time() - start:0.4} sec : {message}')
            return ret
        return wrapper
    return _calc_time

関数の引数をつかったメッセージを表示したいケースがあるかと思うので、メッセージ加工用の関数オブジェクトを渡せるようにしています

使用例

test.py
import time


def message_parser(message, *args, **kargs):
    return f"{message} and {args[0]}"


def calc_time(message='', parser=None):
    def _calc_time(func):
        import functools

        @functools.wraps(func)
        def wrapper(*args, **kargs):
            start = time.time()
            ret = func(*args, **kargs)
            if parser:
                parsed_message = parser(message, *args, **kargs)
                print(
                    f'end time : {time.time() - start:0.4} sec : {parsed_message}')
            else:
                print(f'end time : {time.time() - start:0.4} sec : {message}')
            return ret
        return wrapper
    return _calc_time


@calc_time()
def test1():
    time.sleep(0.2)
    print('call test1')


@calc_time('something message')
def test2():
    time.sleep(0.2)
    print('call test2')


@calc_time('something message', parser=message_parser)
def test3(something_args):
    time.sleep(0.2)
    print('call test3')


@calc_time('something message',
           parser=lambda message, *args, **kargs: f"{message} and {args[0]}")
def test4(something_args):
    time.sleep(0.2)
    print('call test4')

@calc_time('something message',
           parser=lambda message, *args, **kargs: f"{message} and {kargs['something_args']}")
def test5(something_args):
    time.sleep(0.2)
    print('call test4')

@calc_time(parser=lambda message, *args, **kargs: f"{args[0]}")
def test6(something_args):
    time.sleep(0.2)
    print('call test4')

def main():
    test1()
    test2()
    test3('something args')
    test4('something args')
    test5(something_args='something args')
    test6('something args')

if __name__ == '__main__':
    main()
実行例
$ python test.py
call test1
end time : 0.2001 sec : 
call test2
end time : 0.2 sec : something message
call test3
end time : 0.2001 sec : something message and something args
call test4
end time : 0.2 sec : something message and something args
call test4
end time : 0.2 sec : something message and something args
call test4
end time : 0.2008 sec : something args

参考

Pythonのデコレータについて - Qiita
[python]デコレータでfunctools.wrap()を使う - logging.info(self)
Python: 色々なデコレータの作り方と使い方、そして本質 | CUBE SUGAR STORAGE

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
7