From mboxrd@z Thu Jan 1 00:00:00 1970 Return-path: Received: from mail-ee0-f41.google.com ([74.125.83.41]:61815 "EHLO mail-ee0-f41.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751423AbaAMVtv (ORCPT ); Mon, 13 Jan 2014 16:49:51 -0500 Received: by mail-ee0-f41.google.com with SMTP id e49so1740704eek.14 for ; Mon, 13 Jan 2014 13:49:50 -0800 (PST) Message-ID: <52D45FC4.10106@googlemail.com> Date: Mon, 13 Jan 2014 22:51:00 +0100 From: =?ISO-8859-1?Q?Frank_Sch=E4fer?= MIME-Version: 1.0 To: Mauro Carvalho Chehab , unlisted-recipients:; CC: Linux Media Mailing List , Mauro Carvalho Chehab Subject: Re: [PATCH 5/7] em28xx-audio: remove a deplock circular dependency References: <1389567649-26838-1-git-send-email-m.chehab@samsung.com> <1389567649-26838-6-git-send-email-m.chehab@samsung.com> In-Reply-To: <1389567649-26838-6-git-send-email-m.chehab@samsung.com> Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Sender: linux-media-owner@vger.kernel.org List-ID: Am 13.01.2014 00:00, schrieb Mauro Carvalho Chehab: > We can't lock at pcm close, as it causes circular dependency > lock issues with .init and .fini callbacks. So, move the code > that puts the device on mute to the kthread. > > [ 322.026316] ====================================================== > [ 322.026356] [ INFO: possible circular locking dependency detected ] > [ 322.026397] 3.13.0-rc1+ #24 Not tainted > [ 322.026437] ------------------------------------------------------- > [ 322.026476] khubd/54 is trying to acquire lock: > [ 322.026516] (&pcm->open_mutex){+.+.+.}, at: [] snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.026727] > but task is already holding lock: > [ 322.026767] (register_mutex#3){+.+.+.}, at: [] snd_pcm_dev_disconnect+0x24/0x1e0 [snd_pcm] > [ 322.027005] > which lock already depends on the new lock. > > [ 322.027045] > the existing dependency chain (in reverse order) is: > [ 322.027084] > -> #2 (register_mutex#3){+.+.+.}: > [ 322.027318] [] __lock_acquire+0xb43/0x1330 > [ 322.027401] [] lock_acquire+0xa2/0x120 > [ 322.027479] [] mutex_lock_nested+0x5c/0x3c0 > [ 322.027559] [] snd_pcm_dev_disconnect+0x24/0x1e0 [snd_pcm] > [ 322.027642] [] snd_device_disconnect+0x6a/0xf0 [snd] > [ 322.027727] [] snd_device_disconnect_all+0x4c/0x90 [snd] > [ 322.027814] [] snd_card_disconnect+0x126/0x1d0 [snd] > [ 322.027898] [] snd_card_free+0x18/0x90 [snd] > [ 322.027982] [] em28xx_audio_fini+0x8f/0xa0 [em28xx_alsa] > [ 322.028063] [] em28xx_close_extension+0x56/0x90 [em28xx] > [ 322.028143] [] em28xx_usb_disconnect+0x79/0x90 [em28xx] > [ 322.028222] [] usb_unbind_interface+0x67/0x1d0 > [ 322.028302] [] __device_release_driver+0x7f/0xf0 > [ 322.028381] [] device_release_driver+0x25/0x40 > [ 322.028462] [] bus_remove_device+0x11c/0x1a0 > [ 322.028540] [] device_del+0x136/0x1d0 > [ 322.028619] [] usb_disable_device+0xb0/0x290 > [ 322.028698] [] usb_disconnect+0xb5/0x1d0 > [ 322.028779] [] hub_port_connect_change+0xd6/0xad0 > [ 322.028859] [] hub_events+0x313/0x9b0 > [ 322.028940] [] hub_thread+0x35/0x170 > [ 322.029019] [] kthread+0xff/0x120 > [ 322.029099] [] ret_from_fork+0x7c/0xb0 > [ 322.029179] > -> #1 (&dev->lock#2){+.+.+.}: > [ 322.029414] [] __lock_acquire+0xb43/0x1330 > [ 322.029494] [] lock_acquire+0xa2/0x120 > [ 322.029572] [] mutex_lock_nested+0x5c/0x3c0 > [ 322.029651] [] snd_em28xx_pcm_close+0x3e/0x100 [em28xx_alsa] > [ 322.029732] [] snd_pcm_release_substream.part.29+0x3f/0x90 [snd_pcm] > [ 322.029816] [] snd_pcm_release+0xb0/0xd0 [snd_pcm] > [ 322.029900] [] __fput+0xe2/0x230 > [ 322.029979] [] ____fput+0xe/0x10 > [ 322.030057] [] task_work_run+0x9f/0xe0 > [ 322.030135] [] do_notify_resume+0x61/0xa0 > [ 322.030223] [] int_signal+0x12/0x17 > [ 322.030294] > -> #0 (&pcm->open_mutex){+.+.+.}: > [ 322.030473] [] check_prevs_add+0x947/0x950 > [ 322.030546] [] __lock_acquire+0xb43/0x1330 > [ 322.030618] [] lock_acquire+0xa2/0x120 > [ 322.030689] [] mutex_lock_nested+0x5c/0x3c0 > [ 322.030760] [] snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.030835] [] snd_device_disconnect+0x6a/0xf0 [snd] > [ 322.030913] [] snd_device_disconnect_all+0x4c/0x90 [snd] > [ 322.030988] [] snd_card_disconnect+0x126/0x1d0 [snd] > [ 322.031067] [] snd_card_free+0x18/0x90 [snd] > [ 322.031146] [] em28xx_audio_fini+0x8f/0xa0 [em28xx_alsa] > [ 322.031220] [] em28xx_close_extension+0x56/0x90 [em28xx] > [ 322.031292] [] em28xx_usb_disconnect+0x79/0x90 [em28xx] > [ 322.031363] [] usb_unbind_interface+0x67/0x1d0 > [ 322.031433] [] __device_release_driver+0x7f/0xf0 > [ 322.031503] [] device_release_driver+0x25/0x40 > [ 322.031573] [] bus_remove_device+0x11c/0x1a0 > [ 322.031643] [] device_del+0x136/0x1d0 > [ 322.031714] [] usb_disable_device+0xb0/0x290 > [ 322.031784] [] usb_disconnect+0xb5/0x1d0 > [ 322.031853] [] hub_port_connect_change+0xd6/0xad0 > [ 322.031922] [] hub_events+0x313/0x9b0 > [ 322.031992] [] hub_thread+0x35/0x170 > [ 322.032062] [] kthread+0xff/0x120 > [ 322.032135] [] ret_from_fork+0x7c/0xb0 > [ 322.032205] > other info that might help us debug this: > > [ 322.032240] Chain exists of: > &pcm->open_mutex --> &dev->lock#2 --> register_mutex#3 > > [ 322.032547] Possible unsafe locking scenario: > > [ 322.032582] CPU0 CPU1 > [ 322.032616] ---- ---- > [ 322.032654] lock(register_mutex#3); > [ 322.032793] lock(&dev->lock#2); > [ 322.032929] lock(register_mutex#3); > [ 322.033064] lock(&pcm->open_mutex); > [ 322.033168] > *** DEADLOCK *** > > [ 322.033204] 6 locks held by khubd/54: > [ 322.033239] #0: (&__lockdep_no_validate__){......}, at: [] hub_events+0xb4/0x9b0 > [ 322.033446] #1: (&__lockdep_no_validate__){......}, at: [] usb_disconnect+0x66/0x1d0 > [ 322.033655] #2: (&__lockdep_no_validate__){......}, at: [] device_release_driver+0x1d/0x40 > [ 322.033859] #3: (em28xx_devlist_mutex){+.+.+.}, at: [] em28xx_close_extension+0x27/0x90 [em28xx] > [ 322.034067] #4: (&dev->lock#2){+.+.+.}, at: [] em28xx_close_extension+0x31/0x90 [em28xx] > [ 322.034307] #5: (register_mutex#3){+.+.+.}, at: [] snd_pcm_dev_disconnect+0x24/0x1e0 [snd_pcm] > [ 322.034552] > stack backtrace: > [ 322.034588] CPU: 3 PID: 54 Comm: khubd Not tainted 3.13.0-rc1+ #24 > [ 322.034624] Hardware name: SAMSUNG ELECTRONICS CO., LTD. 550P5C/550P7C/SAMSUNG_NP1234567890, BIOS P04ABI.013.130220.dg 02/20/2013 > [ 322.034659] ffffffff82513770 ffff880221bcd7c8 ffffffff816a03c6 ffffffff8250a810 > [ 322.034832] ffff880221bcd808 ffffffff8169a203 ffff880221bcd830 0000000000000005 > [ 322.035004] ffff8802222b2880 ffff8802222b3020 ffff8802222b3020 0000000000000006 > [ 322.035187] Call Trace: > [ 322.035230] [] dump_stack+0x45/0x56 > [ 322.035276] [] print_circular_bug+0x200/0x20e > [ 322.035320] [] check_prevs_add+0x947/0x950 > [ 322.035365] [] ? native_sched_clock+0x13/0x80 > [ 322.035409] [] __lock_acquire+0xb43/0x1330 > [ 322.035454] [] lock_acquire+0xa2/0x120 > [ 322.035500] [] ? snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.035550] [] mutex_lock_nested+0x5c/0x3c0 > [ 322.035596] [] ? snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.035648] [] ? snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.035697] [] ? trace_hardirqs_on_caller+0x105/0x1d0 > [ 322.035744] [] snd_pcm_dev_disconnect+0x46/0x1e0 [snd_pcm] > [ 322.035797] [] snd_device_disconnect+0x6a/0xf0 [snd] > [ 322.035852] [] snd_device_disconnect_all+0x4c/0x90 [snd] > [ 322.035904] [] snd_card_disconnect+0x126/0x1d0 [snd] > [ 322.035957] [] snd_card_free+0x18/0x90 [snd] > [ 322.036008] [] em28xx_audio_fini+0x8f/0xa0 [em28xx_alsa] > [ 322.036054] [] em28xx_close_extension+0x56/0x90 [em28xx] > [ 322.036100] [] em28xx_usb_disconnect+0x79/0x90 [em28xx] > [ 322.036144] [] usb_unbind_interface+0x67/0x1d0 > [ 322.036188] [] __device_release_driver+0x7f/0xf0 > [ 322.036231] [] device_release_driver+0x25/0x40 > [ 322.036274] [] bus_remove_device+0x11c/0x1a0 > [ 322.036318] [] device_del+0x136/0x1d0 > [ 322.036361] [] usb_disable_device+0xb0/0x290 > [ 322.036404] [] usb_disconnect+0xb5/0x1d0 > [ 322.036447] [] hub_port_connect_change+0xd6/0xad0 > [ 322.036492] [] ? usb_control_msg+0xd4/0x110 > [ 322.036535] [] hub_events+0x313/0x9b0 > [ 322.036579] [] ? trace_hardirqs_on_caller+0x105/0x1d0 > [ 322.036623] [] hub_thread+0x35/0x170 > [ 322.036667] [] ? abort_exclusive_wait+0xb0/0xb0 > [ 322.036711] [] ? hub_events+0x9b0/0x9b0 > [ 322.036756] [] kthread+0xff/0x120 > [ 322.036802] [] ? kthread_create_on_node+0x250/0x250 > [ 322.036846] [] ret_from_fork+0x7c/0xb0 > [ 322.036890] [] ? kthread_create_on_node+0x250/0x250 > > Signed-off-by: Mauro Carvalho Chehab > --- > drivers/media/usb/em28xx/em28xx-audio.c | 10 +++++++--- > 1 file changed, 7 insertions(+), 3 deletions(-) > > diff --git a/drivers/media/usb/em28xx/em28xx-audio.c b/drivers/media/usb/em28xx/em28xx-audio.c > index cdc2fcf3e05e..5e16fcf18cac 100644 > --- a/drivers/media/usb/em28xx/em28xx-audio.c > +++ b/drivers/media/usb/em28xx/em28xx-audio.c > @@ -311,20 +311,17 @@ static int snd_em28xx_pcm_close(struct snd_pcm_substream *substream) > dprintk("closing device\n"); > > dev->mute = 1; > - mutex_lock(&dev->lock); > dev->adev.users--; > if (atomic_read(&dev->stream_started) > 0) { > atomic_set(&dev->stream_started, 0); > schedule_work(&dev->wq_trigger); > } > > - em28xx_audio_analog_set(dev); > if (substream->runtime->dma_area) { > dprintk("freeing\n"); > vfree(substream->runtime->dma_area); > substream->runtime->dma_area = NULL; > } > - mutex_unlock(&dev->lock); > > return 0; > } > @@ -395,6 +392,13 @@ static void audio_trigger(struct work_struct *work) > } else { > dprintk("stopping capture"); > em28xx_deinit_isoc_audio(dev); > + > + /* Mute device if needed */ > + if (dev->mute) { > + mutex_lock(&dev->lock); > + em28xx_audio_analog_set(dev); > + mutex_unlock(&dev->lock); > + } > } > } It's already late and I don't understand this deadlock yet completely, but are you sure this is the proper fix for this issue ? What happens when capturing is restarted ? Shouldn't the device then be unmuted again ? How often does the start/stop/resume happen ?