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-hardware/get-started/adk-install For my Win10 1803 it costs 2. Launch elevated command prompt and execute to start the trace: Code: 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: Code: 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: Code: 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: Spoiler Code: -------------------------- 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 Spoiler Code: -------------------------- 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.
And "Windows Performance Toolkit" comes with GUI tools "Windows Performance Recorder" and "Windows Performance Analyzer" as well. I started to prepare screenshots with these tools but decided to write only about "xperf" usage as a simplest one. But you can open etl-files in "Windows Performance Analyzer" and view raw ETW info in sophisticated and complicated way to feel as very smart person.
>3. Run the game, the video, or whatever you are trying to troubleshoot. none of the vendors will accept DPC/ISR bug reports when the device is busy.
Who cares what vendors do? It is just a way to find possible culprit, troubleshoot, and change the vendor if troubleshooting was not successful.
I've heard of this but majority use latencymon... I should try this whenever I have enough time and my craptastic internet becomes more stable again. ATT sucking it with DNS probe problems... this I believe is across the U.S
When I try this, I get this error: xperf: error: NT Kernel Logger: Cannot create a file when that file already exists. (0xb7). Any idea why? Googling reveals others suggesting this can happen if Process Monitor/Hacker/Explorer is open at the time, however, I definitely have all of them closed.
Is it possible to just observe one module? e.g. ndis.sys? Also I've tried running this and some of the commands don't work like: $date = date start-sleep -s 5 write-host "started" start-sleep -s 30 This seems to work but I also don't know what to expect here as well. xperf -on Latency -stackwalk profile -BufferSize 1024 Should I run your command? The "xperf -on base+interrupt+dpc"? https://github.com/djdallmann/GamingPCSetup/blob/master/CONTENT/SCRIPTS/xperfdpcisr.ps1
Let`s see what a kernel provider offers - output of "xperf -providers K" command: Code: Kernel Flags: PROC_THREAD : Process and Thread create/delete LOADER : Kernel and user mode Image Load/Unload events PROFILE : CPU Sample profile CSWITCH : Context Switch COMPACT_CSWITCH: Compact Context Switch DISPATCHER : CPU Scheduler DPC : DPC Events IDEAL_PROC : Ideal processor events INTERRUPT : Interrupt events INTERRUPT_STEER: Interrupt Steering events WDF_DPC : WDF DPC events WDF_INTERRUPT : WDF Interrupt events SYSCALL : System calls PRIORITY : Priority change events SPINLOCK : Spinlock Collisions KQUEUE : Kernel Queue Enqueue/Dequeue ALPC : Advanced Local Procedure Call PERF_COUNTER : Process Perf Counters DISK_IO : Disk I/O DISK_IO_INIT : Disk I/O Initiation FILE_IO : File system operation end times and results FILE_IO_INIT : File system operation (create/open/close/read/write) HARD_FAULTS : Hard Page Faults FILENAME : FileName (e.g., FileName create/delete/rundown) SPLIT_IO : Split I/O REGISTRY : Registry tracing REG_HIVE : Registry hive tracing DRIVERS : Driver events POWER : Power management events CC : Cache manager events NETWORKTRACE : Network events (e.g., tcp/udp send/receive) VIRT_ALLOC : Virtual allocation reserve and release MEMINFO : Memory List Info ALL_FAULTS : All page faults including hard, Copy on write, demand zero faults, etc. MEMINFO_WS : Working set Info VAMAP : MapFile info FOOTPRINT : Support footprint analysis MEMORY : Memory tracing REFSET : Support footprint analysis HIBERRUNDOWN : Rundown(s) during hibernate CONTMEMGEN : Contiguous Memory Generation POOL : Pool tracing SHOULDYIELD : Tracing for the cooperative DPC mechanism VTL_CHANGE : VTL1 Entry and Exit CPU_CONFIG : NUMA topology, Processor Group and Processor Index to Number mapping. By default it is always enabled. SESSION : Session rundown/create/delete events. IDLE_STATES : CPU Idle States TIMER : Timer settings and its expiration CLOCKINT : Clock Interrupt Events IPI : Inter-processor Interrupt Events OPTICAL_IO : Optical I/O OPTICAL_IO_INIT: Optical I/O Initiation FLT_IO_INIT : Minifilter callback initiation FLT_IO : Minifilter callback completion FLT_FASTIO : Minifilter fastio callback completion FLT_IO_FAILURE : Minifilter callback completion with failure OB_HANDLE : Object handle events OB_OBJECT : Object events KE_CLOCK : Clock Configuration events PMC_PROFILE : PMC sampling events DPC_QUEUE : DPC queue events CACHE_FLUSH : Cache flush events DEBUG_EVENTS : Debugger scheduling events HV_CALLOUTS : NT Hypercalls into HyperV Events Kernel Groups: Base : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+PROFILE+MEMINFO+MEMINFO_WS Diag : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+DPC+INTERRUPT+CSWITCH+PERF_COUNTER+COMPACT_CSWITCH DiagEasy : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+DPC+INTERRUPT+CSWITCH+PERF_COUNTER Latency : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+DPC+INTERRUPT+CSWITCH+PROFILE FileIO : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+FILE_IO+FILE_IO_INIT IOTrace : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+CSWITCH ResumeTrace : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+PROFILE+POWER SysProf : PROC_THREAD+LOADER+PROFILE ResidentSet : PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+MEMORY+MEMINFO+VAMAP+SESSION+VIRT_ALLOC ReferenceSet : PROC_THREAD+LOADER+HARD_FAULTS+MEMORY+FOOTPRINT+VIRT_ALLOC+MEMINFO+VAMAP+SESSION+REFSET+MEMINFO_WS Network : PROC_THREAD+LOADER+NETWORKTRACE Kernel flags and groups are the strings which can be used with "xperf -on " command - https://docs.microsoft.com/en-us/windows-hardware/test/wpt/start: So "base+interrupt+dpc" command option in OP is a combination of kernel flags: PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+PROFILE+MEMINFO+MEMINFO_WS + INTERRUPT + DPC where "latency" command option is a combination of flags: PROC_THREAD+LOADER+DISK_IO+HARD_FAULTS+PROFILE+CSWITCH+INTERRUPT+DPC You can see that both command options contain INTERRUPT and DPC flags. "-stackwalk" parameter is about the API functions calls - https://docs.microsoft.com/en-us/windows-hardware/test/wpt/stackwalk, so I do not know why it was used there. So the command "xperf -on base+interrupt+dpc" gives the same results as "xperf -on latency".
I'm trying to check if the Interrupt Affinity Policy Tool has any effect. It adds the key DevicePolicy to regedit when I set a specific cpu and changes the policy to 'SpecifiedProcessors'. I changed ethernet to cpu 3. I'm not sure if I'm reading this right but the ndis.sys (network?) in the 'Interrupt Info' section shows that only cpu 0 has usec. Does this mean that the policy does nothing (for network at least) to change cpu interrupts ?
There are two tables for CPU usage in report - DPCs and ISRs. DPCs usually are spread across multiple CPUs. ISRs are usually isolated on CPU 0. It is hard to tell whether Interrupt Affinity Policy Tool deals with ISRs only or with DPCs only or with both. You can experiment with ndis.sys to see whether DPCs are affected by setting in Interrupt Affinity Policy Tool.
If you want Interrupts across all cores try the setting in power plan "Interrupt steering settings> Interrupt steering mode = any unparked process. I tried this a yr ago and got pretty good spread across cores. I only tested the setting, I have it at default value now. PS: Use mbk1969 excellent tool PowerSettingExplorer.
