Jump to content

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


Recommended Posts


hmm, you don't really have a DPC/Interrupt issue. But the good question is why the kernel takes 25% cpu usage. Does it also happen if you remove AVG from your system?

Yep, I actually installed AVG after it started happening so I could scan for a possible virus or something.

I just noticed something interesting though. The 25% CPU usage only happens when I'm connected to my home Internet connection (wireless), if I'm connected at college it doesn't happen at all, it stays at 0% CPU constantly. It's odd and it's driving me insane, since the computer is new I'm considering returning it to its Factory state and see if it helps.

I'm not sure if it's possible to save a CPU usage graph using Process Explorer, but I'm attaching a screenshot. All those spikes are from System, they have the same 25 - 28% magnitude and they all last around the same time.

EDIT: Just checked System properties using Process Explorer, under Threads it shows that the thread causing the CPU spikes is called "ntoskrnl.exe!KeAcquireInStackQueuedSpinLockAtDpcLevel+0x1e0"

Trying to figure out what that means.

post-344236-0-10869300-1326937035_thumb.

Edited by Damascus
Link to comment
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?

Link to comment
Share on other sites

Hi

I'm having trouble loading the symbols. I've installed xperf with the .NET Framework 4 SDK Web installer, so the process wasn't quite the same as on the page you linked to in your first post, but I installed WPT and Debugging tools under Common Utilities and WPT under Redistributable Packages. Might not have needed all those but wasn't sure.

Anyway, that gives a Start Menu shortcut, Windows SDK 7.1 Command Prompt, so I used that and created the trace with xperf. Then I open it with WPA and change the NT_SYMBOL_PATH to srv*C:\symbols*http://msdl.microsoft.com/download/symbols tick Load Symbols and click on Summary Table, but everything's listed under Unknown.

I might already have enough information from LatencyMon for you to go on though.

I'm running Win7 x64 Ultimate SP1 on a MSI 990FXA-GD80 motherboard with Phenom II X4 955 processor and 8GB DDR3.

I first found I was having dpc latency problems that were being caused by Outpost Security Suite, so I uninstalled that and installed Comodo Firewall instead. I also had to kill/disable the nusb3mon.exe utility, which brought the max execution time for USBPORT.SYS down from 1.3ms to 0.38ms.

Later, I installed VMware Workstation (as I was having problems doing some things in Virtualbox so wanted to see if VMware worked better) and noticed problems again. I reduced them by disabling the two NICs that it installed, but had to disable all it's services as well to completely sort it out, so I uninstalled it.

However, I'm still having problems. I notice if I open a browser (IE or Iron Portable) the execution time for ndis.sys jumps up to 0.5-0.8ms. Although LatencyMon reports that my system is still OK to play video with latency around 500us, I get spikes much higher (around 1100us) and ndis.sys can hit 1.35ms-2.8ms and then LatencyMon reports that my system isn't OK. With Outpost SS, tcpip.sys was the problem (around 0.7ms with spikes every 5 seconds), followed by ataport.sys and USBPORT.SYS.

After getting rid of OSS, I tried disabling the two Standard Dual Channel PCI IDE Controllers (one of which is off a PCI standard PCI-to-PCI bridge) that don't have anything connected, the 1394 Controller, the AMD 6950 HD Audio, the two USB 3 Controllers, three Standard Enhanced PCI to USB Host Controllers and three Standard OpenHCD USB Host Controllers, but was still having a problem with USBPORT.SYS hitting 1.3ms:

http://imageshack.us/photo/my-images/198/latencymonhighusb.png/

I then disabled nusb3mon.exe which brought it down to 0.38ms and moved my KVM from a USB3 port (running at USB2 I imagine considering what I'd disabled) to a USB2/SATA combo port, which brought it down to 0.25ms but I still had problems with ataport.sys:

http://imageshack.us/photo/my-images/703/latencymonkvminusb2comb.png/

http://imageshack.us/photo/my-images/545/latencymonkvminusb2comb.png/

Then I transferred my KVM to a normal USB2 port, after which USBPORT.sys and ataport.sys didn't go above 0.25ms although uninstalling OSS seemed to have caused ndis.sys to increase from 0.03ms to 0.28ms

http://imageshack.us/photo/my-images/16/latencymonkvminusb232mi.png/

http://imageshack.us/photo/my-images/594/latencymonkvminusb232mi.png/

However, since installing/uninstalling VMware I'm now having problems with ataport.sys again. I've still got all the devices listed above disabled, and still only have things plugged in the normal USB2 ports.

http://imageshack.us/photo/my-images/37/latencymonafteruninstal.png/

http://imageshack.us/photo/my-images/259/latencymondriversafteru.png/

http://imageshack.us/photo/my-images/213/latencymonmainafterunin.png/

http://imageshack.us/photo/my-images/195/latencymondriversafteru.png/

I've just unplugged my USB hub (with only an Xbox360 controller plugged in) so that only my KVM is connected to a USB port, which may have brought the ataport.sys execution time down somewhat, but the latency's still rather high.

http://imageshack.us/photo/my-images/337/latencymonmainmplivetvu.png/

http://imageshack.us/photo/my-images/864/latencymondriversmplive.png/

Edited by doveman
Link to comment
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

Link to comment
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.

Link to comment
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
_________________________________________________________________________________________________________

Link to comment
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

Link to comment
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.
×
×
  • Create New...