[mythtv-users] Strange Interrupts Issue

Fri Apr 27 03:33:45 UTC 2007

Hi all,

I've been beating my head against the wall for weeks now trying to
figure this out- I don't really even know what group to look to for
help. Since this is my mythtv (front/backend combined) box, well, I'll
start with you guys :)

The cut-to-the-quick version is, I'm pretty sure I have a device
driver that is taking too long to return during its interrupt "cycle"
(or whatever the proper term is), but I can't figure out how to
determine which driver is taking too long. How can I do this?

The long story, my evidence suggesting that I'm having interrupt
issues, follows:

I have a mythbox set up for HD recording, and all is working pretty
well, except that I have some driver that stalls in its interrupt
routine, and causes things like lost ticks, occasional skips in
recording/playback, and the system clock gradually losing time,
occasional pauses when typing (which often leads to key repeats even
if the key was just down for a normal keypress length of time).

I have a pcHDTV-5500, which seems to be especially sensitive to the
issue, often reporting more than 30 buffers handled when it is
decoding:

Apr 22 21:26:55 localhost kernel: cx88_wakeup: 4 buffers handled (should be 1)
Apr 22 21:26:55 localhost kernel: cx88_wakeup: 2 buffers handled (should be 1)
Apr 22 21:26:56 localhost kernel: cx88_wakeup: 23 buffers handled (should be 1)
Apr 22 21:26:56 localhost kernel: cx88_wakeup: 23 buffers handled (should be 1)
Apr 22 21:26:57 localhost kernel: cx88_wakeup: 30 buffers handled (should be 1)
Apr 22 21:26:57 localhost kernel: cx88_wakeup: 8 buffers handled (should be 1)
Apr 22 21:26:57 localhost kernel: cx88_wakeup: 28 buffers handled (should be 1)

lost tick messages around this time (both listings are grepped out of
/var/log/messages, so there's probably some interleave here, but not

Apr 22 21:26:57 localhost kernel: time.c: Lost 30 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:26:57 localhost kernel: time.c: Lost 16 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:26:57 localhost kernel: time.c: Lost 30 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:26:57 localhost kernel: time.c: Lost 16 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:26:57 localhost kernel: time.c: Lost 2 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:26:57 localhost kernel: time.c: Lost 2 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:27:07 localhost kernel: time.c: Lost 1 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:27:07 localhost kernel: time.c: Lost 1 timer tick(s)! rip
__do_softirq+0x4a/0xc3)
Apr 22 21:27:11 localhost kernel: time.c: Lost 2 timer tick(s)! rip
__do_softirq+0x4a/0xc3)

is a general sampling of /var/log/messages, regardless of which tuner
is recording. Having both tuners recording usually causes severe
corruption of one of the two streams, and a lot of lost time.

This made me initially suspect the pchdtv drivers as causing the
problem, but I physically removed the card from the system and ensured
the drivers were no longer loaded, and I still had the
interrupt-hogging issue (evidenced by lost ticks reported by
report_lost_ticks kernel option). Also, the lost ticks still happen
just when doing playback (i.e. on already recorded streams), or when
recording only (frontend not running at all or completely idle).

I also have an AverMedia A180, which seems to have a bigger buffer or
generally get along better with this problem, and has allowed me to
mostly use the system "as-is"  while trying to figure this out. (with
ntpd continually dragging the clock back into alignment)

**************
My main question is, how do I determine which driver is taking the
ungodly amount of time? I haven't seen a good way of determining this.
I can then look into debugging this, but without a foothold to start
looking into, I feel like I'm shooting into the dark here.
**************

I'm running on Fedora Core 6, myth add-ons built according to Jarod's
guide (atrpms, etc). Hard drive is SATA, DVD drive is IDE, and an
nvidia 7600 PCIE x16 video card. Core 2 Duo 6600 running at stock 2.4
GHz.

Other things that might be useful are I tried recording a dvd today,
which worked, but I lost a *lot* of clock time during this process--
the burn took about 15-20 minutes, and the clock was about 20 minutes
behind afterwards (was within a second or two of correct when the burn
started).

[mythtv at myth ~]$ uname -a
Linux myth 2.6.20-1.2944.fc6 #1 SMP Tue Apr 10 17:46:00 EDT 2007
x86_64 x86_64 x86_64 GNU/Linux

[mythtv at myth ~]$ cat /proc/interrupts
          CPU0       CPU1
 0:    3077162          0   IO-APIC-edge      timer
 1:          2          0   IO-APIC-edge      i8042
 8:          1          0   IO-APIC-edge      rtc
 9:          0          0   IO-APIC-fasteoi   acpi
14:       7941       8027   IO-APIC-edge      libata
15:      27236          0   IO-APIC-edge      ide1
16:       1945     185151   IO-APIC-fasteoi   uhci_hcd:usb4, nvidia
17:          1     294559   IO-APIC-fasteoi   Intel ICH7, saa7133[0]
18:          0          0   IO-APIC-fasteoi   uhci_hcd:usb3, cx88[0]
19:          0          0   IO-APIC-fasteoi   uhci_hcd:usb2
20:        136       4613   IO-APIC-fasteoi   eth0
23:         82        451   IO-APIC-fasteoi   uhci_hcd:usb1
NMI:          0          0
LOC:    3076480    3076408
ERR:          0

(saa7133 is the AverMedia A180 card, cx88 is the pcHDTV-5500)

Thanks!
Matt