From mboxrd@z Thu Jan 1 00:00:00 1970 Return-path: Received: from mail-ea0-f179.google.com ([209.85.215.179]:60787 "EHLO mail-ea0-f179.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751458AbaANSmn (ORCPT ); Tue, 14 Jan 2014 13:42:43 -0500 Received: by mail-ea0-f179.google.com with SMTP id r15so561ead.24 for ; Tue, 14 Jan 2014 10:42:41 -0800 (PST) Message-ID: <52D58569.3000405@googlemail.com> Date: Tue, 14 Jan 2014 19:43:53 +0100 From: =?UTF-8?B?RnJhbmsgU2Now6RmZXI=?= MIME-Version: 1.0 To: Mauro Carvalho Chehab 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> <52D45FC4.10106@googlemail.com> <20140114134541.1e1f2469@samsung.com> In-Reply-To: <20140114134541.1e1f2469@samsung.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit Sender: linux-media-owner@vger.kernel.org List-ID: On 14.01.2014 16:45, Mauro Carvalho Chehab wrote: > Em Mon, 13 Jan 2014 22:51:00 +0100 > Frank Schäfer escreveu: > >> 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 *** I don't get it. Where is the deadlock here ??? Mauro, be honest: did you understand what's going on here ? >>> >>> [ 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); >>> + } >>> } >>> } After thinking about this for a while: Does your patch [PATCH] em28xx: push mutex down to extensions on .fini callback which you've sent afterwards fix this warning, too ? >> 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 ? > This is one possible way to fix. > >> What happens when capturing is restarted ? Shouldn't the device then be >> unmuted again ? > Please note that, inside em28xx-audio.c, only the open callback unmutes > the device, and only the close callback sets it to mute. > > As the close callback ask the work tree to run, the above code will > defer mute to when the work queue runs. > > So, the logic seems equivalent to the existing logic. > > It should be noticed that we can change that code to always call > em28xx_audio_analog_set() there, and remove the code that calls > it from snd_em28xx_capture_open(). > > I can't see any functional changes with such changes. > > That's said, I remember we spent lots of time at linux-media > discussing if the alsa start should automatically unmute a > device or just keep it as-is. > > I don't remember the exact results, but I think we opted to put the > unmute code there due to pulseaudio bugs, as, without such code, > pulseaudio would change the mixers and make some mess. >> >> >> How often does the start/stop/resume happen ? > At device open, it starts. At device closes, it stops. > > If a buffer underrun/overrun occurs, it will stop/start, but, > in that case, the dev->mute state won't change. True, but if dev->mute=1, you are calling em28xx_audio_analog_set(dev) again and again. That's crap. Yes, Sometimes dirty workarounds are needed for the sake of fixing bugs. But I prefer to understand what's wrong before coming up with solution. Of course, I can't force anybody to spend more time on this and I don't have the hardware to reproduce/investigate this issue. So it seems I lost. Regards, Frank > > Regards, > > Cheers, > Mauro