pilot python Fl.1 - profile runtime -

春が近づいて暖かくなってきたので銭湯巡りを再開した tmorimoto です。先日、越の湯 へ行ってきました。気さくなお母さんが番台に座っておられます。浴室に描かれた壁画が立派で印象に残りました。古き良き日本の1つですね。

以前から「python を勉強しようと思っているんです」、、、と周りに言い続けて、少しずつ夜カフェでお気に入りの工人舎 PC で勉強していました。勉強の履歴をブログにまとめていきます。

プログラミングに興味がある方、python そのものに興味がある方の初学者を対象として書きたいと思います。同コンセプトで書いている姉妹連載の awk walking も宜しくです。(複数の言語を比較してみると、さらに理解が深くなるし、また面白いですよ)

最初なのでインパクトのある良いものを書きたいと思っていましたが、そんな才覚はないので、諦めてデバッグから書きます。今、データ構造の基本について再勉強しています(また後日書きます)。python を使ってデータ構造の違いによるパフォーマンス(実行時間)を測定しようと考え、「初めての python (第2版)」の「27.7.3 時間の計測」でサンプルプログラムを見つけました。

以下がそのサンプルプログラムです。

$ cat makezeros.py
#!/bin/env python

def lots_of_appends():
    zeros = []
    for i in range(10000):
        zeros.append(0)

def one_multiply():
    zeros = [0] * 10000

$ cat profile_time_orig.py
#!/bin/env python

import time, makezeros

def do_timing(num_times, *funcs):
    totals = {}
    for func in funcs:
        totals[func] = 0.0
        starttime = time.clock()
        for x in range(num_times):
            for func in funcs:
                apply(func)
        stoptime = time.clock()
        elapsed = stoptime - starttime
        totals[func] = totals[func] + elapsed
    
    for func in funcs:
        print "Running %s %d times took %.3f seconds" %(func.__name__, num_times, totals[func])

do_timing(100, (makezeros.lots_of_appends, makezeros.one_multiply))

これをそのまま実行すると、以下のエラーが出ます。

$ python profile_time_orig.py
Traceback (most recent call last):
  File "profile_time_orig.py", line 19, in module
    do_timing(100, (makezeros.lots_of_appends, makezeros.one_multiply))
  File "profile_time_orig.py", line 12, in do_timing
    apply(func)
TypeError: 'tuple' object is not callable

do_timing() の仮引数の *funcs は、実引数をタプルとして受け取ります。オリジナルのサンプルでは、実引数に "(makezeros.lots_of_appends, makezeros.one_multiply)" をタプルとして渡していますが、これはタプルにしなくて良いと思います。
あと、もう1点、apply()関数で func を実行する際のループが不要です。*funcs として受け取ったタプルの各々の要素(計測したい関数)を num_times 回だけ実行して時間計測したいわけですから。

修正した内容は以下の通りです。

$ diff -uNr profile_time_orig.py profile_time.py
--- profile_time_orig.py        2008-03-27 10:00:19.000000000 +0900
+++ profile_time.py     2008-03-24 02:20:43.000000000 +0900
@@ -8,12 +8,11 @@
         totals[func] = 0.0
         starttime = time.clock()
         for x in range(num_times):
-            for func in funcs:
-                apply(func)
+            apply(func)
         stoptime = time.clock()
         elapsed = stoptime - starttime
         totals[func] = totals[func] + elapsed
     for func in funcs:
         print "Running %s %d times took %.3f seconds" %(func.__name__, num_times, totals[func])

-do_timing(100, (makezeros.lots_of_appends, makezeros.one_multiply))
+do_timing(100, makezeros.lots_of_appends, makezeros.one_multiply)

この修正を施した実行結果は以下の通りです。

profile_time.pyをダウンロード

$ python profile_time.py
Running lots_of_appends 100 times took 0.590 seconds
Running one_multiply 100 times took 0.010 seconds

学習の最初は、詳細はよく分からなくても、取り合えずサンプルコードを真似たり、実行したり、改造したりして雰囲気を掴むのが良いのでは？と、私は思います。「動く」と言うことがおもしろくて、モチベーションに繋がるからです。本連載でも、そうやって動かせて楽しみながら、徐々にレベルアップしていければと思います。

次回は、もう少し基礎的なことを書きたいと思います。