defadviceを使ってrequireにかかる時間を計測する

起動時間を計測する - すぎゃーんメモにてid:hirose31さんからコメントで

http://www.bookshelf.jp/pukiwiki/pukiwiki.php?Meadow%2F%B5%AF%C6%B0%C2%AE%C5%D9
の下の方の defadvice require で個別に時間測るのとか捗りそうですね！！

と教えていただきました。確かに、defadviceを使うと毎回のrequireに対してかかった時間を計測できるはず。
ということで書いてみた。

(defadvice require (around require-benchmark activate)
  (let* ((before (current-time))
         (result ad-do-it)
         (after  (current-time))
         (time (+ (* (- (nth 1 after) (nth 1 before)) 1000)
                  (/ (- (nth 2 after) (nth 2 before)) 1000))))
    (when (> time 50)
      (message "%s: %d msec" (ad-get-arg 0) time))))

~/.emacs.elの先頭にこんなのを書いておくと、その先のrequireで50ms以上かかった場合にmessage出力してくれる(全部出力しているとスゴい数になってしまったので適当な閾値で絞った)。自分の今の環境で起動してみると、以下のような結果が。

recentf-ext: 90 msec
tramp: 212 msec
url: 59 msec
anything-config: 489 msec
auto-install: 78 msec

やっぱりtrampとそれを含むanything-configが重いなー。

ちなみに設定ファイル分割してinit-loaderで読み込んでいる場合はload関数で読み込んでいるので、loadに対してadviceかけてやらないとそれぞれのload時間は計測できない。
(※追記: init-loaderは中でbenchmarkしてくれているので、M-x init-loader-show-logでそれぞれのloadにかかった時間を参照することができます。)