Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1758495AbZKFOzV (ORCPT ); Fri, 6 Nov 2009 09:55:21 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1757606AbZKFOzU (ORCPT ); Fri, 6 Nov 2009 09:55:20 -0500 Received: from 88-97-16-53.dsl.zen.co.uk ([88.97.16.53]:45135 "EHLO andromeda.kingswood-consulting.co.uk" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1754959AbZKFOzO (ORCPT ); Fri, 6 Nov 2009 09:55:14 -0500 X-Greylist: delayed 305 seconds by postgrey-1.27 at vger.kernel.org; Fri, 06 Nov 2009 09:55:12 EST Message-ID: <4AF437A1.4020509@kingswood-consulting.co.uk> Date: Fri, 06 Nov 2009 14:50:09 +0000 From: Frank Kingswood User-Agent: Mozilla-Thunderbird 2.0.0.22 (X11/20090706) MIME-Version: 1.0 Newsgroups: gmane.linux.kernel To: linux-kernel@vger.kernel.org, shaggy@linux.vnet.ibm.com Subject: Re: JFS inconsistent lock state References: In-Reply-To: Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 63980 Lines: 1415 Frank A. Kingswood wrote: >>> I'm running jfs on md and got this error. The system is still usable >>> afterwards (and has not been rebooted yet) so I could provide more >>> information if needed. >>> >>> The system has occasionally had hard crashes during file access (perhaps >>> starting with about 2.6.29) and these may be related. >> >> The same happens with 2.6.31-rc8 >> >> Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar >> ... MAX_LOCKDEP_SUBCLASSES: 8 >> ... MAX_LOCK_DEPTH: 48 >> ... MAX_LOCKDEP_KEYS: 8191 >> ... CLASSHASH_SIZE: 4096 >> ... MAX_LOCKDEP_ENTRIES: 16384 >> ... MAX_LOCKDEP_CHAINS: 32768 >> ... CHAINHASH_SIZE: 16384 >> memory used by lock dependency info: 6207 kB >> per task-struct memory footprint: 2688 bytes >> >> ...a while later... >> Dave Kleikamp wrote: > > I looked at this a while back: > > http://lkml.org/lkml/2009/5/18/358 > > I didn't get a response to that, and I didn't follow up. I guess it's > time to get back on it. I'll try to recreate the warning and see if > this patch helps: > > diff --git a/mm/filemap.c b/mm/filemap.c > index ccea3b6..59f5406 100644 > --- a/mm/filemap.c > +++ b/mm/filemap.c > @@ -1702,7 +1702,8 @@ repeat: > page = page_cache_alloc_cold(mapping); > if (!page) > return ERR_PTR(-ENOMEM); > - err = add_to_page_cache_lru(page, mapping, index, GFP_KERNEL); > + err = add_to_page_cache_lru(page, mapping, index, > + mapping_gfp_mask(mapping)); > if (unlikely(err)) { > page_cache_release(page); > if (err == -EEXIST) > With this patch on 2.6.31.5 a lock trace still happens. I only booted into this kernel yesterday, so it happens pretty soon. I guess after the first trace no further are reported? [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] txUnlock+0xb8/0x2b0 [] txCommit+0xd55/0xe90 [] jfs_rename+0x42e/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] __set_page_dirty_nobuffers+0x54/0x180 [] set_page_dirty+0x35/0x70 [] release_metapage+0x108/0x1a0 [] put_metapage+0x6e/0x180 [] txUnlock+0x117/0x2b0 [] txCommit+0xd55/0xe90 [] jfs_rename+0x42e/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff -> (key#44){......} ops: 81174 { INITIAL USE at: [] __lock_acquire+0x1b1/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] __wake_up+0x2d/0x70 [] txEnd+0xbd/0x170 [] jfs_lazycommit+0x257/0x260 [] kthread+0xa6/0xc0 [] child_rip+0xa/0x20 [] 0xffffffffffffffff } ... key at: [] __key.24083+0x0/0x8 ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] __wake_up+0x2d/0x70 [] txEnd+0xbd/0x170 [] jfs_rename+0x43c/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] __wake_up+0x2d/0x70 [] __wake_up_bit+0x2c/0x30 [] unlock_page+0x22/0x30 [] __get_metapage+0x30f/0x4c0 [] find_index+0x12b/0x150 [] modify_index+0x40/0xf0 [] dtDelete+0x213/0xb10 [] jfs_rename+0x32a/0x900 [] vfs_rename+0x199/0x410 [] nfsd_rename+0x3f8/0x470 [] nfsd3_proc_rename+0xcc/0x190 [] nfsd_dispatch+0xbb/0x260 [] svc_process+0x499/0x770 [] nfsd+0xdd/0x160 [] kthread+0xa6/0xc0 [] child_rip+0xa/0x20 [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [] __slab_alloc+0x425/0x5b0 [] kmem_cache_alloc+0x106/0x110 [] mempool_alloc_slab+0x11/0x20 [] mempool_alloc+0x56/0x150 [] __get_metapage+0xd9/0x4c0 [] xtSearch+0x30a/0x5b0 [] xtLookup+0x94/0x180 [] find_index+0xfa/0x150 [] dtDelete+0x2ef/0xb10 [] jfs_rename+0x32a/0x900 [] vfs_rename+0x199/0x410 [] nfsd_rename+0x3f8/0x470 [] nfsd3_proc_rename+0xcc/0x190 [] nfsd_dispatch+0xbb/0x260 [] svc_process+0x499/0x770 [] nfsd+0xdd/0x160 [] kthread+0xa6/0xc0 [] child_rip+0xa/0x20 [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] jfs_rename+0x245/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff -> (&jfs_ip->commit_mutex/2){+.+...} ops: 52 { HARDIRQ-ON-W at: [] __lock_acquire+0x5a1/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] jfs_rename+0x227/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff SOFTIRQ-ON-W at: [] __lock_acquire+0x5d5/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] jfs_rename+0x227/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff INITIAL USE at: [] __lock_acquire+0x1b1/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] jfs_rename+0x227/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff } ... key at: [] __key.25249+0x2/0x8 ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [] __mark_inode_dirty+0x6b/0x140 [] dtInsert+0x1e1/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [] txLock+0x35/0x7a0 [] dtInsert+0x12b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] __wake_up+0x2d/0x70 [] release_metapage+0x64/0x1a0 [] diWrite+0x2e6/0x5a0 [] txCommit+0x1ec/0xe90 [] jfs_rename+0x42e/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] lmLog+0x3e/0x1f0 [] txCommit+0x874/0xe90 [] jfs_rename+0x42e/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] lmGroupCommit+0x31/0x1e0 [] txCommit+0x3a6/0xe90 [] jfs_rename+0x42e/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] activate_page+0x47/0x160 [] mark_page_accessed+0x65/0x80 [] read_cache_page_async+0xb2/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] mutex_lock_nested+0x5c/0x340 [] jfs_rename+0x245/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] add_to_page_cache_locked+0x5e/0xe0 [] add_to_page_cache_lru+0x2c/0x80 [] read_cache_page_async+0x7d/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] wait_barrier+0x2e/0x130 [] make_request+0x81/0x680 [] md_make_request+0x138/0x1a0 [] generic_make_request+0x265/0x330 [] submit_bio+0x5e/0xe0 [] metapage_readpage+0x164/0x220 [] read_cache_page_async+0x91/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] __make_request+0x60/0x3f0 [] generic_make_request+0x265/0x330 [] submit_bio+0x5e/0xe0 [] metapage_readpage+0x164/0x220 [] read_cache_page_async+0x91/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] prepare_to_wait_exclusive+0x25/0x80 [] __wait_on_bit_lock+0x40/0xb0 [] __lock_page+0x64/0x70 [] read_cache_page_async+0xec/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [] scsi_request_fn+0x154/0x4d0 [] __generic_unplug_device+0x30/0x40 [] generic_unplug_device+0x29/0x40 [] blk_unplug+0x12/0x20 [] unplug_slaves+0xd9/0x160 [] raid10_unplug+0x18/0x30 [] blk_unplug+0x12/0x20 [] blk_backing_dev_unplug+0xd/0x10 [] block_sync_page+0x39/0x70 [] sync_page+0x33/0x70 [] __wait_on_bit_lock+0x52/0xb0 [] __lock_page+0x64/0x70 [] read_cache_page_async+0xec/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [] ata_scsi_queuecmd+0x44/0x2e0 [] scsi_dispatch_cmd+0xe9/0x240 [] scsi_request_fn+0x3c6/0x4d0 [] __generic_unplug_device+0x30/0x40 [] generic_unplug_device+0x29/0x40 [] blk_unplug+0x12/0x20 [] unplug_slaves+0xd9/0x160 [] raid10_unplug+0x18/0x30 [] blk_unplug+0x12/0x20 [] blk_backing_dev_unplug+0xd/0x10 [] block_sync_page+0x39/0x70 [] sync_page+0x33/0x70 [] __wait_on_bit_lock+0x52/0xb0 [] __lock_page+0x64/0x70 [] read_cache_page_async+0xec/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irqsave+0x44/0x90 [] __wake_up+0x2d/0x70 [] md_wakeup_thread+0x27/0x30 [] raid10_unplug+0x24/0x30 [] blk_unplug+0x12/0x20 [] blk_backing_dev_unplug+0xd/0x10 [] block_sync_page+0x39/0x70 [] sync_page+0x33/0x70 [] __wait_on_bit_lock+0x52/0xb0 [] __lock_page+0x64/0x70 [] read_cache_page_async+0xec/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock_irq+0x38/0x70 [] schedule+0xcc/0x350 [] io_schedule+0x37/0x50 [] sync_page+0x3d/0x70 [] __wait_on_bit_lock+0x52/0xb0 [] __lock_page+0x64/0x70 [] read_cache_page_async+0xec/0x1a0 [] read_cache_page+0xe/0x70 [] __get_metapage+0x25a/0x4c0 [] add_index+0x242/0x720 [] dtInsertEntry+0x117/0x4b0 [] dtInsert+0x15b/0x18d0 [] jfs_rename+0x77f/0x900 [] vfs_rename+0x199/0x410 [] sys_renameat+0x20e/0x250 [] sys_rename+0x16/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff ... acquired at: [] __lock_acquire+0xe05/0x1250 [] lock_acquire+0x91/0xc0 [] _spin_lock+0x31/0x70 [