From mboxrd@z Thu Jan 1 00:00:00 1970 From: Daniel Mack Subject: Re: aplay: possible circular locking dependency detected Date: Thu, 25 Feb 2010 16:48:04 +0100 Message-ID: <20100225154804.GZ28972@buzzloop.caiaq.de> References: <20100221133151.GA28396@buzzloop.caiaq.de> Mime-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Return-path: Received: from buzzloop.caiaq.de (buzzloop.caiaq.de [212.112.241.133]) by alsa0.perex.cz (Postfix) with ESMTP id 43982244E3 for ; Thu, 25 Feb 2010 16:48:20 +0100 (CET) Received: from localhost (localhost [127.0.0.1]) by buzzloop.caiaq.de (Postfix) with ESMTP id 1CEF184000D for ; Thu, 25 Feb 2010 16:48:19 +0100 (CET) Received: from buzzloop.caiaq.de ([127.0.0.1]) by localhost (buzzloop.caiaq.de [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id aI49UY1-oyhS for ; Thu, 25 Feb 2010 16:48:05 +0100 (CET) Content-Disposition: inline In-Reply-To: <20100221133151.GA28396@buzzloop.caiaq.de> List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: alsa-devel-bounces@alsa-project.org Errors-To: alsa-devel-bounces@alsa-project.org To: alsa-devel@alsa-project.org List-Id: alsa-devel@alsa-project.org On Sun, Feb 21, 2010 at 02:31:51PM +0100, Daniel Mack wrote: > I got this once while testing an USB audio device. Appeareantly not reproducable. Contrary to what I claimed, this _is_ in fact reproducable, and happend every first time after a reboot. Just tried again with 2.6.33-vanilla, and it still happens to me. Random lockups occur afterwards. Before I dig into this myself to find the root cause: does anyone have an idea? Thanks, Daniel > Feb 21 14:26:29 jup kernel: [69661.385427] > Feb 21 14:26:29 jup kernel: [69661.385430] ======================================================= > Feb 21 14:26:29 jup kernel: [69661.385435] [ INFO: possible circular locking dependency detected ] > Feb 21 14:26:29 jup kernel: [69661.385439] 2.6.33-rc8 #21 > Feb 21 14:26:29 jup kernel: [69661.385441] ------------------------------------------------------- > Feb 21 14:26:29 jup kernel: [69661.385444] aplay/11761 is trying to acquire lock: > Feb 21 14:26:29 jup kernel: [69661.385446] (sysfs_mutex){+.+.+.}, at: [] sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385457] > Feb 21 14:26:29 jup kernel: [69661.385457] but task is already holding lock: > Feb 21 14:26:29 jup kernel: [69661.385460] (&pcm->open_mutex){+.+.+.}, at: [] snd_pcm_release+0x55/0x9e [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385474] > Feb 21 14:26:29 jup kernel: [69661.385474] which lock already depends on the new lock. > Feb 21 14:26:29 jup kernel: [69661.385476] > Feb 21 14:26:29 jup kernel: [69661.385478] > Feb 21 14:26:29 jup kernel: [69661.385479] the existing dependency chain (in reverse order) is: > Feb 21 14:26:29 jup kernel: [69661.385481] > Feb 21 14:26:29 jup kernel: [69661.385482] -> #2 (&pcm->open_mutex){+.+.+.}: > Feb 21 14:26:29 jup kernel: [69661.385487] [] __lock_acquire+0x10ff/0x1422 > Feb 21 14:26:29 jup kernel: [69661.385493] [] lock_acquire+0xa8/0xbf > Feb 21 14:26:29 jup kernel: [69661.385498] [] mutex_lock_nested+0x47/0x2b2 > Feb 21 14:26:29 jup kernel: [69661.385503] [] snd_pcm_release+0x55/0x9e [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385513] [] __fput+0xeb/0x196 > Feb 21 14:26:29 jup kernel: [69661.385517] [] fput+0x19/0x1b > Feb 21 14:26:29 jup kernel: [69661.385522] [] remove_vma+0x39/0x58 > Feb 21 14:26:29 jup kernel: [69661.385528] [] do_munmap+0x23c/0x259 > Feb 21 14:26:29 jup kernel: [69661.385532] [] sys_munmap+0x30/0x3f > Feb 21 14:26:29 jup kernel: [69661.385536] [] sysenter_do_call+0x12/0x36 > Feb 21 14:26:29 jup kernel: [69661.385541] > Feb 21 14:26:29 jup kernel: [69661.385542] -> #1 (&mm->mmap_sem){++++++}: > Feb 21 14:26:29 jup kernel: [69661.385547] [] __lock_acquire+0x10ff/0x1422 > Feb 21 14:26:29 jup kernel: [69661.385551] [] lock_acquire+0xa8/0xbf > Feb 21 14:26:29 jup kernel: [69661.385556] [] might_fault+0x6b/0x88 > Feb 21 14:26:29 jup kernel: [69661.385561] [] copy_to_user+0x2c/0xfc > Feb 21 14:26:29 jup kernel: [69661.385565] [] filldir64+0x97/0xcd > Feb 21 14:26:29 jup kernel: [69661.385570] [] sysfs_readdir+0x117/0x14b > Feb 21 14:26:29 jup kernel: [69661.385574] [] vfs_readdir+0x68/0x94 > Feb 21 14:26:29 jup kernel: [69661.385578] [] sys_getdents64+0x63/0xa0 > Feb 21 14:26:29 jup kernel: [69661.385582] [] sysenter_do_call+0x12/0x36 > Feb 21 14:26:29 jup kernel: [69661.385587] > Feb 21 14:26:29 jup kernel: [69661.385587] -> #0 (sysfs_mutex){+.+.+.}: > Feb 21 14:26:29 jup kernel: [69661.385592] [] __lock_acquire+0xe55/0x1422 > Feb 21 14:26:29 jup kernel: [69661.385597] [] lock_acquire+0xa8/0xbf > Feb 21 14:26:29 jup kernel: [69661.385601] [] mutex_lock_nested+0x47/0x2b2 > Feb 21 14:26:29 jup kernel: [69661.385605] [] sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385609] [] sysfs_remove_group+0x1e/0xa3 > Feb 21 14:26:29 jup kernel: [69661.385614] [] dpm_sysfs_remove+0x10/0x12 > Feb 21 14:26:29 jup kernel: [69661.385619] [] device_del+0x33/0x154 > Feb 21 14:26:29 jup kernel: [69661.385625] [] device_unregister+0xb/0x15 > Feb 21 14:26:29 jup kernel: [69661.385629] [] usb_remove_ep_devs+0x15/0x1f > Feb 21 14:26:29 jup kernel: [69661.385635] [] remove_intf_ep_devs+0x21/0x32 > Feb 21 14:26:29 jup kernel: [69661.385640] [] usb_set_interface+0x18c/0x22c > Feb 21 14:26:29 jup kernel: [69661.385644] [] snd_usb_playback_close+0x20/0x33 [snd_usb_audio] > Feb 21 14:26:29 jup kernel: [69661.385654] [] snd_pcm_release_substream+0x3d/0x66 [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385664] [] snd_pcm_release+0x5c/0x9e [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385673] [] __fput+0xeb/0x196 > Feb 21 14:26:29 jup kernel: [69661.385677] [] fput+0x19/0x1b > Feb 21 14:26:29 jup kernel: [69661.385681] [] remove_vma+0x39/0x58 > Feb 21 14:26:29 jup kernel: [69661.385685] [] do_munmap+0x23c/0x259 > Feb 21 14:26:29 jup kernel: [69661.385689] [] sys_munmap+0x30/0x3f > Feb 21 14:26:29 jup kernel: [69661.385693] [] sysenter_do_call+0x12/0x36 > Feb 21 14:26:29 jup kernel: [69661.385698] > Feb 21 14:26:29 jup kernel: [69661.385698] other info that might help us debug this: > Feb 21 14:26:29 jup kernel: [69661.385700] > Feb 21 14:26:29 jup kernel: [69661.385702] 2 locks held by aplay/11761: > Feb 21 14:26:29 jup kernel: [69661.385705] #0: (&mm->mmap_sem){++++++}, at: [] sys_munmap+0x23/0x3f > Feb 21 14:26:29 jup kernel: [69661.385711] #1: (&pcm->open_mutex){+.+.+.}, at: [] snd_pcm_release+0x55/0x9e [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385723] > Feb 21 14:26:29 jup kernel: [69661.385724] stack backtrace: > Feb 21 14:26:29 jup kernel: [69661.385727] Pid: 11761, comm: aplay Not tainted 2.6.33-rc8 #21 > Feb 21 14:26:29 jup kernel: [69661.385730] Call Trace: > Feb 21 14:26:29 jup kernel: [69661.385735] [] ? printk+0xf/0x11 > Feb 21 14:26:29 jup kernel: [69661.385740] [] print_circular_bug+0x90/0x9c > Feb 21 14:26:29 jup kernel: [69661.385744] [] __lock_acquire+0xe55/0x1422 > Feb 21 14:26:29 jup kernel: [69661.385748] [] ? __lock_acquire+0x120e/0x1422 > Feb 21 14:26:29 jup kernel: [69661.385753] [] ? try_to_del_timer_sync+0x9c/0xa4 > Feb 21 14:26:29 jup kernel: [69661.385758] [] lock_acquire+0xa8/0xbf > Feb 21 14:26:29 jup kernel: [69661.385762] [] ? sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385766] [] ? sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385769] [] mutex_lock_nested+0x47/0x2b2 > Feb 21 14:26:29 jup kernel: [69661.385773] [] ? sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385777] [] ? __mutex_unlock_slowpath+0xe9/0x105 > Feb 21 14:26:29 jup kernel: [69661.385781] [] ? trace_hardirqs_on_caller+0xff/0x120 > Feb 21 14:26:29 jup kernel: [69661.385785] [] sysfs_get_dirent+0x15/0x4c > Feb 21 14:26:29 jup kernel: [69661.385789] [] sysfs_remove_group+0x1e/0xa3 > Feb 21 14:26:29 jup kernel: [69661.385793] [] dpm_sysfs_remove+0x10/0x12 > Feb 21 14:26:29 jup kernel: [69661.385797] [] device_del+0x33/0x154 > Feb 21 14:26:29 jup kernel: [69661.385801] [] device_unregister+0xb/0x15 > Feb 21 14:26:29 jup kernel: [69661.385805] [] usb_remove_ep_devs+0x15/0x1f > Feb 21 14:26:29 jup kernel: [69661.385809] [] remove_intf_ep_devs+0x21/0x32 > Feb 21 14:26:29 jup kernel: [69661.385813] [] usb_set_interface+0x18c/0x22c > Feb 21 14:26:29 jup kernel: [69661.385822] [] snd_usb_playback_close+0x20/0x33 [snd_usb_audio] > Feb 21 14:26:29 jup kernel: [69661.385830] [] snd_pcm_release_substream+0x3d/0x66 [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385839] [] snd_pcm_release+0x5c/0x9e [snd_pcm] > Feb 21 14:26:29 jup kernel: [69661.385843] [] __fput+0xeb/0x196 > Feb 21 14:26:29 jup kernel: [69661.385847] [] fput+0x19/0x1b > Feb 21 14:26:29 jup kernel: [69661.385851] [] remove_vma+0x39/0x58 > Feb 21 14:26:29 jup kernel: [69661.385854] [] do_munmap+0x23c/0x259 > Feb 21 14:26:29 jup kernel: [69661.385858] [] sys_munmap+0x30/0x3f > Feb 21 14:26:29 jup kernel: [69661.385862] [] sysenter_do_call+0x12/0x36