messageデバッグを投げ捨てろ! debug-print.el -- .emacs Advent Calendar 2013 24日目

これは .emacs Advent Calendar 2013 24日目の記事です. 日本時間ではもう25日ですがイタリア出張で時間感覚が狂っていたのでセーフです. (すみません.)
printfデバッグを簡単に便利に使えるようにする debug-print.el を紹介します.

インストール

debug-print.el はGitHubに上げています. (https://github.com/kenoss/debug-print) ダウンロードしてパスを通すか, el-getを使っている場合は

(push '(:name debug-print
        :type git
        :url "https://github.com/kenoss/debug-print"
        :description "Gauche's reader macro for printf debugging")
      el-get-sources)

を評価してから M-x el-get-install RET debug-print でインストールできます.

紹介

皆さん Emacs Lisp を書くときにデバッグには何を使われているのでしょうか. backtrace? edebug? 個人的には, backtrace は本当に最低限でデバッグという用途には向かず, 一方 trace-function や edebug は高機能ですが, 例えば前者の場合traceするかどうかをいちいち切り替えする必要があり, 多少面倒だと思います.

これらの中間に位置する使いやすいデバッグ方法は, 誰でも知っているはずのprintfデバッグです. 例えば次のような階乗を計算する函数の呼び出しの挙動を見てみましょう:

(defun fact (n)
(if (zerop n)
    1
    (* n (fact n))))

(見るからに無限ループしそうです...) これを C-x C-e (eval-last-sexp) で定義して (fact 5) してみましょう. おおっと! 予想通り下の方に Lisp nesting exceeds `max-lisp-eval-depth' と出ましたね. こういうバグは backtrace では検知できません.

Emacs Lispでprintfデバッグをするにはmessage函数を使います. 函数 fact がどの様に呼び出されているのかを見てみましょう.

(defun fact (n)
  (message "fact is called with n=%s" n)
  (if (zerop n)
      1
      (* n (fact n))))
(fact 5)

このとき上を評価したときの *Messages* バッファは次のようになりました.

fact
fact is called with n=5
Entering debugger...
yas-extra-modes: Lisp nesting exceeds `max-lisp-eval-depth'
 [2 times]

んー, 「fact is called with n=5」が何回も出て無限ループであることがわかると思ったんですが...

しょうがないですね. debug-print.el を使ってみましょう.

;; debug-print.el を使えるようにする. (予め load-path に通しておく.)
(require 'debug-print)
(debug-print-init)
(define-key global-map (kbd "C-x C-e") 'debug-print-eval-last-sexp)

(defun fact (n)
  (if (zerop n)
      1
      (* n ::?= (fact ::?= n))))
(fact 5)

factの定義と (fact 5) を C-x C-e (debug-print-eval-last-sexp)) で評価すると *debug-print* バッファに次の様なメッセージが延々出てきます.

::?="fact"::(fact (debug-print n nil))    
::?="fact"::n                             
::?-    5                             
::?="fact"::(fact (debug-print n nil))    
::?="fact"::n                             
::?-    5                             
::?="fact"::(fact (debug-print n nil))    
::?="fact"::n                             
::?-    5                             
::?="fact"::(fact (debug-print n nil))    
::?="fact"::n                             
::?-    5                             

無限ループですね!! ちゃんとした函数に戻しておきましょう.

(defun fact (n)
  (if (zerop n)
      1
      (* n ::?= (fact ::?= (- n 1)))))
(fact 5)

このとき *debug-print* バッファは次の様になります.

::?="fact"::(fact (debug-print (- n 1) fact))
::?="fact"::(- n 1)                       
::?-    4                             
::?="fact"::(fact (debug-print (- n 1) fact))
::?="fact"::(- n 1)                       
::?-    3                             
::?="fact"::(fact (debug-print (- n 1) fact))
::?="fact"::(- n 1)                       
::?-    2                             
::?="fact"::(fact (debug-print (- n 1) fact))
::?="fact"::(- n 1)                       
::?-    1                             
::?="fact"::(fact (debug-print (- n 1) fact))
::?="fact"::(- n 1)                       
::?-    0                             
::?-    1                             
::?-    1                             
::?-    2                             
::?-    6                             
::?-    24                            

もう使ってしまいましたが, 拙著 debug-print.el (https://github.com/kenoss/debug-print) はprintfデバッグを簡単に便利に使えるようにします. お気付きの方も多いと思いますが, 仕組みはGaucheのリーダマクロ #?= を元にしています. (emacsでは #?= は使えないので debug-print.el では ::?= になっています.) debug-print.el を使えるようにするには, (load-path に debug-print.el を見えるようにした後で) .emcas に次の様に書きます.

(require 'debug-print)
(debug-print-init)
(define-key global-map (kbd "C-x C-e") 'debug-print-eval-last-sexp)

函数 debug-print-eval-last-sexp は eval-last-sexp と似ていますが, シンボル ::?= (変数 debug-print-symbol のデフォルト値)に続くS式をマクロ debug-print で包んでから評価します. 上記例では

(* n ::?= (fact ::?= (- n 1)))))

の行は

(* n (debug-print (fact (debug-print (- n 1) "fact")) "fact"))))

に変換されます. debug-printの2番目の(オプショナルな)引数は「そのS式はどの関数の中にあるか」を示します. 関数 debug-print は *debug-print* バッファに受け取ったS式とそれを評価した結果を表示します. (バッファ名は変数 debug-print-buffer-name で変更可能.) debug-print-eval-last-sexp は下請けの eval-with-bebug-print にS式を渡しますが, ただのS式変換器なので引数が ::?= を含まない場合の作用は普通に評価した場合と同じになります.

至極単純な機構ですが, Gaucheで使っている経験上, 普通のprintfデバッグよりも便利だと思います. 例えば次の

(hoge (something-with-side-effect a) b c)

hogeの第一引数がどうなっているのか調べたいとき, messageを使うには

(hoge (let ((tmp (something-with-side-effect a)))
        (message "%s" tmp)
        tmp)
      b c)

の様に let (+progn) を使わなければなりません. messageの書式を指定するのも, 確認が終わって元に戻すのも面倒です. その点 debug-print.el は調べたいものの前に ::?= を挟むだけなのでこれらの問題点は全て解消されます.

Merry Christmas & enjoy debugging Emacs Lisp!

明日はtakaxpさんです.