DTrace コード サンプル
DTrace では、D プログラミング言語がサポートされています。 このトピックでは、D コード サンプルを提供します。
Windows 上の DTrace の一般的な情報については、「DTrace」を参照してください。
DTraceの詳細については、ケンブリッジ大学のOpenDTrace Specification version 1.0を参照してください。
Note
DTraceは、バージョン18980およびWindows Server Build 18975以降のInsiderのビルドでサポートされています。
追加のサンプルスクリプト
Windows シナリオに適用できる追加の D スクリプトは、DTrace ソース コードの samples ディレクトリで入手できます。
https://github.com/microsoft/DTrace-on-Windows/tree/windows/samples/windows
有用な opentrace ツールキット スクリプトのセットは、https://github.com/opendtrace/toolkit で入手できます。
名前によるディスク使用量
このスクリプトは、特定の実行可能ファイル名のディスク カウンターを提供します。 実行可能ファイル名は大文字と小文字が区別され、スクリプトの起動時にコマンド ラインで指定されます。
#pragma D option quiet
#pragma D option destructive
intptr_t curptr;
struct nt`_EPROCESS *eprocess_ptr;
int found;
int firstpass;
BEGIN
{
curptr = (intptr_t) ((struct nt`_LIST_ENTRY *) (void*)&nt`PsActiveProcessHead)->Flink;
found = 0;
firstpass = 1;
bytesread = 0;
byteswrite = 0;
readcount = 0;
writecount = 0;
flushcount = 0;
}
tick-1ms
/found == 0/
{
/* use this for pointer parsing */
if (found == 0)
{
eprocess_ptr = (struct nt`_EPROCESS *)(curptr - offsetof(nt`_EPROCESS, ActiveProcessLinks));
processid = (string) eprocess_ptr->ImageFileName;
if ($1 == processid)
{
found = 1;
}
else
{
curptr = (intptr_t) ((struct nt`_LIST_ENTRY *) (void*)curptr)->Flink;
}
}
}
tick-2s
{
system ("cls");
if (found == 1)
{
if (firstpass)
{
firstpass = 0;
bytesread = (unsigned long long) eprocess_ptr->DiskCounters->BytesRead;
byteswrite = (unsigned long long) eprocess_ptr->DiskCounters->BytesWritten;
readcount = eprocess_ptr->DiskCounters->ReadOperationCount;
writecount = eprocess_ptr->DiskCounters->WriteOperationCount;
flushcount = eprocess_ptr->DiskCounters->FlushOperationCount;
}
else
{
bytesread = (unsigned long long) (eprocess_ptr->DiskCounters->BytesRead - bytesread);
byteswrite = (unsigned long long) (eprocess_ptr->DiskCounters->BytesWritten - byteswrite);
readcount = eprocess_ptr->DiskCounters->ReadOperationCount - readcount;
writecount = eprocess_ptr->DiskCounters->WriteOperationCount - writecount;
flushcount = eprocess_ptr->DiskCounters->FlushOperationCount - flushcount;
printf("*** Reports disk read/write every second *** \n");
printf("Process name: %s\n", eprocess_ptr->ImageFileName);
printf("Process Id: %d\n", (int) eprocess_ptr->UniqueProcessId);
printf("Bytes Read %llu \n", (unsigned long long) bytesread);
printf("Bytes Written %llu \n", (unsigned long long) byteswrite);
printf("Read Operation Count %d \n", readcount);
printf("Write Operation Count %d \n",writecount);
printf("Flush Operation Count %d \n", flushcount);
bytesread = (unsigned long long) eprocess_ptr->DiskCounters->BytesRead;
byteswrite = (unsigned long long) eprocess_ptr->DiskCounters->BytesWritten;
readcount = eprocess_ptr->DiskCounters->ReadOperationCount;
writecount = eprocess_ptr->DiskCounters->WriteOperationCount;
flushcount = eprocess_ptr->DiskCounters->FlushOperationCount;
}
}
else
{
printf("No matching process found for %s \n", $1);
exit(0);
}
}
ファイルを diskuagebyname.d として保存し、-s オプションを使用してテスト スクリプトを実行します。 必要な exe の名前を、Notepad.exe のように、大文字と小文字を区別して指定します
C:\>dtrace -s diskusagebyname.d Notepad.exe
*** Reports disk read/write every second ***
Process name: Notepad.exe
Process Id: 6012
Bytes Read 0
Bytes Written 0
Read Operation Count 0
Write Operation Count 0
Flush Operation Count 0
*** Reports disk read/write every second ***
Process name: cmd.exe
Process Id: 4428
Bytes Read 18446744073709480960
Bytes Written 18446744073709522944
Read Operation Count -5
Write Operation Count -7
Flush Operation Count 0
ディスク アクティビティの実行中のログを保持するには、次に示すように、コマンドの出力をテキスト ファイルにリダイレクトします。
C:\>dtrace -s diskusagebyname.d Notepad.exe>>diskstats.txt
メモリ使用量のダンプ
一部の診断では、状況を理解するためにカーネル構造をダンプする必要があります。 このコードは、システム メモリの使用量をダンプする例を示しています。 次の D スクリプトは、タイマー プローブを 3 秒ごとに発生させ、システム メモリの使用量を更新します。
#pragma D option quiet
#pragma D option destructive
tick-3s
{
system ("cls");
this->pp = ((struct nt`_MI_PARTITION *) &nt`MiSystemPartition);
printf("***** Printing System wide page information ******* \n");
printf( "Total Pages Entire Node: %u MB \n", this->pp->Core.NodeInformation->TotalPagesEntireNode*4096/(1024*1024));
printf("Total Available Pages: %u Mb \n", this->pp->Vp.AvailablePages*4096/(1024*1024));
printf("Total ResAvail Pages: %u Mb \n", this->pp->Vp.ResidentAvailablePages*4096/(1024*1024));
printf("Total Shared Commit: %u Mb \n", this->pp->Vp.SharedCommit*4096/(1024*1024));
printf("Total Pages for PagingFile: %u Mb \n", this->pp->Vp.TotalPagesForPagingFile*4096/(1024*1024));
printf("Modified Pages : %u Mb \n", this->pp->Vp.ModifiedPageListHead.Total*4096/(1024*1024));
printf("Modified No Write Page Count : %u Mb \n", this->pp->Vp.ModifiedNoWritePageListHead.Total*4096/(1024*1024));
printf("Bad Page Count : %d Mb \n", this->pp->PageLists.BadPageListHead.Total*4096/(1024*1024));
printf("Zero Page Count : %d Mb \n", this->pp->PageLists.ZeroedPageListHead.Total*4096/(1024*1024));
printf("Free Page Count : %d Mb \n", this->pp->PageLists.FreePageListHead.Total*4096/(1024*1024));
/********** Printing Commit info ******************/
this->commit = ((struct nt`_MI_PARTITION_COMMIT ) ((struct nt`_MI_PARTITION *) &nt`MiSystemPartition)->Commit);
printf("***** Printing Commit Info ******* \n");
printf("Total Committed Pages: %u Mb \n", this->pp->Vp.TotalCommittedPages*4096/(1024*1024));
printf("Total Commit limit: %u Mb \n", this->pp->Vp.TotalCommitLimit*4096/(1024*1024));
printf("Peak Commitment: %u Mb \n", this->commit.PeakCommitment*4096/(1024*1024));
printf("Low Commit Threshold: %u Mb \n", this->commit.LowCommitThreshold*4096/(1024*1024));
printf("High Commit Threshold: %u Mb \n", this->commit.HighCommitThreshold*4096/(1024*1024));
printf("System Commit Reserve: %u Mb \n", this->commit.SystemCommitReserve*4096/(1024*1024));
}
ファイルを dumpmemoryusage.d として保存します。
このサンプルはシンボルを使用するため、インストールで説明されているようにシンボル パスを設定します。
set _NT_SYMBOL_PATH=srv*C:\symbols*https://msdl.microsoft.com/download/symbols
-s オプションを使用してテスト スクリプトを実行します。
C:\>dtrace -s dumpmemoryusage.d
***** Printing System wide page information *******
Total Pages Entire Node: 2823 MB
Total Available Pages: 622 Mb
Total ResAvail Pages: 2369 Mb
Total Shared Commit: 166 Mb
Total Pages for PagingFile: 30 Mb
Modified Pages : 30 Mb
Modified No Write Page Count : 0 Mb
Bad Page Count : 0 Mb
Zero Page Count : 7 Mb
Free Page Count : 0 Mb
***** Printing Commit Info *******
Total Committed Pages: 2401 Mb
Total Commit limit: 4551 Mb
Peak Commitment: 2989 Mb
Low Commit Threshold: 3413 Mb
High Commit Threshold: 4295 Mb
System Commit Reserve: 5 Mb
このプログラムは、メモリの使用量を監視し続けるように設計されています。 Ctrl + C キーを押して終了します。
アクティビティのヒープ解放時間の内訳の識別
このサンプルでは、RtlFreeHeap 関数をサブ関数に分割し、それらの関数の実行にかかる最大時間を表示します。
/* Mark script destructive as we call "cls" in the tick-1sec provider*/
#pragma D option destructive
/* Program to calculate time taken in RtlFreeHeap function. Hit Ctrl-C to break. */
dtrace:::BEGIN
{
counter1 = 0;
}
tick-1sec
{
system ("cls");
printf("count of function hit = %d << Press Ctrl-C to exit >> \n", counter1);
}
/* Instrument entry of RtlFreeHeap*/
pid$1:ntdll:RtlFreeHeap:entry
{
/* self is thread local */
self->ts = timestamp;
self->depth = 0;
counter1++;
}
pid$1:ntdll:RtlFreeHeap:return
/self->ts/
{
this->ts = timestamp - self->ts;
@disttime = quantize(this->ts);
@funcName[probemod,probefunc] = max(this->ts);
self->ts = 0;
}
pid$1:::entry
/ self->ts /
{
self->functime[self->depth] = timestamp;
self->depth++;
}
pid$1:::return
/ self->ts /
{
if (self->depth > 0)
{
self->depth--;
/* this is a local scope */
this->ts = timestamp - self->functime[self->depth];
@funcName[probemod,probefunc] = max(this->ts);
}
}
END
{
system ("cls");
/* Print overall time distribution for RtlFreeHeap */
printa (@disttime);
/* Print top 15 functions along with average time spent executing them */
trunc (@funcName, 15);
printa( @funcName);
}
ファイルを heapfree.d として保存します。
このスクリプトは、プロセス ID または PID を受け取ります。 スクリプトをテストするには、コマンド プロンプトでタスクリストを実行し、目的の PID を見つけます。
C:\>tasklist
Image Name PID Session Name Session# Mem Usage
========================= ======== ================ =========== ============
System Idle Process 0 Services 0 8 K
System 4 Services 0 108 K
Registry 72 Services 0 35,576 K
...
Notepad.exe 7944 31C5CE94259D4006 2 20,736 K
パラメーターとして PID を指定し、-s オプションを使用して、次のようにテスト スクリプトを実行します。
C:\>dtrace -s heapfree.d 7944
count of function hit = 28 <<Press Ctrl-C to exit>>
PID に関連付けられているプログラムで、関心のある何らかのタスク (たとえば、メモ帳での入力や、フォントの変更) を実行します。
Ctrl キーを押しながら C キーを押すと、スタック情報と共にヒープの使用状況が表示されます。
value ------------- Distribution ------------- count
4096 | 0
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 23
16384 |@@@@@@ 4
32768 | 0
65536 | 0
131072 |@ 1
262144 | 0
ntdll RtlTryEnterCriticalSection 9444
ntdll RtlGetCurrentServiceSessionId 12302
ntdll RtlFreeHeap 151354
メモリ プールの追跡
注: このスクリプトを実行するときには、aggsortkeypos 変数を設定します。 この変数は、最初のインデックス (サイズ) に基づいて出力を並べ替えるように D-Trace に通知します。
使用法:
dtrace -s <script.d> <Time> <Tag> -x aggsortkey -x aggsortkeypos=1
KSec リークを追跡する例: dtrace -s PoolTrackingSummary.d "120s" 0x6365734b -x aggsortkey -x aggsortkeypos=1
<Tag>
値は、メモリ プール タグのエンコードされた ASCII 値です。 たとえば、nt ファイル システムのタグ値 (NtFf) をエンコードするには、最初に 2 つの文字セットを逆転して、fFtN にします。 ASCII 文字を 16 進数に変換すると、46 66 74 4e になります。プログラムのパラメーターとしては、0x4666744e になります。
別の例として、Ksec の変換があります。
最初に文字の順序を逆にします: cesK
その後、これらの文字を 16 進数に変換し、63 65 73 4b にします。プログラムへのパラメーターとしては、0x6365734b です。
プール タグと一致させるために、大文字と小文字の区別が重要であることに注意してください。
出力: スクリプトは 120 秒間実行され、KSec の割り当て/解放の概要が出力されます。 これは、必要な任意の時間に設定できます。
#pragma D option destructive
#pragma D option quiet
#pragma D option dynvarsize=240m
#pragma D option bufsize=120m
#pragma D option aggsize=120m
fbt:nt:ExAllocatePoolWithTag:entry
{
/* This is E100 in reserve. Convert ASCII to Hex => Hex('001E').*/
if (arg2 == $2)
{
self->size = (unsigned int) arg1;
@allocstack[stack(), self->size] = count();
}
}
fbt:nt:ExAllocatePoolWithTag:return
/self->size/
{
@mem[(uintptr_t) arg1] = sum(1);
addr[(uintptr_t) arg1] = 1;
/* printf("%Y: Execname %s allocated size %d bytes return ptr %x", walltimestamp, execname, (uint64_t) self->size, (uintptr_t) arg1 );*/
size[(uintptr_t) arg1] = self->size;
@sizealloc[self->size] = count();
@delta[self->size] = sum(1);
self->size = 0;
}
fbt:nt:ExFreePoolWithTag:entry
/addr[(uintptr_t) arg0]/
{
@mem[(uintptr_t) arg0] = sum (-1);
addr[(uintptr_t) arg0] -= 1;
@sizefree[size[(uintptr_t) arg0]] = count();
@delta[size[(uintptr_t) arg0]] = sum(-1);
}
tick-$1
{
exit(0);
}
END
{
printf("%10s %10s %10s %10s\n", "SIZE", "ALLOC", "FREE", "DELTA");
printa("%10d %@10d %@10d %@10d\n", @sizealloc, @sizefree, @delta);
printf("Printing stacks \n");
printa (@allocstack);
printf("== REPORT ==\n\n");
printa("0x%x => %@u\n",@mem);
}
ファイルを pooltrackingsummary.d として保存し、-s オプションを使用してテスト スクリプトを実行して、タグ値と上で説明したその他のパラメーターを指定します。
120s オプションでは、プログラムは 2 分間実行されます。 その間は、Windows を使用して、監視対象のメモリ プールを動作させます。 たとえば、Web ブラウザーやその他のプログラムの読み込みとアンロードを行います。
C:\>dtrace -s pooltrackingsummary.d "120s" 0x4666744e -x aggsortkey -x aggsortkeypos=1
SIZE ALLOC FREE DELTA
1552 16 0 16
Printing stacks
Ntfs.sys`NtfsCreateFcb+0x388
Ntfs.sys`NtfsCreateNewFile+0xaa8
Ntfs.sys`NtfsCommonCreate+0x2303
Ntfs.sys`NtfsFsdCreate+0x284
nt`IofCallDriver+0x55
FLTMGR.SYS`FltpLegacyProcessingAfterPreCallbacksCompleted+0x1b9
FLTMGR.SYS`FltpCreate+0x324
nt`IofCallDriver+0x55
nt`IoCallDriverWithTracing+0x34
nt`IopParseDevice+0x6ac
nt`ObpLookupObjectName+0x3fe
nt`ObOpenObjectByNameEx+0x1fa
nt`IopCreateFile+0x40f
nt`NtCreateFile+0x79
nt`KiSystemServiceCopyEnd+0x38
1552 3
Ntfs.sys`NtfsCreateFcb+0x388
Ntfs.sys`NtfsOpenFile+0x2d7
Ntfs.sys`NtfsCommonCreate+0x25a8
Ntfs.sys`NtfsFsdCreate+0x284
nt`IofCallDriver+0x55
FLTMGR.SYS`FltpLegacyProcessingAfterPreCallbacksCompleted+0x1b9
FLTMGR.SYS`FltpCreate+0x324
nt`IofCallDriver+0x55
nt`IoCallDriverWithTracing+0x34
nt`IopParseDevice+0x6ac
nt`ObpLookupObjectName+0x3fe
nt`ObOpenObjectByNameEx+0x1fa
nt`IopCreateFile+0x40f
nt`NtCreateFile+0x79
nt`KiSystemServiceCopyEnd+0x38
1552 4
Ntfs.sys`NtfsCreateFcb+0x388
Ntfs.sys`NtfsOpenFile+0x2d7
Ntfs.sys`NtfsCommonCreate+0x25a8
Ntfs.sys`NtfsFsdCreate+0x284
nt`IofCallDriver+0x55
FLTMGR.SYS`FltpLegacyProcessingAfterPreCallbacksCompleted+0x1b9
FLTMGR.SYS`FltpCreate+0x324
nt`IofCallDriver+0x55
nt`IoCallDriverWithTracing+0x34
nt`IopParseDevice+0x6ac
nt`ObpLookupObjectName+0x3fe
nt`ObOpenObjectByNameEx+0x1fa
nt`IopCreateFile+0x40f
nt`NtOpenFile+0x58
nt`KiSystemServiceCopyEnd+0x38
1552 3
...
== REPORT ==
0xffffd304c98dd380 => 1
0xffffd304cc4655a0 => 1
0xffffd304cccf15a0 => 1
0xffffd304ccdeb990 => 1
0xffffd304ce048760 => 1
0xffffd304cf1ee990 => 1
0xffffd304d0473010 => 1
0xffffd304d12075a0 => 1
0xffffd304d14135a0 => 1
0xffffd304d1674010 => 1
0xffffd304d33b3660 => 1
0xffffd304d3b29010 => 1
0xffffd304d42c6010 => 1
0xffffd304d48b2010 => 1
0xffffd304de1fa5f0 => 1
0xffffd304e1ad56a0 => 1
GUID の比較
DTrace は GUID をネイティブにサポートしていませんが、このサンプル コードに示すように構造体を作成して操作できます。 以下に、GUID を比較する方法のサンプルを示します。
nt`_GUID guidcmp;
/* Sleep After GUID: 29f6c1db-86da-48c5-9fdb-f2b67b1f44da */
dtrace:::BEGIN
{
printf("Begin\n");
guidcmp.Data1 = 0x29f6c1db;
guidcmp.Data2 = 0x86da;
guidcmp.Data3 = 0x48c5;
guidcmp.Data4[0] = 0x9f;
guidcmp.Data4[1] = 0xdb;
guidcmp.Data4[2] = 0xf2;
guidcmp.Data4[3] = 0xb6;
guidcmp.Data4[4] = 0x7b;
guidcmp.Data4[5] = 0x1f;
guidcmp.Data4[6] = 0x44;
guidcmp.Data4[7] = 0xda;
}
pid$target:PowrProf:PowerReadACValueIndexEx:entry
{
cidstr = (nt`_GUID *) (copyin(arg2, sizeof(nt`_GUID)));
printf("\nPrinting GUID to compare\n");
print(guidcmp);
printf("\nPrinting GUID received \n");
print(*cidstr);
if ( (cidstr->Data1 == guidcmp.Data1) &&
(cidstr->Data2 == guidcmp.Data2) &&
(cidstr->Data3 == guidcmp.Data3) &&
(cidstr->Data4[0] == guidcmp.Data4[0]) &&
(cidstr->Data4[1] == guidcmp.Data4[1]) &&
(cidstr->Data4[2] == guidcmp.Data4[2]) &&
(cidstr->Data4[3] == guidcmp.Data4[3]) &&
(cidstr->Data4[4] == guidcmp.Data4[4]) &&
(cidstr->Data4[5] == guidcmp.Data4[5]) &&
(cidstr->Data4[6] == guidcmp.Data4[6]) &&
(cidstr->Data4[7] == guidcmp.Data4[7]) )
{
printf("GUID matched \n");
}
else
{
printf("No match");
}
}
dtrace:::END
{
printf("End\n");
}
次に示すパラメーターを指定して、ファイルを comparequid.d として保存し、-s オプションを使用してテスト スクリプトを実行します。
C:\Windows\system32>dtrace -s compareguid.d -c "powercfg /qh scheme_current sub_sleep standbyidle"
dtrace: script 'compareguid.d' matched 9 probes
CPU ID FUNCTION:NAME
0 1 :BEGIN Begin
Power Scheme GUID: 381b4222-f694-41f0-9685-ff5bb260df2e (Balanced)
GUID Alias: SCHEME_BALANCED
Subgroup GUID: 238c9fa8-0aad-41ed-83f4-97be242c8f20 (Sleep)
GUID Alias: SUB_SLEEP
Power Setting GUID: 29f6c1db-86da-48c5-9fdb-f2b67b1f44da (Sleep after)
GUID Alias: STANDBYIDLE
Minimum Possible Setting: 0x00000000
Maximum Possible Setting: 0xffffffff
Possible Settings increment: 0x00000001
Possible Settings units: Seconds
Current AC Power Setting Index: 0x00000708
Current DC Power Setting Index: 0x00000384
dtrace: pid 7560 has exited
0 42695 PowerReadACValueIndexEx:entry
Printing GUID to compare
struct _GUID {
UInt32 Data1 = 0x29f6c1db
UInt16 Data2 = 0x86da
UInt16 Data3 = 0x48c5
UInt8 [8] Data4 = [ 0x9f, 0xdb, 0xf2, 0xb6, 0x7b, 0x1f, 0x44, 0xda ]
}
Printing GUID received
struct _GUID {
UInt32 Data1 = 0x29f6c1db
UInt16 Data2 = 0x86da
UInt16 Data3 = 0x48c5
UInt8 [8] Data4 = [ 0x9f, 0xdb, 0xf2, 0xb6, 0x7b, 0x1f, 0x44, 0xda ]
}
0 42695 PowerReadACValueIndexEx:entry GUID matched