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

[Kessu]

Andre,

Short version: Solved. The cause was AVer Trinity TV card.

Long version: During various attempts I have realized that the kernel timer latency reported by LetencyMon is a bit on high side (cca 0,3- 0,4 ms) for the machine even at the idle state of PC (just services running, including Mediaoportal TV service => CPU cca 2%-3%. In “stall” of PC (=CPU > 50%) kernel latency exploded to hundreds of ms. Tried to disable various devices in device manager => no change. Then I started from scratch, physically unplugged all devices (idle kernel timer latency about 0,1 ms) and returned devices one by one. As I plugged the Aver TV card, latency increased to previous 0,3-0,4 ms in idle state. Here we go. No freezes so far.

What is interesting:

- the TV card generally worked – able to tune, watch… everything

- the lockouts of CPU NEVER happened during use of the TV Card, always when doing something else, usually (not always) when some heavy USB data traffic occurs

- device manager enable/disable the card doesn’t change anything on the performance

The Aver TV card used to be weakest point from the very beginning of this PC (2 years ago), however I thought I solved it and it is OK. At the end it was not.

Learning point: What a fool man can become seeing interesting piece of HW in the catalogue. Even from almost no name company from Taiwan…

Thanks a lot for inspiration and … you know, it helps sometimes just to share the troubles with somebody

THX!

[MagicAndre1981]

Short version: Solved. The cause was AVer Trinity TV card.

As I plugged the Aver TV card, latency increased to previous 0,3-0,4 ms in idle state. Here we go. No freezes so far.

ok, nice to hear this.

@doveman

maybe it is also your TV card. Can you put your Hauppauge WinTV-HVR 1100 into a different PCIe slot? Maybe this fixes it.

[doveman]

@doveman

maybe it is also your TV card. Can you put your Hauppauge WinTV-HVR 1100 into a different PCIe slot? Maybe this fixes it.

Hi

I may have stumbled across what's causing the problem (other than VMWare player's services, which disabling certainly reduced the problem a lot).

I've done various tests today and the continuity errors appear every hour at 35 minutes past!

From 15:03 - 17:05 I had the Xperf trace running with TV Server config running timeshifting and there were errors at 15:35 and 16:35

Then I stopped the Xperf trace and started MediaPortal and watched TV until 19:00 and there were errors at 17:35, 18:35

Then I closed MP, switched power mode from High Performance to Balanced and ran timeshifting via TV Server config again until 21:04 and there were errors at 19:35 and 20:35 (so the problem doesn't appear to be affected by power mode)

The obvious thing to check was Task Scheduler. I don't see any tasks that ran at those times but Ractask is the only thing that runs every hour and that ran at 19:07, 18:08, 17:03, 16:13, 15:10, so I'll try disabling that.

[Kessu]

>doveman

Hi,

i am far to regard myself as specialist, however your case is quite similar to mine (HTPC, based on Athlon II, running mediaportal…) so I am sharing unsorted experience and ideas… may be something helps:

- Blame mediaportal as last option. By my experience it is pretty solid-coded. All the tweaks, patches and so are usually created to bridge some other HW/SW issues, not the mediaportal itself errors.

- Do the glitches occur when Mediaportal is completely down? I mean have you tried to shut down mediaportal including TV service and run the log while for example some stand-alone player (WMP…) is running?

- You wrote (Posted 28 June 2012 - 02:30 PM): “Mediaportal logs show continuity errors at 21:03:50” and (Posted Yesterday, 02:32 PM): “errors appear every hour at 35 minutes past” which is a bit contradictory. It might be long path to follow this direction.

- You wrote (Posted 12 July 2012 - 02:31 PM): “Latency stayed under 300 or 400 ms” – which is according my experience above normal and can be the right indicator of system health. The kernel latency should be < 0,1 ms in average (I know, LatencyMonitor is not showing the average, its just “as you see the actual latency” estimation…) peaks <0,2ms max. The trick is you can see it immediately after various attempts and tests, you don’t have to wait until some bigger/random hiccup occurs.

- Have you tried to run safe mode and then investigate the system performance? Might be interesting benchmark.

- And the last one – in my case no software trick helped. Simply the physical presence of the TV card caused the issue and no tool or log or utility pointed this direction…

[doveman]

@Kessu

Thanks for the tips, seems we're in similar boats

RACtask was definitely the problem. Since disabling that I don't get the regular continuity errors (at 35 minutes past) anymore and I haven't seen any "freezes". There are still the odd continuity errors (like the one at 21:03:50) and a lot of discontuity messages, but they don't seem to cause any noticeable problems and may be due to minor signal problems.

However, as RACtask was causing problems I'd like to find out why and see if there's anything else that might be causing the remaining continuity/discontinuity messages other than signal problems. I've been advised that HDD load can cause them and so I'd like to re-enable RACtask and monitor the HDD load to see if that is indeed what's happening but I don't know of a good way to monitor the HDD load as Resource Monitor only seems to have a 60sec graph which isn't sufficient.

I have no idea how to get the latency as low as 0.1-0.2ms which is quite a drop from 300-400ms but I'll try your suggestions of checking in safe mode and also removing the card to see if that makes any difference.

[Kessu]

@Kessu

I have no idea how to get the latency as low as 0.1-0.2ms which is quite a drop from 300-400ms ...

Actually I believe 300-400ms is just a typo, you mean 300-400µs. And I mean 100-200µs = 01,-02,ms. If your latency is really 300ms, then I have bad news for you... :wacko:

Grats for firs hit and good luck!

[doveman]

Actually I believe 300-400ms is just a typo, you mean 300-400µs. And I mean 100-200µs = 01,-02,ms. If your latency is really 300ms, then I have bad news for you... :wacko:

Yeah, that's true. Not so much of a drop then

[MagicAndre1981]

RACtask was definitely the problem.

ok, but none of the traces show RACtask activity. You can delete all error reports in action center and delete the RAC data (C:\ProgramData\Microsoft\RAC\PublishedData) and look if this helps.

[doveman]

ok, but none of the traces show RACtask activity. You can delete all error reports in action center and delete the RAC data (C:\ProgramData\Microsoft\RAC\PublishedData) and look if this helps.

OK, I've deleted all problem reports and the file (RacWmiDatabase.sdf 1876Kb) in that folder. I think I'll leave RACtask disabled though as I don't think I really need it and if it's going to cause problems it's not worth the hassle.

I was just monitoring with LatencyMon whilst using MP and when I closed MP I saw this

Now I connect via VNC to do this sort of stuff (close MP, start/stop LatencyMon) so I wondered if it's just using VNC that's causing these high numbers, but then again I've always used VNC when starting/stopping the xperf traces and they didn't show any such problems so I guess that doesn't explain it. Before starting MP, the latency was around 220us and in that screenshot the current latency is 173us, so perhaps something I did in MP caused a blip. Again I'd have expected that to show in the xperf trace, although I may not have done the same actions in MP when doing those traces, so maybe I should make another trace and try and repeat those actions?

EDIT: It seems just loading MP sends the latency to 1200+ and ndis.sys to 0.44, netbt.sys to 0.4 and tcpip.sys to 0.28. When making the xperf traces I was waiting for an video glitch before closing MP and stopping the trace, so I guess it wouldn't have gone back far enough to show what happened when starting MP. If I restart LatencyMon after MP is loaded and then start LiveTV (with MP windowed so I can see LatencyMon), the latency stays below 400us (in a short test) but then when I close MP it goes up to 1200+ again and ataport.sys is 0.32ms, ndis.sys 0.29ms and tcpip.sys 0.20ms. I would have expected the xperf traces to show any blips when closing MP, as I was doing this just before stopping the trace.

Edited July 21, 2012 by doveman

[MagicAndre1981]

ataport = issues because the HDD runs in IDE mode.

[doveman]

ataport = issues because the HDD runs in IDE mode.

It's not running in IDE mode though. I changed it to AHCI (on your advice) quite a while ago.

I don't have any other devices (HDD or DVD drive) connected at the moment either, just the one SATA HDD. I might have the IDE interface enabled though. Either way, this is the same as it was when I was making the xperf traces, so if the high latency is triggered when closing MP it should have been reflected in the traces.

[MagicAndre1981]

I'm currently asking Microsoft why it shows as IDE (IDE\DISKSAMSUNG_HD103SJ_________________________1AJ10001\5&3759548D&0&0.1.0). Mine shows up as SCSI when using AHCI (SCSI\DISK&VEN_SAMSUNG&PROD_HD103SJ\4&1C08B97F&0&040000)

[doveman]

I'm currently asking Microsoft why it shows as IDE (IDE\DISKSAMSUNG_HD103SJ_________________________1AJ10001\5&3759548D&0&0.1.0). Mine shows up as SCSI when using AHCI (SCSI\DISK&VEN_SAMSUNG&PROD_HD103SJ\4&1C08B97F&0&040000)

Yeah, it's the same on my other PC (single SATA HDD in AHCI mode, no IDE devices but IDE interface enabled) with IDE\DiskSAMSUNG_HD204UI_________________________1AQ10001.

[MagicAndre1981]

which motherboard do you use on both PCs? Do you use the MS or the AMD AHCI driver?

[doveman]

which motherboard do you use on both PCs? Do you use the MS or the AMD AHCI driver?

The HTPC I've been doing the xperf traces on uses a Biostar TA790GXBE with AMD Sata Controller v1.2.1.331 (11/04/2012) and my other PC uses a MSI 990FXA-GD80 with the Standard AHCI 1.0 Serial ATA Controller v6.1.7601.17514 (21/06/2006)