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 や mysql があり¹、どちらも内部で libmysqlclient を FFI で呼び出しています。
このうち mysql hackage については問題ありませんが、HDBC-mysql については注意する必要があります。

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 システムコールを使っています。これを使うと、指定した間隔²で SIGVTALRM シグナルがプロセスに投げ込まれるため、これを GHC RTS のシグナルハンドラが受けとることで定期的な処理のために利用できるという仕組みです。

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

試しに、次のような何もしない²プログラムを作り、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 では、withRTSSignalsBlocked という、一時的に SIGVTALRM をマスクする関数が提供されています。しかし、ライブラリのユーザが自分自身で MySQL にアクセスする部分を withRTSSignalsBlocked で保護してやる必要があり、やや面倒です。

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

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

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

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

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

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

1. 最近は、従来の 3306 ポートを使うプロトコルとは別の、X Protocol という新しいプロトコルを pure Haskell で喋るライブラリが作られているようです。 https://github.com/naoto-ogawa/h-xproto-mysql 期待。 ↩

2. SIGVTALRM のインターバルタイマはプロセス実行中のみ減少するため、threadDelay などを使って休んでいると減少しません。 ↩ ↩²