Simple way to measure DPCs and ISRs

Everyone uses Latencymon nowadays to troubleshoot DPC latencies. I stumbled across even simpler way provided by Microsoft.

1. Install “Windows Performance Toolkit” from Windows ADK (for your version of Windows)
https://docs.microsoft.com/en-us/windows…ted/adk-install
For my Win10 1803 it costs


2. Launch elevated command prompt and execute to start the trace:

1
2
3
4
 

cd "C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit"
xperf -on base+interrupt+dpc
 
 


3. Run the game, the video, or whatever you are trying to troubleshoot.

4. Return to command prompt to stop the trace and to save the trace file:
1
2
3
 

xperf -d c:\temp\trace.etl
 
 

Choose your own path and name for that trace file.

5. Generate the text report file for DPCs and ISRs:
1
2
3
 

xperf -i c:\temp\trace.etl -o c:\temp\report.txt -a dpcisr
 
 


6. Now you can open that text report file to browse quite detailed info.
My example for DPCs:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
 

--------------------------
DPC Info
--------------------------
CPU Usage Summing By Module For the Whole Trace
CPU Usage from 0 us to 45524244 us:
CPU 0 Usage, CPU 1 Usage, CPU 2 Usage, CPU 3 Usage, CPU 4 Usage, CPU 5 Usage, CPU 6 Usage, CPU 7 Usage, CPU 8 Usage, CPU 9 Usage, CPU 10 Usage, CPU 11 Usage,
usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, Module
0 0.00, 0 0.00, 27 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, CLASSPNP.SYS
3180 0.01, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, HDAudBus.sys
45 0.00, 0 0.00, 1 0.00, 2 0.00, 31 0.00, 0 0.00, 9 0.00, 2 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, Ndu.sys
5 0.00, 0 0.00, 5 0.00, 0 0.00, 23 0.00, 0 0.00, 7 0.00, 0 0.00, 8 0.00, 0 0.00, 0 0.00, 0 0.00, Ntfs.sys
211 0.00, 0 0.00, 23 0.00, 7 0.00, 36 0.00, 0 0.00, 13 0.00, 7 0.00, 0 0.00, 15 0.00, 7 0.00, 8 0.00, USBPORT.SYS
14 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, WdFilter.sys
2852 0.01, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, asmtxhci.sys
27992 0.06, 0 0.00, 108 0.00, 8 0.00, 208 0.00, 0 0.00, 55 0.00, 14 0.00, 8 0.00, 8 0.00, 34 0.00, 9 0.00, dxgkrnl.sys
247 0.00, 0 0.00, 41 0.00, 0 0.00, 97 0.00, 5 0.00, 32 0.00, 11 0.00, 18 0.00, 3 0.00, 36 0.00, 5 0.00, dxgmms2.sys
1 0.00, 0 0.00, 5 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, hal.dll
14 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, kbdhid.sys
681 0.00, 0 0.00, 43 0.00, 22 0.00, 101 0.00, 0 0.00, 16 0.00, 0 0.00, 19 0.00, 23 0.00, 12 0.00, 13 0.00, ndis.sys
32259 0.07, 510 0.00, 4375 0.01, 1879 0.00, 10845 0.02, 1776 0.00, 4951 0.01, 2481 0.01, 2466 0.01, 2638 0.01, 7674 0.02, 3018 0.01, ntoskrnl.exe
167796 0.37, 0 0.00, 147 0.00, 60 0.00, 459 0.00, 7 0.00, 93 0.00, 36 0.00, 7 0.00, 32 0.00, 85 0.00, 4 0.00, nvlddmkm.sys
0 0.00, 0 0.00, 0 0.00, 0 0.00, 6 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, rdyboost.sys
82 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, storahci.sys
939 0.00, 21 0.00, 649 0.00, 82 0.00, 896 0.00, 0 0.00, 1113 0.00, 9 0.00, 428 0.00, 929 0.00, 842 0.00, 22 0.00, storport.sys
64 0.00, 15 0.00, 302 0.00, 128 0.00, 145 0.00, 0 0.00, 324 0.00, 4 0.00, 0 0.00, 106 0.00, 0 0.00, 298 0.00, tcpip.sys
 
Total = 17090
Elapsed Time, > 0 usecs AND <= 1 usecs, 977, or 5.72%
Elapsed Time, > 1 usecs AND <= 2 usecs, 1067, or 6.24%
Elapsed Time, > 2 usecs AND <= 4 usecs, 3668, or 21.46%
Elapsed Time, > 4 usecs AND <= 8 usecs, 4017, or 23.50%
Elapsed Time, > 8 usecs AND <= 16 usecs, 1486, or 8.70%
Elapsed Time, > 16 usecs AND <= 32 usecs, 1711, or 10.01%
Elapsed Time, > 32 usecs AND <= 64 usecs, 3634, or 21.26%
Elapsed Time, > 64 usecs AND <= 128 usecs, 457, or 2.67%
Elapsed Time, > 128 usecs AND <= 256 usecs, 73, or 0.43%
Total, 17090
 
Total = 5453 for module ntoskrnl.exe
Elapsed Time, > 0 usecs AND <= 1 usecs, 108, or 1.98%
Elapsed Time, > 1 usecs AND <= 2 usecs, 313, or 5.74%
Elapsed Time, > 2 usecs AND <= 4 usecs, 1537, or 28.19%
Elapsed Time, > 4 usecs AND <= 8 usecs, 1277, or 23.42%
Elapsed Time, > 8 usecs AND <= 16 usecs, 431, or 7.90%
Elapsed Time, > 16 usecs AND <= 32 usecs, 834, or 15.29%
Elapsed Time, > 32 usecs AND <= 64 usecs, 946, or 17.35%
Elapsed Time, > 64 usecs AND <= 128 usecs, 5, or 0.09%
Elapsed Time, > 128 usecs AND <= 256 usecs, 2, or 0.04%
Total, 5453
 
...
 
 



and for ISRs

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
 

--------------------------
Interrupt Info
--------------------------
CPU Usage Summing By Module For the Whole Trace
CPU Usage from 0 us to 45524244 us:
CPU 0 Usage, CPU 1 Usage, CPU 2 Usage, CPU 3 Usage, CPU 4 Usage, CPU 5 Usage, CPU 6 Usage, CPU 7 Usage, CPU 8 Usage, CPU 9 Usage, CPU 10 Usage, CPU 11 Usage,
usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, usec %, Module
4328 0.01, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, HDAudBus.sys
1747 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, asmtxhci.sys
235333 0.52, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, dxgkrnl.sys
767 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, ndis.sys
2903 0.01, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, 0 0.00, storport.sys
 
Total = 6733
Elapsed Time, > 0 usecs AND <= 1 usecs, 248, or 3.68%
Elapsed Time, > 1 usecs AND <= 2 usecs, 277, or 4.11%
Elapsed Time, > 2 usecs AND <= 4 usecs, 470, or 6.98%
Elapsed Time, > 4 usecs AND <= 8 usecs, 907, or 13.47%
Elapsed Time, > 8 usecs AND <= 16 usecs, 513, or 7.62%
Elapsed Time, > 16 usecs AND <= 32 usecs, 965, or 14.33%
Elapsed Time, > 32 usecs AND <= 64 usecs, 1272, or 18.89%
Elapsed Time, > 64 usecs AND <= 128 usecs, 2080, or 30.89%
Elapsed Time, > 128 usecs AND <= 256 usecs, 1, or 0.01%
Total, 6733
 
Total = 728 for module HDAudBus.sys
Elapsed Time, > 0 usecs AND <= 1 usecs, 0, or 0.00%
Elapsed Time, > 1 usecs AND <= 2 usecs, 0, or 0.00%
Elapsed Time, > 2 usecs AND <= 4 usecs, 0, or 0.00%
Elapsed Time, > 4 usecs AND <= 8 usecs, 670, or 92.03%
Elapsed Time, > 8 usecs AND <= 16 usecs, 53, or 7.28%
Elapsed Time, > 16 usecs AND <= 32 usecs, 4, or 0.55%
Elapsed Time, > 32 usecs AND <= 64 usecs, 0, or 0.00%
Elapsed Time, > 64 usecs AND <= 128 usecs, 1, or 0.14%
Total, 728
 
...
 
 



where "us", "usec" and "usecs" stand for "microseconds".
You can see how many DPCs/ISRs for each module fall to ranges - between 0 and 1 microseconds, between 1 and 2 microseconds, and so forth.
Also you can see summaries for DPCs and ISRs per CPU.