3.07.2011

Core dump analysis with mdb

mdbによるコアダンプ解析

UNIX環境(特にSolaris)におけるユーザープロセスのダンプ解析についてのメモ。

1. 準備

まず、実際にコアを吐くプログラムを作ってみる。

  • ソースコード(C)
#include <assert.h>

int main(void) {
  assert(!"THIS IS A CRASH TEST.");
  return 0;
}
  • コンパイルと実行(手順例)
$ /usr/sfw/bin/g++ -O2 -Wall -o ./crash_test ./crash_test.c
$ ./crash_test
Assertion failed: !"THIS IS A CRASH TEST.", file ./crash_test.c, line 4
異常終了(コアダンプ)
  • 生成されたコアダンプ
$ ls -l ./core.crash_test*
-rw-------   1 root     root     2906931  3月  6日  19:36 ./core.crash_test.869

 

2. procツールによる解析

Solaris環境におけるコアダンプの解析ツールは、「pstack」をはじめとするprocツールと呼ばれるコマンド群、「mdb」(Modular Debugger)、「dbx」などがある。

procツールは、稼働中のプロセス(※)だけでなくコアダンプに対しても使用することができる。
(※稼働中のプロセスに対して実行するとプロセスが一旦ロックされるのでタイミングは慎重に)

  • proc マニュアルページ(man proc)の一部(Solaris 10)
     ⇒ ハイライト行のコマンドがコアに対して使用可能
【名前】
     proc, pflags,  pcred,  pldd,  psig,  pstack,  pfiles,  pwdx,
     pstop, prun, pwait, ptime - proc ツール

【形式】
     /usr/bin/pflags  [-r] pid | core [/lwp] ...
     /usr/bin/pcred  [pid |  core]...
     /usr/bin/pcred  [-u user/uid] [-g group/gid] [-G grouplist] pid...
     /usr/bin/pcred  -l login pid...
     /usr/bin/pldd  [-F] [pid |  core]...
     /usr/bin/psig  [-n] pid ...
     /usr/bin/pstack  [-F] pid | core  [/lwp] ...
     /usr/bin/pfiles  [-Fn] pid...
     /usr/bin/pwdx  pid...
     /usr/bin/pstop  pid...
     /usr/bin/prun  pid...
     /usr/bin/pwait  [-v] pid...
     /usr/bin/ptime  command [arg]...
  • pmap マニュアルページ(man pmap)の一部(Solaris 10)
【名前】
     pmap - プロセスのアドレス空間に関する情報を表示する

【形式】
     /usr/bin/pmap  [-rslF] [pid |  core]...
     /usr/bin/pmap  -x [-aslF] [pid |  core]...
     /usr/bin/pmap  -S [-alF] [pid |  core]...
  • 各コマンドの実行結果は以下のようになった。
# pflags ./core.crash_test.869
core './core.crash_test.869' of 869:    ./crash_test
        data model = _ILP32  flags = MSACCT|MSFORK
 /1:    flags = 0
        sigmask = 0xffffbefc,0x0000ffff  cursig = SIGABRT
 
# pcred ./core.crash_test.869
core of 869:    e/r/suid=101  e/r/sgid=10
# pldd ./core.crash_test.869
core './core.crash_test.869' of 869:    ./crash_test
/usr/sfw/lib/libstdc++.so.6.0.3
/lib/libm.so.2
/usr/sfw/lib/libgcc_s.so.1
/lib/libc.so.1
# pstack ./core.crash_test.869
core './core.crash_test.869' of 869:    ./crash_test
 d25bab25 _lwp_kill (1, 6) + 15
 d2561ee3 raise    (6) + 1f
 d2541d1d abort    (8047e64, d27fc818, 65737341, 6f697472, 6166206e, 64656c69) + cd
 d2541f37 _assert  (80509ab, 805099c, 4, 8060b88, 0, 8050932) + 6b
 08050921 main     (1, 8047ea8, 8047eb0) + 1d
 080507ac _start   (1, 8047f48, 0, 8047f55, 8047f64, 8047f73) + 80
# pmap ./core.crash_test.869
core './core.crash_test.869' of 869:    ./crash_test
08046000       8K rwx--    [ stack ]
08050000       4K r-x--
08060000       4K rwx--
08061000       8K rwx--    [ heap ]
D2510000    1080K r-x--  /lib/libc.so.1
D262E000      32K rw---  /lib/libc.so.1
D2636000       8K rw---  /lib/libc.so.1
D2640000      28K r-x--  /usr/sfw/lib/libgcc_s.so.1
D2656000       4K rwx--  /usr/sfw/lib/libgcc_s.so.1
D2660000     268K r-x--  /lib/libm.so.2
D26B2000      16K rwx--  /lib/libm.so.2
D26C0000     688K r-x--  /usr/sfw/lib/libstdc++.so.6.0.3
D2770000      24K rwx--
D277B000     132K rwx--  /usr/sfw/lib/libstdc++.so.6.0.3
D279C000      24K rwx--  /usr/sfw/lib/libstdc++.so.6.0.3
D27B9000       4K rwx--
D27C0000       4K rwx--
D27C4000     160K r-x--  /lib/ld.so.1
D27F0000       4K rwx--
D27FC000       8K rwx--  /lib/ld.so.1
D27FE000       4K rwx--  /lib/ld.so.1
 total      2512K

pstackの結果(17〜21行目)から、クラッシュの発生箇所が特定できる。
下から読んでいくと、main関数から「_assert」が呼び出され、「abort」「raise」「_lwp_kill」という順で関数がコールされたことがわかる。

lwpとはLight Weight Processの略で、プロセスの内部のプログラムの実行単位である。
詳細は以下を参照。
http://kotobank.jp/word/LWP

 

3. mdbによる解析

「dbx」を使用するためには別途インストールが必要なため、今回はOS標準となっている「mdb」を使ってみよう。

まずは mdb コアファイルのパス で起動。

「>」というプロンプトが返ってきたら、dcmd(Debugger CoMmanD)と呼ばれるコマンドを入力してデバッグ情報を参照する。

  • ::help でヘルプ、::dcmds で使用可能なコマンドの一覧が表示される。
# mdb ./core.crash_test.869
Loading modules: [ libc.so.1 ld.so.1 ]
> ::help
 
Each debugger command in mdb
 is structured as follows:
 
      [ address [, count]] verb [ arguments ... ]
             ^       ^      ^      ^
 the start --+       |      |      +-- arguments are strings which can be
 address can be an   |      |          quoted using "" or '' or
 expression          |      |          expressions enclosed in $[ ]
                     |      |
 the repeat count  --+      +--------- the verb is a name which begins
 is also an expression                 with either $, :, or ::.  it can also
                                       be a format specifier (/ \ ? or =)
 
For information on debugger commands (dcmds) and walkers, type:
 
      ::help cmdname ... for more detailed information on a command
      ::dcmds        ... for a list of dcmds and their descriptions
      ::walkers      ... for a list of walkers and their descriptions
      ::dmods -l     ... for a list of modules and their dcmds and walkers
      ::formats      ... for a list of format characters for / \ ? and =
 
For information on command-line options, type:
 
      $ mdb -?      ... in your shell for a complete list of options
 
> ::dcmds
$<                       - replace input with macro
$<<                      - source macro
$>                       - log session to a file
$?                       - print status and registers
$C                       - print stack backtrace
$G                       - enable/disable C++ demangling support
$L                       - print list of the active lwp ids
$M                       - list macro aliases
$P                       - set debugger prompt string
$Q                       - quit debugger
(以下略)
  • ::status でクラッシュの概要を表示
> ::status
debugging core file of crash_test (32-bit) from freya
file: /home/mog/crash_test
initial argv: ./crash_test
threading model: multi-threaded
status: process terminated by SIGABRT (Abort)
panic message: Assertion failed: !"THIS IS A CRASH TEST.", file ./crash_test.c, line 4
  • ::stack または $C でスタックトレースを表示(pstackと同等)
> ::stack
libc.so.1`_lwp_kill+0x15(1, 6)
libc.so.1`raise+0x1f(6)
libc.so.1`abort+0xcd(8047e64, d27fc818, 65737341, 6f697472, 6166206e, 64656c69)
libc.so.1`_assert+0x6b(80509ab, 805099c, 4, 8060b88, 0, 8050932)
main+0x1d(1, 8047ea8, 8047eb0)
_start+0x80(1, 8047f48, 0, 8047f55, 8047f64, 8047f73)
  • アドレス::dump でメモリの内容を表示できる
> 80509ab::dump
           0 1 2 3  4 5 6 7  8 9 a\/  c d e f  0123456789avcdef
80509a0:  6173685f 74657374 2e630021 22544849  ash_test.c.!"THI

0x080509ab はassertで指定した文字列(assert()の引数)のアドレスであることがわかる。

より広範囲のアドレスをダンプするには、アドレス,バイト数::dump というフォーマットを使う。(バイト数は16進)
例えば、「80509ab,100::dump」とすれば、アドレス 80509ab から 100(16進) = 256(10進) バイトの範囲の
メモリ内容が表示される。
http://mogproject.blogspot.jp/2011/03/solaris-mdb.html

  • $? はレジスタの情報などを表示、$m はpmapと同等
> $?
no process
SIGABRT: Abort
%cs = 0x016b            %eax = 0x00000000
%ds = 0x0173            %ebx = 0xd262e000
%ss = 0x0173            %ecx = 0x08047bc4
%es = 0x0173            %edx = 0xd8956ee0
%fs = 0x0000            %esi = 0x08047c48
%gs = 0x01c3            %edi = 0x08047ee0
 
 %eip = 0xd25bab25 libc.so.1`_lwp_kill+0x15
 %ebp = 0x08047bd4
%kesp = 0xe51a8fe4
 
%eflags = 0x00000282
  id=0 vip=0 vif=0 ac=0 vm=0 rf=0 nt=0 iopl=0x0
  status=
 
   %esp = 0x08047bc4
%trapno = 0xe
   %err = 0x14
> $m
    BASE    LIMIT     SIZE NAME
 8046000  8048000     2000 [ stack ]
 8050000  8051000     1000 /home/mog/crash_test
 8060000  8061000     1000 /home/mog/crash_test
 8061000  8063000     2000 [ heap ]
d2510000 d261e000   10e000 /lib/libc.so.1
d262e000 d2636000     8000 /lib/libc.so.1
d2636000 d2638000     2000 /lib/libc.so.1
d2640000 d2647000     7000 /usr/sfw/lib/libgcc_s.so.1
d2656000 d2657000     1000 /usr/sfw/lib/libgcc_s.so.1
d2660000 d26a3000    43000 /lib/libm.so.2
d26b2000 d26b6000     4000 /lib/libm.so.2
d26c0000 d276c000    ac000 /usr/sfw/lib/libstdc++.so.6.0.3
d2770000 d2776000     6000
d277b000 d279c000    21000 /usr/sfw/lib/libstdc++.so.6.0.3
d279c000 d27a2000     6000 /usr/sfw/lib/libstdc++.so.6.0.3
d27b9000 d27ba000     1000
d27c0000 d27c1000     1000
d27c4000 d27ec000    28000 /lib/ld.so.1
d27f0000 d27f1000     1000
d27fc000 d27fe000     2000 /lib/ld.so.1
d27fe000 d27ff000     1000 /lib/ld.so.1
  • ::nm はアドレスに割り当てられたシンボルの表示
>  ::nm
Value      Size       Type  Bind  Other Shndx    Name
0x00000000|0x00000000|NOTY |LOCL |0x0  |UNDEF   |
0x00000000|0x00000000|FILE |LOCL |0x0  |ABS     |./crash_test
0x080500d4|0x00000000|SECT |LOCL |0x0  |1       |
0x080500e8|0x00000000|SECT |LOCL |0x0  |2       |
(中略)
0x08060b88|0x00000018|OBJT |LOCL |0x0  |24      |object.2
0x080508a0|0x00000000|FUNC |LOCL |0x0  |11      |frame_dummy
0x00000000|0x00000000|FILE |LOCL |0x0  |ABS     |crash_test.c
0x00000000|0x00000000|FILE |LOCL |0x0  |ABS     |crtstuff.c
0x08060b28|0x00000000|OBJT |LOCL |0x0  |19      |__CTOR_END__
(中略)
0x080609c4|0x00000000|OBJT |GLOB |0x0  |16      |_GLOBAL_OFFSET_TABLE_
0x08050980|0x00000018|FUNC |GLOB |0x0  |13      |_fini
0x080506fc|0x00000000|FUNC |GLOB |0x0  |UNDEF   |__assert
0x0805068c|0x00000000|FUNC |GLOB |0x0  |UNDEF   |atexit
0x00000000|0x00000000|NOTY |WEAK |0x0  |UNDEF   |_Jv_RegisterClasses
0x00000000|0x00000000|NOTY |WEAK |0x0  |UNDEF   |__fsr_init_value
0x0805070c|0x00000000|FUNC |WEAK |0x0  |UNDEF   |_get_exit_frame_monitor
0x08060b1c|0x00000004|OBJT |GLOB |0x0  |18      |__longdouble_used
0x080507c4|0x0000007b|FUNC |GLOB |0x0  |11      |__fsr
0x0805069c|0x00000000|FUNC |GLOB |0x0  |UNDEF   |__fpstart
0x08050904|0x00000021|FUNC |GLOB |0x0  |11      |main
0x080506ac|0x00000000|FUNC |GLOB |0x0  |UNDEF   |exit
0x080506dc|0x00000000|FUNC |WEAK |0x0  |UNDEF   |__register_frame_info_bases
0xd26c0000|0x00000000|NOTY |LOCL |0x0  |UNDEF   |
0xd26c0000|0x00000000|FILE |LOCL |0x0  |ABS     |.libs/libstdc++.so.6.0.3
0xd26c00b4|0x00000000|SECT |LOCL |0x0  |1       |
0xd26c7314|0x00000000|SECT |LOCL |0x0  |2       |
(以下略)
  • ::quit または $q で終了
> ::quit
 
#

 

個人的な経験としては、

  1. コア以外の情報(Syslog、アプリログ、JVM出力、ハードウェアリソース状況など)から概要を把握
  2. pstack コア で事象が発生した関数を特定
  3. mdb コア で mdb を起動し、::status::stack でより詳細な情報を得る
  4. ::stack で確認できた「関数の引数に指定されたアドレス」に対して アドレス,100::dump を実行し、
    アドレス参照先の情報を確認する  ※特に文字列が格納されている場合は分かりやすい
  5. 事象が発生した部分のソースコードを確認し、どのような場合に事象が発生するのか仮説を立てて検証する

 といった流れで原因の特定にたどり着くことが多い。

 

References

※2012/11/4時点リンク切れ
http://developers.sun.com/solaris/articles/manage_core_dump.html

Core Dump Management on the Solaris OS
http://www.oracle.com/technetwork/server-storage/solaris10/manage-core-dump-138834.html

Solaris 8 オペレーティング環境の概要 - proc ツールによるコアファイルの検査
http://download.oracle.com/docs/cd/E19455-01/806-6320/whatsnewch2-147/index.html

Solaris Core Analysis, Part 1: mdb - Ben Rockwood
http://cuddletech.com/blog/pivot/entry.php?id=965

mdbでサクサクとカーネルをデバック - mdb (modular debugger) ※2012/11/4時点リンク切れ
http://blogs.sun.com/eota/entry/mdb%E3%81%A7%E3%82%B5%E3%82%AF%E3%82%B5%E3%82%AF%E3%81%A8%E3%82%AB%E3%83%BC%E3%83%8D%E3%83%AB%E3%82%92%E3%83%87%E3%83%90%E3%83%83%E3%82%AF_mdb_modular_debugger

0 件のコメント:

コメントを投稿