Python の profile で実行時間をプロファイルしてみると、関数呼び出し回数や積算実行時間などはそれなりに役に立つのだが、1呼び出し当たりの時間を示す percall がほとんどの関数で 0.000 秒という表示になってしまう。
結局、回数で合計された時間を割って1呼び出し当たりの値を求める概算を暗算ですることになる。
なんという無駄。
そんなわけで percall の表示をミリ秒にしてみよう、という試みをする。
断っておくが表示をミリ秒にするフラグを profile.run その他もろもろに追加するというような正攻法ではない。
とりあえず出ればいいやという場当たり的なもの。
まず、次のスクリプトを preprofile.py として保存しておく。
from pstats import f8, func_std_string
from types import MethodType
def new_print_line(self, func):
cc, nc, tt, ct, callers = self.stats[func]
c = str(nc)
if nc != cc:
c = c + '/' + str(cc)
print >> self.stream, c.rjust(9),
print >> self.stream, f8(tt),
if nc == 0:
print >> self.stream, ' '*8,
else:
print >> self.stream, f8(float(tt)*1000/nc),
print >> self.stream, f8(ct),
if cc == 0:
print >> self.stream, ' '*8,
else:
print >> self.stream, f8(float(ct)*1000/cc),
print >> self.stream, func_std_string(func)
import pstats
pstats.Stats.print_line = MethodType(new_print_line, None, pstats.Stats)
これを profile を利用する予定の python インタプリタを起動するときに -i preprofile.py を指定して読み込ませておく。
その上で profile.run などを実行すると、出力の percall の欄が 1000 倍されて(単位が秒からミリ秒に1/1000になって)表示される。
という具合。
preprofile.py の中身を解説しておくと、表示に使われている pstats.Stats.print_line メソッドを抜き出して percall 欄の値を 1000 倍にしただけの new_print_line という関数を定義し、types .MethodType を利用してこの関数をメソッド化して、それで pstats.Stats.print_line を書き換える、ということをしている。
MethodType の使い方は Pythonでメソッドをクラスまたはインスタンスに動的に追加する というブログを参考にした。
|