よーし今日もやるぞ！と最新のソースから Chromium OS 用の Chromium (Chrome OS 用の Chrome のオープンソース版) をビルドして手元の環境で実行したら、起動の途中で固まってしまった。いきなり不調だが、ツリーの先端だとだとこういうこともたまにはある。
とりあえず、困ったら人に聞いてみよう、といういつもの調子で他の開発者にメールを投げてみた。既知の問題だったら自分で調べる必要はないからだ。
返事を待つ間に、とりあえずデバッガ上で走らせてみることにした。起動の途中で止まったところで、おもむろにプログラムを停止してスタックトレースを表示させると興味深いものがでてきた。
NSSという暗号系のライブラリをロードする途中で dlopen() という関数が呼ばれて他のライブラリを動的に読み込んでいる真っ最中、そんなところのスタックトレースだったのだ。dlopen() の途中で止まってしまうなんて何かがおかしい。これは本気で調べなければ！
そんなあたりで、一人から反応があった。いわく、彼はデバッグビルドで走らせていて再現しないとのこと。一方、私はリリースビルドを走らせていたので、それが関係しているのかもしれない。というわけで、さっそくデバッグでビルドして走らせてみると、確かに再現しない！なぜだ？
この奇妙な現象を見てもらおうと同僚を呼ぶことにした。リリースビルドを実行する。固まる。デバッグビルドを実行する。固まる。え？さっきはデバッグビルドでは通っていたはずなのに？
何度か実行してみてわかったのはリリースビルドだろうとデバッグビルドだろうと固まるときは固まるのだ。しかも、やっているうちにどちらでも再現しなくなってしまった。
仕方がないので、しばらく他のことで時間を潰してからおもむろに実行してみると、ありがたいことに固まってくれた。ふたたびデバッガでスタックトレースをみると、前回と同じところで止まっている。なんでこんなところで止まるんだ？そもそもメインのスレッドでNSSのロードなんてやらないはずなんだけど。。
と思ってスタックトレースをよくみると、根っこは clone から始まっている。つまり、これはメインスレッドではない。じゃあメインスレッドは何をやっているかといえば、こんなところで止まっていた:
file_util::PathExists(FilePath const&)
これは、指定したパスがファイルシステムに存在するか調べるだけの関数だ。こんなところで止まるはずはないのだが、と思いつつもパス名を表示させてみた：
/home/chronos/.oobe_completed
ああ、わかった！これが原因に違いない！というのも私の開発環境では /home 以下はNFSでオートマウントする設定になっていて、このパスが指定されると /home/chronos をオートマウントしようするのだ。で、NFSからの反応がなくて固まってしまうのだろう。試しに ls を実行してみると、この仮説が検証できた：
% time ls /home/chronos/.oobe_completed
ls: cannot access /home/chronos/.oobe_completed: No such file or directory
108.11s total : 0.00s user 0.00s system 0% cpu
エラーが返るまでに 108秒もかかっている。 ls を何度か実行していると、すぐに反応するようになった。どうも不安定だ。昨日までこの問題が発生しなかったのは NFS が問題なく動いていたからだろう。
実際のデバイスでは当然 /home/chronos は NFS ではないので、このコードは問題なく通る。結局、この問題は実行環境をチェックして挙動を少し変えるだけで簡単に解決した。
わかってしまえばくだらない問題であった。挙動だけをみるとおそろしげなバグに見えたのだけど。