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

[ChristSavesU2]

this is very confusing. I have no real idea why this is so

I have found out it is not a temperature issue. I tried letting the computer boot up to the hard drive encryption password, which should only have run the BIOS checks, and then hitting control, alt, delete, to reboot, and then letting it boot up normally from there. Doing this, there are no DPC latency issues all day and the computer works fine. I tried flashing the BIOS and booted normally the next day and the DPC issues are still there, but today I did the immediate reboot and it is working fine. I don't know what the change is when I do the immediate reboot, but it seems to work.

[doveman]

The MediaPortal may hang becasue it waits. I can see it causes ntkrpamp.exe!KiProcessThreadWaitList calls which calls ntkrpamp.exe!KiReadyThread.

So we must capture ReadyThread data, too.

xperf -on latency+POWER+DISPATCHER -stackwalk profile+CSwitch+ReadyThread -buffersize 1024 -MaxFile 256 -FileMode Circular && timeout -1 && xperf -d DPC_Interrupt.etl

But I must say I never used xperf to analyze hangs. I've uses the Builin profiler of Visual Studio 2010 which uses xperf/ETW in background and shiows me nice list.

Hi MagicAndre

I managed to substantially reduce the frequency of the hangs in Mediaportal by disabling all four VMware Player services (VMWare Authorisation Service, VMWare DHCP Service, VMWare NAT Service, VMWare USB Arbitration Service) but the hangs still occur and are as severe, just less frequent. MediaPortal's just been updated to 1.3 Alpha, which might have helped a bit as well. I've uploaded a trace just after one such hang at http://www.mediafire.com/?c2444sa1k4hsh0c

I also checked with LatencyMon (not at the same time) without Mediaportal running and noticed:

Latency stayed under 300 or 400 ms (although I didn't monitor for more than a few minutes)

The highest driver time was ndis.sys at 0.3432 ms, followed by tcpip.sys at 0.19 ms and ntkrnlpa.exe at 0.11 ms. All others were under 0.1 ms. (A later run showed netbt.sys at 0.5 ms and ndis.sys at 0.31 ms).

Highest reported hard pagefault resolution time still seems high at 32394.7125 us.

I've now also uninstalled True Image and will see if that's helped. If not, I'll completely uninstall VMWare Player, as well as Virtualbox as Virtual PC as they all install Virtual NICs (which I have disabled) as well as filter drivers that attach to the real NIC for Bridge Mode, so as my highest times seem to be associated with network components this seems sensible.

I'll wait to hear if you can see anything useful in the trace first though.

[MagicAndre1981]

Could you see something interesting in the logs, please? What about the hal.dll?

Logs: https://docs.google.com/open?id=0B-XYYunI5kZqRDEtbFJLZzdZY00

looks like you've uploaded the kernel.etl. This file is useless for me. The file only works on the PC where the data were captured.

[MagicAndre1981]

I tried letting the computer boot up to the hard drive encryption password, which should only have run the BIOS checks, and then hitting control, alt, delete, to reboot, and then letting it boot up normally from there.

can you disable this hard drive encryption password? Does this make a difference?

[MagicAndre1981]

I managed to substantially reduce the frequency of the hangs in Mediaportal by disabling all four VMware Player services (VMWare Authorisation Service, VMWare DHCP Service, VMWare NAT Service, VMWare USB Arbitration Service) but the hangs still occur and are as severe, just less frequent. MediaPortal's just been updated to 1.3 Alpha, which might have helped a bit as well. I've uploaded a trace just after one such hang at http://www.mediafire.com/?c2444sa1k4hsh0c

I also checked with LatencyMon (not at the same time) without Mediaportal running and noticed:

Latency stayed under 300 or 400 ms (although I didn't monitor for more than a few minutes)

The highest driver time was ndis.sys at 0.3432 ms, followed by tcpip.sys at 0.19 ms and ntkrnlpa.exe at 0.11 ms. All others were under 0.1 ms. (A later run showed netbt.sys at 0.5 ms and ndis.sys at 0.31 ms).

Highest reported hard pagefault resolution time still seems high at 32394.7125 us.

DPCs should be no issue.

MediaPortla uses Timers which do some .Net Remoting (SOAP) calls (System.Runtime.Serialization.Formatters.Soap.dll!?) which seems to block the tool. I think such a coding issue causes the hangs.

[doveman]

I managed to substantially reduce the frequency of the hangs in Mediaportal by disabling all four VMware Player services (VMWare Authorisation Service, VMWare DHCP Service, VMWare NAT Service, VMWare USB Arbitration Service) but the hangs still occur and are as severe, just less frequent. MediaPortal's just been updated to 1.3 Alpha, which might have helped a bit as well. I've uploaded a trace just after one such hang at http://www.mediafire.com/?c2444sa1k4hsh0c

I also checked with LatencyMon (not at the same time) without Mediaportal running and noticed:

Latency stayed under 300 or 400 ms (although I didn't monitor for more than a few minutes)

The highest driver time was ndis.sys at 0.3432 ms, followed by tcpip.sys at 0.19 ms and ntkrnlpa.exe at 0.11 ms. All others were under 0.1 ms. (A later run showed netbt.sys at 0.5 ms and ndis.sys at 0.31 ms).

Highest reported hard pagefault resolution time still seems high at 32394.7125 us.

DPCs should be no issue.

MediaPortla uses Timers which do some .Net Remoting (SOAP) calls (System.Runtime.Serialization.Formatters.Soap.dll!?) which seems to block the tool. I think such a coding issue causes the hangs.

It seems unlikely, as many people use Mediaportal to watch TV without having this problem. Disabling those VMWare services seems to have substantially reduced the frequency of the hangs and I recall VMWare Workstartion caused latency problems for me previously that messed up Mediaportal.

Anyway, this is what the MediaPortal developers have told me:

"EVR presenter calls SetThreadAffinityMask() to workaround some buggy bios / HW -> http://msdn.microsoft.com/en-us/library/ms644904(VS.85).aspx. In any case it is perfectly valid to call that method, if it triggers some issue then there must be some underlying issue with the HW (or most likely drivers).

ISR/DPC <-- those are both kernel level stuff. ISR == interrupt service routine, DPC == deferred procedure call. Both are something that MediaPortal (or any other user mode program) cannot difrectly trigger.

After 1.3.0 alpha is out (and you have updated to it) I can build a dshowhelper. dll without that one specific call for testing. The side effect is that it would probably break lot of older systems that are currently working ok (we don't have any clue what HW Microsoft is talking about). It will require quite big amount of testing to be able to remove that workaround from the code - it will affect the video frame scheduling accuracy.

In any case I would say that there is some driver level issue on the system where you see the ISR/DPC spikes. "

[ChristSavesU2]

can you disable this hard drive encryption password? Does this make a difference?

The only way to disable the encryption password would be to decrypt the hard drive. What I did try was to not let the BIOS get completely through its process and turned off the computer before it got to the encryption password prompt. Then switched it back on and let it boot normally. That worked as well, no DPC latency issues all day.

[Kessu]

Could you see something interesting in the logs, please? What about the hal.dll?

Logs: https://docs.google.com/open?id=0B-XYYunI5kZqRDEtbFJLZzdZY00

looks like you've uploaded the kernel.etl. This file is useless for me. The file only works on the PC where the data were captured.

For sure no,t as:

1) can parse the file on another PC

2) dont know, how to create kernel.etl

The only strange thing is that the log is cumulated in the beggining of time axis even thou it has logged something like 5 minutes. Not sure if the time axis labels are seconds...

Anywa will try to log once more, when the isuue occur.

Thanks so far!

[MagicAndre1981]

Anywa will try to log once more, when the isuue occur.

do you run LatencyMon in background?

[Kessu]

do you run LatencyMon in background?

Not during this log.

I made this error before, however got just error message from xperf, google helped me to find the reason. This log is without latencymon running. Only if there is some service... might be the case (havent check that).

Edited July 15, 2012 by Kessu

[MagicAndre1981]

do you runthe Win7 resource monitor in background or ProcessExplorer? Booth tools can also cause xperf capturing issues.

Also which xperf version do you use?

[doveman]

Well I've now uninstalled VMWare Player and Virtualbox and am still having the same problems. I haven't uninstalled Virtual PC yet as that said it would delete my VM, but it didn't have a virtual NIC installed for it like the other two anyway (which were all disabled but you never know). It does have the "Virtual PC Network Filter Driver" attached to the real NIC but I've unticked that.

I started the xperf trace at 08:17 and according to the Mediaportal logs, the last continuity errors were at 09:52. However, I closed MP before making the trace after the last hang I encountered and apparently I closed MP around 09:58, so I've got a feeling that last hang (and perhaps others as well) isn't reflected as a continuity error in the MP logs. I don't know if the trace would go back far enough to catch them, but the logs also show continuity errors at 08:52, 08:42, 08:38. http://www.mediafire.com/?wb45l34pb74zyci

[MagicAndre1981]

I'm out of ideas Hight latencies are 128-256µs

[doveman]

Oh well, thanks for looking at the traces anyway.

I've also now disabled my second TV tuner card (WinTV), the USB redirector device (part of VirtualPC I believe) and installed the 12.6 AMD AHCI/Chipset drivers but I don't think it's made much difference and I still seem to get at least one hang an hour.

I'm fairly sure disabling those four VMWare Player services made a big difference though, as before that it seemed like I was getting several hangs per programme.

Hopefully the Mediaportal developers can come up with a solution.

[doveman]

I also tried disabling the AMD external events service and the AMD Fuel service, which didn't help. In fact it seems the AMD Fuel service needs to be running as this morning I was getting high render times and jerky video until I restarted that.

I then switched back to High Performance power mode and haven't seen a hang today. The Mediaportal logs do show some continuity errors at around 12:30 and it's possible there was a hang then that I missed but I would normally see at least one an hour, so it seems to have helped a lot anyway.