ZFS deadlock in zfs_freebsd_lookup/zfs_freebsd_rename on head r271170

[Bryan Drewery]

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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 488 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freebsd.org/pipermail/freebsd-fs/attachments/20140919/07de8b5c/attachment.sig>