C++ のプログラムのデバッグを楽にする方法
Google が公開しているソフトウェアの解説シリーズ(→その1 , その2)の続きです。今回は google-glog を使ってスタックトレースを表示する方法についてご紹介します。
C++ でプログラムを書いているとよく遭遇するのがセグメンテーション違反というエラーです。不正なアドレスへのアクセスなどによりセグメンテーション違反が起きると、通常、 UNIX 系の OS では SIGSEGV というシグナルによってプログラムが終了するとともに、 core というファイルが作られます。
core ファイルにはデバッガから参照できるいろいろな情報が残っていますが、多くの場合に役に立つのは、スタックトレースという情報です。スタックトレースを見れば、プログラムがどこでクラッシュしたのか、どのような関数を経由してそこにたどり着いたのかがわかります。プログラムがクラッシュした箇所を特定できれば、単純なバグは容易に修正できます。
google-glog でスタックトレース表示
このように、 core ファイルは有用なのですが、いちいちデバッガを立ち上げるのは少々面倒です。そこで、 Google 社内では、プログラムがセグメンテーション違反などを起こしたときはスタックトレースを表示してから終了するように工夫しています。ちょうど、 Python や Java などのプログラムでエラー終了時にスタックトレースが表示されるのと同じ感じです。
このエラー終了時にスタックトレースを表示する機能は、オープンソースで公開している google-glog という C++ 用のログライブラリに含まれています。この機能は ELF というバイナリフォーマットを採用した Linux などの OS、または Mac OS X 10.5 以降で利用できます。
google::InstallFailureSignalHandler() という関数を呼ぶと、 SIGSEGV, SIGABRT といったシグナルに対して google-glog が提供するシグナルハンドラーがセットされます。プログラムがそれらのシグナルを受け取ると、次のようなスタックトレースを表示してから終了します。
*** Aborted at 1225095260 (unix time) try "date -d @1225095260" if you are using GNU date ***
*** SIGSEGV (@0x0) received by PID 17711 (TID 0x7f893090a6f0) from PID 0; stack trace: ***
PC: @ 0x412eb1 TestWaitingLogSink::send()
@ 0x7f892fb417d0 (unknown)
@ 0x412eb1 TestWaitingLogSink::send()
@ 0x7f89304f7f06 google::LogMessage::SendToLog()
@ 0x7f89304f35af google::LogMessage::Flush()
@ 0x7f89304f3739 google::LogMessage::~LogMessage()
@ 0x408cf4 TestLogSinkWaitTillSent()
@ 0x4115de main
@ 0x7f892f7ef1c4 (unknown)
@ 0x4046f9 (unknown)
このスタックトレースを見るといろいろなことがわかります：
- プログラムは TestWaitingLogSink::send() という関数の中の 0x412eb1 というアドレスでクラッシュしている (PC: の行を参照)。
関数が大きい場合、関数の中のどの行でクラッシュしているか知りたいときがあります。デバッガを使わなくても、バイナリにデバッグ情報が残っていれば、GNU Binary Utilities の addr2line というツールを使えばアドレス (この場合は 0x412eb1) からファイル名と行番号を取得できます。この方法は core ファイルを紛失しているときに役立ちます。 - この関数にいたるには main() → TestLogSinkWaitTillSent() → google::LogMessage::~LogMessage() → google::LogMessage::Flush() → google::LogMessage::SendToLog() → TestWaitingLogSink::send() という経路を辿っている。
- 0x0 というアドレス (おそらくは NULL ポインタ) をアクセスしたことによって SIGSEGV が発生している (SIGSEGV (@0x0) を参照)。
- エラーが発生したのは UNIX 時間で 1225095260、つまり Mon Oct 27 17:14:20 JST 2008 である。
- シグナルはプロセスID 17711 が受け取った。スレッドID は 0x7f893090a6f0 である。
- シグナルはプロセスID 0 から送られてきた (自分自身)。この情報は SIGTERM の場合など、他のプロセスからシグナルが送られてきているときに役立ちます。
これだけの情報がデバッガを立ち上げなくても得られるのはなかなか便利ではないかと思います。ただし、関数名はシンボル名が削られているバイナリでは表示されません。
スタックトレース表示の仕組み
上のようなスタックトレースを表示するために、 google-glog 内では次のような処理をシグナルハンドラの中で行っています。
- スタックトレースを取得する。
この処理はアーキテクチャごとに異なります。x86 の場合はフレームポインタをたどることによってスタックトレースを取得できます。フレームポインタなしでコンパイルされた x86_64 のプログラムの場合は複雑な処理が必要なため、 google-glog では libunwind というライブラリに任せています。 - アドレスを関数名に変換する。
ステップ 1 で取得したスタックトレースは生のアドレスのリストです。アドレスだけでは不便なので、アドレスを関数名に変換してやります。この処理はバイナリフォーマットに依存します。 google-glog では、 ELF というバイナリフォーマットの場合は自力でシンボルテーブルをスキャンして変換、 Mac OS X の場合はシステムライブラリが提供する dladdr() という関数を使って変換を行います。 - C++ の関数名を読みやすくする。
C++ の関数名はバイナリの中では Foo::Foo() → _ZN3FooC1Ev のように変換された形で記録されています (この変換はマングリングと呼ばれます)。_ZN3FooC1Ev は読みにくいので Foo::Foo() に変換してやります (この変換はデマングリングと呼ばれます)。名前を変換する方式にはいろいろありますが、 google-glog では GCC バージョン 3 から使われている Itanium C++ ABI にのみ対応しています。
シグナルハンドラ内で処理するという性質上、できるだけすべての処理を async signal safe (たとえば malloc は使わない) に行うようにがんばっています。将来的にはステップ 4 として「アドレスからファイル名と行番号を取得する」を追加したいと考えています。
まとめ
C++ のプログラムのデバッグを楽にする方法として、 google-glog のスタックトレース表示機能を紹介しました。C++ のプログラムのデバッグは難しいケースも多いのですが、簡単なケースのデバッグはスタックトレース表示によって効率化できるのではないかと思います。
