Jupyter notebookを使ってコードの実行時間を測るとき、多くの人は%timeコマンドで実行時間を計測し、さらに何度か時間して平均的な実行時間を測定するのに%timeitマジックコマンドを使っていると思います（少なくとも私はそうです）。
しかし%timeitの出力が何を意味しているのかよく判っていなかったので調べました。
2019-04-07追記：google colabの実装に関して追記
timeitマジックコマンドとは
まずは%timeitの使い方を念の為復習しておきましょう。
%timeitマジックコマンドとはjupyter上でコードの平均的な実行時間を計測するのに使うマジックコマンドです。
使い方を見てみましょう
使い方
下の関数は実行すると2秒間待ってreturnするだけの関数です。
import time def func(): for i in range(2): time.sleep(1) return
これの平均的な実行時間を計測するには
%timeit func()
とします。 アウトプットは以下のようになります。
2 s ± 77.5 µs per loop (mean ± std. dev. of 7 runs, 1 loop each)
またセル内の全てのコードの実行時間を測る場合は以下のように%%timeitを使います。
%%timeit func() func()
こちらもアウトプットは同様の形式です。
4 s ± 51 µs per loop (mean ± std. dev. of 7 runs, 1 loop each)
%timeitの出力の意味
さて、ここからが本題です。
4 s ± 51 µs per loop (mean ± std. dev. of 7 runs, 1 loop each)
先程のこのアウトプットの出力は何を表しているのでしょうか。
7回実行したうちの実行時間の平均が4秒で標準偏差が51μsなのは分かりますが、1 loop eachとは何を意味しているのでしょうか。
%timeitの公式ドキュメントを見てみると以下のように書いてあるのを発見しました。
Options: -n<N>: execute the given statement <N> times in a loop. If <N> is not provided, <N> is determined so as to get sufficient accuracy.
-r<R>: number of repeats <R>, each consisting of <N> loops, and take the best result. Default: 7
なるほど、R回測定を行い、各測定の中ではN回プログラムを実行してその実行時間の合計を返してそこから統計量を計算しているようです。 試しにRとNの数字を変えて実行してみると確かに結果の表示も変わります。
%timeit -r 8 -n 2 func() 2 s ± 274 µs per loop (mean ± std. dev. of 8 runs, 2 loops each)
さて、%timeitが何をしているかはなんとなく分かりましたがなぜ「R回測定を行い、各測定の中ではN回プログラムを実行してその実行時間の合計を返す」というのは具体的にどういう処理をしているのでしょうか。それに「実行時間の合計を返す」というのが何を意味するのかよくわかりません。
Jupyterの公式ドキュメントだけを見てもよく分からなかったので%timeitのソースコードを見てみます。
どうやら1001行目の
timer = Timer(timer=timefunc)
で時間計測用のインスタンスを作成し、1151行目の
all_runs = timer.repeat(repeat, number)
で時間の計測を行っている様です。
そしてこのTImerクラスは140行目を見ると
class Timer(timeit.Timer):
の様にtimeit.pyのTimerクラスを継承して作成されていることが分かります。
つまり%timeitコマンドはtimeit.pyのTimer.repeat()を使用して実行時間を計測しているのです。
ではtimeit.Timer.repeat()とはどういうものなのでしょうか。
timeit.Timerの公式ドキュメント（日本語）を見てみましょう。
するとtimeit.Timer.repeat()はtimeit.Timer.timeit()をrepeatで指定したR回だけ実行するものだと書いてあります。
そしてtimeit.Timer.timeit()は指定した文をnumberで指定したN回だけ実行するのにかかる時間を測ると書いてあります。
なるほどつまり、
%timeit -r <R> -n <N> func()
は裏で
t = timeit.Timer(func) t.repeat(repeat=<R>, number=<N>)
を呼び出して、func()をN回実行するのにかかる時間をR回測定しているということです。
確かめてみましょう。
func()を1回と2回実行するのかかる時間を5回分測ってみると、
import timeit # func()を1回実行するのかかる時間を5回測定する t = timeit.Timer(func) t.repeat(repeat=5, number=1) [2.002275400009239, 2.002227912977105, 2.002274207014125, 2.002269165008329, 2.0022183680266608]
# func()を2回実行するのかかる時間を5回測定する t.repeat(repeat=5, number=2) [4.00444053998217, 4.004444975988008, 4.004590104013914, 4.004582158988342, 4.004545628995402]
確かに2回実行するのにかかる時間は1回の2倍になっていて、戻り値はrepeatで指定した長さ5のlistで返ってきています。
これで漸く%timeitが何を計算しているのかが解りました。
%timeitは実際にはこの返り値ををもとに平均と標準偏差を計算しています。
以下のコードは%timeitのソースの1151 - 1154行目です。これを見ると%timeitでは戻り値をall_runsという変数で受け取り、Nで割ることでN回の実行にかかる時間を1回あたりの実行時間に割り戻しています（上の例だとそれぞれ1と2で割ることになります）。そして出来上がった1回あたりの平均実行時間をR個格納した配列から平均と標準偏差をTimeitResultクラスで計算して表示しています。
all_runs = timer.repeat(repeat, number)
best = min(all_runs) / number
worst = max(all_runs) / number
timeit_result = TimeitResult(number, repeat, best, worst, all_runs, tc, precision)
スポンサーリンク
実行時間は最小値と平均のどちらを見るべきか
少し話は変わりますが%timeitコマンドではこれまで見てきたように実行時間の平均を出力しています。
しかし、一方でtimeit.Timer.repeat()の公式ドキュメントには次のようにも書かれています。
注釈 結果のベクトルから平均値や標準偏差を計算して出力させたいと思うかもしれませんが、それはあまり意味がありません。多くの場合、最も低い値がそのマシンが与えられたコード断片を実行する場合の下限値です。結果のうち高めの値は、Python のスピードが一定しないために生じたものではなく、その他の計測精度に影響を及ぼすプロセスによるものです。したがって、結果のうち min() だけが見るべき値となるでしょう。この点を押さえた上で、統計的な分析よりも常識的な判断で結果を見るようにしてください。
これを読むと%timeitは正しくない実行時間の測り方をしているように読めます。
実行時間の最小値と平均値のどちらを見るべきなのでしょうか。
調べてみるとstachoverflowを見ると正にそのままの質問がありました。
java - Should we measure the average or the minimum execution time of a function? - Stack Overflow
これを読むと、
常に実行時間の最小値を測るべきだ。 execution path(実行のされ方？）が複数ある場合は平均実行時間を見るしかないが、その場合はシステムのオーバーヘッドを含めた時間を計測していることに注意しろ。
という風に書いてあります。では何故%timeitは平均実行時間を計算しているのかが気になるところですが調べても理由は見つかりませんでした。しかし取り敢えず結論としては実行時間をきちんと図りたいのであれば、%timeitではなくtimeit.Timer.repeat()を使ってその最小値を取った方が良さそうであることは解りました。
余談ですが、最初に引用した%timeitの公式ドキュメントには、
-r<R>: number of repeats <R>, each consisting of <N> loops, and take the best result. Default: 7
と最小値を取るかのような文言が記載されています、何故・・・？
2019-04-07追記：
google colabのドキュメントを見るとcolabの%timeitは上記のドキュメントの様に最小実行時間を返すようです。
# 以下を実行すると、 # （N回プログラムを実行するのにかかる時間）/N、から1回あたりの平均実行時間を取得する # ということを6回繰り返し、その6回の内最も早かった実行時間を返す %timeit -n 2 -r 6 L = [n ** 2 for n in range(1000)]
ますますjupyterがなんで統計量を計算しているのかがわからない・・・。
スポンサーリンク
まとめ
ここまで%timeitが内部で何を計算しているのかを見てきました。
そして%timeitは内部でtimeit.Timer.repeat()を用い、計測したい文の%timeitが何故平均値を取っているのかはわかりませんでした。
