Date: Fri, 19 Sep 2014 15:51:18 -0500 From: Bryan Drewery <bdrewery@FreeBSD.org> To: FreeBSD FS <freebsd-fs@FreeBSD.org> Subject: Re: ZFS deadlock in zfs_freebsd_lookup/zfs_freebsd_rename on head r271170 Message-ID: <541C9746.5020606@FreeBSD.org> In-Reply-To: <541C93AE.60906@FreeBSD.org> References: <541C5E01.9050609@FreeBSD.org> <541C93AE.60906@FreeBSD.org>
next in thread | previous in thread | raw e-mail | index | archive | help
[-- Attachment #1 --] 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/py27-PasteScript-1.7.5_2 >>> root 96903 0.0 0.0 8196 1912 2 D+ 11:01AM 0:00.00 rename /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/deps/py27-PasteDeploy-1.5.0_1 /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/cleaning/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-PasteDeploy-1.5.0_1 /poudriere/data/.m/exp-head-commit-test-devel/ref/.p/cleaning/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_dirlook+0x1b0 zfs_lookup+0x223 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_APV+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_stdlock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa zfs_lookup+0x462 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_APV+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV+0xf1 lookup+0x5ad namei+0x4e4 kern_statat_vnhook+0xae sys_fstatat+0x2c amd64_syscall+0x25a >>> 96903 101290 rename - mi_switch+0x179 sleepq_switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0xea1 vop_stdlock+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 filemon_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 fork_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_thread+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_thread+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+0x9e 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_quiesce_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_trampoline+0xe >>> 3720 100969 rename - mi_switch+0x179 sleepq_switch+0x152 sleepq_wait+0x43 _cv_wait+0x1da zfs_dirent_lock+0x212 zfs_dirlook+0x1b0 zfs_lookup+0x223 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_APV+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_stdlock+0x3c VOP_LOCK1_APV+0xfc _vn_lock+0xaa zfs_lookup+0x462 zfs_freebsd_lookup+0x91 VOP_CACHEDLOOKUP_APV+0xf1 vfs_cache_lookup+0xd6 VOP_LOOKUP_APV+0xf1 lookup+0x5ad namei+0x4e4 kern_statat_vnhook+0xae sys_fstatat+0x2c amd64_syscall+0x25a >>> 96903 101290 rename - mi_switch+0x179 sleepq_switch+0x152 sleepq_wait+0x43 sleeplk+0x14a __lockmgr_args+0xea1 vop_stdlock+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 filemon_wrapper_rename+0x19 amd64_syscall+0x25a Xfast_syscall+0xfb >> >> >> > > PID 96903 / TID 101290: zfs_rename takes dirent_lock. It then calls > zfs_rename_lock, which then is stuck in vrele() > > PID 3720 / TID 100969: zfs_dirlook waits on zfs_dirent_lock. > > PID 96901 I think can be ignored, it was fallout and ran 4 minutes after > 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. -- Regards, Bryan Drewery [-- Attachment #2 --] -----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-----
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?541C9746.5020606>