(cache)Haskell でのデバッグ手法あれこれ

プログラムにバグはつきものです。強力な型システムを備えている Haskell でもそれは同じです。この記事では、 Haskell プログラムのデバッグ手法をいくつか挙げてみます。

なお、使用している GHC は 8.2.2 です。より新しいバージョンで追加されるであろうより便利な機能は、この記事の対象外です。

目次 [hide]

1 心構え：処理を分割せよ
2 Haskell 版 printf デバッグ：Debug.Trace
3 対話的デバッグ： GHCi Debugger
4 バックトレースの取得：プロファイリング情報
5 バックトレースの取得：HasCallStack 制約
6 実践

心構え：処理を分割せよ

Haskell は純粋な言語です。IOが絡まない関数であれば、同じ引数に対しては同じ結果が返ってくることが期待されます。

よって、処理を細かく（純粋な）関数に分割し、それぞれ GHCi で動作を確かめていけば、どこにバグが潜んでいるのか絞り込むことができます。

この際、関数の実行結果の型は Show クラスのインスタンスにしておくと便利です。

-- 良くないコード：
main = do
  x <- ...
  ...でかい処理...
  print result

-- 良いコード：
foo :: X -> Y
foo x = ...ひとまとまり処理...

bar :: Y -> Z
bar y = ...ひとまとまりの処理...

main = do
  x <- ...
  let result = bar (foo x)
  print result
-- 機能を分割したことにより、 foo や bar を GHCi で個別にテストできる！

Haskell 版 printf デバッグ：Debug.Trace

C言語を始めとする手続き型プログラミング言語では、デバッグしたい箇所に printf などの命令を挟むことにより、「そのコードパスが実行されること」「その時点での各種変数の値」を確認することがあります。このような手法は俗に「printf デバッグ」と呼ばれます。

一方 Haskell では、純粋な関数においては基本的に、ログ出力のような副作用のある処理を実行できません。

しかしそれでは不便なので、 Debug.Trace というモジュールに「純粋な関数でログ出力できる関数」が（抜け道的に）用意されています：

-- Debug.Trace
trace :: String -> a -> a
traceShow :: Show a => a -> b -> b

他にもいくつかログ出力の関数が用意されています。ドキュメントを読むなり、 “Haskell Debug.Trace” でググるなりしてください。

Debug.Trace のドキュメント (Hackage)

（Debug.Trace はもちろん内部的には unsafePerformIO を使っていますが、 unsafePerformIO を直で使うよりも便利で安全だと思います。）

もちろん、 Haskell はデフォルトで遅延評価の言語ですし、 GHC は処理が純粋だと仮定して最適化するので、ログ出力の順番や回数は期待したものとは異なるかもしれません。

例えば、下記のコードを筆者の環境の GHC 8.2.2 で試したところ、 stack runghc で実行した場合は

foo
bar
1512

が、 stack ghc -- -O3 でコンパイルした場合は

bar
foo
1512

が出力されました（i.e. 最適化によって出力の順番が違う）。

import Debug.Trace
main = do
  let x = trace "foo" 42
  let y = trace "bar" 36
  print (x * y)

対話的デバッグ： GHCi Debugger

GHCi にはデバッガーとしての機能が備わっています。

例えば、 :break 〈関数名〉 でその関数にブレークポイントを設置できます。 :step でステップ実行ができます。詳しくはドキュメントを見てください。

欠点として、 GHCi のバイトコードインタープリターで実行できないコードに対しては適用できません。例えば、 unboxed tuples や unboxed sums を使っているとバイトコードコンパイルに失敗するようです。

参照：

バックトレースの取得：プロファイリング情報

コードの深いところでエラーが出ても、そのコード片がどこから呼ばれたのかわからないと困ります。いわゆるバックトレースが欲しくなります。

GHC では、プロファイリング情報を利用したバックトレースを取得できます。

プロファイリングを有効にして、バックトレースを取得するにはコンパイル時に -prof -fprof-auto オプションをつけます。

例：

-- Test.hs
foo :: Int -> Int
foo n | n < 0 = error "negative!"
      | otherwise = n^2

bar :: Int -> Int
bar n = foo (n^2 - 3 * n)

main = print (bar 2)

stack ghc -- -prof -fprof-auto Test.hs でコンパイルし、 ./Test で実行します：

$ stack ghc -- -prof -fprof-auto Test.hs
$ ./Test
Test: negative!
CallStack (from HasCallStack):
  error, called at Test.hs:2:17 in main:Main
CallStack (from -prof):
  Main.foo (Test.hs:(2,1)-(3,23))
  Main.bar (Test.hs:6:1-25)
  Main.main (Test.hs:8:1-20)
  Main.CAF (<entire-module>)

出力のうち、 CallStack (from -prof) がプロファイリング情報によるバックトレースです。

参照：

バックトレースの取得：HasCallStack 制約

GHC 8 では HasCallStack 制約という機能が追加されました。これは関数の型に制約として書くことができ、その関数内で使う error 呼び出しに関数の呼び出し元の情報を含めることができます。

「プロファイリング情報によるバックトレース」に比べた利点は、

特別なコンパイルオプションが要らない
GHCi でも利用できる

あたりでしょうか。手軽なんです。

例を見てみましょう：

import GHC.Stack (HasCallStack)

foo :: HasCallStack => Int -> Int
foo n | n < 0 = error "negative!" -- error 関数に foo の呼び出し元の情報が渡される
      | otherwise = n^2

bar :: Int -> Int
bar n = foo (n^2 - 3 * n) -- bar の情報が foo に渡される

main = print (bar 2) -- main の情報は foo には渡らない

実行結果：

Test.hs: negative!
CallStack (from HasCallStack):
  error, called at Test.hs:4:17 in main:Main
  foo, called at Test.hs:8:9 in main:Main

foo 関数に HasCallStack 制約をつけない場合は、 error が foo 関数（Test.hs の4行目）で発生したことしかわかりませんが、 foo 関数に HasCallStack 制約をつけた場合は、エラーメッセージに foo の呼び出し元の情報（Test.hs の 8 行目；つまり bar 関数）も含まれるようになります。

制限として、 HasCallStack 制約を持たない関数があるとそこでバックトレースが途切れます。例では、関数 bar は HasCallStack 制約を持たないので、「foo の呼び出し元が bar である」ことはわかっても、「bar の呼び出し元が誰なのか」はわかりません。

（Haskell に詳しい人は関数の型クラス制約は詰まるところ暗黙の引数なんだということはご存知でしょう。 HasCallStack 制約も暗黙の引数の一種であって、型レベルのナニカ、あるいはオブジェクトコードのデバッグ情報的なナニカではなく、単に呼び出し元の情報をデータとして渡しているだけのようです。そう考えれば、 HasCallStack 制約が途切れるとバックトレースが途切れるという動作にも納得がいくでしょう。）

なお、トップレベル関数の型注釈を省略した場合、通常の型クラス制約は型推論で補われますが、 HasCallStack 制約は補われません。HasCallStack 制約を書きましょう。

参照：

実践

一般論はここまでです。ここからは、筆者が今日行ったデバッグの話をします。興味がなかったら読み飛ばしていただいて結構です。

今日のデバッグ対象は、 arithmoi パッケージの Math.NumberTheory.Primes.sieveFrom 関数です。

この関数は sieveFrom :: Integer -> [Integer] という型を持ち、与えられた引数以上の素数をリストで返します。例えば、

> take 10 $ sieveFrom 100
[101,103,107,109,113,127,131,137,139,149]

という具合です。

ただし、あまりに大きい整数を与えると Out of memory が出ます：

> take 10 $ sieveFrom (10^48)
<interactive>: Out of memory

まあ、 Out of memory が出るのは仕様です。ドキュメントにもそういうことが書かれています。

しかし…

> take 10 $ sieveFrom 5801977483380505537128388351953140502138565165057
*** Exception: integerSquareRoot: negative argument

期待される動作は Out of memory ですが、これは…？

integerSquareRoot :: Integral a => a -> a は同じ arithmoi の Math.NumberTheory.Powers.Squares モジュールで定義されている関数で、ソースを見ればわかりますが、負の整数を与えるとエラーを吐きます。

可能性としては、 sieveFrom で実行されるコード中に Int を使っている箇所があって、そこでオーバーフローを起こしていることが考えられます。突き止めてみましょう。

準備

arithmoi のソースを手元に持ってきて、 stack repl で実行できるようにします。

$ git clone https://github.com/cartazio/arithmoi.git
$ cd arithmoi
$ stack init
$ stack repl

行動1. integerSquareRoot にブレークポイントを仕掛ける

GHCi のデバッグ機能を使って、 integerSquareRoot にブレークポイントを設定しましょう。…と言いたいところですが、 arithmoi パッケージには unboxed tuple を使っている箇所があるため、 GHCi で読み込めません！

[17 of 55] Compiling Math.NumberTheory.Utils ( **/arithmoi/Math/NumberTheory/Utils.hs, interpreted )
Error: bytecode compiler can't handle unboxed tuples and sums.
  Possibly due to foreign import/export decls in source.
  Workaround: use -fobject-code, or compile this module to .o separately.

Workaround に示されているように -fobject-code オプションを使うと REPL は起動しますが、肝心のデバッグができません。

当該モジュールを別途コンパイルすると回避できるとか言ってますが、面倒くさそうです。unboxed tuple を使わないようにコードを書き換えるという手も考えましたが、やはり面倒くさそうです。

よって、 GHCi のデバッグ機能は諦めます。

以降、 REPL は stack repl --ghc-options -fobject-code で起動します。

sieveFrom という名前の関数は複数のモジュールで定義されているため、 GHCi の :m Math.NumberTheory.Primes コマンドにより曖昧さをなくします。

$ stack repl --ghc-options -fobject-code
.......
.......> :m Math.NumberTheory.Primes
Prelude Math.NumberTheory.Primes> take 10 $ sieveFrom 5801977483380505537128388351953140502138565165057
*** Exception: integerSquareRoot: negative argument
CallStack (from HasCallStack):
　 error, called at **/arithmoi/Math/NumberTheory/Powers/Squares.hs:50:19 in main:Math.NumberTheory.Powers.Squares

行動2. integerSquareRoot に HasCallStack を仕掛ける

なんとかして integerSquareRoot の呼び出し元を調べたいものです。

GHCi で試す都合上、プロファイリング情報によるバックトレースは使えません。仕方がないので、 HasCallStack 制約によるバックトレースを使います。

integerSquareRoot は Math/NumberTheory/Powers/Squares.hs に

integerSquareRoot :: Integral a => a -> a
integerSquareRoot n
  | n < 0 = error "integerSquareRoot: negative argument"
  | otherwise = integerSquareRoot' n

として定義されています。このファイルの先頭の方に import GHC.Stack (HasCallStack) を追加し、 integerSquareRoot の型を integerSquareRoot :: (HasCallStack, Integral a) => a -> a に変えます。

変更を保存したら、 GHCi で :r を叩き、再読み込みします。もう一度同じコード片を実行すると

Prelude Math.NumberTheory.Primes> :r
...
Prelude Math.NumberTheory.Primes Math.NumberTheory.Zeta> take 10 $ sieveFrom 5801977483380505537128388351953140502138565165057
*** Exception: integerSquareRoot: negative argument
CallStack (from HasCallStack):
  error, called at **/arithmoi/Math/NumberTheory/Powers/Squares.hs:50:19 in main:Math.NumberTheory.Powers.Squares
  integerSquareRoot, called at **/arithmoi/Math/NumberTheory/Primes/Sieve/Eratosthenes.hs:222:14 in main:Math.NumberTheory.Primes.Sieve.Eratosthenes

と、バックトレースが増えました。問題となる integerSquareRoot の呼び出し元は Math/NumberTheory/Primes/Sieve/Eratosthenes.hs の222行目のようです。当該部分を見ると

sieveTo :: Integer -> ST s (STUArray s Int Bool)
sieveTo bound = arr
  where
    (bytes,lidx) = idxPr bound
    !mxidx = 8*bytes+lidx
    mxval :: Integer
    mxval = 30*fromIntegral bytes + fromIntegral (rho lidx)
    !mxsve = integerSquareRoot mxval ----------------- ← 222行目！
    (kr,r) = idxPr mxsve
    !svbd = 8*kr+r

となっているので、 mxval が負になっていると予想できます。

行動3. Debug.Trace

mxval の定義から、 bytes :: Int または rho lidx :: Int がオーバーフローして負になっていると考えられます。関数の引数である bound もチェックしておきたいところです。

先に説明したように、今回 GHCi のデバッグ機能は使えないので、 Debug.Trace を利用します。

Erathosthenes.hs の先頭の方に import Debug.Trace を追加し、mxsve の定義に traceShow を仕込みます：

   !mxsve = traceShow (bound, bytes, rho lidx) $ integerSquareRoot mxval

複数の変数を show するのが面倒なので、タプルにして traceShow を使っています。

再度 GHCi で :r を叩き、問題のコードを実行します：

Prelude Math.NumberTheory.Primes Math.NumberTheory.Zeta> :r
[29 of 55] Compiling Math.NumberTheory.Primes.Sieve.Eratosthenes ( **/arithmoi/Math/NumberTheory/Primes/Sieve/Eratosthenes.hs, **/arithmoi/.stack-work/odir/Math/NumberTheory/Primes/Sieve/Eratosthenes.o )
Ok, 55 modules loaded.
Prelude Math.NumberTheory.Primes Math.NumberTheory.Zeta> take 10 $ sieveFrom 5801977483380505537128388351953140502138565165057
(2408729433411005906443201,-7695839157481303009,31)
*** Exception: integerSquareRoot: negative argument
CallStack (from HasCallStack):
  error, called at **/arithmoi/Math/NumberTheory/Powers/Squares.hs:50:19 in main:Math.NumberTheory.Powers.Squares
  integerSquareRoot, called at **/arithmoi/Math/NumberTheory/Primes/Sieve/Eratosthenes.hs:222:51 in main:Math.NumberTheory.Primes.Sieve.Eratosthenes

traceShow の結果は (2408729433411005906443201,-7695839157481303009,31) で、要するに bytes がオーバーフローにより負になっていることがわかりました。

あとは bytes 変数の由来である idxPtr 関数を調べるなりできそうです。しかし配列のインデックスに Int を使う以上、この手のオーバーフローは避けられなさそうです。どうするのがいいのか（もっとわかりやすいエラーを出すべき？）筆者にはわかりません。

ともあれ、 Haskell におけるデバッグの良い演習にはなったと思います。

雑記帳

人生がつらい

Haskell でのデバッグ手法あれこれ

心構え：処理を分割せよ

Haskell 版 printf デバッグ：Debug.Trace

対話的デバッグ： GHCi Debugger

バックトレースの取得：プロファイリング情報

バックトレースの取得：HasCallStack 制約

実践

準備

行動1. integerSquareRoot にブレークポイントを仕掛ける

行動2. integerSquareRoot に HasCallStack を仕掛ける

行動3. Debug.Trace

コメントを残すコメントをキャンセル

心構え：処理を分割せよ

Haskell 版 printf デバッグ：Debug.Trace

対話的デバッグ： GHCi Debugger

バックトレースの取得：プロファイリング情報

バックトレースの取得：HasCallStack 制約

実践

準備

行動1. integerSquareRoot にブレークポイントを仕掛ける

行動2. integerSquareRoot に HasCallStack を仕掛ける

行動3. Debug.Trace

コメントを残す コメントをキャンセル

コメントを残すコメントをキャンセル