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

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

# 実装例

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

```py3:関数の実行時間を計測するデコレータの定義
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
```

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

# 使用例

```py3: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()
```

```console:実行例
$ 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](http://qiita.com/mtb_beta/items/d257519b018b8cd0cc2e)
[[python]デコレータでfunctools.wrap()を使う - logging.info(self)](http://d.hatena.ne.jp/aroma_black/20110228/1298905581)
[Python: 色々なデコレータの作り方と使い方、そして本質 | CUBE SUGAR STORAGE](http://momijiame.tumblr.com/post/86112194941/python-%E8%89%B2%E3%80%85%E3%81%AA%E3%83%87%E3%82%B3%E3%83%AC%E3%83%BC%E3%82%BF%E3%81%AE%E4%BD%9C%E3%82%8A%E6%96%B9%E3%81%A8%E4%BD%BF%E3%81%84%E6%96%B9%E3%81%9D%E3%81%97%E3%81%A6%E6%9C%AC%E8%B3%AA)