はじめに
Haskell を実用していると、ネットワーク通信をしてり、FFI で外部ライブラリを呼び出すことが増えるかと思います。
そういったレイヤで出たバグを解析するために、コンパイル時に生成されるデバッグ情報を元にバグの原因を調査する必要があるかもしれません。
この記事では、主に Linux などで利用されている ELF 形式の実行バイナリに対応するデバッグ情報である DWARF を使って、Haskell でもスタックトレースを吐かせて遊んでみることにします。
Haskell での DWARF
GHC 8.2.1 のリリースノート を見ると、
More reliable DWARF debug information
という記述があるので DWARF を使って、Haskell のスタックトレースを出して遊んでみることにします。
GHC のランタイムシステムにスタックトレースを吐かせる方法としては次の 2 種類の方法があります。
- GHC.ExecutionStack モジュールを使って、プログラム内部からアクセスする方法
- 実行中のプロセスに SIGQUIT を送る方法
どちらの方法も、GHC 自体が libdw サポートを有効にした状態でコンパイルされている必要があります。
お使いの GHC が libdw をサポートしているかは ghc --info で確認することができます。
$ ghc --info | grep libdw
,("RTS expects libdw","NO")
# stack を使う場合
$ stack ghc -- --info | grep libdw
,("RTS expects libdw","NO")
普通に stack 等でインストールされた GHC では libdw サポートは有効になっていないと思われるので、libdw で遊びたい場合は自前で GHC をコンパイルする必要があります。
GHC のコンパイル手順
1. GHC ビルド用の環境を整える
まずはじめに GHC ビルド用の環境を整えます。
などを参考にしてください。GHC ソースコードを Git 取得したい場合は、ghc.haskell.org より githab.com のミラーの方が早いので、Building/GettingTheSources – GHC を参考にして GitHub を使うように設定すると良いです。
2. libdw 開発用ライブラリのインストール
libdw のヘッダファイルを取得します。Debian GNU/Linux では libdw-dev パッケージを、RedHat 系では elfutils-devel あたりをインストールします。
3. GHC のコンパイル
DWARF/Status – GHC を参考にして、GHC をコンパイルします。
まずは、ビルド設定ファイル mk/build.mk に下記の内容を追記します。
GhcLibHcOpts += -g3
GhcRtsHcOpts += -g3
このオプションを有効にすることで、RTS や base, bytestring など、GHC 組み込みのライブラリのコンパイルでも DWARF 情報の生成が有効になります。
次に、configure スクリプトを使って Makefile を作成します。この際、--enable-dwarf-unwind を configure スクリプトの引数に指定することで、GHC の libdw サポートが有効になります。
ソースコードを tarball ではなく Git などから取得した場合は boot コマンドも実行しておくようにしてください。
$ ./boot
$ ./configure --enable-dwarf-unwind
configure スクリプトが成功したら libdw が有効になっているか確認しておきましょう。
$ grep UseLibdw config.status
S["UseLibdw"]="YES"
ちゃんと有効になっていますね。
後は make するだけです。並列数 (-j) を環境に合わせて適宜指定してください。
それなりに時間が掛かるのでコーヒーなどを飲んで気長に待ちましょう。
$ make -j XXX
stage2 までやる設定になっていれば、出来上がった ghc バイナリはビルドしたディレクトリの inplace/bin/ghc-stage2 に配置されています。
ちゃんと libdw が有効になっているか確認してみます。
$ inplace/bin/ghc-stage2 --info | grep libdw
,("RTS expects libdw","YES")
DWARF で stack trace を吐いて遊んでみる
お試し
試しに、単純な入力待ちをするコードを書き、SIGQUIT を送ってスタックトレースを吐かせてみます。
sample.hs:
module Main where
main :: IO ()
main = getLine >>= putStrLn
-g3 を付けてコンパイルします。何回かコンパイルして確認したい場合は -fforce-recomp を付けて強制的に再コンパイルが走るようにすると良いと思います。
$ inplace/bin/ghc-stage2 -g3 -fforce-recomp ./sample.hs
[1 of 1] Compiling Main ( sample.hs, sample.o )
Linking sample ...
端末からフォアグラウンドのプロセスに SIGQUIT を送るには Ctrl-\ を押します。
$ ./sample
^\
Caught SIGQUIT; Backtrace:
0x48850f set_initial_registers (rts/Libdw.c:288.0)
0x7faecd3a88b8 dwfl_thread_getframes (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7faecd3a8347 (null) (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7faecd3a8673 dwfl_getthreads (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7faecd3a8c30 dwfl_getthread_frames (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x488af7 libdwGetBacktrace (rts/Libdw.c:259.0)
0x478f66 backtrace_handler (rts/posix/Signals.c:534.0)
0x7faecd7e70bf (null) (/lib/x86_64-linux-gnu/libpthread-2.24.so)
0x7faecd0b83a2 __select (../sysdeps/unix/syscall-template.S:84.0)
0x479c8b awaitEvent (rts/posix/Select.c:335.0)
0x46bff2 scheduleWaitThread (rts/Schedule.c:898.0)
0x471dfc hs_main (rts/RtsMain.c:73.0)
0x406f6e (null) (/home/taka/sample)
0x7faeccff72e1 __libc_start_main (../csu/libc-start.c:325.0)
0x406cca _start (/home/taka/sample)
ちゃんと select で止まっている様子が確認できました。
GHC.ExecutionStack を使ってみる
libdw サポートを有効にすると、SIGQUIT を送る以外にも、GHC.ExecutionStack モジュールにより、アプリ内部からスタックトレースにアクセスする方法が提供されるようになります。
sample2.hs:
import GHC.ExecutionStack
myFunction :: IO ()
myFunction = mapM_ putStrLn =<< showStackTrace
$ inplace/bin/ghc-stage2 -g3 -fforce-recomp ./sample2.hs
[1 of 1] Compiling Main ( sample2.hs, sample2.o )
Linking nya ...
$ ./sample2.hs
sample2: Failed to get stack frames of current process: no matching address range: Success
Stack trace:
set_initial_registers (rts/Libdw.c:288.0) in /home/taka/sample2
dwfl_thread_getframes in
in /usr/lib/x86_64-linux-gnu/libdw-0.168.so
dwfl_getthreads in /usr/lib/x86_64-linux-gnu/libdw-0.168.so
dwfl_getthread_frames in /usr/lib/x86_64-linux-gnu/libdw-0.168.so
libdwGetBacktrace (rts/Libdw.c:259.0) in /home/taka/sample2
base_GHCziExecutionStackziInternal_collectStackTrace1_info (libraries/base/GHC/ExecutionStack/Internal.hsc:74.10) in /home/taka/sample2
それっぽいスタックトレースが出ていますが、なにやら不穏なメッセージ (Failed to get stack frames of current process: no matching address range: Success) が出てしまいました。どうやら、きちんとスタックトレースが遡れていない様子です。
GHC 8.2.1 リリース後も、#14510 (GHC.ExecutionStack.showStackTrace broken) – GHC みたいな issue が上がっているようなので、まだまだ実験的な機能なのかもしれません。
実際のアプリで使ってみる
サンプルコードでの動作確認ができたので、実際のアプリで使ってみましょう。
最近は Haskell アプリの開発には Stack を使う場合が多いですが、Stack は最新のコンパイラや、独自ビルドのコンパイラを使う目的には使い辛いので、cabal new-build を使います。
Cabal new-build は Cabal User's Guide の Chapter 5. Nix-style Local Builds に詳細な説明があります。
既に cabal new-build の環境が整っているのであれば、new-build に、今回ビルドした GHC を使うようにオプションを指定してあげれば OK です。
cabal new-build \
-g3 \
--with-compiler=/path/to/ghc/inplace/bin/ghc-stage2 \
--package-db=/path/to/ghc/inplace/lib/package.conf.d \
all
出来上がったプログラムを実行しつつ、SIGQUIT を送ってみます。
$ dist-newstyle/build/x86_64-linux/ghc-8.6.3/cgrepos-0.6.4/x/cgrepos/build/cgrepos/cgrepos
Caught SIGQUIT; Backtrace:
0x343704f set_initial_registers (rts/Libdw.c:288.0)
0x7f52b453b8b8 dwfl_thread_getframes (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7f52b453b347 (null) (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7f52b453b673 dwfl_getthreads (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x7f52b453bc30 dwfl_getthread_frames (/usr/lib/x86_64-linux-gnu/libdw-0.168.so)
0x3437637 libdwGetBacktrace (rts/Libdw.c:259.0)
0x34279a6 backtrace_handler (rts/posix/Signals.c:535.0)
0x7f52b54260bf (null) (/lib/x86_64-linux-gnu/libpthread-2.24.so)
0x7f52b424967c poll (../sysdeps/unix/syscall-template.S:84.0)
0x7f52b564e16f (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b564e2bc (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b564e448 (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b564ee93 (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b564feed (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b5656262 (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b5656c58 (null) (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x7f52b5657167 mysql_real_query (/usr/lib/x86_64-linux-gnu/libmariadb.so.2)
0x23c373a _hs_mysql_real_query (/home/taka/work/cgrepos/dist-newstyle/build/x86_64-linux/ghc-8.6.3/cgrepos-0.6.4/x/cgrepos/build/cgrepos/cgrepos)
0x234e426 sUOn_info (/home/taka/work/cgrepos/dist-newstyle/build/x86_64-linux/ghc-8.6.3/cgrepos-0.6.4/x/cgrepos/build/cgrepos/cgrepos)
cgrepos: Failed to get stack frames of current process: アドレス範囲に対応しません: 成功です
あいかわらず不穏なメッセージが出ていますが、なにやら mysql で query している途中っぽいことが分かりました。
実際のアプリで何かしら詰まって反応が無くなった場合などに雑に SIGQUIT 送るだけで情報が出てくれるのは便利そうですね。
まとめ
まだまだ実験中の機能のような気がしますが、DWARF を元にスタックトレースを吐かせて遊んでみました。
まだ GHC を自分でビルドしないといけないので面倒ですが、デフォルトで有効になって (& 安定して) くれると、いろいろと捗ると思います。