Manu Abraham wrote:
> [EMAIL PROTECTED] wrote:
>> 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.
>>
>
>
> Can you replicate the problem when you aren't using videobuf, ie: when
> not using the devices that depend on videobuf and video_buf_dvb ?
Sorry, I'm being thick here, but I'm not sure I understand the question. I am
only reading DVB from these devices. The error occurs with the stock drivers
from the 2.6.23.14 kernel and the latest hg drivers as well.
>
> Regards,
> Manu
>
>
> _______________________________________________
> linux-dvb mailing list
> [email protected]
> http://www.linuxtv.org/cgi-bin/mailman/listinfo/linux-dvb
_______________________________________________
linux-dvb mailing list
[email protected]
http://www.linuxtv.org/cgi-bin/mailman/listinfo/linux-dvb
