トレースデータの表示
コンシューマを特定したら、::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