GHC 8.2 以前で FFI を使う際に注意すること

本日 LTS 10.0 がリリースされたので本格的に GHC 8.2 系が使えるようになりました。やったね！
https://www.stackage.org/lts-10.0

ということで、この記事の内容は若干陳腐化しています。

Haskell を生活に使っていると、データベースのような外の世界とやりとりする機会が多いと思います。外の世界と付きあうにあたり避けて通れないのが Foreign Function Interface (FFI) とシステムコールです。
しかし、Haskell で FFI をする際には注意すべき点があります。

## GHC threaded RTS と SIGVTALRM ##

(以前僕が遭遇して痛い目にあった) MySQL にアクセスする場合を例に取ります。
Haskell で MySQL を使う場合、メジャーなライブラリとして [HDBC-mysql][HDBC-mysql hackage] や [mysql][mysql hackage] があり[^1]、どちらも内部で `libmysqlclient` を FFI で呼び出しています。
このうち [mysql hackage][] については問題ありませんが、[HDBC-mysql][HDBC-mysql hackage] については注意する必要があります。

HDBC-mysql でちょっと時間が掛かるクエリを発行する際、運が悪いと次のようなエラーメッセージを吐いて死ぬことがあります。

~~~~
SqlError {
  seState = "", 
  seNativeError = 2003, 
  seErrorMsg = "Can't connect to MySQL server on 'localhost' (4)"
}
~~~~

一見、サーバーに接続できなかったようなエラーに見えますが、実は Haskell の threaded RTS の仕組みが原因です。

GHC 8.0 以前の threaded RTS では、スケジューラのコンテキストスイッチやプロファイリング、デッドロックの検出のために、POSIX 系 OS では `timer_create` システムコールを使っています。これを使うと、指定した間隔[^2]で `SIGVTALRM` シグナルがプロセスに投げ込まれるため、これを GHC RTS のシグナルハンドラが受けとることで定期的な処理のために利用できるという仕組みです。

<https://ghc.haskell.org/trac/ghc/wiki/Commentary/Rts/Signals>

試しに、次のような何もしない[^2]プログラムを作り、GHC 7.10 で `-threaded` 付きでコンパイルして実行し、threaded RTS の挙動を確認してみましょう。

~~~~ {.haskell}
-- example.hs

import Control.Monad

main :: IO ()
main = forever $ putStr ""
~~~~

~~~~ {.shell-session}
$ ghc --version
The Glorious Glasgow Haskell Compilation System, version 7.10.3
$ ghc -threaded -rtsopts example.hs
$ strace -tt -ff ./example +RTS -N 2>&1 | tee example.trace.log
~~~~

strace を使うと、システムコールやシグナルのトレースを取ることができます。`-f` を付けると子プロセスのトレースが、`-tt` オプションを付けるとマイクロ秒単位の時刻付きでトレースが取れるので、これらのオプションを併せて指定します。実行すると標準エラー出力に大量のトレースが出るので、適当なファイルに出力しておきます。`example.hs` は無限ループするので、実行してトレースが吐かれているのを確認したら適当に Ctrl+C 等で止めましょう。

`example.trace.log` を確認してみると、実際に `timer_create` を呼んでいる様子や、

~~~~
[pid  9226] 23:39:22.462483 timer_create(CLOCK_MONOTONIC, {sigev_signo=SIGVTALRM, sigev_notify=SIGEV_SIGNAL}, [0]) = 0
[pid  9226] 23:39:22.462515 rt_sigaction(SIGVTALRM, {sa_handler=0x474090, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc382cb50c0}, NULL, 8) = 0
[pid  9226] 23:39:22.462543 timer_settime(0, 0, {it_interval={tv_sec=0, tv_nsec=10000000}, it_value={tv_sec=0, tv_nsec=10000000}}, NULL) = 0
~~~~

`timer_settime` でインターバル `tv_nsec=10000000` と指定されている通り、おおよそ 0.01 秒おきに `SIGVTALRM` が飛んできている様子が観察できます。

~~~~
[pid  9236] 23:39:22.472593 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=0, ptr=NULL}} ---
[pid  9226] 23:39:22.558351 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=4, si_value={int=0, ptr=NULL}} ---
[pid  9226] 23:39:22.565919 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=0, ptr=NULL}} ---
[pid  9236] 23:39:22.566216 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=2, si_value={int=0, ptr=NULL}} ---
[pid  9240] 23:39:22.618234 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=4, si_value={int=0, ptr=NULL}} ---
[pid  9243] 23:39:22.622569 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=0, ptr=NULL}} ---
[pid  9243] 23:39:22.632596 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=0, ptr=NULL}} ---
[pid  9226] 23:39:22.652514 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=0, ptr=NULL}} ---
~~~~

この間隔は RTS の `-V` オプションで制御することができます。

~~~~ {.shell-session}
$ ./example +RTS -?

... (snip) ...

example:   -V<secs>  Master tick interval in seconds (0 == disable timer).
example:             This sets the resolution for -C and the heap profile timer -i,
example:             and is the frequence of time profile samples.
example:             Default: 0.01 sec.
~~~~

試しに `-V0` を付けると `timer_create` が呼ばれず、実際に `SIGVTALRM` が飛んできていない状況も観測できます。

~~~~ {.shell-session}
$ strace -tt -f ./example +RTS -N -V0 2>&1 | grep "SIGVTALRM"
(何も出ないはず)
~~~~

## FFI と SIGVTALRM ##

実際に threaded RTS が SIGVTALRM を使っている様子を見てきましたが、このシグナルが運悪く FFI でシステムコールを実行している最中に届いてしまうと、システムコールが `errno == EINTR` で中断されるため、呼び出しているライブラリの実装によっては問題が起こります。例に挙げた `libmysqlclient` では、システムコールが EINTR で中断された場合はエラーとして扱うため、ちょっとした SQL を実行するだけでもエラーになる可能性があります。

これを防ぐために、[HDBC-mysql][HDBC-mysql hackage] では、[withRTSSignalsBlocked](https://hackage.haskell.org/package/HDBC-mysql-0.7.1.0/docs/Database-HDBC-MySQL.html#v:withRTSSignalsBlocked) という、一時的に `SIGVTALRM` をマスクする関数が提供されています。しかし、ライブラリのユーザが自分自身で MySQL にアクセスする部分を withRTSSignalsBlocked で保護してやる必要があり、やや面倒です。

一方、[mysql][mysql hackage] では `libmysqlclient` の関数を呼びだす際に `SIGVTALRM` をマスクし、呼び終わったら解除するラッパー ([mysql_signals.c](https://github.com/paul-rouse/mysql/blob/bee7a794422c7bb18e40e0973035764bd3505743/cbits/mysql_signals.c)) を用意し、Haskell からは、そのラッパーを FFI で呼びだすように作られているため、ライブラリのユーザはそれと意識せずに使うことができます。

[mysql hackage]: https://hackage.haskell.org/package/mysql
[HDBC-mysql hackage]: https://hackage.haskell.org/package/HDBC-mysql

`libmysqlclient` を例に取りましたが、他のライブラリや、自分で書いた C のライブラリを呼びだす場合も例外ではありません。システムコールが `errno == EINTR` で失敗した場合の処理を適切に行なってエラーにならないようにするか、[mysql hackage][] に倣ってシグナルをマスクするなど、適切に実装する必要があります。

幸いなことに、`SIGVTALRM` を使う実装は GHC 8.0 系 (Mac OS X 系では 8.2 系) からは timerfd を利用する実装に切り替わっているため、上記のような対策は必要無くなっています。

- [#10840 (Periodic alarm signals can cause a retry loop to get stuck) – GHC](https://ghc.haskell.org/trac/ghc/ticket/10840)

なお Mac OS X 系は、GHC 8.0 系の時点では `SIGVTALRM` を使う実装のままだったので、残念ながら 8.2 系でないとダメなようです。

GHC マイナーバージョンを 3 つ維持するといったポリシーだと、GHC 7.10 系は切れないのでライブラリ開発者はまだまだ注意する必要はありますが、将来的にはこのあたりを気にしなくても良くなるかもしれません。

[^1]: 最近は、従来の 3306 ポートを使うプロトコルとは別の、X Protocol という新しいプロトコルを pure Haskell で喋るライブラリが作られているようです。 <https://github.com/naoto-ogawa/h-xproto-mysql> 期待。
[^2]: SIGVTALRM のインターバルタイマはプロセス実行中のみ減少するため、`threadDelay` などを使って休んでいると減少しません。

去年ごろ、僕以外にも FFI と `SIGVTALRM` で死ぬ問題でハマっている人を Twitter で観測したので、Advent Calendar のネタにしようと思っていたら、一瞬で埋まってしまい放置していたら、いつのまにか GHC が進化していました。よかったよかった。

まじめに Haskell で何か作って運用する際には、RTS が何しているのか、ある程度意識しておくと良いでしょう。