From mboxrd@z Thu Jan 1 00:00:00 1970 From: Valdis.Kletnieks@vt.edu Subject: mmotm 2010-11-09 - lockdep splat in ext4/quota code Date: Thu, 11 Nov 2010 14:25:41 -0500 Message-ID: <19688.1289503541@localhost> References: <201011100003.oAA03O3c015222@imap1.linux-foundation.org> Mime-Version: 1.0 Content-Type: multipart/signed; boundary="==_Exmh_1289503541_5030P"; micalg=pgp-sha1; protocol="application/pgp-signature" Content-Transfer-Encoding: 7bit Cc: linux-kernel@vger.kernel.org, linux-fsdevel@vger.kernel.org To: Andrew Morton , "Theodore Ts'o" , Andreas Dilger , Jan Kara Return-path: Received: from lennier.cc.vt.edu ([198.82.162.213]:39289 "EHLO lennier.cc.vt.edu" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754437Ab0KKTZ4 (ORCPT ); Thu, 11 Nov 2010 14:25:56 -0500 In-Reply-To: Your message of "Tue, 09 Nov 2010 15:31:15 PST." <201011100003.oAA03O3c015222@imap1.linux-foundation.org> Sender: linux-fsdevel-owner@vger.kernel.org List-ID: --==_Exmh_1289503541_5030P Content-Type: text/plain; charset=us-ascii On Tue, 09 Nov 2010 15:31:15 PST, akpm@linux-foundation.org said: > The mm-of-the-moment snapshot 2010-11-09-15-31 has been uploaded to > > http://userweb.kernel.org/~akpm/mmotm/ Still seeing this just after quotas get turned on ext4. First seen in 2.6.36-mmotm1022, but problem has apparently been there since 2.6.36-rc5-mmotm0922 (oldest kernel I have lying around). The last few relevant commands from rc.sysinit: /sbin/quotaon -aug dd if=/dev/urandom of=/var/lib/random-seed count=1 bs=512 <- this triggers the trace [ 48.967833] ======================================================= [ 48.968162] [ INFO: possible circular locking dependency detected ] [ 48.968411] 2.6.37-rc1-mmotm1109 #1 [ 48.968553] ------------------------------------------------------- [ 48.968592] dd/3253 is trying to acquire lock: [ 48.968592] (&s->s_dquot.dqio_mutex){+.+...}, at: [] dquot_commit+0x26/0xda [ 48.968592] [ 48.968592] but task is already holding lock: [ 48.968592] (&s->s_dquot.dqptr_sem){++++..}, at: [] __dquot_free_space+0x66/0x16b [ 48.968592] [ 48.968592] which lock already depends on the new lock. [ 48.968592] [ 48.968592] [ 48.968592] the existing dependency chain (in reverse order) is: [ 48.968592] [ 48.968592] -> #2 (&s->s_dquot.dqptr_sem){++++..}: [ 48.968592] [] lock_acquire+0x100/0x126 [ 48.968592] [] down_read+0x42/0x51 [ 48.968592] [] __dquot_free_space+0x66/0x16b [ 48.968592] [] dquot_free_block+0x19/0x2a [ 48.968592] [] ext4_free_blocks+0x75b/0x810 [ 48.968592] [] ext4_ext_truncate+0x3af/0x853 [ 48.968592] [] ext4_truncate+0x98/0x51a [ 48.968592] [] vmtruncate+0x3f/0x4b [ 48.968592] [] ext4_setattr+0x305/0x3a7 [ 48.968592] [] notify_change+0x1a1/0x2a1 [ 48.968592] [] do_truncate+0x67/0x84 [ 48.968592] [] do_last+0x4ce/0x5b2 [ 48.968592] [] do_filp_open+0x248/0x64a [ 48.968592] [] do_sys_open+0x60/0xfb [ 48.968592] [] sys_open+0x1b/0x1d [ 48.968592] [] system_call_fastpath+0x16/0x1b [ 48.968592] [ 48.968592] -> #1 (&ei->i_data_sem){++++..}: [ 48.968592] [] lock_acquire+0x100/0x126 [ 48.968592] [] down_read+0x42/0x51 [ 48.968592] [] ext4_map_blocks+0x3e/0x20e [ 48.968592] [] ext4_getblk+0x71/0x19b [ 48.968592] [] ext4_bread+0x11/0x61 [ 48.968592] [] ext4_quota_read+0x86/0xf0 [ 48.968592] [] v2_read_header+0x1e/0x4f [ 48.968592] [] v2_read_file_info+0x20/0x2ae [ 48.968592] [] vfs_load_quota_inode+0x292/0x448 [ 48.968592] [] dquot_quota_on_path+0x4c/0x55 [ 48.968592] [] ext4_quota_on+0x123/0x175 [ 48.968592] [] do_quotactl+0x1d1/0x465 [ 48.968592] [] sys_quotactl+0xfd/0x11a [ 48.968592] [] system_call_fastpath+0x16/0x1b [ 48.968592] [ 48.968592] -> #0 (&s->s_dquot.dqio_mutex){+.+...}: [ 48.968592] [] __lock_acquire+0xa4c/0xd4e [ 48.968592] [] lock_acquire+0x100/0x126 [ 48.968592] [] __mutex_lock_common+0x5d/0x56c [ 48.968592] [] mutex_lock_nested+0x34/0x39 [ 48.968592] [] dquot_commit+0x26/0xda [ 48.968592] [] ext4_write_dquot+0x65/0x87 [ 48.968592] [] ext4_mark_dquot_dirty+0x3e/0x49 [ 48.968592] [] mark_all_dquot_dirty+0x22/0x48 [ 48.968592] [] __dquot_free_space+0x139/0x16b [ 48.968592] [] dquot_free_block+0x19/0x2a [ 48.968592] [] ext4_free_blocks+0x75b/0x810 [ 48.968592] [] ext4_ext_truncate+0x3af/0x853 [ 48.968592] [] ext4_truncate+0x98/0x51a [ 48.968592] [] vmtruncate+0x3f/0x4b [ 48.968592] [] ext4_setattr+0x305/0x3a7 [ 48.968592] [] notify_change+0x1a1/0x2a1 [ 48.968592] [] do_truncate+0x67/0x84 [ 48.968592] [] do_last+0x4ce/0x5b2 [ 48.968592] [] do_filp_open+0x248/0x64a [ 48.968592] [] do_sys_open+0x60/0xfb [ 48.968592] [] sys_open+0x1b/0x1d [ 48.968592] [] system_call_fastpath+0x16/0x1b [ 48.968592] [ 48.968592] other info that might help us debug this: [ 48.968592] [ 49.458584] 5 locks held by dd/3253: [ 49.458584] #0: (&sb->s_type->i_mutex_key#13){+.+.+.}, at: [] do_truncate+0x5b/0x84 [ 49.458584] #1: (&sb->s_type->i_alloc_sem_key#5){+.+...}, at: [] notify_change+0x189/0x2a1 [ 49.458584] #2: (jbd2_handle){+.+...}, at: [] start_this_handle+0x57a/0x605 [ 49.458584] #3: (&ei->i_data_sem){++++..}, at: [] ext4_ext_truncate+0x91/0x853 [ 49.458584] #4: (&s->s_dquot.dqptr_sem){++++..}, at: [] __dquot_free_space+0x66/0x16b [ 49.458584] [ 49.458584] stack backtrace: [ 49.458584] Pid: 3253, comm: dd Not tainted 2.6.37-rc1-mmotm1109 #1 [ 49.458584] Call Trace: [ 49.458584] [] print_circular_bug+0xa8/0xb7 [ 49.458584] [] __lock_acquire+0xa4c/0xd4e [ 49.458584] [] ? dquot_commit+0x26/0xda [ 49.458584] [] lock_acquire+0x100/0x126 [ 49.458584] [] ? dquot_commit+0x26/0xda [ 49.458584] [] __mutex_lock_common+0x5d/0x56c [ 49.458584] [] ? dquot_commit+0x26/0xda [ 49.458584] [] ? dquot_mark_dquot_dirty+0x27/0x7a [ 49.458584] [] ? dquot_commit+0x26/0xda [ 49.458584] [] mutex_lock_nested+0x34/0x39 [ 49.458584] [] dquot_commit+0x26/0xda [ 49.458584] [] ext4_write_dquot+0x65/0x87 [ 49.458584] [] ext4_mark_dquot_dirty+0x3e/0x49 [ 49.458584] [] mark_all_dquot_dirty+0x22/0x48 [ 49.458584] [] __dquot_free_space+0x139/0x16b [ 49.458584] [] dquot_free_block+0x19/0x2a [ 49.458584] [] ext4_free_blocks+0x75b/0x810 [ 49.458584] [] ? jbd2_journal_extend+0x5d/0xb8 [ 49.458584] [] ext4_ext_truncate+0x3af/0x853 [ 49.458584] [] ? trace_preempt_on+0x15/0x28 [ 49.458584] [] ? unmap_mapping_range+0x279/0x288 [ 49.458584] [] ext4_truncate+0x98/0x51a [ 49.458584] [] ? unmap_mapping_range+0x279/0x288 [ 49.458584] [] ? trace_hardirqs_on_caller+0x117/0x13b [ 49.458584] [] ? trace_hardirqs_on+0xd/0xf [ 49.458584] [] vmtruncate+0x3f/0x4b [ 49.458584] [] ext4_setattr+0x305/0x3a7 [ 49.458584] [] notify_change+0x1a1/0x2a1 [ 49.458584] [] do_truncate+0x67/0x84 [ 49.458584] [] ? get_write_access+0x49/0x50 [ 49.458584] [] ? _raw_spin_unlock+0x30/0x69 [ 49.458584] [] ? sub_preempt_count+0x35/0x48 [ 49.458584] [] ? security_path_truncate+0x48/0x4d [ 49.458584] [] do_last+0x4ce/0x5b2 [ 49.458584] [] do_filp_open+0x248/0x64a [ 49.458584] [] ? trace_preempt_on+0x15/0x28 [ 49.458584] [] ? alloc_fd+0x17c/0x18e [ 49.458584] [] ? _raw_spin_unlock+0x30/0x69 [ 49.458584] [] ? sub_preempt_count+0x35/0x48 [ 49.458584] [] ? alloc_fd+0x17c/0x18e [ 49.458584] [] do_sys_open+0x60/0xfb [ 49.458584] [] ? trace_hardirqs_on_thunk+0x3a/0x3f [ 49.458584] [] sys_open+0x1b/0x1d [ 49.458584] [] system_call_fastpath+0x16/0x1b --==_Exmh_1289503541_5030P Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.10 (GNU/Linux) Comment: Exmh version 2.5 07/13/2001 iD8DBQFM3EM1cC3lWbTT17ARAhyTAKDT/oRwSNtd9wWEV9C4zd9NINmnDwCgliVG wGA+PRVx1xsHD2iymQ95y0M= =n9I2 -----END PGP SIGNATURE----- --==_Exmh_1289503541_5030P--