From owner-freebsd-fs@FreeBSD.ORG Fri Sep 19 20:51:26 2014 Return-Path: Delivered-To: freebsd-fs@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id D1BCCB3C for ; Fri, 19 Sep 2014 20:51:26 +0000 (UTC) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:1900:2254:206c::16:87]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id B3A3A9EC for ; Fri, 19 Sep 2014 20:51:26 +0000 (UTC) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.9/8.14.9) with ESMTP id s8JKpQhg060162 for ; Fri, 19 Sep 2014 20:51:26 GMT (envelope-from bdrewery@freefall.freebsd.org) Received: (from bdrewery@localhost) by freefall.freebsd.org (8.14.9/8.14.9/Submit) id s8JKpQlA060161 for freebsd-fs@FreeBSD.org; Fri, 19 Sep 2014 20:51:26 GMT (envelope-from bdrewery) Received: (qmail 30170 invoked from network); 19 Sep 2014 15:51:25 -0500 Received: from unknown (HELO ?10.10.0.24?) (freebsd@shatow.net@10.10.0.24) by sweb.xzibition.com with ESMTPA; 19 Sep 2014 15:51:25 -0500 Message-ID: <541C9746.5020606@FreeBSD.org> Date: Fri, 19 Sep 2014 15:51:18 -0500 From: Bryan Drewery Organization: FreeBSD User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Thunderbird/31.1.1 MIME-Version: 1.0 To: FreeBSD FS Subject: Re: ZFS deadlock in zfs_freebsd_lookup/zfs_freebsd_rename on head r271170 References: <541C5E01.9050609@FreeBSD.org> <541C93AE.60906@FreeBSD.org> In-Reply-To: <541C93AE.60906@FreeBSD.org> OpenPGP: id=6E4697CF; url=http://www.shatow.net/bryan/bryan2.asc Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="Ed7oGQgwKD5u9WmSs78TFlrUaXm7aV2tC" X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 19 Sep 2014 20:51:26 -0000 This is an OpenPGP/MIME signed message (RFC 4880 and 3156) --Ed7oGQgwKD5u9WmSs78TFlrUaXm7aV2tC Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable On 9/19/2014 3:35 PM, Bryan Drewery wrote: > On 9/19/2014 11:46 AM, Bryan Drewery wrote: >> rename is: https://people.freebsd.org/~bdrewery/rename.c >> >> All files are in the same mountpoint. >> >>> # ps uaxwww|egrep "(rm|rename)" >>> root 96901 0.0 0.0 12300 1948 2 D+ 11:01AM 0:00.00 rm= -rf /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/cleaning/deps/p= y27-PasteScript-1.7.5_2 >>> root 96903 0.0 0.0 8196 1912 2 D+ 11:01AM 0:00.00 re= name /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/deps/py27-Paste= Deploy-1.5.0_1 /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/clean= ing/deps/py27-PasteDeploy-1.5.0_1 >>> root 3720 0.0 0.0 8196 1912 3 D+ 11:05AM 0:00.00 ./= rename /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/deps/py27-Pas= teDeploy-1.5.0_1 /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/cle= aning/deps/py27-PasteDeploy-1.5.0_1 >>> >>> # procstat -kka|egrep "(96901|96903|3720)" >>> 3720 100969 rename - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 _cv_wait+0x1da zfs_dirent_lock+0x212 zfs_d= irlook+0x1b0 zfs_lookup+0x223 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_AP= V+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV+0xf1 lookup+0x5ad namei+0x4e4= kern_renameat+0x95 filemon_wrapper_rename+0x19 amd64_syscall+0x25a Xfast= _syscall+0xfb >>> 96901 101213 rm - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0x862 vop_std= lock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa zfs_lookup+0x462 zfs_freebsd_l= ookup+0x91 VOP_CACHEDLOOKUP_APV+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV= +0xf1 lookup+0x5ad namei+0x4e4 kern_statat_vnhook+0xae sys_fstatat+0x2c a= md64_syscall+0x25a >>> 96903 101290 rename - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0xea1 vop_std= lock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa vputx+0x232 zfs_rename_unlock+= 0x78 zfs_freebsd_rename+0xfbb VOP_RENAME_APV+0xfc kern_renameat+0x3ef fil= emon_wrapper_rename+0x19 amd64_syscall+0x25a Xfast_syscall+0xfb >>> >>> # procstat -kka|grep zfs >>> 0 100698 kernel zfs_vn_rele_task mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 _sleep+0x366 taskqueue_thread_loop+0xc8 fo= rk_exit+0x84 fork_trampoline+0xe >>> 3 100159 zfskern arc_reclaim_thre mi_switch+0x179 sleepq= _switch+0x152 sleepq_timedwait+0x43 _cv_timedwait_sbt+0x200 arc_reclaim_t= hread+0x2de fork_exit+0x84 fork_trampoline+0xe >>> 3 100160 zfskern l2arc_feed_threa mi_switch+0x179 sleepq= _switch+0x152 sleepq_timedwait+0x43 _cv_timedwait_sbt+0x200 l2arc_feed_th= read+0x1d8 fork_exit+0x84 fork_trampoline+0xe >>> 3 100681 zfskern trim zroot mi_switch+0x179 sleepq= _switch+0x152 sleepq_timedwait+0x43 _cv_timedwait_sbt+0x200 trim_thread+0= x9e fork_exit+0x84 fork_trampoline+0xe >>> 3 100715 zfskern txg_thread_enter mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 _cv_wait+0x1da txg_thread_wait+0x9b txg_qu= iesce_thread+0x420 fork_exit+0x84 fork_trampoline+0xe >>> 3 100716 zfskern txg_thread_enter mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 _cv_wait+0x1da zio_wait+0x9b dsl_pool_sync= +0x35c spa_sync+0x530 txg_sync_thread+0x24d fork_exit+0x84 fork_trampolin= e+0xe >>> 3720 100969 rename - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 _cv_wait+0x1da zfs_dirent_lock+0x212 zfs_d= irlook+0x1b0 zfs_lookup+0x223 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_AP= V+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV+0xf1 lookup+0x5ad namei+0x4e4= kern_renameat+0x95 filemon_wrapper_rename+0x19 amd64_syscall+0x25a Xfast= _syscall+0xfb >>> 96901 101213 rm - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0x862 vop_std= lock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa zfs_lookup+0x462 zfs_freebsd_l= ookup+0x91 VOP_CACHEDLOOKUP_APV+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV= +0xf1 lookup+0x5ad namei+0x4e4 kern_statat_vnhook+0xae sys_fstatat+0x2c a= md64_syscall+0x25a >>> 96903 101290 rename - mi_switch+0x179 sleepq= _switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0xea1 vop_std= lock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa vputx+0x232 zfs_rename_unlock+= 0x78 zfs_freebsd_rename+0xfbb VOP_RENAME_APV+0xfc kern_renameat+0x3ef fil= emon_wrapper_rename+0x19 amd64_syscall+0x25a Xfast_syscall+0xfb >> >> >> >=20 > PID 96903 / TID 101290: zfs_rename takes dirent_lock. It then calls > zfs_rename_lock, which then is stuck in vrele() >=20 > PID 3720 / TID 100969: zfs_dirlook waits on zfs_dirent_lock. >=20 > PID 96901 I think can be ignored, it was fallout and ran 4 minutes afte= r > the deadlock. Oops, that is all wrong. PID 3720 can be ignored. This is not related to zfs_dirent_lock. I will look at the core a bit later to determine which vnodes each thread has locked and are waiting on. I need to run out at the moment. --=20 Regards, Bryan Drewery --Ed7oGQgwKD5u9WmSs78TFlrUaXm7aV2tC Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.10 (MingW32) iQEcBAEBAgAGBQJUHJdGAAoJEDXXcbtuRpfPvToH/1DKwLOxtXS4Sx1mecW2e6sT tBxrn0NzegQaqehZjti5pfjeWgwHKNZCZkmV1E4FmNTj41Z1NmxQDpsCLg24WcnF eu3JpVE6KrjSdIuNCiPYVbrVUl+wrP9CRcjqXCAROgvB6ouDngUXynay/kr9Ao1q 1THN5/3WTRnQeJTDWPtLU3JKTk7J4kkSEN9CS9PgR9qUQ1pBm5Id8QKJtymBfU8h zHnrxUCXWqZss47bQnQSW17+R+Dkz6ej5mxw8x20/aMg3YJDrTEfjrA8h4oD2B1/ rzVIfUPmvTzPcnAUuxjGyd+JcKOIjDX+pwTHNE5yNYSnZHZsdejoxDnRlUEM6kg= =q3ex -----END PGP SIGNATURE----- --Ed7oGQgwKD5u9WmSs78TFlrUaXm7aV2tC--