第 37 章 事後トレース
この章では、DTrace コンシューマのカーネル内データを「事後」に抽出し処理する、DTrace 機能について説明します。たとえばシステムがクラッシュした場合、それまでに DTrace で記録された情報が、障害の根本原因を探る重要な手がかりになる可能性があります。システムのクラッシュダンプから DTrace データを抽出し、処理したあと、このデータを基に、システムの致命的な障害について調べることができます。このような DTrace の事後機能とリングバッファーポリシー (第 11 章バッファーとバッファリングを参照) を組み合わせると、DTrace は、オペレーティングシステム内で、飛行機の「ブラックボックス」 (フライトデータレコーダー) と同じような役割を果たします。
クラッシュダンプから DTrace データを抽出するには、まず、そのクラッシュダンプに対して Solaris モジューラデバッガ (mdb(1)) を実行します。すると、DTrace 機能が格納されている MDB モジュールが自動的にロードされます。MDB の詳細については、『『Solaris モジューラデバッガ』』を参照してください。
DTrace コンシューマの表示
DTrace コンシューマから DTrace データを抽出するには、まず ::dtrace_state MDB dcmd を実行して、抽出元の DTrace コンシューマを特定する必要があります。
> ::dtrace_state
ADDR MINOR PROC NAME FILE
ccaba400 2 - <anonymous> -
ccab9d80 3 d1d6d7e0 intrstat cda37078
cbfb56c0 4 d71377f0 dtrace ceb51bd0
ccabb100 5 d713b0c0 lockstat ceb51b60
d7ac97c0 6 d713b7e8 dtrace ceb51ab8
|
このコマンドを実行すると、DTrace の状態構造が表形式で出力されます。表の各行には、次の情報が含まれています。
-
状態構造のアドレス
-
dtrace(7D) デバイスのマイナー番号
-
DTrace コンシューマのプロセス構造のアドレス
-
DTrace コンシューマ名 (匿名コンシューマの場合は <anonymous>)
-
dtrace(7D) オープンデバイスのファイル構造の名前
特定の DTrace コンシューマの詳細情報が必要な場合は、::ps dcmd に、そのプロセス構造のアドレスを指定します。
> d71377f0::ps S PID PPID PGID SID UID FLAGS ADDR NAME R 100647 100642 100647 100638 0 0x00004008 d71377f0 dtrace |
トレースデータの表示
コンシューマを特定したら、::dtrace dcmd に状態構造のアドレスを指定して、まだ消費されていないバッファーのデータを検出します。以下は、trace(execname) アクションが関連付けられている syscall:::entry の匿名有効化に対して ::dtrace dcmd を実行したときの出力例です。
> ::dtrace_state
ADDR MINOR PROC NAME FILE
cbfb7a40 2 - <anonymous> -
> cbfb7a40::dtrace
CPU ID FUNCTION:NAME
0 344 resolvepath:entry init
0 16 close:entry init
0 202 xstat:entry init
0 202 xstat:entry init
0 14 open:entry init
0 206 fxstat:entry init
0 186 mmap:entry init
0 186 mmap:entry init
0 186 mmap:entry init
0 190 munmap:entry init
0 344 resolvepath:entry init
0 216 memcntl:entry init
0 16 close:entry init
0 202 xstat:entry init
0 14 open:entry init
0 206 fxstat:entry init
0 186 mmap:entry init
0 186 mmap:entry init
0 186 mmap:entry init
0 190 munmap:entry init
...
|
::dtrace dcmd は、dtrace(1M) と同じようにしてエラーを処理します。コンシューマの実行中に、欠落、エラー、投機欠落などが発生した場合、::dtrace は、dtrace(1M) メッセージと同様のメッセージを発行します。
::dtrace は、常に CPU 内の古いイベントから順に出力します。CPU バッファー自体は、番号順に出力されます。複数の異なる CPU 上のイベントに番号を付ける必要がある場合は、timestamp 変数をトレースします。
特定の CPU のデータだけを出力したい場合は、::dtrace に -c オプションを指定します。
> cbfb7a40::dtrace -c 1 CPU ID FUNCTION:NAME 1 14 open:entry init 1 206 fxstat:entry init 1 186 mmap:entry init 1 344 resolvepath:entry init 1 16 close:entry init 1 202 xstat:entry init 1 202 xstat:entry init 1 14 open:entry init 1 206 fxstat:entry init 1 186 mmap:entry init ... |
::dtrace は、カーネル内の D トレースデータしか処理しません。カーネルから消費され、dtrace(1M) などによって処理されたデータを、再度 ::dtrace で処理することはできません。障害発生時にもデータを最大限に確保するには、リングバッファーポリシーを使用します。バッファーポリシーの詳細については、第 11 章バッファーとバッファリングを参照してください。
以下は、非常に小さい (16K) リングバッファーを作成し、すべてのシステムコールとその呼び出し元プロセスを記録する例です。
# dtrace -P syscall'{trace(curpsinfo->pr_psargs)}' -b 16k -x bufpolicy=ring
dtrace: description 'syscall:::entry' matched 214 probes
|
このコマンドを実行したときのクラッシュダンプは、以下のようになります。
> ::dtrace_state
ADDR MINOR PROC NAME FILE
cdccd400 3 d15e80a0 dtrace ced065f0
> cdccd400::dtrace
CPU ID FUNCTION:NAME
0 139 getmsg:return mibiisa -r -p 25216
0 138 getmsg:entry mibiisa -r -p 25216
0 139 getmsg:return mibiisa -r -p 25216
0 138 getmsg:entry mibiisa -r -p 25216
0 139 getmsg:return mibiisa -r -p 25216
0 138 getmsg:entry mibiisa -r -p 25216
0 139 getmsg:return mibiisa -r -p 25216
0 138 getmsg:entry mibiisa -r -p 25216
0 139 getmsg:return mibiisa -r -p 25216
0 138 getmsg:entry mibiisa -r -p 25216
0 17 close:return mibiisa -r -p 25216
...
0 96 ioctl:entry mibiisa -r -p 25216
0 97 ioctl:return mibiisa -r -p 25216
0 96 ioctl:entry mibiisa -r -p 25216
0 97 ioctl:return mibiisa -r -p 25216
0 96 ioctl:entry mibiisa -r -p 25216
0 97 ioctl:return mibiisa -r -p 25216
0 96 ioctl:entry mibiisa -r -p 25216
0 97 ioctl:return mibiisa -r -p 25216
0 16 close:entry mibiisa -r -p 25216
0 17 close:return mibiisa -r -p 25216
0 124 lwp_park:entry mibiisa -r -p 25216
1 68 access:entry mdb -kw
1 69 access:return mdb -kw
1 202 xstat:entry mdb -kw
1 203 xstat:return mdb -kw
1 14 open:entry mdb -kw
1 15 open:return mdb -kw
1 206 fxstat:entry mdb -kw
1 207 fxstat:return mdb -kw
1 186 mmap:entry mdb -kw
...
1 13 write:return mdb -kw
1 10 read:entry mdb -kw
1 11 read:return mdb -kw
1 12 write:entry mdb -kw
1 13 write:return mdb -kw
1 96 ioctl:entry mdb -kw
1 97 ioctl:return mdb -kw
1 364 pread64:entry mdb -kw
1 365 pread64:return mdb -kw
1 366 pwrite64:entry mdb -kw
1 367 pwrite64:return mdb -kw
1 364 pread64:entry mdb -kw
1 365 pread64:return mdb -kw
1 38 brk:entry mdb -kw
1 39 brk:return mdb -kw
>
|
CPU 1 の最新のレコードに、mdb -kw プロセスによる一連の write(2) システムコールが含まれている点に注目してください。この結果がシステム障害の原因に関係していると推測されます。というのは、mdb(1) に -k オプションと -w オプションを指定して実行すると、実行中のカーネルのデータやテキストをユーザーが変更できるからです。この例では、DTrace のデータから、障害の原因そのものではないにしても、それを探る道筋のようなものを見出すことができます。
- © 2010, Oracle Corporation and/or its affiliates