アプリケーションにトラブルが発生した場合の解析手段をまとめておく。
◆ 目次
- 前提
- 何を調査するか
- ソースコード解析
静的解析
動的解析
- コアファイルからの解析
- クラッシュはしないけれど性能が劣化している場合の解析
スタックトレースを利用して原因分析
プログラムが利用するシステムコールを監視して原因分析
別の目的でWebエンジニアのためのデータベース技術[実践]入門という書籍を購入したのだが、その中でソースハッキングする手法が説明されており、分かりやすかった。こちらを参考にさせてもらっている。
◆ 前提
解析にmysqlを利用するためソースからインストールしておく。
バージョン：mysql-5系
インストールパス：/usr/local/mysql-5.X.XX/
# cd /usr/local/src
# wget http://～/mysql-5.X.XX.tar.gz
# tar zxvf mysql-5.X.XX.tar.gz
$ cd mysql-5.X.XX
$ ./configure --prefix=/usr/local/mysql-5.X.XX --with-debug=full
cmakeが使えるなら、
$ cmake ./ -DCMAKE_INSTALL_PREFIX=/usr/local/mysql-5.X.XX -DCMAKE_BUILD_TYPE=Debug
当然だが、本番系ではdebugモードをつけない。
$ make -j12
$ sudo make install
◆ 何を調査するか
mysqlサーバに接続しようとして失敗した回数を記録するステータス変数である、Aborted_connects がいつ加算されていくのかを調査する。
◆ ソースコード解析
● 静的解析
静的解析とは目的のソースファイルと行数を調べてリーディングして解析する方法である。
$ cd /usr/local/src/mysql-5.X.XX/
$ grep -r Aborted_connects ./
./sql/mysqld.cc: {"Aborted_connects", (char*) &aborted_connects, SHOW_LONG},
もしくは
$ find ./ -type f -name '*cc' -exec grep -l Aborted_connects {} \;
aborted_connectsという変数があやしい。
このがどこで利用されているかを確認する。
$ grep -r aborted_connects ./
./sql/mysqld.cc:ulong aborted_threads, aborted_connects;
./sql/mysqld.cc: statistic_increment(aborted_connects,&LOCK_status);
./sql/mysqld.cc: {"Aborted_connects", (char*) &aborted_connects, SHOW_LONG},
./sql/mysqld.cc: aborted_threads= aborted_connects= 0;
./sql/sql_connect.cc: statistic_increment(aborted_connects,&LOCK_status);
./sql/sql_connect.cc: statistic_increment(aborted_connects,&LOCK_status);
./sql/sql_connect.cc: statistic_increment(aborted_connects,&LOCK_status);
./sql/mysqld.h:extern ulong aborted_threads,aborted_connects;
もしくは
$ find ./ -type f -name '*cc' -exec grep -l aborted_connects {} \;
各ファイル内で該当の変数が現れる行数を調べておく。
./sql/mysqld.cc
4991行 : statistic_increment(aborted_connects,&LOCK_status);
./sql/sql_connect.cc
546行 : statistic_increment(aborted_connects,&LOCK_status);
591行 : statistic_increment(aborted_connects,&LOCK_status);
772行 : statistic_increment(aborted_connects,&LOCK_status);
あとは力づくでソースコードを読んでいけばよい。
次に紹介する動的解析でこの行番号を利用するため覚えておく。
● 動的解析
ブレークポイントを利用して解析する。
【端末A】
gdbからmysqldを実行する・・・★① ※数字は以下【端末A】と【端末B】での操作順番である
# gdb /usr/local/mysql-5.5.25/bin/mysqld
ブレークポイントを設定する・・・★②
(gdb) br mysqld.cc:4991
(gdb) br sql_connect.cc:546
(gdb) br sql_connect.cc:591
(gdb) br sql_connect.cc:772
mysqldを起動・・・★③
(gdb) run --defaults-file=/etc/my.cnf
ブレークポイントで停止する・・・★⑤
Breakpoint 3, login_connection (thd=0x16d5ba0) at /var/tmp/src/mysql-5.X.XX/sql/sql_connect.cc:591
継続させる・・・★⑥
(gdb) continue
ブレークポイントで停止する・・・★⑧
Breakpoint 3, login_connection (thd=0x16d5ba0) at /var/tmp/src/mysql-5.X.XX/sql/sql_connect.cc:591
591 in /var/tmp/src/mysql-5.5.25/sql/sql_connect.cc
※continueさせているので上記エラーが出るだけで停止はしない
【端末B】
誤ったパスワードでログインする・・・★④
$ /usr/local/mysql-5.5.25/bin/mysql -u root -pbadpassword
3306ポートへ接続する・・・★⑦
$ telnet localhost 3306
その後
ctrl + ] で抜ける。
◆ コアファイルからの解析
クラッシュするような自体になった場合コアから原因を解析する。
# gdb 実行ファイル コアファイル
(gdb) backtrace
◆ クラッシュはしないけれど性能が劣化している場合の解析
● スタックトレースを利用して原因分析
プロセスにstackの情報を取得(アタッチ)する間は該当処理が停まる。
pstack実行以降もずっと停止することはない。しかし、取得するstackの量にもよるが、長い場合は数秒間程度でかかることもあるため、商用系で実施するならよくよく検討した方がいい。
# pstack プロセスID
デバッグモードでビルドしていれば、gdbを使い、ソースコードの行番号も表示させることができる。pstackよりも若干遅くなるが解析には有利であろう。
# gdb --batch --pid=プロセスID
● プログラムが利用するシステムコールを監視して原因分析
-fオプションを付与すればforkした子プロセスもトレースできる。
# strace -p プロセスID
または
# strace 実行ファイル
※デーモン化しない例えばlsコマンドの結果などもトレースできる。
(興味深い記事があったので参考までに)
パーフェクトなCRubyを目指して - 1行のバグ修正に潜む苦労
