田舎で並行処理の夢を見る

試したこと、需要がないかもしれないけど細々とアウトプットしてます

【使用例あり(for文vs内包表記)】Pythonでデコレーターを使って関数の平均実行時間を測定する

実装したデコレーター用の関数

全体のコードはこちら
github.com

すでに似た様な記事が多く記述されているが、指定回数の平均実行時間を出力したいのは自分が初めてだと信じて実装してみた。pythonデコレーターを使用して、指定回数の平均実行時間を算出することが出来る。デコレーターに関する詳しい説明はすでに多くの記事が存在しているのでそちらにおまかせします。

./bench.py

import time
import logging

# benchmark用の関数
def benchmark(try_num):
    """
        TASK: デコレーターを行い関数に対して指定回数の実行を行う
        lst: []int, []float -> 対象の配列
        try_num: int -> 実行回数の合計数
        return ([]float, float) -> (実行結果を格納した配列, 平均値)
    """
    def _timer(exec_func, *args, **kwargs):
        """
            TASK: デコレーター経由で受け取った関数を実行し、実行時間を返す
            exec_func: function -> 実行したい関数
        """
        start = time.time()
        exec_func(*args, **kwargs)
        end = time.time()
        return end - start

    # デコレーターで装飾した関数を受け取る関数
    def _benchmark(exec_func):
        """
            TASK: 関数を受け取り、指定回数実行するサブ関数
            exec_func: function -> 実行したい関数
            return []float
        """
        # 装飾した関数の引数を受け取りベンチマークを実行する関数
        def _sub_bencmark(*args, **kwargs):
            # 計測結果
            logging.info(f"Start benchmark  「{exec_func.__name__}」 ...")
            messured = [_timer(exec_func, *args, **kwargs) for _ in range(0, try_num)]
            average = sum(messured) / len(messured)
            logging.info("Result: Average execution time -> {:.5f} s (total exec {})".format(average, try_num))
            return exec_func(*args, **kwargs)

        return _sub_bencmark

    return _benchmark

サンプル

from bench import benchmark
import logging

# loggerの設定(defaultでDEBUG, INFOは出力は出力されないため必須)
formatter = '%(levelname)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.INFO, format=formatter)

@benchmark(100)
def sample(s):
    return s

sample("nice")

実行結果

INFO : 2020-03-14 20:38:35,967 : Start benchmark  「sample」 ...
INFO : 2020-03-14 20:38:35,967 : Result: Average execution time -> 0.00000 s (total exec 100)

@benchmark(10)と対象の関数の上部に記述することで デコレーターとなり、対象の関数を引数で受け取ることが出来る。ただ、今回は実行する回数を指定して、平均値を算出したいので実行回数を受け取る専用の関数(benchmark)でwrapしている。関数の内部化についてはやや複雑になっているが、

  • 実行回数を受け取る
  • 実行したい関数を受け取る
  • 実行したい関数に渡す引数を受け取る
  • 指定回数だけ実行して平均実行時間をlogに出力

という流れで実行しているだけなので大したことはやっていない。注意としては結果は従来の関数の戻り値に影響を与えないためログに出力している。

使用例: for文内包表記map関数での速度比較

よく「Pythonfor文は遅い。内包表記を使おう」と言われるが、それが本当なのかを先ほど作成したベンチマーク用のデコレーターを用いて検証してみよう。ついでなので、map関数も比較対象に追加した。

配列の各要素を2倍するという処理をfor文, 内包表記, map関数のそれぞれを用いて実装した。それぞれ実行した関数に対して先ほど作成したデコレーターを記述してやる。今回は10,000回実行での平均速度を比較してみよう。

./funcs.py

from bench import benchmark

TRY_NUM = 10000

@benchmark(TRY_NUM)
def for_double(lst):
    """
      TASK: forを使った配列の要素を全て2倍にする関数
      lst: []int, []float -> 対象の配列
      return []int, []float
  """
    res = list()
    for n in lst:
        res.append(n * 2)
    return res

@benchmark(TRY_NUM)
def comprehension_double(lst):
    """
      TASK: 内包表記を使った配列の要素を全て2倍にする関数
      lst: []int, []float -> 対象の配列
      return []int, []float
  """
    return [n * 2 for n in lst]

@benchmark(TRY_NUM)
def map_double(lst):
    """
      TASK: map関数を使った配列の要素を全て2倍にする関数
      lst: []int, []float -> 対象の配列
      return []int, []float
  """
    return list(map(lambda x: x * 2, lst))

これで関数側の用意は完了。次に実行ファイルを作成する。

./main.py

from funcs improt (
  for_double,
    comprehension_double,
    map_double
)

import logging

# loggerの設定(defaultでDEBUG, INFOは出力は出力されないため必須)
formatter = '%(levelname)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.INFO, format=formatter)

def create_data(total_num):
    """
      TASK: テスト用の指定要素数を持つ配列を作成する関数
      total_num: int -> 配列要素数
      return []int
  """
    return [n for n in range(1, total_num+1)]

if __name__ == "__main__":
    # 各種の関数を実行
    data_for_benchmark = create_data(10000)

    # benchmarkを実行
    for_double(data_for_benchmark)
    comprehension_double(data_for_benchmark)
    map_double(data_for_benchmark)

では、結果を確認してみよう。

$ python3 main.py

INFO : 2020-03-14 20:53:47,441 : Start benchmark  「for_double」 ...
INFO : 2020-03-14 20:54:04,680 : Result: Average execution time -> 0.00172 s (total exec 10000)
INFO : 2020-03-14 20:54:04,692 : Start benchmark  「comprehension_double」 ...
INFO : 2020-03-14 20:54:13,866 : Result: Average execution time -> 0.00091 s (total exec 10000)
INFO : 2020-03-14 20:54:13,868 : Start benchmark  「map_double」 ...
INFO : 2020-03-14 20:54:28,890 : Result: Average execution time -> 0.00150 s (total exec 10000)

おお、やはり内包表記はかなり速い。数値としては約2倍ほど速いようだ。以外だったのはmap関数for文とほとんど同速であったということで、この結果の他に何度か検証を行なったが、for文が速い時もあればmap関数が速い時もあった。しかしながら内包表記は常に一番速かった。

こんな感じで、今回、実装したデコレーター用のベンチマーク関数を用いることで関数の平均実行速度を気軽に測定することが出来るので、ぜひ使ってくみて下さいね。

おまけ1: for文, 内包表記, map関数の別結果

INFO : 2020-03-14 20:53:17,841 : Start benchmark  「for_double」 ...
INFO : 2020-03-14 20:53:27,750 : Result: Average execution time -> 0.00099 s (total exec 10000)
INFO : 2020-03-14 20:53:27,753 : Start benchmark  「comprehension_double」 ...
INFO : 2020-03-14 20:53:33,386 : Result: Average execution time -> 0.00056 s (total exec 10000)
INFO : 2020-03-14 20:53:33,389 : Start benchmark  「map_double」 ...
INFO : 2020-03-14 20:53:44,338 : Result: Average execution time -> 0.00109 s (total exec 10000)
INFO : 2020-03-14 21:01:10,190 : Start benchmark  「for_double」 ...
INFO : 2020-03-14 21:01:22,041 : Result: Average execution time -> 0.00118 s (total exec 10000)
INFO : 2020-03-14 21:01:22,045 : Start benchmark  「comprehension_double」 ...
INFO : 2020-03-14 21:01:28,320 : Result: Average execution time -> 0.00062 s (total exec 10000)
INFO : 2020-03-14 21:01:28,328 : Start benchmark  「map_double」 ...
INFO : 2020-03-14 21:01:40,712 : Result: Average execution time -> 0.00124 s (total exec 10000)

おまけ2: 内包表記map関数が好きな人へ

Pythonの内包表記は関数型言語であるHaskellからの輸入品かつ、map関数も同じく関数型言語からの輸入品として有名です。少しでも興味があれば私が押しているElixirという言語について、ぜひ覗いてみて下さい。きっと気に入って頂けると思います。

www.okb-shelf.work
www.okb-shelf.work

参考文献