• Announcements

    • xper

      MSFN Sponsorship and AdBlockers!   07/10/2016

      Dear members, MSFN is made available via subscriptions, donations and advertising revenue. The use of ad-blocking software hurts the site. Please disable ad-blocking software or set an exception for MSFN. Alternatively, become a site sponsor and ads will be disabled automatically and by subscribing you get other sponsor benefits.
MagicAndre1981

How to get the cause of high CPU usage by DPC / Interrupt

1,451 posts in this topic

do you run your DVD/HDD-drives in IDE/ATAPI or AHCI mode?

Just the one HDD and in IDE mode (UDMA 6). I don't have any optical drives connected at the moment.

0

Share this post


Link to post
Share on other sites

is this an IDE drive or do you run a SATA HDD in IDE mode?

0

Share this post


Link to post
Share on other sites

Uninstall AVG and run this command

xperf -start perf!GeneralProfiles.InBuffer && timeout -1 && xperf -stop perf!GeneralProfiles.InBuffer DetailedTrace.etl

to trace more details. How do you connect at college? Also with Wireless like at home or with LAN? Do you use the latest driver for your Intel® Centrino® Wireless-N 1030?

Yesterday I reinstalled all the updated drivers (for network adapters, graphic cards, BIOS, etc) one by one and the problem got solved after flashing the BIOS. It's weird, a few days ago I had already updated my BIOS and yet this time the problem got completely solved. Haven't seen a single spike in the entire day.

Thanks for the great tutorial though, at least I found out there was something wrong going on. :thumbup

0

Share this post


Link to post
Share on other sites

is this an IDE drive or do you run a SATA HDD in IDE mode?

It's a SATA HDD in IDE mode.

0

Share this post


Link to post
Share on other sites

the problem got solved after flashing the BIOS ... Haven't seen a single spike in the entire day.

nice to hear this :)

It's a SATA HDD in IDE mode.

Why do you do this? AHCI is better and should be always used.

0

Share this post


Link to post
Share on other sites

Why do you do this? AHCI is better and should be always used.

The reviews I've read don't really show a major benefit (unless you need hotswapping or RAID) and there's complications like bootup apps (partition utilities, TrueImage) not working in AHCI mode, plus the whole hassle of switching to AHCI mode without ending up with a system that won't boot.

Anyway, ataport.sys was OK with IDE mode before and I can't see that switching to AHCI mode is going to do anything about the USBPORT.SYS issues.

0

Share this post


Link to post
Share on other sites

OK, I did it. If anything it's worse now!

I still don't know how to get the symbols loaded. Do you want me to upload the trace without them?

_________________________________________________________________________________________________________
CONCLUSION
_________________________________________________________________________________________________________
Your system seems to have difficulty handling real-time audio and other tasks. You may experience drop outs, clicks or pops due to buffer underruns.

One or more DPC routines belonging to a driver running in your system appear to be executing for too long. At least one detected problem appears to be

network related. You may have to disable wireless adapters to get better results.
LatencyMon has been analyzing your system for 0:02:05 (h:mm:ss)


_________________________________________________________________________________________________________
System Information
_________________________________________________________________________________________________________
Computer name: X4
OS version: Windows 7 Service Pack 1, 6.1, build: 7601
CPU: AuthenticAMD AMD Phenom(tm) II X4 955 Processor
Logical processors: 4
RAM: 8574287872 total
VM: 2147352576, free: 1983922176


_________________________________________________________________________________________________________
CPU SPEED
_________________________________________________________________________________________________________
Reported CPU speed: 3200 MHz
Measured CPU speed: 3881 MHz

Note: reported execution times may be calculated based on a fixed reported CPU speed. Disable variable speed settings like Intel Speed Step and AMD

Cool N Quiet in the BIOS setup for more accurate results.


_________________________________________________________________________________________________________
MEASURED KERNEL TIMER LATENCIES
_________________________________________________________________________________________________________
Highest measured kernel timer latency (µs): 470.6730


_________________________________________________________________________________________________________
MEASURED SMIs AND CPU STALLS
_________________________________________________________________________________________________________
Highest measured SMI routine or CPU stall (µs) 2.8797


_________________________________________________________________________________________________________
REPORTED DPCs
_________________________________________________________________________________________________________
Highest DPC routine execution time (µs): 1037.5990
Driver with highest DPC routine execution time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Highest reported total DPC routine time (%): 0.1170
Driver with highest DPC total execution time: USBPORT.SYS - USB 1.1 & 2.0 Port Driver, Microsoft Corporation

Total time spent in DPCs (%) 0.4368

DPC count (execution time <250 µs): 373657
DPC count (execution time 250-500 µs): 0
DPC count (execution time 500-999 µs): 32
DPC count (execution time 1000-1999 µs): 1
DPC count (execution time 2000-3999 µs): 0
DPC count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED ISRs
_________________________________________________________________________________________________________
Highest ISR routine execution time (µs): 31.7549
Driver with highest ISR routine execution time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Highest reported total ISR routine time (%): 0.1184
Driver with highest ISR total time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Total time spent in ISRs (%) 0.1819

ISR count (execution time <250 µs): 321196
ISR count (execution time 250-500 µs): 0
ISR count (execution time 500-999 µs): 0
ISR count (execution time 1000-1999 µs): 0
ISR count (execution time 2000-3999 µs): 0
ISR count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED HARD PAGEFAULTS
_________________________________________________________________________________________________________
Process with highest pagefault count: none

Total number of hard pagefaults 2470
Hard pagefault count of hardest hit process: 1176
Highest hard pagefault resolution time (µs): 4292441.3446
Total time spent in hard pagefaults (%): 16.6845
TODO: Number of processes hit: 0


_________________________________________________________________________________________________________
PER CPU DATA
_________________________________________________________________________________________________________
CPU 0 ISR count: 122469
CPU 0 ISR highest execution time: 19.2640
CPU 0 ISR total execution time: 281776.4290
CPU 0 DPC count: 262351
CPU 0 DPC highest execution time: 422.8462
CPU 0 DPC total execution time: 969034.7381
_________________________________________________________________________________________________________
CPU 1 ISR count: 1397
CPU 1 ISR highest execution time: 23.5578
CPU 1 ISR total execution time: 5120.3378
CPU 1 DPC count: 4242
CPU 1 DPC highest execution time: 127.4000
CPU 1 DPC total execution time: 34144.6971
_________________________________________________________________________________________________________
CPU 2 ISR count: 8540
CPU 2 ISR highest execution time: 27.3062
CPU 2 ISR total execution time: 29979.4706
CPU 2 DPC count: 6523
CPU 2 DPC highest execution time: 1037.5990
CPU 2 DPC total execution time: 67178.8306
_________________________________________________________________________________________________________
CPU 3 ISR count: 188790
CPU 3 ISR highest execution time: 31.7549
CPU 3 ISR total execution time: 599794.6865
CPU 3 DPC count: 100574
CPU 3 DPC highest execution time: 149.9778
CPU 3 DPC total execution time: 1130416.2149
_________________________________________________________________________________________________________

0

Share this post


Link to post
Share on other sites

Here you go. I'm seeing absolutely atrocious DPC and ISR execution times now.

_________________________________________________________________________________________________________
CONCLUSION
_________________________________________________________________________________________________________
Your system appears to be having trouble handling real-time audio and other tasks. You are likely to experience buffer underruns appearing as drop outs, clicks or pops. One or more DPC routines belonging to a driver running in your system appear to be executing for too long.
LatencyMon has been analyzing your system for 0:01:25 (h:mm:ss)


_________________________________________________________________________________________________________
System Information
_________________________________________________________________________________________________________
Computer name: X4
OS version: Windows 7 Service Pack 1, 6.1, build: 7601
CPU: AuthenticAMD AMD Phenom(tm) II X4 955 Processor
Logical processors: 4
RAM: 8574287872 total
VM: 2147352576, free: 1972219904


_________________________________________________________________________________________________________
CPU SPEED
_________________________________________________________________________________________________________
Reported CPU speed: 3200 MHz
Measured CPU speed: 1578 MHz

Note: reported execution times may be calculated based on a fixed reported CPU speed. Disable variable speed settings like Intel Speed Step and AMD Cool N Quiet in the BIOS setup for more accurate results.


_________________________________________________________________________________________________________
MEASURED KERNEL TIMER LATENCIES
_________________________________________________________________________________________________________
Highest measured kernel timer latency (µs): 561.8639


_________________________________________________________________________________________________________
MEASURED SMIs AND CPU STALLS
_________________________________________________________________________________________________________
Highest measured SMI routine or CPU stall (µs) 0.6399


_________________________________________________________________________________________________________
REPORTED DPCs
_________________________________________________________________________________________________________
Highest DPC routine execution time (µs): 799212727025.6250
Driver with highest DPC routine execution time: netbt.sys - MBT Transport driver, Microsoft Corporation

Highest reported total DPC routine time (%): 234447.4868
Driver with highest DPC total execution time: USBPORT.SYS - USB 1.1 & 2.0 Port Driver, Microsoft Corporation

Total time spent in DPCs (%) 234448.4756

DPC count (execution time <250 µs): 375423
DPC count (execution time 250-500 µs): 0
DPC count (execution time 500-999 µs): 14
DPC count (execution time 1000-1999 µs): 0
DPC count (execution time 2000-3999 µs): 0
DPC count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED ISRs
_________________________________________________________________________________________________________
Highest ISR routine execution time (µs): 34.4587
Driver with highest ISR routine execution time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Highest reported total ISR routine time (%): 0.8720
Driver with highest ISR total time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Total time spent in ISRs (%) 0.1820

ISR count (execution time <250 µs): 198039
ISR count (execution time 250-500 µs): 0
ISR count (execution time 500-999 µs): 0
ISR count (execution time 1000-1999 µs): 0
ISR count (execution time 2000-3999 µs): 0
ISR count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED HARD PAGEFAULTS
_________________________________________________________________________________________________________
Process with highest pagefault count: none

Total number of hard pagefaults 121
Hard pagefault count of hardest hit process: 75
Highest hard pagefault resolution time (µs): 88186.1915
Total time spent in hard pagefaults (%): 0.1471
TODO: Number of processes hit: 0


_________________________________________________________________________________________________________
PER CPU DATA
_________________________________________________________________________________________________________
CPU 0 ISR count: 72784
CPU 0 ISR highest execution time: 19.8412
CPU 0 ISR total execution time: 150928.8950
CPU 0 DPC count: 173770
CPU 0 DPC highest execution time: 411.7221
CPU 0 DPC total execution time: 606343.9278
_________________________________________________________________________________________________________
CPU 1 ISR count: 1840
CPU 1 ISR highest execution time: 24.5249
CPU 1 ISR total execution time: 7501.8396
CPU 1 DPC count: 7533
CPU 1 DPC highest execution time: 144.5812
CPU 1 DPC total execution time: 129774.9068
_________________________________________________________________________________________________________
CPU 2 ISR count: 7870
CPU 2 ISR highest execution time: 29.6149
CPU 2 ISR total execution time: 32423.7565
CPU 2 DPC count: 19565
CPU 2 DPC highest execution time: 163.5737
CPU 2 DPC total execution time: 336767.3953
_________________________________________________________________________________________________________
CPU 3 ISR count: 115545
CPU 3 ISR highest execution time: 34.4587
CPU 3 ISR total execution time: 429646.2459
CPU 3 DPC count: 174570
CPU 3 DPC highest execution time: 799212727025.6250
CPU 3 DPC total execution time: 799215024682.5240
_________________________________________________________________________________________________________

_________________________________________________________________________________________________________
CONCLUSION
_________________________________________________________________________________________________________
Your system appears to be having trouble handling real-time audio and other tasks. You are likely to experience buffer underruns appearing as drop outs, clicks or pops. One or more DPC routines belonging to a driver running in your system appear to be executing for too long. Also one or more ISR routines belonging to a driver running in your system appear to be executing for too long. At least one detected problem appears to be network related. You may have to disable wireless adapters to get better results.
LatencyMon has been analyzing your system for 0:01:18 (h:mm:ss)


_________________________________________________________________________________________________________
System Information
_________________________________________________________________________________________________________
Computer name: X4
OS version: Windows 7 Service Pack 1, 6.1, build: 7601
CPU: AuthenticAMD AMD Phenom(tm) II X4 955 Processor
Logical processors: 4
RAM: 8574287872 total
VM: 2147352576, free: 1923952640


_________________________________________________________________________________________________________
CPU SPEED
_________________________________________________________________________________________________________
Reported CPU speed: 3200 MHz
Measured CPU speed: 3485 MHz

Note: reported execution times may be calculated based on a fixed reported CPU speed. Disable variable speed settings like Intel Speed Step and AMD Cool N Quiet in the BIOS setup for more accurate results.


_________________________________________________________________________________________________________
MEASURED KERNEL TIMER LATENCIES
_________________________________________________________________________________________________________
Highest measured kernel timer latency (µs): 414.3860


_________________________________________________________________________________________________________
MEASURED SMIs AND CPU STALLS
_________________________________________________________________________________________________________
Highest measured SMI routine or CPU stall (µs) 0.6399


_________________________________________________________________________________________________________
REPORTED DPCs
_________________________________________________________________________________________________________
Highest DPC routine execution time (µs): 878682298826.2500
Driver with highest DPC routine execution time: ndis.sys - NDIS 6.20 driver, Microsoft Corporation

Highest reported total DPC routine time (%): 280955.3694
Driver with highest DPC total execution time: USBPORT.SYS - USB 1.1 & 2.0 Port Driver, Microsoft Corporation

Total time spent in DPCs (%) 280956.6014

DPC count (execution time <250 µs): 391624
DPC count (execution time 250-500 µs): 0
DPC count (execution time 500-999 µs): 22
DPC count (execution time 1000-1999 µs): 0
DPC count (execution time 2000-3999 µs): 0
DPC count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED ISRs
_________________________________________________________________________________________________________
Highest ISR routine execution time (µs): 876666328360.0000
Driver with highest ISR routine execution time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Highest reported total ISR routine time (%): 280310.7704
Driver with highest ISR total time: ataport.SYS - ATAPI Driver Extension, Microsoft Corporation

Total time spent in ISRs (%) 280310.9965

ISR count (execution time <250 µs): 214463
ISR count (execution time 250-500 µs): 0
ISR count (execution time 500-999 µs): 0
ISR count (execution time 1000-1999 µs): 0
ISR count (execution time 2000-3999 µs): 0
ISR count (execution time >=4000 µs): 0


_________________________________________________________________________________________________________
REPORTED HARD PAGEFAULTS
_________________________________________________________________________________________________________
Process with highest pagefault count: none

Total number of hard pagefaults 82
Hard pagefault count of hardest hit process: 58
Highest hard pagefault resolution time (µs): 613464.6159
Total time spent in hard pagefaults (%): 0.2686
TODO: Number of processes hit: 0


_________________________________________________________________________________________________________
PER CPU DATA
_________________________________________________________________________________________________________
CPU 0 ISR count: 71552
CPU 0 ISR highest execution time: 21.4780
CPU 0 ISR total execution time: 160968.1250
CPU 0 DPC count: 169634
CPU 0 DPC highest execution time: 878682298826.2500
CPU 0 DPC total execution time: 878682935279.2156
_________________________________________________________________________________________________________
CPU 1 ISR count: 1852
CPU 1 ISR highest execution time: 25.5637
CPU 1 ISR total execution time: 7795.4499
CPU 1 DPC count: 7664
CPU 1 DPC highest execution time: 151.4821
CPU 1 DPC total execution time: 138336.6906
_________________________________________________________________________________________________________
CPU 2 ISR count: 10299
CPU 2 ISR highest execution time: 29.8112
CPU 2 ISR total execution time: 42305.8959
CPU 2 DPC count: 24448
CPU 2 DPC highest execution time: 164.2675
CPU 2 DPC total execution time: 434669.6046
_________________________________________________________________________________________________________
CPU 3 ISR count: 130761
CPU 3 ISR highest execution time: 876666328360.0000
CPU 3 ISR total execution time: 876666824415.3699
CPU 3 DPC count: 189901
CPU 3 DPC highest execution time: 183.9871
CPU 3 DPC total execution time: 2643608.7499
_________________________________________________________________________________________________________

DPC_Interrupt.zip

0

Share this post


Link to post
Share on other sites

you haven't used the correct commands I posted. the file doesn't contain any useful data. Don't run LatancyMon and xperf the same time.

0

Share this post


Link to post
Share on other sites

I did

xperf -on latency -stackwalk profile

and after seeing problems in LatencyMon

xperf -d DPC_Interrupt.etl

how can I know when "the high DPC and Interrupt usage occurs" if I don't run LatencyMon?

0

Share this post


Link to post
Share on other sites

don't run LatancyMon the same time. run an older ProcExpl version (12.04) or ProcessHacker with NetWork/Disk IO tracing disabled.

0

Share this post


Link to post
Share on other sites

don't run LatancyMon the same time. run an older ProcExpl version (12.04) or ProcessHacker with NetWork/Disk IO tracing disabled.

OK, but how do I identify high ISR or DPC execution time or high kernel latency with ProcExpl? This is what I'm seeing:

procexpl.png

And what commands do you want me to run to make the trace if the ones I posted from your original post are no good?

0

Share this post


Link to post
Share on other sites

OK, but how do I identify high ISR or DPC execution time or high kernel latency with ProcExpl?

procexpl.png

look for high CPU usage of the nodes DPC/Interrupt. If you see this, run the command inside ProcExp with File->Run (CTRL+R) when you see the high CPU usage.

0

Share this post


Link to post
Share on other sites
look for high CPU usage of the nodes DPC/Interrupt. If you see this, run the command inside ProcExp with File->Run (CTRL+R) when you see the high CPU usage.

OK, thanks.

EDIT: Actually that doesn't seem practical, as firstly ProcExp doesn't report high usage, so I'd have to sit staring at it for ages trying to catch a spike and also even if the CPU usage doesn't go high, I'm still seeing excessively high kernel latency and/or DPC and latency execution times in LatencyMon.

Edited by doveman
0

Share this post


Link to post
Share on other sites

yes, Procexp shows high usage f you have it. As I said, you can't run t programs side by side which use ETW to capture data. This is a Windows limitation.

0

Share this post


Link to post
Share on other sites

yes, Procexp shows high usage f you have it. As I said, you can't run t programs side by side which use ETW to capture data. This is a Windows limitation.

Oh well, looks like I'll have to try and work this out on my own. The ataport.sys does seem much better now, but I uninstalled some software as well so I'm not sure what fixed that. Really only ndis.sys and netbt.sys are too high (0.43ms) for my liking now. The next highest are USBPORT.sys 0.25ms, CLASSPNP.SYS 0.22ms, ntoskrnl.exe 0.18ms with everything else under 0.09ms

Edited by doveman
0

Share this post


Link to post
Share on other sites

the values you have are ok. Do you have any issues (audio, video drops)?

0

Share this post


Link to post
Share on other sites

the values you have are ok. Do you have any issues (audio, video drops)?

I think things are OK at the moment. I get brief breaks in sound with TV (which aren't replicated if I rewind and play that section again) but I don't think it's a latency issue as it doesn't happen when watching movie files. Cutscenes in games are OK now, but I still get quite a bit of brief freezing / stuttering when actually playing the game, but I guess it could just be the game loading data and something I have to put up with.

I was just a bit bothered by ndis.sys and netbt.sys as they used to be much lower, and I'd like to use VMware workstation but last time I tried it, these two (and tcpip.sys) went much higher and I had bad video / audio problems again.

0

Share this post


Link to post
Share on other sites

Ask the VMWare support if they can fix the nigh ndis/tcpip.sys spikes when using VMWare workstation.

0

Share this post


Link to post
Share on other sites

Ask the VMWare support if they can fix the nigh ndis/tcpip.sys spikes when using VMWare workstation.

Yeah I have, they're looking into it.

0

Share this post


Link to post
Share on other sites

Dammit, ataport.sys just spiked to 2.86ms. Highest kernel latency is 858us.

0

Share this post


Link to post
Share on other sites

have you now made a trace which can be used or do you still run LatencyMon the same time?

0

Share this post


Link to post
Share on other sites

have you now made a trace which can be used or do you still run LatencyMon the same time?

No, there's no way for me to tell when the latency or ISR or DPC execution time goes too high without running LatencyMon, so it's impossible for me to know when to make a trace.

The ataport.sys spike seems to have been linked to Truecrypt and hasn't reoccured since I closed that. ndis.sys is higher than ever though now at 0.69ms (netbt.sys is at 0.1ms and tcpip.sys is at 0.26ms) and the highest kernel latency is on the edge at 906us.

0

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!


Register a new account

Sign in

Already have an account? Sign in here.


Sign In Now

  • Recently Browsing   0 members

    No registered users viewing this page.