Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753980Ab2BENeE (ORCPT ); Sun, 5 Feb 2012 08:34:04 -0500 Received: from mailout10.t-online.de ([194.25.134.21]:53014 "EHLO mailout10.t-online.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751496Ab2BENeB (ORCPT ); Sun, 5 Feb 2012 08:34:01 -0500 Message-ID: <4F2E8537.9070308@t-online.de> Date: Sun, 05 Feb 2012 14:33:43 +0100 From: Knut Petersen User-Agent: Mozilla/5.0 (X11; Linux i686; rv:9.0) Gecko/20111220 Thunderbird/9.0 MIME-Version: 1.0 To: Linus Torvalds CC: linux-kernel@vger.kernel.org, linux-media@vger.kernel.org, mchehab@infradead.org, Greg KH Subject: Re: [BUG] v3.2.1: circular locking dvb_device_open / videobuf_dvb_find_frontend References: <4F170E93.5070604@t-online.de> In-Reply-To: <4F170E93.5070604@t-online.de> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit X-ID: rPXBNcZCohrg6uSQ3Yd6wMpLoAr8+ENXxgd4Q4hWBDyjoMjJJHeqYw4WyX78QAZgS7 X-TOI-MSGID: 93cac11d-e8c7-484e-bef9-1f6ce00e541a Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 16721 Lines: 314 Hi Linus! The problem still exists in 3.2.4, but nobody seems to be interested ... cu, Knut Am 18.01.2012 19:25, schrieb Knut Petersen: > System > ====== > AOpen i915GMm-hfs mobo with Pentium-M (Dothan) and 2GB > distribution: openSuSE 12.1 > kernel: v3.2.1 (commit b8ed9e5b8c34dc9...) > xorg: current git master > kaffeine: 1.2.2 > reproducibility: 100% > > After installation of a Hauppauge WinTV Nova HD-S2 > I see the following kernel info: > > [ 11.528283] udevd[390]: starting version 173 > [ 12.493113] Linux video capture interface: v2.00 > [ 12.897710] IR NEC protocol handler initialized > [ 13.018103] IR RC5(x) protocol handler initialized > [ 13.119275] cx88/2: cx2388x MPEG-TS Driver Manager version 0.0.9 loaded > [ 13.131005] cx88/0: cx2388x v4l2 driver version 0.0.9 loaded > [ 13.137251] cx88[0]: subsystem: 0070:6906, board: Hauppauge WinTV-HVR4000(Lite) DVB-S/S2 [card=69,autodetected], frontend(s): 1 > [ 13.141210] cx88[0]: TV tuner type -1, Radio tuner type -1 > [ 13.201058] IR RC6 protocol handler initialized > [ 13.261732] IR JVC protocol handler initialized > [ 13.393637] i2c-core: driver [tuner] using legacy suspend method > [ 13.409331] IR Sony protocol handler initialized > [ 13.420037] i2c-core: driver [tuner] using legacy resume method > [ 13.450185] IR MCE Keyboard/mouse protocol handler initialized > [ 13.540261] tveeprom 17-0050: Hauppauge model 69100, rev B4C3, serial# 7900937 > [ 13.543914] tveeprom 17-0050: MAC address is 00:0d:fe:78:8f:09 > [ 13.547637] tveeprom 17-0050: tuner model is Conexant CX24118A (idx 123, type 4) > [ 13.551355] tveeprom 17-0050: TV standards ATSC/DVB Digital (eeprom 0x80) > [ 13.554965] tveeprom 17-0050: audio processor is None (idx 0) > [ 13.558488] tveeprom 17-0050: decoder processor is CX880 (idx 20) > [ 13.561975] tveeprom 17-0050: has no radio, has IR receiver, has no IR transmitter > [ 13.565472] cx88[0]: hauppauge eeprom: model=69100 > [ 13.587102] cx2388x alsa driver version 0.0.9 loaded > [ 13.608928] lirc_dev: IR Remote Control driver registered, major 251 > [ 13.694230] IR LIRC bridge handler initialized > [ 13.709152] snd_hda_intel 0000:00:1b.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16 > [ 13.716593] snd_hda_intel 0000:00:1b.0: irq 46 for MSI/MSI-X > [ 13.716655] snd_hda_intel 0000:00:1b.0: setting latency timer to 64 > [ 13.724033] Registered IR keymap rc-hauppauge > [ 13.742601] input: cx88 IR (Hauppauge WinTV-HVR400 as /devices/pci0000:00/0000:00:1e.0/0000:05:05.2/rc/rc0/input5 > [ 13.751082] rc0: cx88 IR (Hauppauge WinTV-HVR400 as /devices/pci0000:00/0000:00:1e.0/0000:05:05.2/rc/rc0 > [ 13.774993] input: MCE IR Keyboard/Mouse (cx88xx) as /devices/virtual/input/input6 > [ 13.782063] rc rc0: lirc_dev: driver ir-lirc-codec (cx88xx) registered at minor = 0 > [ 13.787629] cx88[0]/2: cx2388x 8802 Driver Manager > [ 13.793692] cx88-mpeg driver manager 0000:05:05.2: PCI INT A -> GSI 17 (level, low) -> IRQ 17 > [ 13.800770] cx88[0]/2: found at 0000:05:05.2, rev: 5, irq: 17, latency: 32, mmio: 0xd3000000 > [ 13.818585] cx8800 0000:05:05.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17 > [ 13.828935] input: HDA Digital PCBeep as /devices/pci0000:00/0000:00:1b.0/input/input7 > [ 13.834870] cx88[0]/0: found at 0000:05:05.0, rev: 5, irq: 17, latency: 32, mmio: 0xd1000000 > [ 13.844582] cx88[0]/0: registered device video0 [v4l2] > [ 13.861254] cx88[0]/0: registered device vbi0 > [ 13.883504] snd_rme96 0000:05:04.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16 > [ 13.891201] cx88/2: cx2388x dvb driver version 0.0.9 loaded > [ 13.896111] cx88/2: registering cx8802 driver, type: dvb access: shared > [ 13.899622] cx88[0]/2: subsystem: 0070:6906, board: Hauppauge WinTV-HVR4000(Lite) DVB-S/S2 [card=69] > [ 13.910340] cx88_audio 0000:05:05.1: PCI INT A -> GSI 17 (level, low) -> IRQ 17 > [ 13.914069] cx88[0]/2: cx2388x based DVB/ATSC card > [ 13.917646] cx8802_alloc_frontends() allocating 1 frontend(s) > [ 13.924218] cx88[0]/1: CX88x/0: ALSA support for cx2388x boards > [ 13.999524] DVB: registering new adapter (cx88[0]) > [ 14.004892] DVB: registering adapter 0 frontend 0 (Conexant CX24116/CX24118)... > [...] > [ 143.850012] > [ 143.850019] ====================================================== > [ 143.850027] [ INFO: possible circular locking dependency detected ] > [ 143.850036] 3.2.1-main #19 > [ 143.850040] ------------------------------------------------------- > [ 143.850048] kaffeine/3749 is trying to acquire lock: > [ 143.850055] (&fe->lock){+.+.+.}, at: [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850074] > [ 143.850075] but task is already holding lock: > [ 143.850082] (minor_rwsem#2){++++..}, at: [] dvb_device_open+0x24/0x185 [dvb_core] > [ 143.850102] > [ 143.850103] which lock already depends on the new lock. > [ 143.850105] > [ 143.850113] > [ 143.850114] the existing dependency chain (in reverse order) is: > [ 143.850123] > [ 143.850124] -> #2 (minor_rwsem#2){++++..}: > [ 143.850135] [] lock_acquire+0x45/0x5c > [ 143.850148] [] down_write+0x1b/0x36 > [ 143.850158] [] dvb_register_device+0x10e/0x1e8 [dvb_core] > [ 143.850173] [] dvb_register_frontend+0x168/0x17f [dvb_core] > [ 143.850190] [] videobuf_dvb_register_bus+0xbe/0x2ca [videobuf_dvb] > [ 143.850202] [] cx8802_dvb_probe+0x1df5/0x1e6a [cx88_dvb] > [ 143.850215] [] cx8802_register_driver+0x116/0x1cc [cx8802] > [ 143.850231] [] 0xf85ea01c > [ 143.850241] [] do_one_initcall+0x70/0x118 > [ 143.850250] [] sys_init_module+0x1346/0x15ab > [ 143.850260] [] syscall_call+0x7/0xb > [ 143.850269] > [ 143.850270] -> #1 (dvbdev_register_lock){+.+.+.}: > [ 143.850281] [] lock_acquire+0x45/0x5c > [ 143.850290] [] mutex_lock_nested+0x35/0x275 > [ 143.850300] [] dvb_register_device+0x1f/0x1e8 [dvb_core] > [ 143.850314] [] dvb_dmxdev_init+0xc0/0xf0 [dvb_core] > [ 143.850328] [] videobuf_dvb_register_bus+0x169/0x2ca [videobuf_dvb] > [ 143.850340] [] cx8802_dvb_probe+0x1df5/0x1e6a [cx88_dvb] > [ 143.850351] [] cx8802_register_driver+0x116/0x1cc [cx8802] > [ 143.850363] [] 0xf85ea01c > [ 143.850371] [] do_one_initcall+0x70/0x118 > [ 143.850379] [] sys_init_module+0x1346/0x15ab > [ 143.850388] [] syscall_call+0x7/0xb > [ 143.850397] > [ 143.850398] -> #0 (&fe->lock){+.+.+.}: > [ 143.850407] [] __lock_acquire+0xd88/0x12b8 > [ 143.850416] [] lock_acquire+0x45/0x5c > [ 143.850425] [] mutex_lock_nested+0x35/0x275 > [ 143.850434] [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850446] [] cx88_dvb_bus_ctrl+0x22/0x9a [cx88_dvb] > [ 143.850457] [] dvb_frontend_open+0x14b/0x2ee [dvb_core] > [ 143.850472] [] dvb_device_open+0xcf/0x185 [dvb_core] > [ 143.850486] [] chrdev_open+0x14e/0x16c > [ 143.850504] [] __dentry_open+0x193/0x288 > [ 143.850518] [] nameidata_to_filp+0x42/0x50 > [ 143.850530] [] do_last+0x6da/0x6ec > [ 143.850543] [] path_openat+0xa0/0x2c1 > [ 143.850555] [] do_filp_open+0x21/0x5d > [ 143.850567] [] do_sys_open+0xec/0x165 > [ 143.850580] [] sys_open+0x1e/0x26 > [ 143.850591] [] syscall_call+0x7/0xb > [ 143.850603] > [ 143.850604] other info that might help us debug this: > [ 143.850606] > [ 143.850625] Chain exists of: > [ 143.850626] &fe->lock --> dvbdev_register_lock --> minor_rwsem > [ 143.850643] > [ 143.850654] Possible unsafe locking scenario: > [ 143.850655] > [ 143.850669] CPU0 CPU1 > [ 143.850678] ---- ---- > [ 143.850687] lock(minor_rwsem); > [ 143.850697] lock(dvbdev_register_lock); > [ 143.850710] lock(minor_rwsem); > [ 143.850722] lock(&fe->lock); > [ 143.850732] > [ 143.850733] *** DEADLOCK *** > [ 143.850734] > [ 143.850752] 2 locks held by kaffeine/3749: > [ 143.850761] #0: (dvbdev_mutex){+.+...}, at: [] dvb_device_open+0x1a/0x185 [dvb_core] > [ 143.850784] #1: (minor_rwsem#2){++++..}, at: [] dvb_device_open+0x24/0x185 [dvb_core] > [ 143.850808] > [ 143.850809] stack backtrace: > [ 143.850823] Pid: 3749, comm: kaffeine Not tainted 3.2.1-main #19 > [ 143.850834] Call Trace: > [ 143.850846] [] ? console_unlock+0x1ad/0x1d3 > [ 143.850859] [] print_circular_bug+0x215/0x222 > [ 143.850872] [] __lock_acquire+0xd88/0x12b8 > [ 143.850884] [] ? print_context_stack+0x7a/0x8d > [ 143.850896] [] ? dump_trace+0x78/0xa5 > [ 143.850909] [] lock_acquire+0x45/0x5c > [ 143.850922] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850938] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850952] [] mutex_lock_nested+0x35/0x275 > [ 143.850966] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850981] [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] > [ 143.850998] [] cx88_dvb_bus_ctrl+0x22/0x9a [cx88_dvb] > [ 143.851017] [] dvb_frontend_open+0x14b/0x2ee [dvb_core] > [ 143.851037] [] dvb_device_open+0xcf/0x185 [dvb_core] > [ 143.851051] [] chrdev_open+0x14e/0x16c > [ 143.851064] [] __dentry_open+0x193/0x288 > [ 143.851077] [] ? sub_preempt_count+0x81/0x8e > [ 143.851089] [] nameidata_to_filp+0x42/0x50 > [ 143.851101] [] ? cdev_put+0x1a/0x1a > [ 143.851112] [] do_last+0x6da/0x6ec > [ 143.851124] [] path_openat+0xa0/0x2c1 > [ 143.851136] [] do_filp_open+0x21/0x5d > [ 143.851149] [] ? sub_preempt_count+0x81/0x8e > [ 143.851161] [] ? _raw_spin_unlock+0x27/0x3d > [ 143.851174] [] ? alloc_fd+0xb3/0xbe > [ 143.851186] [] do_sys_open+0xec/0x165 > [ 143.851198] [] sys_open+0x1e/0x26 > [ 143.851209] [] syscall_call+0x7/0xb > [ 143.851220] [] ? w83627hf_probe+0x25b/0x7e2 > > It´s the first time I use DVB-S card with linux, so I don´t know when > this bug was introduced. If necessary I could bisect. > > BTW: maybe it would be a good idea to enable a few more > kernel debug options by default ... > > cu, > Knut [13134.171930] [13134.171938] ====================================================== [13134.171946] [ INFO: possible circular locking dependency detected ] [13134.171954] 3.2.4-main #22 [13134.171959] ------------------------------------------------------- [13134.171967] kaffeine/1037 is trying to acquire lock: [13134.171974] (&fe->lock){+.+.+.}, at: [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.171993] [13134.171994] but task is already holding lock: [13134.172001] (minor_rwsem#2){++++..}, at: [] dvb_device_open+0x24/0x185 [dvb_core] [13134.172006] [13134.172006] which lock already depends on the new lock. [13134.172006] [13134.172006] [13134.172006] the existing dependency chain (in reverse order) is: [13134.172006] [13134.172006] -> #2 (minor_rwsem#2){++++..}: [13134.172006] [] lock_acquire+0x45/0x5c [13134.172006] [] down_write+0x1b/0x36 [13134.172006] [] dvb_register_device+0x10e/0x1e8 [dvb_core] [13134.172006] [] dvb_register_frontend+0x168/0x17f [dvb_core] [13134.172006] [] videobuf_dvb_register_bus+0xbe/0x2ca [videobuf_dvb] [13134.172006] [] cx8802_dvb_probe+0x1df5/0x1e6a [cx88_dvb] [13134.172006] [] cx8802_register_driver+0x116/0x1cc [cx8802] [13134.172006] [] 0xf852601c [13134.172006] [] do_one_initcall+0x70/0x118 [13134.172006] [] sys_init_module+0x1346/0x15ab [13134.172006] [] syscall_call+0x7/0xb [13134.172006] [13134.172006] -> #1 (dvbdev_register_lock){+.+.+.}: [13134.172006] [] lock_acquire+0x45/0x5c [13134.172006] [] mutex_lock_nested+0x35/0x275 [13134.172006] [] dvb_register_device+0x1f/0x1e8 [dvb_core] [13134.172006] [] dvb_dmxdev_init+0xc0/0xf0 [dvb_core] [13134.172006] [] videobuf_dvb_register_bus+0x169/0x2ca [videobuf_dvb] [13134.172006] [] cx8802_dvb_probe+0x1df5/0x1e6a [cx88_dvb] [13134.172006] [] cx8802_register_driver+0x116/0x1cc [cx8802] [13134.172006] [] 0xf852601c [13134.172006] [] do_one_initcall+0x70/0x118 [13134.172006] [] sys_init_module+0x1346/0x15ab [13134.172006] [] syscall_call+0x7/0xb [13134.172006] [13134.172006] -> #0 (&fe->lock){+.+.+.}: [13134.172006] [] __lock_acquire+0xd88/0x12b8 [13134.172006] [] lock_acquire+0x45/0x5c [13134.172006] [] mutex_lock_nested+0x35/0x275 [13134.172006] [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.172006] [] cx88_dvb_bus_ctrl+0x22/0x9a [cx88_dvb] [13134.172006] [] dvb_frontend_open+0x14b/0x2ee [dvb_core] [13134.172006] [] dvb_device_open+0xcf/0x185 [dvb_core] [13134.172006] [] chrdev_open+0x14e/0x16c [13134.172006] [] __dentry_open+0x193/0x288 [13134.172006] [] nameidata_to_filp+0x42/0x50 [13134.172006] [] do_last+0x6da/0x6ec [13134.172006] [] path_openat+0xa0/0x2c1 [13134.172006] [] do_filp_open+0x21/0x5d [13134.172006] [] do_sys_open+0xec/0x165 [13134.172006] [] sys_open+0x1e/0x26 [13134.172006] [] syscall_call+0x7/0xb [13134.172006] [13134.172006] other info that might help us debug this: [13134.172006] [13134.172006] Chain exists of: [13134.172006] &fe->lock --> dvbdev_register_lock --> minor_rwsem [13134.172006] [13134.172006] Possible unsafe locking scenario: [13134.172006] [13134.172006] CPU0 CPU1 [13134.172006] ---- ---- [13134.172006] lock(minor_rwsem); [13134.172006] lock(dvbdev_register_lock); [13134.172006] lock(minor_rwsem); [13134.172006] lock(&fe->lock); [13134.172006] [13134.172006] *** DEADLOCK *** [13134.172006] [13134.172006] 2 locks held by kaffeine/1037: [13134.172006] #0: (dvbdev_mutex){+.+...}, at: [] dvb_device_open+0x1a/0x185 [dvb_core] [13134.172006] #1: (minor_rwsem#2){++++..}, at: [] dvb_device_open+0x24/0x185 [dvb_core] [13134.172006] [13134.172006] stack backtrace: [13134.172006] Pid: 1037, comm: kaffeine Not tainted 3.2.4-main #22 [13134.172006] Call Trace: [13134.172006] [] ? console_unlock+0x1ad/0x1d3 [13134.172006] [] print_circular_bug+0x215/0x222 [13134.172006] [] __lock_acquire+0xd88/0x12b8 [13134.172006] [] ? print_context_stack+0x7a/0x8d [13134.172006] [] ? dump_trace+0x78/0xa5 [13134.172006] [] lock_acquire+0x45/0x5c [13134.172006] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.172006] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.172006] [] mutex_lock_nested+0x35/0x275 [13134.172006] [] ? videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.172006] [] videobuf_dvb_find_frontend+0x16/0x3e [videobuf_dvb] [13134.172006] [] cx88_dvb_bus_ctrl+0x22/0x9a [cx88_dvb] [13134.172006] [] dvb_frontend_open+0x14b/0x2ee [dvb_core] [13134.172006] [] dvb_device_open+0xcf/0x185 [dvb_core] [13134.172006] [] chrdev_open+0x14e/0x16c [13134.172006] [] __dentry_open+0x193/0x288 [13134.172006] [] ? sub_preempt_count+0x81/0x8e [13134.172006] [] nameidata_to_filp+0x42/0x50 [13134.172006] [] ? cdev_put+0x1a/0x1a [13134.172006] [] do_last+0x6da/0x6ec [13134.172006] [] path_openat+0xa0/0x2c1 [13134.172006] [] do_filp_open+0x21/0x5d [13134.172006] [] ? sub_preempt_count+0x81/0x8e [13134.172006] [] ? _raw_spin_unlock+0x27/0x3d [13134.172006] [] ? alloc_fd+0xb3/0xbe [13134.172006] [] do_sys_open+0xec/0x165 [13134.172006] [] sys_open+0x1e/0x26 [13134.172006] [] syscall_call+0x7/0xb [13134.172006] [] ? i801_probe+0x1b1/0x2f4 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/