アセンブリ読んだら負けかなと思ってる

子供のころからできるだけ手抜きして成果を挙げることだけは長けている山本です。

今回は、C/C++ で作ったプログラムが運用中にクラッシュするときのデバッグ方法のお話しです。 開発中のデバッグgdb などでソース追いながらデバッグできますが、運用中ですと strip していたり最適化していたりしてデバッグが難しくなります。 そもそも、いきなりクラッシュすると情報が残らずに困ってしまいます。そんなときどうするか。

Step1. スタックトレースを出力する

こんな関数を用意しましょう。Linux 以外の人はそれなりに実装してください。

#include <execinfo.h>
#include <unistd.h>

void dump_stack() {
    void* bt[100];
    int n = backtrace(bt, 100);
    backtrace_symbols_fd(bt, n, STDERR_FILENO);
}

dump_stack()標準エラー出力に以下のようなスタックトレースを出力する関数です。

/usr/local/sbin/yrmcdsd[0x420564]
/usr/local/sbin/yrmcdsd[0x41b665]
/usr/local/sbin/yrmcdsd[0x41be9f]
/usr/local/sbin/yrmcdsd[0x41c0ee]
/usr/local/sbin/yrmcdsd[0x40bf23]
/usr/local/sbin/yrmcdsd[0x40c965]
/usr/local/sbin/yrmcdsd[0x404fa2]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xed)[0x7fe98bad376d]
/usr/local/sbin/yrmcdsd[0x4039c9]

読み方はあとで解説します。

Step2. 落ちる箇所に dump を仕込む

事前に落ちる箇所でスタックトレースを出力するようにしないと、情報がとれません。そこで落ちそうなポイントに dump_stack() を仕込んでいきます。

自分で例外を投げるところ

当然ですね。throw をマクロにしてソースコードのファイル名・行番号を出力するようにするのもいいかもしれません。

#define THROW(e) { \
    fprintf(stderr, "%s:%d %s\n", __FILE__, __LINE__, #e); \
    dump_stack(); \
    throw (e); }

void foo() {
    THROW( std::runtime_error("hoge") );
}

実行結果はこんな感じになります。

aaa.cpp:19 std::runtime_error("hoge")
./aaa[0x400f8f]
./aaa[0x400ff7]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xed)[0x7fd0bbce776d]
./aaa[0x400e89]

シグナル

メモリアクセス違反で飛んでくる SIGSEGV や、C++ で飛ばしがちな SIGABRT あたりをハンドルしてやりましょう。

2013/07/06 編集: SIGABRT を受けたらコアファイルを残せるように修正。

#include <signal.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>

const char ABORT_MESSAGE[] = "got a signal.\n";

void dump_and_abort(int) {
    write(STDERR_FILENO, ABORT_MESSAGE, sizeof(ABORT_MESSAGE) - 1);
    dump_stack();
    abort();                        // will generate a core file.
}

...
    struct sigaction act;
    memset(&act, 0, sizeof(act));
    act.sa_handler = dump_and_abort;
    act.sa_flags = SA_RESETHAND;    // one-shot handler.
    sigaction(SIGABRT, &act, NULL); // for SIGABRT
...

Step3. シンボルテーブルを作成する

strip は好きですか? 私は好きです。最適化しちゃうとソースコードとは対比とれなくなるので、デバッグ情報を残していても仕方ないと思うんです。C++STL を多用しているようなプログラムでしたら、strip 前は 11 MiB のバイナリが、strip 後は 700 KiB になるなんてざらです。やけに具体的な数字なのは突っ込まないでください。

とはいえ、strip はデバッグ情報だけでなく、シンボル情報も取り除いてしまいます。対策は二つあります。

デバッグ情報だけ取り除く

--strip-debug オプションを指定すれば、デバッグ情報だけ取り除いてくれます。シンボル情報は残るので、いつでも nm で参照できます。

$ strip --strip-debug EXE

あらかじめシンボルテーブルを作成しておく

シンボルテーブルとは、実行ファイルに含まれる関数のアドレスをソートして一覧できるようにしたものです。nm で以下のように作成します。

$ nm -n EXE > EXE.map

中身はこんな感じになります。

000000000040ab30 t _ZNSt17_Function_handlerIFvRN6cybozu7reactorEEZN6yrmcds6server12serve_masterEvEUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
000000000040b8c0 T _ZN6yrmcds6server16make_repl_socketEi
000000000040bc40 t _ZNSt17_Function_handlerIFSt10unique_ptrIN6cybozu10tcp_socketESt14default_deleteIS2_EEiRKNS1_10ip_addressEEZN6yrmcds6server5serveEvEUliS8_E1_E9_M_invokeERKSt9_Any_dataiS8_
000000000040bc60 T _ZN6yrmcds6server12serve_masterEv
000000000040c600 T _ZN6yrmcds6server5serveEv
000000000040ce30 W _ZN6cybozu8resource13on_invalidateEv
000000000040ce40 W _ZNSt16_Sp_counted_baseILN9__gnu_cxx12_Lock_policyE2EE10_M_destroyEv

C++ のシンボルは mangling されているので読めませんね。以下のようにすれば読みやすくなります。

$ c++filt < EXE.map | less
000000000040ab30 t std::_Function_handler<void (cybozu::reactor&), yrmcds::server::serve_master()::{lambda(cybozu::reactor&)#1}>::_M_invoke(std::_Any_data const&, cybozu::reactor&)
000000000040b8c0 T yrmcds::server::make_repl_socket(int)
000000000040bc40 t std::_Function_handler<std::unique_ptr<cybozu::tcp_socket, std::default_delete<cybozu::tcp_socket> > (int, cybozu::ip_address const&), yrmcds::server::serve()::{lambda(int, cybozu::ip_address const&)#3}>::_M_invoke(std::_Any_data const&, int, cybozu::ip_address const&)
000000000040bc60 T yrmcds::server::serve_master()
000000000040c600 T yrmcds::server::serve()
000000000040ce30 W cybozu::resource::on_invalidate()
000000000040ce40 W std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_destroy()

Step4. シンボルテーブルからスタックトレースで落ちている箇所を探す

先ほどのスタックトレースを再掲します。

/usr/local/sbin/yrmcdsd[0x420564]
/usr/local/sbin/yrmcdsd[0x41b665]
/usr/local/sbin/yrmcdsd[0x41bfdf]
/usr/local/sbin/yrmcdsd[0x41c0ee]
/usr/local/sbin/yrmcdsd[0x40bf23]
/usr/local/sbin/yrmcdsd[0x40c965]
/usr/local/sbin/yrmcdsd[0x404fa2]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xed)[0x7fe98bad376d]
/usr/local/sbin/yrmcdsd[0x4039c9]

[] 内に表示されているアドレス情報をシンボルテーブルで探します。ぴったり一致する番地はないので、その一つ前のシンボルを。 例えば 0x41bfdf の場合、シンボルテーブルに以下の情報があるとすると、cybozu::reactor::poll() で落ちているのが分かります。

000000000041be20 T cybozu::reactor::poll()
000000000041c1e0 T cybozu::reactor::run(std::function<void (cybozu::reactor&)>, int)

Final Step. 実行ファイルを disassemble して解析する

ここまで読んでくれる人は何人いるでしょうか。多分大半の人が脱落していると思いますが、一番書きたかったのはここだったりします。 さて、cybozu::reactor::poll() のどこかで落ちていることが分かったので、アセンブリを見てみましょう。大丈夫、怖くない

gdb を立ち上げて、シンボルテーブルから該当する関数を disassemble します。

$ gdb EXE
(gdb) disass 0x41be20, 0x41c1e0
Dump of assembler code from 0x41be20 to 0x41c1e0:
...
   0x000000000041be67:  sub    %rax,%rdx
   0x000000000041be6a:  add    %rdx,%rdx
   0x000000000041be6d:  callq  0x41ca40
   0x000000000041be72:  cmp    $0x43,%r12
...
   0x000000000041bf36:  callq  0x41c7d0
   0x000000000041bf3b:  mov    (%rax),%rdi
   0x000000000041bf3e:  mov    (%rdi),%rax
   0x000000000041bf41:  callq  *0x18(%rax)
   0x000000000041bf44:  test   %al,%al
...
   0x000000000041bf4f:  add    $0x4,%rbp
   0x000000000041bf53:  callq  0x41b5b0
   0x000000000041bf58:  cmp    %rbp,%r13
...
   0x000000000041bfd6:  add    $0x4,%rbp
   0x000000000041bfda:  callq  0x41b5b0
   0x000000000041bfdf:  cmp    %rbp,%r13
...

うにゃっと出てきます。ここで assembly を読もうと努力する真面目なあなた、働いたら負けですよ!

ここで注目するべきは callq です。抜粋してみます。

   0x000000000041be6d:  callq  0x41ca40
   0x000000000041be82:  callq  0x41c560
   0x000000000041bf36:  callq  0x41c7d0
   0x000000000041bf41:  callq  *0x18(%rax)
   0x000000000041bf53:  callq  0x41b5b0
   0x000000000041bfda:  callq  0x41b5b0

callq の引数はシンボルテーブルにあるはずなので、探してみます。

000000000041ca40 W void std::__introsort_loop<__gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >, long>(__gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >, __gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >, long)

000000000041c560 W void std::__insertion_sort<__gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > > >(__gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >, __gnu_cxx::__normal_iterator<int*, std:
:vector<int, std::allocator<int> > >)

000000000041c7d0 W std::__detail::_Map_base<int, std::pair<int const, std::unique_ptr<cybozu::resource, std::default_delete<cybozu::resource> > >, std::allocator<std::pair<int const, std::unique_ptr<cybozu::resource, std::default_delete<cybozu::resource> > > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true>, true>::operator[](int const&)

000000000041b5b0 T cybozu::reactor::remove_resource(int)

STL でうにゃっとソートした後に、cybozu::reactor::remove_resource(int) の2回目の呼び出しで落ちていそうということが分かりますね。 ほら、怖くない

以上です。C/C++ でまじめに運用するのってここら辺ができないと辛いですよね、ご同業のみなさん。