1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.

Simple way to trace DPCs and ISRs

Discussion in 'Operating Systems' started by mbk1969, Nov 12, 2018.

  1. mbk1969

    mbk1969 Ancient Guru

    Messages:
    7,334
    Likes Received:
    3,842
    GPU:
    GeForce GTX 1070
    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
    [​IMG]

    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:
    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
    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.
     
    Last edited: Nov 12, 2018
    BetA, user1 and akbaar like this.
  2. mbk1969

    mbk1969 Ancient Guru

    Messages:
    7,334
    Likes Received:
    3,842
    GPU:
    GeForce GTX 1070
    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. Astyanax

    Astyanax Ancient Guru

    Messages:
    2,072
    Likes Received:
    496
    GPU:
    GTX 1080ti
    DPC and ISR values obtained during system load are invalid.
     
  4. mbk1969

    mbk1969 Ancient Guru

    Messages:
    7,334
    Likes Received:
    3,842
    GPU:
    GeForce GTX 1070
    Why are you talking about obtaining DPC and ISR during system load?
     

  5. Astyanax

    Astyanax Ancient Guru

    Messages:
    2,072
    Likes Received:
    496
    GPU:
    GTX 1080ti
    >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.
     
  6. mbk1969

    mbk1969 Ancient Guru

    Messages:
    7,334
    Likes Received:
    3,842
    GPU:
    GeForce GTX 1070
    Who cares what vendors do? It is just a way to find possible culprit, troubleshoot, and change the vendor if troubleshooting was not successful.
     
  7. limeay

    limeay Member

    Messages:
    47
    Likes Received:
    0
    GPU:
    Nvidia GTX 1080 Ti
    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
     
  8. mbk1969

    mbk1969 Ancient Guru

    Messages:
    7,334
    Likes Received:
    3,842
    GPU:
    GeForce GTX 1070
    Latencymon doesn`t offer detailed info on DPCs and ISRs.
     

Share This Page