カーネルダンプのスタック情報
ダンプ解析をしつつ、自分の理解を確認するために、カーネルダンプのスタックの見方の基本を書いてみます。間違いを発見した方はぜひコメントに入力しておいてください。
このエントリでは、各プロセスのスタックを見るための基本的な情報を記しておきます。
まず最初にpsでプロセス一覧を取得します。
--------------------
crash> ps
PID PPID CPU TASK ST %MEM VSZ RSS COMM
0 0 0 c0322a80 RU 0.0 0 0 [swapper]
> 0 1 1 f7e110b0 RU 0.0 0 0 [swapper]
> 0 1 2 f7e10b30 RU 0.0 0 0 [swapper]
> 0 1 3 f7e105b0 RU 0.0 0 0 [swapper]
1 0 2 f7e11630 IN 0.1 2056 632 init
..... 略 ....
10327 14 2 f74f4230 UN 0.0 0 0 [khelper]
---------
今回、このPID 10327のプロセスのバックトレースを見てみます。
--------
crash> bt 10327
PID: 10327 TASK: f74f4230 CPU: 2 COMMAND: "khelper"
#0 [f364ac34] schedule at c02d26dd
#1 [f364ac98] io_schedule at c02d2e69
#2 [f364aca4] __wait_on_buffer at c015c6cf
#3 [f364acf0] ext3_get_inode_loc at f8844571
#4 [f364ad1c] ext3_reserve_inode_write at f8844eda
#5 [f364ad34] ext3_mark_inode_dirty at f8844f65
#6 [f364ad54] ext3_dirty_inode at f8844fce
#7 [f364ad64] __mark_inode_dirty at c0177566
#8 [f364ad84] update_atime at c017204c
#9 [f364ad9c] do_generic_mapping_read at c0141889
#10 [f364ae10] __generic_file_aio_read at c0141af9
#11 [f364ae58] generic_file_aio_read at c0141b57
#12 [f364ae74] do_sync_read at c015b552
#13 [f364af10] vfs_read at c015b63a
#14 [f364af2c] kernel_read at c0164222
#15 [f364af48] prepare_binprm at c0164cff
#16 [f364af5c] do_execve at c0165131
#17 [f364af80] sys_execve at c01049b5
#18 [f364af94] system_call at c02d47a4
EAX: 0000000b EBX: c0327c80 ECX: f7f52e74 EDX: f491d280 EBP: f491d280
DS: 007b ESI: 00000000 ES: 007b EDI: 00000000
CS: 0060 EIP: c0130bec ERR: 0000000b EFLAGS: 00000282
---------------
この結果は、バックトレースなので、下側から順番に実行されたことを意味します。
一番最初の行、
-----------------
PID: 10327 TASK: f74f4230 CPU: 2 COMMAND: "khelper"
-----------------
ここより、PIDが10327、task_struct構造体のポインタが0xf74f4230、CPU 2で稼働していて、
コマンド名がkhelperであることがわかります。
さらにトレースだけでなく、そのときのスタックの状態を見るために、-fオプションを使います。
------------
crash> bt -f 10327
PID: 10327 TASK: f74f4230 CPU: 2 COMMAND: "khelper"
#0 [f364ac34] schedule at c02d26dd
[RA: c02d2e6e SP: f364ac34 FP: f364ac98 SIZE: 104]
f364ac34: f364ac94 00000046 00000009 c012a3e9
f364ac44: 00000000 f7d7ed30 00000019 c181ede0
f364ac54: f7d7ed30 00000000 c1817740 c1816de0
f364ac64: 00000002 002f89b1 5d154af1 00000188
f364ac74: f7d7ed30 f74f4230 f74f439c 00000008
f364ac84: 00000002 c1816de0 c046a880 00000460
f364ac94: f364aca0 c02d2e6e
#1 [f364ac98] io_schedule at c02d2e69
[RA: c015c6d4 SP: f364ac9c FP: f364aca4 SIZE: 12]
f364ac9c: f5f72800 f7410998 c015c6d4
#2 [f364aca4] __wait_on_buffer at c015c6cf
[RA: f8844576 SP: f364aca8 FP: f364acf0 SIZE: 76]
f364aca8: f5f72800 00000000 f74f4230 c015c57c
f364acb8: f364acd8 f364acd8 c015f391 00700128
f364acc8: f5f72800 00000000 f74f4230 c015c57c
f364acd8: c046a888 c046a888 f5f72800 f364acec
f364ace8: f7f2e200 f5f72800 f8844576
.... 省略 ....
-------------
このような感じになります。
短めなio_schedule()の部分を使って説明します。
-----------
#1 [f364ac98] io_schedule at c02d2e69
[RA: c015c6d4 SP: f364ac9c FP: f364aca4 SIZE: 12]
f364ac9c: f5f72800 f7410998 c015c6d4
------------
まず最初の行です。
------------
#1 [f364ac98] io_schedule at c02d2e69
-------------
これは、#1のエントリがカーネルのio_schedule()中の0xc2d2e69番地を実行中だった時のスタック情報であることを表しています。
disコマンドで、io_schedule()を逆アセンブルしてみます。
------------
crash> dis io_schedule
0xc02d2e48 <io_schedule>: push %ebp
0xc02d2e49 <io_schedule+1>: mov $0xfffff000,%eax
0xc02d2e4e <io_schedule+6>: mov %esp,%ebp
0xc02d2e50 <io_schedule+8>: push %ebx
0xc02d2e51 <io_schedule+9>: mov $0xc03c3e80,%ebx
0xc02d2e56 <io_schedule+14>: and %esp,%eax
0xc02d2e58 <io_schedule+16>: mov 0x10(%eax),%eax
0xc02d2e5b <io_schedule+19>: add 0xc03cf120(,%eax,4),%ebx
0xc02d2e62 <io_schedule+26>: lock incl 0x930(%ebx)
0xc02d2e69 <io_schedule+33>: call 0xc02d1ea0 <schedule>
0xc02d2e6e <io_schedule+38>: lock decl 0x930(%ebx)
0xc02d2e75 <io_schedule+45>: pop %ebx
0xc02d2e76 <io_schedule+46>: pop %ebp
0xc02d2e77 <io_schedule+47>: ret
-------------------
disコマンドで逆アセンブルした結果で確認すると、0xc02d2e69番地は、call命令であることがわかります。
call命令はサブ関数にジャンプするための命令で、スタックにリターンアドレスを積んでから、指定されたアドレス(ここでは 0xc02d1ea0 <schedule>)へジャンプします。
ここでさきほどのio_scedule()のスタックの前後も見てみます。
---------------
f364ac94: f364aca0 c02d2e6e
#1 [f364ac98] io_schedule at c02d2e69
[RA: c015c6d4 SP: f364ac9c FP: f364aca4 SIZE: 12]
f364ac9c: f5f72800 f7410998 c015c6d4
#2 [f364aca4] __wait_on_buffer at c015c6cf
[RA: f8844576 SP: f364aca8 FP: f364acf0 SIZE: 76]
----------
上記で、赤字にしたのは、スタックのアドレスです。
メモリに並んでいる状況で書くと次のようになります。
---------------------------------
アドレス : メモリの内容
f364ac94 : f364aca0
f356ac98: c02d2e6e
f364ac9c: f5f72800
f364aca0: f7410998
f364aca4: c015c6d4
-----------------------------
32bitマシンなので、4バイトずつアドレスが増えています。
さて元に戻って、call命令はリターンアドレスをスタックに積んでから、次の命令にジャンプするといいました。
---------------
#0 [f364ac34] schedule at c02d26dd
[RA: c02d2e6e SP: f364ac34 FP: f364ac98 SIZE: 104]
f364ac34: f364ac94 00000046 00000009 c012a3e9
.... 省略 ....
f364ac94: f364aca0 c02d2e6e
#1 [f364ac98] io_schedule at c02d2e69
[RA: c015c6d4 SP: f364ac9c FP: f364aca4 SIZE: 12]
f364ac9c: f5f72800 f7410998 c015c6d4
#2 [f364aca4] __wait_on_buffer at c015c6cf
[RA: f8844576 SP: f364aca8 FP: f364acf0 SIZE: 76]
----------
それぞれの関数のスタックの最後にリターンアドレスが入っていて、その数値が、RA;xxxxx の部分にリターンアドレスとして表示されているのです。
さてio_schedule()の0xc02d2e69番地から、次のschedule()へジャンプしたときのスタックは
次のようになっていたことが既にわかりました。
このとき、io_schedule()のスタックには、SP: f364ac9cと記載されています。
さきほどのメモリの状態と見比べると次のようになります。
---------------------------------
アドレス : メモリの内容
f364ac94 : f364aca0
f356ac98: c02d2e6e ← schedule()が終わったときに戻っていくリターンアドレス[ RA: c02d2e6e]
f364ac9c: f5f72800 ← SP
f364aca0: f7410998
f364aca4: c015c6d4 ← io_schedule()が終わったときに戻っていくリターンアドレス [RA: c015c6d4]
-----------------------------
SPとは、スタックポインタを意味し、今どのスタックを使っているかを表します。
この場合、io_schedule()の処理中に、0xf364ac9cまでのスタックを利用した段階で、次のschedule()へジャンプしていったことを示しています。
後は、リターンアドレスとその前のリターンアドレスの間に、いくつかのデータが入っています。
これはその関数(今回の場合 io_schedule)で利用したローカル変数などのデータが入っています。
このように、カーネルダンプのスタックを見るだけでかなりの情報を得ることができます。
投稿者 yasuma
日時 2006年7月 5日15:16
カーネルダンプ
すごく勉強になりました。
バックトレースをみてると結構、面白いね。今後の展開がすごく楽しみです(^^)
投稿： ひら | 2006年7月 5日 (水) 22:19
ひらさん。こんにちは。
実は一番勉強になっているのは私です。今後も続けていきたいと思います。
投稿： やすま | 2006年7月 7日 (金) 08:55