Solaris 動的トレースガイド

データ記録アクション

DTrace のコアアクションは、データ記録アクションで構成されています。これらのアクションのデフォルトの動作は、主バッファーへのデータの格納ですが、投機バッファーへのデータの格納も可能です。主バッファーの詳細については、第 11 章バッファーとバッファリングを参照してください。投機バッファーについては、第 13 章投機トレースを参照してください。この節では「指定バッファー」という語を使用して、データの記録先が主バッファーか投機バッファー (アクションが speculate() の後ろに指定されている場合) であることを示しています。

trace()

void trace(expression)

もっとも基本的なアクションは、D 式 expression を引数とし、指定バッファーに結果をトレースする trace() アクションです。以下に、trace() アクションの例を示します。

trace(execname);
trace(curlwpsinfo->pr_pri);
trace(timestamp / 1000);
trace(`lbolt);
trace("somehow managed to get here");

tracemem()

void tracemem(address, size_t nbytes)

tracemem() アクションは、最初の引数として D 式 address、2 番目の引数として定数 nbytes をとります。tracemem() は、address で指定されたアドレスから nbytes で指定された長さのメモリーを、指定バッファーにコピーします。

printf()

void printf(string format, ...) 

printf() アクションは、trace() と同じように、D 式をトレースします。ただし、printf() では、複雑な printf(3C) 形式の書式が使用されます。printf(3C) の場合と同じく、パラメータは format 文字列と任意の数の引数です。デフォルトでは、これらの引数が指定バッファーにトレースされます。その後、指定された書式設定文字列に従って、これらの引数に dtrace(1M) の出力書式が設定されます。たとえば、trace() の最初の 2 つの trace() の例を、単一の printf() 内で組み合わせて使用すると、以下のようになります。

printf("execname is %s; priority is %d", execname, curlwpsinfo->pr_pri);

printf() の詳細については、第 12 章出力書式を参照してください。

printa()

void printa(aggregation)
void printa(string format, aggregation)

printa() アクションでは、集積体に書式を設定して表示できます。集積体の詳細については、第 9 章集積体を参照してください。format を省略した場合、printa() は、aggregation で指定された集積体の処理を行い、デフォルトの書式で表示せよという DTrace コンシューマへの指令をトレースする以外に、何も行いません。format を指定した場合、集積体に指定された書式が設定されます。printa() の書式文字列については、第 12 章出力書式を参照してください。

printa() は、DTrace コンシューマに集積体を処理させる指令をトレースするだけです。カーネル内で集積体の処理を行うことはありません。したがって、printa() のトレース指令から実際に指令が処理されるまでの時間は、バッファー処理に影響を及ぼす要因によって変化します。こうした要因には、集積間隔、バッファリングポリシー、バッファーの切り替え間隔 (バッファリングポリシーが switching である場合) などがあります。これらの要因の詳細については、第 9 章集積体第 11 章バッファーとバッファリングを参照してください。

stack()

void stack(int nframes)
void stack(void)

stack() アクションは、カーネルスタックトレースを指定バッファーに記録します。カーネルスタックの深さは、nframes で指定します。nframes を省略した場合、stackframes オプションで指定された数のスタックフレームが記録されます。次に例を示します。


# dtrace -n uiomove:entry'{stack()}'
  CPU     ID                    FUNCTION:NAME
    0   9153                    uiomove:entry 
                genunix`fop_write+0x1b
                namefs`nm_write+0x1d
                genunix`fop_write+0x1b
                genunix`write+0x1f7

    0   9153                    uiomove:entry 
                genunix`fop_read+0x1b
                genunix`read+0x1d4

    0   9153                    uiomove:entry 
                genunix`strread+0x394
                specfs`spec_read+0x65
                genunix`fop_read+0x1b
                genunix`read+0x1d4
   ...

stack() アクションは、集積体キーとしても使用できるという点で、その他のアクションとは少し異なっています。


# dtrace -n kmem_alloc:entry'{@[stack()] = count()}'
dtrace: description 'kmem_alloc:entry' matched 1 probe
^C

                rpcmod`endpnt_get+0x47c
                rpcmod`clnt_clts_kcallit_addr+0x26f
                rpcmod`clnt_clts_kcallit+0x22
                nfs`rfscall+0x350
                nfs`rfs2call+0x60
                nfs`nfs_getattr_otw+0x9e
                nfs`nfsgetattr+0x26
                nfs`nfs_getattr+0xb8
                genunix`fop_getattr+0x18
                genunix`cstat64+0x30
                genunix`cstatat64+0x4a
                genunix`lstat64+0x1c
                  1

                genunix`vfs_rlock_wait+0xc
                genunix`lookuppnvp+0x19d
                genunix`lookuppnat+0xe7
                genunix`lookupnameat+0x87
                genunix`lookupname+0x19
                genunix`chdir+0x18
                  1

                rpcmod`endpnt_get+0x6b1
                rpcmod`clnt_clts_kcallit_addr+0x26f
                rpcmod`clnt_clts_kcallit+0x22
                nfs`rfscall+0x350
                nfs`rfs2call+0x60
                nfs`nfs_getattr_otw+0x9e
                nfs`nfsgetattr+0x26
                nfs`nfs_getattr+0xb8
                genunix`fop_getattr+0x18
                genunix`cstat64+0x30
                genunix`cstatat64+0x4a
                genunix`lstat64+0x1c
                  1
    ...

ustack()

void ustack(int nframes, int strsize)
void ustack(int nframes)
void ustack(void)

ustack() アクションは、指定バッファーにユーザースタックトレースを記録します。ユーザースタックの深さは、nframes で指定します。nframes を省略した場合、ustackframes オプションで指定された数のスタックフレームが記録されます。ustack() では、プローブ起動時の呼び出しフレームのアドレスを特定できますが、DTrace コンシューマがユーザーレベルで ustack() アクションを処理しないかぎり、スタックフレームはシンボルに翻訳されません。strsize にゼロ以外の値が指定されている場合、ustack() は指定された量の文字列空間を割り当て、これを使ってカーネルから直接、アドレスからシンボルへの翻訳を行います。このユーザーシンボルの直接翻訳機能は、現在、Java 仮想マシンのバージョン 1.5 以降でしか提供されていません。Java のアドレスからシンボルへの翻訳が行われると、Java クラスとメソッド名を持つ Java フレームが含まれているユーザースタックに、注釈が付けられます。翻訳できなかったフレームは、16 進アドレスで表されます。

以下の例では、文字列空間を持たないスタックをトレースしているため、Java のアドレスからシンボルへの翻訳は行われません。


# dtrace -n syscall::write:entry'/pid == $target/{ustack(50, 0); 
    exit(0)}' -c "java -version"
dtrace: description 'syscall::write:entry' matched 1 probe
java version "1.5.0-beta3"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0-beta3-b58)
Java HotSpot(TM) Client VM (build 1.5.0-beta3-b58, mixed mode)
dtrace: pid 5312 has exited
CPU     ID                    FUNCTION:NAME
  0     35                      write:entry 
              libc.so.1`_write+0x15
              libjvm.so`__1cDhpiFwrite6FipkvI_I_+0xa8
              libjvm.so`JVM_Write+0x2f
              d0c5c946
              libjava.so`Java_java_io_FileOutputStream_writeBytes+0x2c
              cb007fcd
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb002a7b
              cb000152
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_
                          pnMmethodHandle_pnRJavaCallArguments_
                          pnGThread__v_+0x187
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_
                          pnMmethodHandle_pnRJavaCallArguments_
                          pnGThread__v2468_v_+0x14
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_
                          pnRJavaCallArguments_pnGThread __v_+0x28
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_
                          pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_
                          ArgumentPusher_pnGThread__v_+0x180
              libjvm.so`jni_CallStaticVoidMethod+0x10f
              java`main+0x53d

Java 仮想マシンの C と C++ のスタックフレームは、C++ 符号化シンボル名でシンボリックに表現されます。Java スタックフレームは、16 進アドレスで表現されます。以下は、ゼロでない文字列空間で ustack() を呼び出す例です。


# dtrace -n syscall::write:entry'/pid == $target/{ustack(50, 500); exit(0)}'
      -c "java -version"
dtrace: description 'syscall::write:entry' matched 1 probe
java version "1.5.0-beta3"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0-beta3-b58)
Java HotSpot(TM) Client VM (build 1.5.0-beta3-b58, mixed mode)
dtrace: pid 5308 has exited
CPU     ID                    FUNCTION:NAME
  0     35                      write:entry 
              libc.so.1`_write+0x15
              libjvm.so`__1cDhpiFwrite6FipkvI_I_+0xa8
              libjvm.so`JVM_Write+0x2f
              d0c5c946
              libjava.so`Java_java_io_FileOutputStream_writeBytes+0x2c
              java/io/FileOutputStream.writeBytes
              java/io/FileOutputStream.write
              java/io/BufferedOutputStream.flushBuffer
              java/io/BufferedOutputStream.flush
              java/io/PrintStream.write
              sun/nio/cs/StreamEncoder$CharsetSE.writeBytes
              sun/nio/cs/StreamEncoder$CharsetSE.implFlushBuffer
              sun/nio/cs/StreamEncoder.flushBuffer
              java/io/OutputStreamWriter.flushBuffer
              java/io/PrintStream.write
              java/io/PrintStream.print
              java/io/PrintStream.println
              sun/misc/Version.print
              sun/misc/Version.print
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_
                          pnMmethodHandle_pnRJavaCallArguments_pnGThread
                          __v_+0x187
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_
                          pnMmethodHandle_pnRJavaCallArguments_pnGThread
                          __v2468_v_+0x14
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle
                          _pnRJavaCallArguments_pnGThread__v_+0x28
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI
                          _jobject_nLJNICallType_pnK_jmethodID_pnSJNI
                          _ArgumentPusher_pnGThread__v_+0x180
              libjvm.so`jni_CallStaticVoidMethod+0x10f
              java`main+0x53d
              8051b9a

この出力例から、Java スタックフレームのシンボリックなスタックフレーム情報を確認できます。いくつかの関数が静的関数で、アプリケーションシンボルテーブルにエントリがないので、この出力にはまだ 16 進フレームが含まれています。これらのフレームを翻訳することはできません。

Java フレーム以外のフレームの ustack() シンボル翻訳は、スタックデータの記録に行われます。このため、シンボル翻訳の実行前に対応するユーザープロセスが終了してしまい、スタックフレーム翻訳ができない可能性があります。シンボル翻訳の前にユーザープロセスが終了した場合、次の例のように、dtrace からの警告メッセージと、16 進スタックフレームのリストが表示されます。


  dtrace: failed to grab process 100941: no such process
                c7b834d4
                c7bca85d
                c7bca1a4
                c7bd4374
                c7bc2628
                8047efc

この問題に対処するためのテクニックについては、第 33 章ユーザープロセスのトレースを参照してください。

最後に、事後 DTrace デバッガコマンドはフレーム翻訳を実行できないので、ring バッファーポリシーで ustack() を使用すると、常に生の ustack() データが返されることになります。

以下の D プログラムの例では、ustack() が使用されていますが、strsize の指定は省略されています。

syscall::brk:entry
/execname == $$1/
{
	@[ustack(40)] = count();
}

デフォルトの Solaris インストールで、Netscape の Web ブラウザ .netscape.bin を指定してこのプログラムを実行するには、次のコマンドを使用します。


# dtrace -s brk.d .netscape.bin
dtrace: description 'syscall::brk:entry' matched 1 probe
^C
                libc.so.1`_brk_unlocked+0xc
                88143f6
                88146cd
                .netscape.bin`unlocked_malloc+0x3e
                .netscape.bin`unlocked_calloc+0x22
                .netscape.bin`calloc+0x26
                .netscape.bin`_IMGCB_NewPixmap+0x149
                .netscape.bin`il_size+0x2f7
                .netscape.bin`il_jpeg_write+0xde
                8440c19
                .netscape.bin`il_first_write+0x16b
                8394670
                83928e5
                .netscape.bin`NET_ProcessHTTP+0xa6
                .netscape.bin`NET_ProcessNet+0x49a
                827b323
                libXt.so.4`XtAppProcessEvent+0x38f
                .netscape.bin`fe_EventLoop+0x190
                .netscape.bin`main+0x1875
                   1

                libc.so.1`_brk_unlocked+0xc
                libc.so.1`sbrk+0x29
                88143df
                88146cd
                .netscape.bin`unlocked_malloc+0x3e
                .netscape.bin`unlocked_calloc+0x22
                .netscape.bin`calloc+0x26
                .netscape.bin`_IMGCB_NewPixmap+0x149
                .netscape.bin`il_size+0x2f7
                .netscape.bin`il_jpeg_write+0xde
                8440c19
                .netscape.bin`il_first_write+0x16b
                8394670
                83928e5
                .netscape.bin`NET_ProcessHTTP+0xa6
                .netscape.bin`NET_ProcessNet+0x49a
                827b323
                libXt.so.4`XtAppProcessEvent+0x38f
                .netscape.bin`fe_EventLoop+0x190
                .netscape.bin`main+0x1875
                  1
    ...

jstack()

void jstack(int nframes, int strsize)
void jstack(int nframes)
void jstack(void)

jstack()ustack() の別名で、jstackframes オプションでスタックフレーム数を指定し、jstackstrsize オプションで文字列空間サイズを指定します。デフォルトでは、jstacksize はゼロ以外の値になります。つまり、jstack() を使用すると、Java フレーム翻訳が適切に行なわれるようにスタックがトレースされます。