多相関数のprintfデバッグをGHCiで

Haskellでのデバッグといえばprintfデバッグなのではないかと思う。printfデバッグは大抵の場合うまくいくが、多相的な関数を書いているときは不便なことがある。表示したい値を文字列にする手段がない場合だ。

import Debug.Trace
import Data.List

mysort :: (Ord a) => [a] -> [a]
mysort [] = []
mysort (x:xs) =
  trace ("inserting " ++ show x) $ -- エラー! xはshowできない
  insert x $ mysort xs

main = print $ mysort [1,3,2,0] -- デバッグ用入力

実際のデバッグ入力であるIntegerはshowできるのだが、mysortの型からはそれが演繹できないのでshowを呼ぶことができない。ここでxを表示するためにはmysortの型を変えて(Show a)制約を追加せねばならない。このように小さな関数ならそれも我慢できるが、呼び出し元にも再帰的に制約が必要になって何十行も変更することになるのは辛い。

ここでやりたいことは、実行時にxの型を調べて、それが表示可能であれば表示することだ。GHCでは実行時の値に型情報が付かないので一見不可能だが、GHCiにはこれを可能にする魔術が実装されている。

GHCiデバッガ

最近のGHCiにはデバッガが搭載されていて、プログラムの任意の位置にブレークポイントを仕掛けることができる。ブレークポイントの付いた式が評価され始めるとそのタイミングで実行が中断され、ローカル変数の値などを調べることができる。詳しくはマニュアル(和訳)を参照。

静的には型の決まっていないローカル変数の値を調べる際、GHCiは実行時のヒープオブジェクトを調べて可能な限り型情報を復元しようとし、成功すればshowを使って表示することができる。この能力をprintfデバッグに転用しよう。

実装

以下のMyDebug.hsを用意する。

module MyDebug where

myTrace :: a -> b -> b
myTrace message _body = const _body message

myTraceM :: (Monad m) => a -> m ()
myTraceM toShow = myTrace toShow $ return ()

myTraceにブレークポイントを仕掛け、ローカル変数messageの値をGHCiで覗くというのが意図だ。

Debug.Trace.traceの代わりにMyDebug.myTraceを使うようにコードを書き換える。

import MyDebug
import Data.List

mysort :: (Ord a) => [a] -> [a]
mysort [] = []
mysort (x:xs) =
  myTrace ("inserting", x) $
  insert x $ mysort xs

main = print $ mysort [1,3,2,0] -- デバッグ用入力

ブレークポイントを設定したり、messageの値を調べた後に実行を再開するのが面倒なので、GHCiスクリプトを書いて自動化する。

:{
let
  ghci_debug_impl expr = return $ unlines
    [ ":break MyDebug 4 25" -- myTraceの定義本体にブレークポイントを設定
    , ":set stop :debug_stop_handler" -- ブレークポイントに到達するたびに自動でdebug_stop_handlerが呼ばれるように
    , expr -- 与えられた式を評価
    , ":unset stop" -- :set stopを消す
    , ":delete *" -- ブレークポイントを消す
    ]
  debug_stop_handler_impl _ = return $ unlines
    [ ":force message" -- 「message」という名前のローカル変数を表示
    , ":continue" -- 実行再開
    ];
:}
:def debug ghci_debug_impl
:def debug_stop_handler debug_stop_handler_impl

-- :force時、可能ならshow関数を使う
:set -fprint-evld-with-show

これで、「:debug <式>」と入力すれば<式>を評価しつつmyTraceが呼ばれるたびに第一引数の値が表示されるようになった。

% ghci sort.hs
GHCi, version 7.4.2: http://www.haskell.org/ghc/  :? for help
Loading package ghc-prim ... linking ... done.
Loading package integer-gmp ... linking ... done.
Loading package base ... linking ... done.
[1 of 2] Compiling MyDebug          ( MyDebug.hs, interpreted )
[2 of 2] Compiling Main             ( sort.hs, interpreted )
Ok, modules loaded: MyDebug, Main.
*Main> :debug main
Breakpoint 0 activated at MyDebug.hs:4:25-43
Stopped at MyDebug.hs:4:25-43
_body :: b = _
_result :: b = _
message :: (a, Integer) = (_,1)
message = ("inserting",1)
Stopped at MyDebug.hs:4:25-43
_body :: b = _
_result :: b = _
message :: (a, Integer) = (_,3)
message = ("inserting",3)
Stopped at MyDebug.hs:4:25-43
_body :: b = _
_result :: b = _
message :: (a, Integer) = (_,2)
message = ("inserting",2)
Stopped at MyDebug.hs:4:25-43
_body :: b = _
_result :: b = _
message :: (a, Integer) = (_,0)
message = ("inserting",0)
[0,1,2,3]
*Main>

ブレークポイントに到達するたびに邪魔な表示が出るのでフィルタする(強引に)。以下のスクリプトをdebugfilter.shという名前で保存しておく。

#!/bin/sh
grep -v '^\(_body :: .*_$\)\|\(_result :: .*_$\)\|\(message :: .*\)\|\(Stopped at MyDebug\.hs:4:25-43$\)\|\(Breakpoint 0 activated at MyDebug\.hs:4:25-43$\)'

「ghci 」の代わりに「ghci | ./debugfilter.sh」のように起動すれば綺麗な出力が得られる。

% ghci sort.hs | ./debugfilter.sh
GHCi, version 7.4.2: http://www.haskell.org/ghc/  :? for help
Loading package ghc-prim ... linking ... done.
Loading package integer-gmp ... linking ... done.
Loading package base ... linking ... done.
[1 of 2] Compiling MyDebug          ( MyDebug.hs, interpreted )
[2 of 2] Compiling Main             ( sort.hs, interpreted )
Ok, modules loaded: MyDebug, Main.
*Main> :debug main
message = ("inserting",1)
message = ("inserting",3)
message = ("inserting",2)
message = ("inserting",0)
[0,1,2,3]
*Main> 

まとめ

もうちょっと邪悪じゃない方法はないものか。