TadaoYamaokaの日記

山岡忠夫Homeで公開しているプログラムの開発ネタを中心に書いていきます。

C++の再現性の低いバグを解析する

先日、dlshogiをfloodgateでテストした際に、goコマンドに対して結果を返さずタイムアップするという事象が発生した。

再現性が低く、全く同じ局面を手動でコンソールからコマンドを入力して何度も探索させても再現しなかった。
スレッドプールの処理に問題がありそうだと予想して、atomic変数のメモリオーダーを設定してみたが、また再現してしまった。

C++のマルチスレッドに関連したバグは、再現性が低いと解析が難しい。
とにかく発生状況をつかまないと原因が解析できないので、なんとかして再現した際に解析できる方法を見つける必要がある。

原因にあたりが付けられる場合は、条件を指定してdebugbreakを仕込んで再現するまで待つということを行うことがある。
今回はあたりが付かなかったので、再現時にcoreダンプを出力するという方法をとった。

再現時に自動でcoreダンプを取得する

usiToCsa.rbを使用してfloodgateに接続していたので、usiToCsa.rbを修正して、サーバからTIME_UPを受信したときに、

`ps | grep usi | awk '{ print "kill -6", $1 }' | sh`

を実行して、子プロセスのusiコマンド(解析対象)にABORTシグナルを送るようにした。

usiコマンドは、ダンプ解析できるように"-g"をオプションを付けてコンパイルしておく。

coreダンプの解析

数日実行してようやく再現して、coreダンプを取得することができた。

coreダンプの解析は、WindowsであればVisual Studioを使うが、今回はLinux上で実行したので、gdbを使って解析した。

gdb usi core

のように引数に実行ファイルとcoreを指定してgdbを起動し、

info threads

で実行中のスレッドを確認して、

thread 1
bt

のように、スレッド番号を指定してスレッドを切り替えてスタックバックトレースを確認するということを、すべてのスレッドについて行う。
これで、想定外の箇所で止まっているスレッドを見つけることができる。

今回の事象は、予想した通りスレッドプールの処理で停止していた。

  1. (探索スレッド)探索開始
  2. (親スレッド)探索終了待機(wait)
  3. (探索スレッド)探索終了
  4. (探索スレッド)探索終了通知(notify_all)
  5. (探索スレッド)スレッド待機(wait)

という流れでcondition_variableを使ってスレッドプールの処理を行っていたが、ゲーム木の状態によって探索が一瞬で終了して2.探索終了待機の前に、4.探索終了通知が行われていた。
そのため、notify_allを受け取れず、waitが解除されないままになっていた。

原因が分かれば修正は簡単で、waitの前に状態を調べてすでに探索が終了していればwaitしないという処理を入れればよかった。
(原因がわかればあらかじめ想定しておくべきことのようだが、コーディングしているときは気付かないものである。)

まとめ

マルチスレッド処理は、想定外の状態が起こりやすいのでバグを埋め込みやすい。
しかもバグの再現性が低く、解析が難しい。
そのような場合は、デバッグツールを使って発生時の状況を調べられると解析が進む。
この記事では、coreダンプを取得して調べる方法について紹介した。