[mythtv] mythfrontend freezing: Waited too long for ringbuffer pause

Al McIntosh junkmail at allanmcintosh.com
Mon Jan 2 18:05:05 UTC 2006 

Hey,

mythtv-frontend-0.18.1-116.rhfc4.at is freezing consistently during 
playback of recorded shows.  The shows were recorded with ivtv4.0
My frontend logs are

This has only started in the past few days. I could really use some help 
tracking this down.

Any ideas or pointers would greatly be appreciated. 

The following appears in /var/log/messages at 15:32:59 then the 
ringbuffer errors appear immediatly after this....

Jan  1 15:32:59 nelson kernel: ------------[ cut here ]------------
Jan  1 15:32:59 nelson kernel: kernel BUG at lib/radix-tree.c:276!
Jan  1 15:32:59 nelson kernel: invalid operand: 0000 [#1]
Jan  1 15:32:59 nelson kernel: Modules linked in: nvidia(U) cx8800 
cx88xx ir_common v4l1_compat bttv video_buf v4l2_common btcx_risc 
lirc_i2c(U) lirc_dev(U) nfsd exportfs ipv6 autofs4 nfs lockd nfs_acl 
sunrpc dm_mod video button battery ac ohci_hcd ehci_hcd tda9887 
msp3400(U) saa7115(U) tuner tveeprom ivtv(U) i2c_algo_bit videodev 
i2c_nforce2 i2c_core shpchp snd_intel8x0(U) snd_ac97_codec(U) 
snd_ac97_bus(U) snd_seq_dummy(U) snd_seq_oss(U) snd_seq_midi_event(U) 
snd_seq(U) snd_seq_device(U) snd_pcm_oss(U) snd_mixer_oss(U) snd_pcm(U) 
snd_timer(U) snd(U) soundcore snd_page_alloc(U) forcedeth floppy ext3 
jbd sata_nv libata sd_mod scsi_mod
Jan  1 15:32:59 nelson kernel: CPU:    0
Jan  1 15:32:59 nelson kernel: EIP:    0060:[<c01cf0ad>]    Tainted: 
PF     VLI
Jan  1 15:32:59 nelson kernel: EFLAGS: 00210086   (2.6.14-1.1637_FC4)
Jan  1 15:32:59 nelson kernel: EIP is at radix_tree_insert+0xd6/0x139
Jan  1 15:32:59 nelson kernel: eax: ffffffff   ebx: ef17f4e4   ecx: 
00000000   edx: 00000000
Jan  1 15:32:59 nelson kernel: esi: 00000003   edi: 00000003   ebp: 
0000000d   esp: dacfcdb4
Jan  1 15:32:59 nelson kernel: ds: 007b   es: 007b   ss: 0068
Jan  1 15:32:59 nelson kernel: Process mythfrontend (pid: 1517, 
threadinfo=dacfc000 task=c5084570)
Jan  1 15:32:59 nelson kernel: Stack: badc0ded c151c0c0 00008fcd 
d6b43e70 ef17f4e4 00000000 c151c0c0 d6b43e6c
Jan  1 15:32:59 nelson kernel:        d6b43e7c c013bb47 00008fcd 
00001000 c151c0c0 00000000 d6b43e6c c013bb9e
Jan  1 15:32:59 nelson kernel:        000000d0 00001000 00000000 
c013c44b 000000d0 00000020 00008fb2 00000000
Jan  1 15:32:59 nelson kernel: Call Trace:
Jan  1 15:32:59 nelson kernel:  [<c013bb47>] add_to_page_cache+0x41/0x83
Jan  1 15:32:59 nelson kernel:  [<c013bb9e>] 
add_to_page_cache_lru+0x15/0x2a
Jan  1 15:32:59 nelson kernel:  [<c013c44b>] 
do_generic_mapping_read+0x411/0x465
Jan  1 15:32:59 nelson kernel:  [<c013c628>] 
__generic_file_aio_read+0xaa/0x1f6
Jan  1 15:32:59 nelson kernel:  [<c013c49f>] file_read_actor+0x0/0xdf
Jan  1 15:32:59 nelson kernel:  [<c013c7b2>] 
generic_file_aio_read+0x3e/0x4f
Jan  1 15:32:59 nelson kernel:  [<c0158ac7>] do_sync_read+0xbf/0x11a
Jan  1 15:32:59 nelson kernel:  [<c01045b8>] do_IRQ+0x51/0x82
Jan  1 15:32:59 nelson kernel:  [<c012db56>] 
autoremove_wake_function+0x0/0x37
Jan  1 15:32:59 nelson kernel:  [<c0158a08>] do_sync_read+0x0/0x11a
Jan  1 15:32:59 nelson kernel:  [<c0158bc2>] vfs_read+0xa0/0x158
Jan  1 15:32:59 nelson kernel:  [<c0158f2f>] sys_read+0x41/0x6a
Jan  1 15:32:59 nelson kernel:  [<c0102edd>] syscall_call+0x7/0xb
Jan  1 15:32:59 nelson kernel: Code: 84 85 db 74 30 83 03 01 8b 04 24 89 
44 ab 04 0f a3 ab 04 01 00 00 19 c0 85 c0 75 68 0f a3 ab 0c 01 00 00 19 
c0 31 c9 85 c0 74 b1 <0f> 0b 14 01 80 cf 32 c0 eb a7 8b 0c 24 8b 54 24 
08 89 4a 08 31

mythfrontend log:

2006-01-01 15:30:51.482 Opening audio device 'default'.
2006-01-01 15:30:51.545 Using XV port 240
2006-01-01 15:30:51.801 Realtime priority would require SUID as root.
2006-01-01 15:30:51.808 Changing from None to WatchingPreRecorded
2006-01-01 15:30:51.981 Video timing method: RTC
2006-01-01 15:33:03.431 prebuffering pause
2006-01-01 15:33:06.472 Waited 4 seconds for data to become available, 
waiting again...
2006-01-01 15:33:10.476 Waited 4 seconds for data to become available, 
waiting again...
2006-01-01 15:33:12.280 Waited too long for ringbuffer pause..
2006-01-01 15:33:21.337 Waited too long for ringbuffer pause..
2006-01-01 15:33:22.341 Waited too long for ringbuffer pause..
2006-01-01 15:33:23.345 Waited too long for ringbuffer pause..
<snip>


A more recent call trace is a little different but the result is the 
same.  This occurred 30 minutes into playback.

Jan  2 10:43:22 nelson kernel: ------------[ cut here ]------------
Jan  2 10:43:22 nelson kernel: kernel BUG at lib/radix-tree.c:276!
Jan  2 10:43:22 nelson kernel: invalid operand: 0000 [#1]
Jan  2 10:43:22 nelson kernel: Modules linked in: nvidia(U) cx8800 
cx88xx ir_common v4l1_compat bttv video_buf v4l2_common btcx_risc 
lirc_i2c(U) lirc_dev(U) nfsd exportfs ipv6 autofs4 nfs lockd nfs_acl 
sunrpc dm_mod video button battery ac ohci_hcd ehci_hcd tda9887 
msp3400(U) saa7115(U) tuner tveeprom ivtv(U) i2c_algo_bit videodev 
i2c_nforce2 i2c_core shpchp snd_intel8x0(U) snd_ac97_codec(U) 
snd_ac97_bus(U) snd_seq_dummy(U) snd_seq_oss(U) snd_seq_midi_event(U) 
snd_seq(U) snd_seq_device(U) snd_pcm_oss(U) snd_mixer_oss(U) snd_pcm(U) 
snd_timer(U) snd(U) soundcore snd_page_alloc(U) forcedeth floppy ext3 
jbd sata_nv libata sd_mod scsi_mod
Jan  2 10:43:22 nelson kernel: CPU:    0
Jan  2 10:43:22 nelson kernel: EIP:    0060:[<c01cf0ad>]    Tainted: 
PF     VLI
Jan  2 10:43:22 nelson kernel: EFLAGS: 00010086   (2.6.14-1.1637_FC4)
Jan  2 10:43:22 nelson kernel: EIP is at radix_tree_insert+0xd6/0x139
Jan  2 10:43:22 nelson kernel: eax: ffffffff   ebx: eb9f74e4   ecx: 
00000000   edx: 00000000
Jan  2 10:43:22 nelson kernel: esi: 00000004   edi: 00000004   ebp: 
0000000d   esp: d3a75c60
Jan  2 10:43:22 nelson kernel: ds: 007b   es: 007b   ss: 0068
Jan  2 10:43:22 nelson kernel: Process mythfrontend (pid: 10514, 
threadinfo=d3a75000 task=f49dd030)
Jan  2 10:43:22 nelson kernel: Stack: badc0ded c1525920 0007e5cd 
f0c47704 eb9f74e4 00000000 c1525920 f0c47700
Jan  2 10:43:22 nelson kernel:        f0c47710 c013bb47 0007e5cd 
c1525920 00000020 00000009 d3a75d84 c017a665
Jan  2 10:43:22 nelson kernel:        000000d0 f88b9074 f0c47700 
f7fca3c0 00000009 00000000 c1201080 c108a4e0
Jan  2 10:43:22 nelson kernel: Call Trace:
Jan  2 10:43:22 nelson kernel:  [<c013bb47>] add_to_page_cache+0x41/0x83
Jan  2 10:43:22 nelson kernel:  [<c017a665>] mpage_readpages+0xed/0x13e
Jan  2 10:43:22 nelson kernel:  [<f88b9074>] ext3_get_block+0x0/0x90 [ext3]
Jan  2 10:43:22 nelson kernel:  [<f88b9e81>] ext3_readpages+0x0/0x15 [ext3]
Jan  2 10:43:22 nelson kernel:  [<c014212a>] read_pages+0x2a/0xf7
Jan  2 10:43:22 nelson kernel:  [<f88b9074>] ext3_get_block+0x0/0x90 [ext3]
Jan  2 10:43:22 nelson kernel:  [<c0140014>] __alloc_pages+0xe7/0x403
Jan  2 10:43:22 nelson kernel:  [<c0142337>] 
__do_page_cache_readahead+0x140/0x145
Jan  2 10:43:22 nelson kernel:  [<c014244f>] 
blockable_page_cache_readahead+0x53/0xbc
Jan  2 10:43:22 nelson kernel:  [<c0142513>] make_ahead_window+0x5b/0x9a
Jan  2 10:43:22 nelson kernel:  [<c01425d7>] page_cache_readahead+0x85/0x15f
Jan  2 10:43:22 nelson kernel:  [<c013c412>] 
do_generic_mapping_read+0x3d8/0x465
Jan  2 10:43:22 nelson kernel:  [<c013c628>] 
__generic_file_aio_read+0xaa/0x1f6
Jan  2 10:43:22 nelson kernel:  [<c013c49f>] file_read_actor+0x0/0xdf
Jan  2 10:43:22 nelson kernel:  [<c013c7b2>] generic_file_aio_read+0x3e/0x4f
Jan  2 10:43:22 nelson kernel:  [<c0158ac7>] do_sync_read+0xbf/0x11a
Jan  2 10:43:22 nelson kernel:  [<c01045b8>] do_IRQ+0x51/0x82
Jan  2 10:43:22 nelson kernel:  [<c012db56>] 
autoremove_wake_function+0x0/0x37
Jan  2 10:43:22 nelson kernel:  [<c0158a08>] do_sync_read+0x0/0x11a
Jan  2 10:43:22 nelson kernel:  [<c0158bc2>] vfs_read+0xa0/0x158
Jan  2 10:43:22 nelson kernel:  [<c0158f2f>] sys_read+0x41/0x6a
Jan  2 10:43:22 nelson kernel:  [<c0102edd>] syscall_call+0x7/0xb
Jan  2 10:43:22 nelson kernel: Code: 84 85 db 74 30 83 03 01 8b 04 24 89 
44 ab 04 0f a3 ab 04 01 00 00 19 c0 85 c0 75 68 0f a3 ab 0c 01 00 00 19 
c0 31 c9 85 c0 74 b1 <0f> 0b 14 01 80 cf 32 c0 eb a7 8b 0c 24 8b 54 24 
08 89 4a 08 31

The corresponding mythfrontend log:

2006-01-02 10:12:48.940 Opening audio device 'default'.
2006-01-02 10:12:48.952 Using XV port 240
2006-01-02 10:12:49.157 Changing from None to WatchingPreRecorded
2006-01-02 10:12:49.157 Realtime priority would require SUID as root.
2006-01-02 10:12:49.282 Video timing method: RTC
2006-01-02 10:43:26.226 prebuffering pause
2006-01-02 10:43:29.264 Waited 4 seconds for data to become available, 
waiting again...
2006-01-02 10:43:33.268 Waited 4 seconds for data to become available, 
waiting again...
2006-01-02 10:43:37.272 Waited 4 seconds for data to become available, 
waiting again...
2006-01-02 10:43:41.276 Waited 4 seconds for data to become available, 
waiting again...
2006-01-02 10:43:45.280 Waited 4 seconds for data to become available, 
waiting again...
2006-01-02 10:43:46.957 Waited too long for ringbuffer pause..
2006-01-02 10:43:47.961 Waited too long for ringbuffer pause..
2006-01-02 10:43:48.966 Waited too long for ringbuffer pause..
2006-01-02 10:43:49.969 Waited too long for ringbuffer pause..
<snip>

More information about the mythtv-dev mailing list