From patchwork Mon Jan 15 12:02:58 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Brian Foster X-Patchwork-Id: 10163621 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id D1D1C602C2 for ; Mon, 15 Jan 2018 12:03:03 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id BD4DA28848 for ; Mon, 15 Jan 2018 12:03:03 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id AF9F82885C; Mon, 15 Jan 2018 12:03:03 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-6.9 required=2.0 tests=BAYES_00,RCVD_IN_DNSWL_HI autolearn=ham version=3.3.1 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 13B4A28848 for ; Mon, 15 Jan 2018 12:03:03 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753638AbeAOMDC (ORCPT ); Mon, 15 Jan 2018 07:03:02 -0500 Received: from mx1.redhat.com ([209.132.183.28]:55394 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754060AbeAOMDA (ORCPT ); Mon, 15 Jan 2018 07:03:00 -0500 Received: from smtp.corp.redhat.com (int-mx01.intmail.prod.int.phx2.redhat.com [10.5.11.11]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 543DD356EB; Mon, 15 Jan 2018 12:03:00 +0000 (UTC) Received: from bfoster.bfoster (dhcp-41-20.bos.redhat.com [10.18.41.20]) by smtp.corp.redhat.com (Postfix) with ESMTP id 1DD7E600D2; Mon, 15 Jan 2018 12:02:59 +0000 (UTC) Received: by bfoster.bfoster (Postfix, from userid 1000) id 0254A1203BD; Mon, 15 Jan 2018 07:02:58 -0500 (EST) Date: Mon, 15 Jan 2018 07:02:58 -0500 From: Brian Foster To: Chris Dunlop Cc: linux-xfs@vger.kernel.org Subject: Re: _xfs_buf_find: Block out of range, then umount hung Message-ID: <20180115120258.GA44369@bfoster.bfoster> References: <20180113145228.GA16780@onthe.net.au> MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: <20180113145228.GA16780@onthe.net.au> User-Agent: Mutt/1.9.1 (2017-09-22) X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.30]); Mon, 15 Jan 2018 12:03:00 +0000 (UTC) Sender: linux-xfs-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-xfs@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP On Sun, Jan 14, 2018 at 01:52:28AM +1100, Chris Dunlop wrote: > Hi, > > tl;dr: a filesystem corruption (cause unknown) has produced an unkillable > umount. Is the only recourse to reboot? > From this particular state, probably. > On linux-4.9.76, I had this error crop up: > > Jan 13 19:57:31 b2 kernel: XFS (sdp1): _xfs_buf_find: Block out of range: block 0x837940948, EOFS 0x6f281288 > Jan 13 19:57:31 b2 kernel: ------------[ cut here ]------------ > Jan 13 19:57:31 b2 kernel: WARNING: CPU: 5 PID: 31412 at /home2/chris/git/linux/fs/xfs/xfs_buf.c:535 _xfs_buf_find+0x2ff/0x370 [xfs] > Jan 13 19:57:31 b2 kernel: Modules linked in: nfsd auth_rpcgss oid_registry nfs_acl nfs lockd grace sunrpc ipt_REJECT nf_reject_ipv4 xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack xt_recent xt_multiport iptable_filter ip_tables x_tables iTCO_wdt iTCO_vendor_support intel_powerclamp coretemp kvm_intel kvm irqbypass lpc_ich mfd_core xfs ipmi_ssif i7core_edac edac_core ioatdma shpchp evdev 8250 8250_base serial_core ipmi_si ipmi_msghandler button acpi_cpufreq processor loop fuse autofs4 ext4 crc16 jbd2 mbcache dm_mod bridge stp llc raid456 async_raid6_recov async_memcpy async_pq async_xor xor async_tx raid6_pq raid1 md_mod ses enclosure sg sd_mod hid_generic usbhid hid bnx2x mpt3sas mdio libcrc32c raid_class crc32c_generic ehci_pci psmouse crc32c_intel igb scsi_transport_sas i2c_algo_bit uhci_hcd > Jan 13 19:57:31 b2 kernel: ehci_hcd i2c_core scsi_mod dca ptp pps_core > Jan 13 19:57:31 b2 kernel: CPU: 5 PID: 31412 Comm: tp_fstore_op Not tainted 4.9.76-otn-00021-g2af03421 #1 > Jan 13 19:57:31 b2 kernel: Hardware name: Supermicro X8DTH-i/6/iF/6F/X8DTH, BIOS 2.1a 12/12/11 > Jan 13 19:57:31 b2 kernel: ffffc900418e3718 ffffffff812a91bb 0000000000000000 0000000000000000 > Jan 13 19:57:31 b2 kernel: ffffc900418e3758 ffffffff8105ab31 00000217418e3778 ffff8817c62cdc00 > Jan 13 19:57:31 b2 kernel: 0000000000000008 ffff8817c62cdc00 ffffc900418e3848 0000000000000000 > Jan 13 19:57:31 b2 kernel: Call Trace: > Jan 13 19:57:31 b2 kernel: [] dump_stack+0x4d/0x72 > Jan 13 19:57:31 b2 kernel: [] __warn+0xd1/0xf0 > Jan 13 19:57:31 b2 kernel: [] warn_slowpath_null+0x1d/0x20 > Jan 13 19:57:31 b2 kernel: [] _xfs_buf_find+0x2ff/0x370 [xfs] > Jan 13 19:57:31 b2 kernel: [] ? xfs_alloc_update_counters.isra.13+0x44/0x50 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_buf_get_map+0x2a/0x2f0 [xfs] > Jan 13 19:57:31 b2 kernel: [] ? xfs_free_ag_extent+0x3e2/0x7b0 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_trans_get_buf_map+0x126/0x1d0 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_btree_get_bufs+0x4f/0x60 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_alloc_fix_freelist+0x1c7/0x390 [xfs] > Jan 13 19:57:31 b2 kernel: [] ? sched_clock_cpu+0x8f/0xa0 > Jan 13 19:57:31 b2 kernel: [] xfs_free_extent_fix_freelist+0x65/0xa0 [xfs] So for one reason or another, you end up trying to remove a bogus block number from the AGFL (perhaps the old agfl size issue?). > Jan 13 19:57:31 b2 kernel: [] xfs_free_extent+0x4b/0x120 [xfs] > Jan 13 19:57:31 b2 kernel: [] ? kmem_cache_alloc+0x1a3/0x1b0 > Jan 13 19:57:31 b2 kernel: [] xfs_trans_free_extent+0x6e/0x130 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_extent_free_finish_item+0x26/0x40 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_defer_finish+0x16c/0x430 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_attr_leaf_addname+0x3e4/0x400 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_attr_set+0x245/0x3f0 [xfs] > Jan 13 19:57:31 b2 kernel: [] xfs_xattr_set+0x52/0xa0 [xfs] > Jan 13 19:57:31 b2 kernel: [] __vfs_setxattr+0x6b/0x90 > Jan 13 19:57:31 b2 kernel: [] __vfs_setxattr_noperm+0x51/0xe0 > Jan 13 19:57:31 b2 kernel: [] vfs_setxattr+0xa7/0xb0 > Jan 13 19:57:31 b2 kernel: [] setxattr+0x12d/0x150 > Jan 13 19:57:31 b2 kernel: [] ? mnt_want_write_file+0x28/0x60 > Jan 13 19:57:31 b2 kernel: [] ? __sb_start_write+0xee/0x1a0 > Jan 13 19:57:31 b2 kernel: [] ? mnt_want_write_file+0x28/0x60 > Jan 13 19:57:31 b2 kernel: [] ? __fget+0x5/0xe0 > Jan 13 19:57:31 b2 kernel: [] SyS_fsetxattr+0x7d/0xa0 > Jan 13 19:57:31 b2 kernel: [] entry_SYSCALL_64_fastpath+0x13/0x99 > Jan 13 19:57:31 b2 kernel: ---[ end trace 144423dbd5ec0057 ]--- > > That whole lot repeated again (same call trace), then: > > Jan 13 19:57:31 b2 kernel: XFS (sdp1): xfs_do_force_shutdown(0x8) called from line 236 of file /home2/chris/git/linux/fs/xfs/libxfs/xfs_defer.c. Return address = 0xffffffffa071d787 > Jan 13 19:57:31 b2 kernel: XFS (sdp1): Corruption of in-memory data detected. Shutting down filesystem > Jan 13 19:57:31 b2 kernel: XFS (sdp1): Please umount the filesystem and rectify the problem(s) The filesystem shuts down, as expected. > Jan 13 19:57:31 b2 kernel: > Jan 13 19:57:31 b2 kernel: ================================================ > Jan 13 19:57:31 b2 kernel: [ BUG: lock held when returning to user space! ] > Jan 13 19:57:31 b2 kernel: 4.9.76-otn-00021-g2af03421 #1 Tainted: G W > Jan 13 19:57:31 b2 kernel: ------------------------------------------------ > Jan 13 19:57:31 b2 kernel: tp_fstore_op/31412 is leaving the kernel with locks still held! > Jan 13 19:57:31 b2 kernel: 1 lock held by tp_fstore_op/31412: > Jan 13 19:57:31 b2 kernel: #0: (sb_internal){......}, at: [] xfs_trans_alloc+0xe3/0x130 [xfs] Though it looks like we return to userspace in transaction context..? This is the same pid as above and the current code looks like the transaction should be cancelled in xfs_attr_set(). We're somewhere down in xfs_attr_leaf_addname(), however. From there, both calls to xfs_defer_finish() jump to out_defer_cancel on failure, which sets args->trans = NULL before we return. Hmm, that looks like a bug to me. Are you able to reproduce this particular hung unmount behavior? If so, does anything change with something like the appended hunk? Note that you may have to backport that to v4.9- since it appears that is before out_defer_cancel was created. Brian ---8<--- --- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html diff --git a/fs/xfs/libxfs/xfs_attr.c b/fs/xfs/libxfs/xfs_attr.c index a76914db72ef..e86c51d39e66 100644 --- a/fs/xfs/libxfs/xfs_attr.c +++ b/fs/xfs/libxfs/xfs_attr.c @@ -717,7 +717,6 @@ xfs_attr_leaf_addname(xfs_da_args_t *args) return error; out_defer_cancel: xfs_defer_cancel(args->dfops); - args->trans = NULL; return error; }