Hi,

I am running a Hauppauge NOVA-S plus (cx2388x based card) and an older 
technotrend S-1500 card in the same chassis. Trying to debug other problems I 
have turned on lock debugging in  the kernel and have started getting the 
following dump when both cards are started:

--------------------------------------------------------------------------------------------

Jan 22 11:00:17 TEMERAIRE kernel: [  218.547514]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547515] 
=================================
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547519] [ INFO: inconsistent lock 
state ]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547521] 2.6.23.14 #5
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547523] 
---------------------------------
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547525] inconsistent {softirq-on-W} -> 
{in-softirq-W} usage.
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547527] startup1.pl/13742 
[HC0[0]:SC1[1]:HE1:SE0] takes:
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547532] (&dvbdemux->lock){-+..}, at: 
[<f0a10df9>] dvb_dmx_swfilter_packets+0x1f/0x49 [dvb_core]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547590] {softirq-on-W} state was 
registered at:
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547598]   [<c0440eb7>] 
__lock_acquire+0x4aa/0xc1a
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547615]   [<c04416a1>] 
lock_acquire+0x7a/0x94
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547682]   [<c06339bd>] 
_spin_lock+0x2e/0x58
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547712]   [<f0a10c8b>] 
dvb_dmx_swfilter+0x21/0x104 [dvb_core]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547737]   [<f0d22383>] 
videobuf_dvb_thread+0x83/0x105 [video_buf_dvb]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547752]   [<c0435b9c>] 
kthread+0x3b/0x63
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547804]   [<c0405b9f>] 
kernel_thread_helper+0x7/0x10
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547874]   [<ffffffff>] 0xffffffff
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547888] irq event stamp: 22178648
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547889] hardirqs last  enabled at 
(22178648): [<c04298e8>] tasklet_action+0x26/0xa8
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547893] hardirqs last disabled at 
(22178647): [<c04298cd>] tasklet_action+0xb/0xa8
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547896] softirqs last  enabled at 
(22178536): [<c0429889>] __do_softirq+0xe3/0xe9
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547899] softirqs last disabled at 
(22178645): [<c0407046>] do_softirq+0x61/0xc7
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547903]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547903] other info that might help us 
debug this:
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547904] no locks held by 
startup1.pl/13742.
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547906]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547906] stack backtrace:
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547908]  [<c0405f18>] 
show_trace_log_lvl+0x1a/0x2f
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547911]  [<c040690a>] 
show_trace+0x12/0x14
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547914]  [<c0406922>] 
dump_stack+0x16/0x18
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547916]  [<c043f3b9>] 
print_usage_bug+0x140/0x14a
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547919]  [<c0440070>] 
mark_lock+0x12e/0x45b
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547921]  [<c0440e47>] 
__lock_acquire+0x43a/0xc1a
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547923]  [<c04416a1>] 
lock_acquire+0x7a/0x94
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547926]  [<c06339bd>] 
_spin_lock+0x2e/0x58
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547928]  [<f0a10df9>] 
dvb_dmx_swfilter_packets+0x1f/0x49 [dvb_core]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547937]  [<f091f73a>] 
vpeirq+0xc0/0x130 [budget_core]
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547941]  [<c0429915>] 
tasklet_action+0x53/0xa8
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547943]  [<c0429815>] 
__do_softirq+0x6f/0xe9
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547946]  [<c0407046>] 
do_softirq+0x61/0xc7
Jan 22 11:00:17 TEMERAIRE kernel: [  218.547948]  =======================
Jan 22 11:00:18 TEMERAIRE kernel: [  219.745305] saa7146_i2c_writeout: timed 
out waiting for end of xfer
--------------------------------------------------------------------------------------------

The same dump occurs with different processes named in the line:
"startup1.pl/13742 [HC0[0]:SC1[1]:HE1:SE0] takes:", though the rest is 
essentially the same.

Now, I am interpreting this as saying that the demux->lock used in 
dvb_dxm_swfilter and dvb_dmx_swfilter_packets has become inconsistent. I think 
this has happened because one of the locks was taken from a soft IRQ.

Changing the spinlocks to spin_lock_irqsave/restore on that lock object in 
dvb_demux.c has stopped that error message.

I am not an expert in this, but is this the correct interpretation and 
resolution? If so, I'll send a patch. If this is not the correct way of fixing 
this, does anyone have any suggestions?

This is of course using an SMP kernel and I have a Intel Core2 6700 @ 2.66GHz
 processor.

Cheers

Pete

_______________________________________________
linux-dvb mailing list
linux-dvb@linuxtv.org
http://www.linuxtv.org/cgi-bin/mailman/listinfo/linux-dvb

Reply via email to