time.clock() と time.time() の違い

　Pythonのtimeモジュールにある関数clock()とtime()の違いで少しハマったのでメモ。（この「○○にハマったのでメモ」って、プログラマーのブログっぽくてやってみたかった）

　やりたいのは、「処理にかかった時間を計測して表示させる」こと。

for i in xrange(n):
    t0 = time.clock() #処理の開始時刻を記録する
    #
    # 計測したい処理
    #
    print time.clock() - t0 #処理時間を計算して表示する

　このコードでループごとにかかる時間を表示できるはずだったのに、正しい時間を表示できなかった。1時間くらい必要な処理なのに、表示される時間は 0.0024(s) になった。 初めは単位を勘違いしてるのかと思ったけど、time.clock()関数は現在のプロセッサ時間秒を浮動小数点数で表示してくれるから単位は秒であってる。

　ちなみに、time.clock() を time.time() にするとちゃんと表示される。time.time()関数は、エポックからの時刻を秒で返してくれる。つまり、Unixなら1970年1月1日の午前0時を0秒として、そこから現在までの時刻を秒で返す。

　結果から言うと、処理の内容が問題だった。処理中で os.system() を使ってシェルにコマンドを実行させてた。というか、処理にかかる時間のほとんどはこのコマンドの実行時間だ。これが原因で、時間が正しく表示されなかったらしい。

　time.clock()関数は、上述の通りプロセッサ時間を返してくれるけど、os.system() でコマンドを実行すると処理が外に移ってしまうからプロセッサ時間にカウントされない。つまり、time.clock() はpythonがCPUを使う時間を計測してるけど、os.system() で実行したコマンドはシェルがCPUを使っていて、pythonが使ってるわけじゃないから計測されないというわけだ。上のコードで言うと、time.clock() が計測してるのは os.system() で実行するコマンド以外の処理（t0の計算とかprintとか時間のかからない処理）にかかる時間だけだったから、表示される時間は 0.0024 という短い時間になった。

　それに対して、time.time()関数はエポックからの現時点までの時間を返すから、処理が他に移ったとしても正しく経過時間を計算できる。

　ドキュメントにもちゃんと time.clock() はプロセッサ時間を返すって書いてあるから当たり前だけど、処理が他に移ってるってのをすっかり見落としててしばらく気づかなかった。もっとリソースがどう使われてるか意識しないといけないなあ、ハードの勉強もしよう。