Udostępnij przez


Przykłady kodu DTrace

Funkcja DTrace obsługuje język programowania D. Ten temat zawiera przykłady kodu D.

Aby uzyskać ogólne informacje na temat funkcji DTrace w systemie Windows, zobacz DTrace.

Aby uzyskać szczegółowe informacje o DTrace, zobacz Specyfikację OpenDTrace w wersji 1.0 na Uniwersytecie w Cambridge.

Uwaga / Notatka

Narzędzie DTrace jest obsługiwane w kompilacjach niejawnych systemu Windows po wersji 18980 i Windows Server Build 18975.

Dodatkowe przykładowe skrypty

Dodatkowe skrypty D stosowane w scenariuszach systemu Windows są dostępne w katalogu przykładów kodu źródłowego DTrace.

https://github.com/microsoft/DTrace-on-Windows/tree/windows/samples/windows

Zestaw przydatnych skryptów zestawu narzędzi opentrace jest dostępny pod adresem https://github.com/opendtrace/toolkit.

Użycie dysku według nazwy

Ten skrypt udostępnia liczniki dysków dla danej nazwy pliku wykonywalnego. Nazwa pliku wykonywalnego uwzględnia wielkość liter i jest udostępniana w wierszu polecenia po uruchomieniu skryptu.


#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);
	}
}

Zapisz plik jako diskuagebyname.d i użyj opcji -s, aby uruchomić skrypt testowy. Podaj nazwę pliku exe z uwzględnieniem wielkości liter, na przykład 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 

Aby zachować uruchomiony dziennik aktywności dysku, przekieruj polecenie do pliku tekstowego, jak pokazano tutaj.

C:\>dtrace -s diskusagebyname.d Notepad.exe>>diskstats.txt

Zrzucanie użycia pamięci

W niektórych przypadkach diagnostycznych istnieje potrzeba zrzutu struktur jądra, aby lepiej zrozumieć sytuację. Ten kod przedstawia przykład, jak zrzucić dane o użyciu pamięci systemowej. Poniższy skrypt D uruchamia sondę czasomierza co 3 sekundy i odświeża użycie pamięci systemowej.

#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));
	

}

Zapisz plik jako dumpmemoryusage.d.

W tym przykładzie użyto symboli, więc ustaw ścieżkę symbolu zgodnie z opisem w instalacji.

set _NT_SYMBOL_PATH=srv*C:\symbols*https://msdl.microsoft.com/download/symbols 

Użyj opcji -s, aby uruchomić skrypt testowy.

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 

Ten program jest przeznaczony do dalszego monitorowania użycia pamięci. Naciśnij CTRL+C, aby zakończyć.

Identyfikowanie podziału czasu wolnego sterta dla działania

Ten przykład zawiera podział funkcji RtlFreeHeap na funkcje podrzędne i maksymalny czas potrzebny na wykonanie tych funkcji.

/* 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);
	
}

Zapisz plik jako heapfree.d.

Ten skrypt przyjmuje identyfikator procesu albo PID. Aby przetestować skrypt, uruchom listę zadań w wierszu polecenia i znajdź żądany identyfikator 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

Określ identyfikator PID jako parametr i użyj opcji -s, aby uruchomić skrypt testowy, jak pokazano.

C:\>dtrace -s heapfree.d 7944

count of function hit = 28 <<Press Ctrl-C to exit>>

Wykonaj jakiekolwiek zadanie, które Cię interesuje, w programie z przypisanym PID, na przykład wpisując coś w Notatniku lub zmieniając czcionkę.

Naciśnij CRTL-C, a wyświetli się użycie sterty oraz informacje o stosie.

           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

Śledzenie puli pamięci

Uwaga: uruchom ten skrypt z zestawem zmiennych aggsortkeypos. Ta zmienna informuje D-Trace o sortowaniu danych wyjściowych na podstawie pierwszego indeksu (rozmiar).

Użycie:

dtrace -s <script.d> <Time> <Tag> -x aggsortkey -x aggsortkeypos=1

Przykład śledzenia przecieków KSec: dtrace -s PoolTrackingSummary.d "120s" 0x6365734b -x aggsortkey -x aggsortkeypos=1

Wartość <Tag> jest zakodowaną wartością ASCII tagu puli pamięci. Na przykład, aby zakodować wartość tagu dla systemu plików nt — NtFf, najpierw odwróć dwa zestawy liter, będzie to fFtN. Konwertowanie znaków ASCII na wartości szesnastkowe będzie reprezentowane jako 46 66 74 4e lub 0x4666744e jako parametr do naszego programu.

Innym przykładem jest konwertowanie protokołu Ksec.

Najpierw odwrócić kolejność liter: cesK

Następnie przekonwertuj te znaki na szesnastkowe, 63 65 73 4b lub 0x6365734b jako parametr do naszego programu.

Należy pamiętać, że wielkie małe litery są ważne, aby pasować do tagu puli.

Wynik: skrypt działa przez 120 sekund i generuje podsumowanie alokacji/zwolnienia KSec. Można ustawić tę wartość na dowolną wymaganą godzinę.

#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);
}

Zapisz plik jako pooltrackingsummary.d i użyj opcji -s, aby uruchomić skrypt testowy, podając wartość tagu i inne parametry omówione powyżej.

Opcja 120s, program działa przez dwie minuty. W tym czasie użyj systemu Windows, aby przećwiczyć monitorowaną pulę pamięci. Na przykład załaduj i zwolnij przeglądarkę internetową lub inne programy.

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

Porównywanie identyfikatorów GUID

Mimo że DTrace nie obsługuje natywnie identyfikatorów GUID, można utworzyć strukturę zgodnie z przedstawionym przykładowym kodem, aby z nimi pracować. Oto przykład sposobu porównywania identyfikatorów 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");
}

Zapisz plik jako comparequid.d i użyj opcji -s, aby uruchomić skrypt testowy, podając parametr pokazany poniżej.

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

Zobacz też

DTrace w systemie Windows

DTrace Windows Programming

DTrace ETW

Zrzut na żywo DTrace