Gauche:プロファイラAPIの使用例

Shiro(2010/03/25 02:58:10 PDT): 既にあるプログラムに対して、後つけで「この手続きの間だけプロファイラをon/offできないか」という話。 http://practical-scheme.net/chaton/gauche/a/2010/03/25#entry-4bab1039-2c8af

特定の式の実行中だけプロファイリング

プロファイラはScheme側からon/offできるので、コードが書き換えられるならこんなことができる。

(define-macro (profiling expr)
  `(dynamic-wind
       profiler-start
       (lambda () ,expr)
       profiler-stop))

(profiling 式) とすれば式の実行中だけプロファイルがとれる。

例えば、適当に重い計算をでっちあげといて：

(define (fib n) (if (<= n 1) 1 (+ (fib (- n 1)) (fib (- n 2)))))

(define (heavy-calc) (fib 35))

(define (tarai x y z)
  (if (<= x y)
    y
    (tarai (tarai (- x 1) y z)
           (tarai (- y 1) z x)
           (tarai (- z 1) x y))))

(define (medium-calc) (tarai 18 9 6))

これが対象となる計算だとする。

(define (some-calc)
  (dotimes (n 3) (+ (heavy-calc) (medium-calc))))

medium-calcのとこだけプロファイリングしたいな、と思ったらこんなふうに書き換えて：

(define (some-calc)
  (dotimes (n 3) (+ (heavy-calc) (profiling (medium-calc)))))

実行。プロファイラはデータを蓄積してゆくので、profiler-resetでデータをクリアしてから対象コードを走らせて、profiler-showで結果を見る。

gosh> (profiler-reset)
#<undef>
gosh> (some-calc)
#t
gosh> (profiler-show)
Profiler statistics (total 155 samples, 1.55 seconds)
                                                    num    time/    total
Name                                                calls  call(ms) samples
---------------------------------------------------+------+-------+-----------
tarai                                              21275559  0.0001   155(100%)
medium-calc                                              3  0.0000     0(  0%)
profiler-stop                                            3  0.0000     0(  0%)

「そうかー、medium-calcが重いのはtaraiのせいだったのかー(棒読み)」

参考: http://practical-scheme.net/gauche/man/?l=jp&p=profiler-start

実行中のコードに動的にアタッチできないか

サーバプログラムなど、既に実行中のプログラムに対して後つけで「この手続きだけプロファイル取りたい」というのを仕込みたい場合。少々強引だが、こういう手がないわけではない。

(define (take-profile proc)
  (lambda args
    (dynamic-wind
        profiler-start
        (lambda () (apply proc args))
        profiler-stop)))

(define *hooked-procedures* '())

(define-macro (attach-profiler! name)
  `(unless (assq ,name *hooked-procedures*)
     (push! *hooked-procedures* (cons ',name ,name))
     (set! ,name (take-profile ,name))))

(define-macro (detach-profiler! name)
  (let1 p (gensym)
    `(and-let* ((,p (assq ',name *hooked-procedures*)))
       (set! ,name (cdr ,p))
       (set! *hooked-procedures* (delete! ,p *hooked-procedures*)))))

先ほどの例のコードで。

まずは定義を戻しておいて：

gosh> (define (some-calc)
        (dotimes (n 3) (+ (heavy-calc) (medium-calc))))
some-calc

普通に実行してもプロファイルは取れない。

gosh> (profiler-reset)
#<undef>
gosh> (some-calc)
#t
gosh> (profiler-show)
No profiling data has been gathered.
#<undef>

今度はheavy-calcにアタッチしてみよう。

gosh> (attach-profiler! heavy-calc)
#<closure (take-profile take-profile)>
gosh> (some-calc)
#t
gosh> (profiler-show)
Profiler statistics (total 669 samples, 6.69 seconds)
                                                    num    time/    total
Name                                                calls  call(ms) samples
---------------------------------------------------+------+-------+-----------
fib                                                89582109  0.0001   669(100%)
profiler-stop                                            3  0.0000     0(  0%)
heavy-calc                                               3  0.0000     0(  0%)
#<undef>
gosh> (detach-profiler! heavy-calc)
()

some-calcがサーバループで実行されてる場合でも、サーバにREPLの口を開けておけば、 attach-profiler!した後のheavy-calcの呼び出しからはプロファイルが取れる。

注意: 上のattach-profiler, detach-profilerは手続名への束縛をset!で置き換えているのだけれど、R6RSではモジュールからexportされている束縛にはset!できないことになっている。この仕様は最適化と相性が良くて、 Gaucheでも実はそうしようかという考えは何年も前からあって、そういうモードも既にコードには仕込んである。もし将来、そのモードをデフォルトにするなら、上のattach-profiler/detach-profiler は動かなくなる。おそらく、一般的なset!を使うのではなく、こういう特殊な用途向けにのみ置き換えを許すようなAPIを別に設けることになると思う。ここのコードを使う際は留意されたし。