ふたたび Chromium OS [1] のバグの話。VPN (Virtual Private Network) に接続するとChromium [2] がクラッシュするというバグが見つかった。つい最近発生したリグレッションらしい。スタックトレースによると、クラッシュは D-Bus [3] 関係のコードの中で起きている。Chromium の中の D-Bus といえば、私が以前にコードを書いた部分だ。というわけで、バグが私のところに回ってきた。
D-Bus 関係のバグは厄介なものであることが多く、以前の「風が吹けば（たまに）桶屋が儲かる式のバグ」 [4] ではえらい苦労した。今回もいやな予感がしつつスタックトレースを眺めてみると、どうもコネクションの切断処理のあたりでクラッシュしているらしい。
コネクションの切断といえば以前から処理がいまいちだった部分で、別のエンジニアが最近その辺のコードをいじくっていたから、彼にふってしまおう。ラッキー！
それにしても不思議な問題である。D-Bus は Unixドメインソケットを使ってプロセス間通信をしているのだが、VPNによってUnixドメインソケットが影響を受けるとは考えにくい。VPN接続によってD-Busに支障が生じるというのは、またもや風が吹けば桶屋が儲かる的なバグである。
で、くだんのエンジニアが召還されてさっそく調査が始まった。クラッシュする直前あたりの様子を調べたところ、どうも "disconnect" というシグナルが D-Bus から飛んできているらしい。VPN接続によって、 D-Bus の接続が切断されるというのはどうもおかしい。
もしかしたら D-Bus デーモンがクラッシュしているのかも？と予想をしてみたが、これが間違っていることはすぐにわかった。VPN接続後も D-Busデーモンは問題なく動いている。じゃあなんで "disconnect" なんていうシグナルが飛んでくるのだろうか？
さらに調査が進んでわかったのは、VPNに接続された直後、 Chromium は D-Bus の Unixドメインソケットからデータを読み取ろうとするものの1バイトも読めずに終わる、ということだ。で、なぜか D-Bus は 0バイトの読み取りを切断の合図として解釈するという仕様なので、この結果、コネクションが切断されてしまう、と。
これもまたおかしな話で、Chromium は Unixドメインソケットを libevent [5] を使って読み取り・書き込み可能かをチェックしているので、読み取り可能というイベントが発生したときしか読み取りにいかないはずなのだ。VPN 接続によって、Unix ドメインソケットの読み取り可能状態が変わるというのはいかにもおかしい。
真の原因はよくわからないが、コネクションが切断される理由はわかった。そこで、くだんのエンジニア氏は ioctl システムコールを使って読み取り可能バイト数をチェックして 0バイトだったら何もしない、というアイディアを考案した。
これは一見名案に思えたが、実際に試してみると、クラッシュはしないものの、その後 D-Bus の通信に一切反応しなくなってしまい、解決にはいたらなかった。
次に試したのが、D-Bus を使った他のプログラムはどうなっているかを調べる、ということだ。他のプログラムも同様にクラッシュしたり、通信に反応しなくなっていたら、Chromium 特有の問題ではないということがわかる。やってみた結果、他のプログラムは何の支障もなく動いている。ううむ。
バグのレポートをよくみると、最近、 D-Bus パッケージのバージョンが更新された、ということが書いてある。最初からこれは疑わしいと思っていたのだが、依存関係などの問題により、パッケージのバージョンを戻すのは結構厄介な作業なので、調査を後回しにしていた。
その辺をいろいろがんばって、くだんのエンジニア氏が D-Bus のバージョンを元に戻してみると、クラッシュは消えた。D-Bus のバージョンをあげたことがこのリグレッションの原因なのだ。かといって、バージョンをあげたのにはそれなりに理由があってのことだし、戻すというのも難しい。それに Chromium 以外のプログラムは何の問題もなく動いているのだ。
しかし、 D-Bus のバージョンがあがるとなんで VPN に影響が出るんだ？VPN接続によってネットワーク構成が変わるとセキュリティ上の理由で既存の接続を一度、無効化するとか？などと私がやみくもに考えているうちに、くだんのエンジニア氏は、こうなったら D-Bus のバージョンをバイセクト（２分探索による問題の特定）しますよ！と言い始めた。
どのバージョンでクラッシュするようになったかわかれば、原因がわかるかもしれない。D-Bus のバージョンは 1.4.2 から 1.6.8 にあがっていた。途中のバージョンの数はそれほど多くないから、バイセクトはそれほど時間がかからないはず。
ということで、しばらく彼の結果を待っていると、すごいことがわかりましたよ！という知らせが入ってきた。というのもバイセクトの結果、1.4.2 でも再現することがわかったのだ。あれ？なんで？1.4.2 は大丈夫じゃなかったの？
エンジニア氏曰く、1.4.2 用の portage [6] のパッケージは複数のリビジョンがあり、微妙にビルドの設定が変更されているとのこと。で、とあるリビジョンで導入された --disable-check というビルドオプションがクラッシュの原因なのだそうな。
えー、なにそれ？configure スクリプトに渡すオプションが変わるとなんで VPN接続時に Chromium がクラッシュするの？そもそも --disable-check ってなんなの？
というわけで、このオプションを外して VPN 接続する様子を観察してみると、非常に単純な問題が発覚した (--disable-check がついていないときはエラーメッセージが出るのだ)。D-Busはリモートのオブジェクトのメソッド呼び出しをするのにオブジェクトパスというものを使うのだが、そのパスが空っぽだったのだ。
--disable-check がついていないときは、D-Busライブラリ内で、そのような不正なオブジェクトパスを排除するコードが働くのだが、--disable-check がついていると、その部分の安全装置が外れて先に進んでしまうため、おかしな状態に入ってしまうらしい。
ううう。じゃあこの空のオブジェクトパスはどこからやってくるのか？これはそんなに難しい問題ではな かった。VPN接続すると、ネットワークを管理しているサーバプロセスから、D-Bus 経由で通知がくるのだがその辺の処理が間違っていて、空のオブジェクトパスが渡ってきてしまうようだ。
というわけで、非常に不可解な問題の謎は解けた。真の問題は空のオブジェクトパスが空、というくだらないものだったが、たったそれだけのことで D-Bus が不可解な形で機能停止してしまったのは残念だ。空のオブジェクトパスでメソッド呼び出しをした瞬間にクラッシュしてくれればすぐに問題がわかったのだが。
そもそも --disable-check というオプションをビルドに追加したのは何のためなのか。これはおそらく、実行時のコードを減らしてスピードを上げるために追加されたのだろう。D-Bus のスピードは少しは速くなっているのかもしれないが、安全装置を停止したことによる代償の方が大きいように思える。
というわけで、--disable-check を復活させてクラッシュ問題はとりあえず解決した。オブジェクトパスが空の問題は別のエンジニアが直すことになった。
これにてひとまず一件落着！なのだけど、よく考えてみると、デバッグで大活躍したエンジニア氏が最後にいじっていた部分のコードと、今回の問題は一切関係がなかったのであった。たまたま関連したコードをいじっていただけで召還されて、大変なデバッグをするはめになったのは、ちょっと不幸かもしれない。よくあることだけども。
[1] Chrome OSの元となるオープンソースのOS http://www.chromium.org/chromium-os
[2] Chrome の元となるオープンソースのブラウザ http://www.chromium.org/chromium
[3] プロセス間通信のシステム。Chromium OSでも使われている。 http://www.freedesktop.org/wiki/Software/dbus
[4] 39.html
[5] epoll() などのシステムコールをラップしたライブラリ http://libevent.org/
[6] Gentoo Linux のパッケージシステム。Chromium OS でも使われている。 http://www.gentoo.org/proj/en/portage/