Skip site navigation (1)Skip section navigation (2)
Date:      Mon, 04 Mar 2019 20:38:36 +0000
From:      bugzilla-noreply@freebsd.org
To:        bugs@FreeBSD.org
Subject:   [Bug 236220] ZFS vnode deadlock on zfs_mknode
Message-ID:  <bug-236220-227-E895PrEUUY@https.bugs.freebsd.org/bugzilla/>
In-Reply-To: <bug-236220-227@https.bugs.freebsd.org/bugzilla/>
References:  <bug-236220-227@https.bugs.freebsd.org/bugzilla/>

next in thread | previous in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D236220

--- Comment #2 from ncrogers@gmail.com ---
It happened again on a different system. Here is relevant procstat and
backtrace of the offending thread and another thread waiting for it.

courtland# procstat -kka | grep zfs
    0 100140 kernel              zfsvfs              mi_switch+0xe1
sleepq_wait+0x2c _sleep+0x237 taskqueue_thread_loop+0xf1 fork_exit+0x83
fork_trampoline+0xe=20
    0 100424 kernel              zfs_vn_rele_taskq   mi_switch+0xe1
sleepq_wait+0x2c _sleep+0x237 taskqueue_thread_loop+0xf1 fork_exit+0x83
fork_trampoline+0xe=20
   23 100119 zfskern             arc_reclaim_thread  mi_switch+0xe1
sleepq_timedwait+0x2f _cv_timedwait_sbt+0x17a arc_reclaim_thread+0x146
fork_exit+0x83 fork_trampoline+0xe=20
   23 100120 zfskern             arc_dnlc_evicts_thr mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 arc_dnlc_evicts_thread+0x16f fork_exit+0x83
fork_trampoline+0xe=20
   23 100122 zfskern             dbuf_evict_thread   mi_switch+0xe1
sleepq_timedwait+0x2f _cv_timedwait_sbt+0x17a dbuf_evict_thread+0x1c8
fork_exit+0x83 fork_trampoline+0xe=20
   23 100139 zfskern             l2arc_feed_thread   mi_switch+0xe1
sleepq_timedwait+0x2f _cv_timedwait_sbt+0x17a l2arc_feed_thread+0x219
fork_exit+0x83 fork_trampoline+0xe=20
   23 100405 zfskern             trim zroot          mi_switch+0xe1
sleepq_timedwait+0x2f _cv_timedwait_sbt+0x17a trim_thread+0x11f fork_exit+0=
x83
fork_trampoline+0xe=20
   23 100441 zfskern             txg_thread_enter    mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 txg_quiesce+0x21b txg_quiesce_thread+0x11b
fork_exit+0x83 fork_trampoline+0xe=20
   23 100442 zfskern             txg_thread_enter    mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 txg_sync_thread+0x13b fork_exit+0x83
fork_trampoline+0xe=20
   23 100443 zfskern             solthread 0xfffffff mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 zthr_procedure+0xcc fork_exit+0x83
fork_trampoline+0xe=20
   23 100444 zfskern             solthread 0xfffffff mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 zthr_procedure+0xcc fork_exit+0x83
fork_trampoline+0xe=20
 7476 100751 postgres            -                   mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 dmu_tx_wait+0x2eb dmu_tx_assign+0x48
zfs_freebsd_create+0x4c8 VOP_CREATE_APV+0x78 vn_open_cred+0x2c9
kern_openat+0x20c amd64_syscall+0x369 fast_syscall_common+0x101=20
 7480 100527 postgres            -                   mi_switch+0xe1
sleepq_wait+0x2c sleeplk+0x1c5 lockmgr_xlock_hard+0x19c VOP_LOCK1_APV+0x7e
_vn_lock+0x40 zfs_znode_alloc+0x434 zfs_mknode+0xa9d zfs_freebsd_create+0x5=
12
VOP_CREATE_APV+0x78 vn_open_cred+0x2c9 kern_openat+0x20c amd64_syscall+0x369
fast_syscall_common+0x101=20
46101 100471 postgres            -                   mi_switch+0xe1
sleepq_wait+0x2c _cv_wait+0x152 dmu_tx_wait+0x2eb dmu_tx_assign+0x48
zfs_freebsd_create+0x4c8 VOP_CREATE_APV+0x78 vn_open_cred+0x2c9
kern_openat+0x20c amd64_syscall+0x369 fast_syscall_common+0x101=20
52625 100488 perl                -                   mi_switch+0xe1
sleepq_wait+0x2c sleeplk+0x1c5 lockmgr_slock_hard+0x2c5 VOP_LOCK1_APV+0x7e
_vn_lock+0x40 zfs_root+0x6d lookup+0x933 namei+0x44b kern_statat+0x77
sys_fstatat+0x2f amd64_syscall+0x369 fast_syscall_common+0x101=20
52675 100643 csh                 -                   mi_switch+0xe1
sleepq_wait+0x2c sleeplk+0x1c5 lockmgr_slock_hard+0x2c5 VOP_LOCK1_APV+0x7e
_vn_lock+0x40 zfs_root+0x6d lookup+0x933 namei+0x44b kern_statat+0x77
sys_fstatat+0x2f amd64_syscall+0x369 fast_syscall_common+0x101=20
52826 100562 ls                  -                   mi_switch+0xe1
sleepq_wait+0x2c sleeplk+0x1c5 lockmgr_slock_hard+0x2c5 VOP_LOCK1_APV+0x7e
_vn_lock+0x40 zfs_root+0x6d lookup+0x933 namei+0x44b kern_statat+0x77
sys_fstatat+0x2f amd64_syscall+0x369 fast_syscall_common+0x101=20
52889 100641 bash                -                   mi_switch+0xe1
sleepq_wait+0x2c sleeplk+0x1c5 lockmgr_slock_hard+0x2c5 VOP_LOCK1_APV+0x7e
_vn_lock+0x40 zfs_root+0x6d lookup+0x933 namei+0x44b kern_statat+0x77
sys_fstatat+0x2f amd64_syscall+0x369 fast_syscall_common+0x101=20
courtland# kgdb
GNU gdb (GDB) 8.2.1 [GDB v8.2.1 for FreeBSD]
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.htm=
l>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-portbld-freebsd12.0".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /boot/kernel/kernel...Reading symbols from
/usr/lib/debug//boot/kernel/kernel.debug...done.
done.
<signal handler called>
(kgdb) tid 100471
(kgdb) bt
#0  sched_switch (td=3D0xfffff8001196c580, newtd=3D0xfffff8000354f580,
flags=3D<optimized out>) at /usr/src/sys/kern/sched_ule.c:2112
#1  0xffffffff80d0e0a1 in mi_switch (flags=3D<optimized out>, newtd=3D0x0) =
at
/usr/src/sys/kern/kern_synch.c:439
#2  0xffffffff80d5c80c in sleepq_wait (wchan=3D<unavailable>, pri=3D<unavai=
lable>)
at /usr/src/sys/kern/subr_sleepqueue.c:692
#3  0xffffffff80c9ca52 in _cv_wait (cvp=3D0xfffff80011354d28,
lock=3D0xfffff80011354c50) at /usr/src/sys/kern/kern_condvar.c:146
#4  0xffffffff80403dfb in dmu_tx_wait (tx=3D0xfffff8037afd1c00) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c:1090
#5  0xffffffff80403748 in dmu_tx_assign (tx=3D0xfffff8037afd1c00, txg_how=
=3D1) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c:1032
#6  0xffffffff804a4ce8 in zfs_create (excl=3D0, mode=3D0, dvp=3D<optimized =
out>,
name=3D<optimized out>, vap=3D<optimized out>, vpp=3D<optimized out>, cr=3D=
<optimized
out>, td=3D<optimized out>) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1875
#7  zfs_freebsd_create (ap=3D0xfffffe008e25a790) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:4996
#8  0xffffffff813aaa68 in VOP_CREATE_APV (vop=3D<optimized out>,
a=3D0xfffffe008e25a790) at vnode_if.c:263
#9  0xffffffff80de20f9 in VOP_CREATE (dvp=3D<unavailable>,
vpp=3D0xfffffe008e25a888, cnp=3D<optimized out>, vap=3D0x18000000001) at
./vnode_if.h:109
#10 vn_open_cred (ndp=3D0xfffffe008e25a828, flagp=3D0xfffffe008e25a954,
cmode=3D<optimized out>, vn_open_flags=3D<optimized out>, cred=3D0xfffff800=
2b529b00,
fp=3D0xfffff80359185aa0) at /usr/src/sys/kern/vfs_vnops.c:243
#11 0xffffffff80dda74c in kern_openat (td=3D0xfffff8001196c580, fd=3D-100,
path=3D0x88d3a0f70 <error: Cannot access memory at address 0x88d3a0f70>,
pathseg=3DUIO_USERSPACE, flags=3D2563, mode=3D<optimized out>) at
/usr/src/sys/kern/vfs_syscalls.c:1082
#12 0xffffffff81222449 in syscallenter (td=3D<optimized out>) at
/usr/src/sys/amd64/amd64/../../kern/subr_syscall.c:135
#13 amd64_syscall (td=3D0xfffff8001196c580, traced=3D0) at
/usr/src/sys/amd64/amd64/trap.c:1076
#14 <signal handler called>
#15 0x000000080131e82a in ?? ()
Backtrace stopped: Cannot access memory at address 0x7fffffffb4c8
(kgdb) tid 100527
(kgdb) bt
#0  sched_switch (td=3D0xfffff8026af9d580, newtd=3D0xfffff80003551000,
flags=3D<optimized out>) at /usr/src/sys/kern/sched_ule.c:2112
#1  0xffffffff80d0e0a1 in mi_switch (flags=3D<optimized out>, newtd=3D0x0) =
at
/usr/src/sys/kern/kern_synch.c:439
#2  0xffffffff80d5c80c in sleepq_wait (wchan=3D<unavailable>, pri=3D<unavai=
lable>)
at /usr/src/sys/kern/subr_sleepqueue.c:692
#3  0xffffffff80cd9105 in sleeplk (lk=3D0xfffff802f256c248, flags=3D<optimi=
zed
out>, ilk=3D<optimized out>, wmesg=3D<optimized out>, pri=3D<optimized out>=
, timo=3D51,
queue=3D0) at /usr/src/sys/kern/kern_lock.c:300
#4  0xffffffff80cd819c in lockmgr_xlock_hard (lk=3D0xfffff802f256c248,
flags=3D525312, ilk=3D0xfffff802f256c278, file=3D<optimized out>, line=3D<o=
ptimized
out>, lwa=3D<optimized out>) at /usr/src/sys/kern/kern_lock.c:822
#5  0xffffffff813acc5e in VOP_LOCK1_APV (vop=3D<optimized out>,
a=3D0xfffffe008e36b280) at vnode_if.c:2087
#6  0xffffffff80de2820 in VOP_LOCK1 (vp=3D0xfffff802f256c1e0, flags=3D52531=
2,
file=3D0xffffffff813c47d0
"/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c",
line=3D730) at ./vnode_if.h:859
#7  _vn_lock (vp=3D0xfffff802f256c1e0, flags=3D525312, file=3D0xffffffff813=
c47d0
"/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c",
line=3D730) at /usr/src/sys/kern/vfs_vnops.c:1533
#8  0xffffffff804ae1f4 in zfs_znode_alloc (zfsvfs=3D<optimized out>,
db=3D<optimized out>, blksz=3D0, obj_type=3D<optimized out>, hdl=3D<optimiz=
ed out>) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c:730
#9  0xffffffff804adc0d in zfs_mknode (dzp=3D0xfffff802f461f440,
vap=3D0xfffffe008e36b6e0, tx=3D<optimized out>, cr=3D0xfffff8002b529b00,
flag=3D<optimized out>, zpp=3D0xfffffe008e36b638, acl_ids=3D0xfffffe008e36b=
5f8) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c:988
#10 0xffffffff804a4d32 in zfs_create (excl=3D0, mode=3D0, dvp=3D<optimized =
out>,
name=3D<optimized out>, vap=3D<optimized out>, vpp=3D<optimized out>, cr=3D=
<optimized
out>, td=3D<optimized out>) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1883
#11 zfs_freebsd_create (ap=3D0xfffffe008e36b790) at
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:4996
#12 0xffffffff813aaa68 in VOP_CREATE_APV (vop=3D<optimized out>,
a=3D0xfffffe008e36b790) at vnode_if.c:263
#13 0xffffffff80de20f9 in VOP_CREATE (dvp=3D<unavailable>,
vpp=3D0xfffffe008e36b888, cnp=3D<optimized out>, vap=3D0x18000000001) at
./vnode_if.h:109
#14 vn_open_cred (ndp=3D0xfffffe008e36b828, flagp=3D0xfffffe008e36b954,
cmode=3D<optimized out>, vn_open_flags=3D<optimized out>, cred=3D0xfffff800=
2b529b00,
fp=3D0xfffff8026d933d70) at /usr/src/sys/kern/vfs_vnops.c:243
#15 0xffffffff80dda74c in kern_openat (td=3D0xfffff8026af9d580, fd=3D-100,
path=3D0x7fffffffc630 <error: Cannot access memory at address 0x7fffffffc63=
0>,
pathseg=3DUIO_USERSPACE, flags=3D1538, mode=3D<optimized out>) at
/usr/src/sys/kern/vfs_syscalls.c:1082
#16 0xffffffff81222449 in syscallenter (td=3D<optimized out>) at
/usr/src/sys/amd64/amd64/../../kern/subr_syscall.c:135
#17 amd64_syscall (td=3D0xfffff8026af9d580, traced=3D0) at
/usr/src/sys/amd64/amd64/trap.c:1076
#18 <signal handler called>
#19 0x000000080138b4fa in ?? ()
Backtrace stopped: Cannot access memory at address 0x7fffffffc138
(kgdb) fr 7
#7  _vn_lock (vp=3D0xfffff802f256c1e0, flags=3D525312, file=3D0xffffffff813=
c47d0
"/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c",
line=3D730) at /usr/src/sys/kern/vfs_vnops.c:1533
warning: Source file is more recent than executable.
1533            error =3D VOP_LOCK1(vp, flags, file, line);
(kgdb) print *vp
$1 =3D {v_tag =3D 0xffffffff8144af45 "zfs", v_op =3D 0xffffffff81c64fd0
<zfs_vnodeops>, v_data =3D 0xfffff802608c3440, v_mount =3D 0x0, v_nmntvnode=
s =3D
{tqe_next =3D 0xfffff8037a047000, tqe_prev =3D 0xfffff802f23feb60}, {v_moun=
tedhere
=3D 0x0, v_unpcb =3D 0x0, v_rdev =3D 0x0, v_fifoinfo =3D 0x0}, v_hashlist =
=3D {le_next =3D
0x0, le_prev =3D 0x0}, v_cache_src =3D {
    lh_first =3D 0x0}, v_cache_dst =3D {tqh_first =3D 0x0, tqh_last =3D
0xfffff802f256c230}, v_cache_dd =3D 0x0, v_lock =3D {lock_object =3D {lo_na=
me =3D
0xffffffff8144af45 "zfs", lo_flags =3D 117112840, lo_data =3D 0, lo_witness=
 =3D 0x0},
lk_lock =3D 18446744073709551605, lk_exslpfail =3D 0, lk_timo =3D 51, lk_pr=
i =3D 96},
v_interlock =3D {lock_object =3D {
      lo_name =3D 0xffffffff814e4508 "vnode interlock", lo_flags =3D 169738=
24,
lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D 0}, v_vnlock =3D 0xfffff80=
2f256c248,
v_actfreelist =3D {tqe_next =3D 0xfffff8037a047000, tqe_prev =3D 0xfffff800=
11333a38},
v_bufobj =3D {bo_lock =3D {lock_object =3D {lo_name =3D 0xffffffff814a9e5f =
"bufobj
interlock", lo_flags =3D 86179840,=20
        lo_data =3D 0, lo_witness =3D 0x0}, rw_lock =3D 1}, bo_ops =3D
0xffffffff81d38600 <buf_ops_bio>, bo_object =3D 0x0, bo_synclist =3D {le_ne=
xt =3D
0x0, le_prev =3D 0x0}, bo_private =3D 0xfffff802f256c1e0, bo_clean =3D {bv_=
hd =3D
{tqh_first =3D 0x0, tqh_last =3D 0xfffff802f256c2f8}, bv_root =3D {pt_root =
=3D 0},
bv_cnt =3D 0}, bo_dirty =3D {bv_hd =3D {tqh_first =3D 0x0,=20
        tqh_last =3D 0xfffff802f256c318}, bv_root =3D {pt_root =3D 0}, bv_c=
nt =3D 0},
bo_numoutput =3D 0, bo_flag =3D 0, bo_domain =3D 1, bo_bsize =3D 16384}, v_=
pollinfo =3D
0x0, v_label =3D 0x0, v_lockf =3D 0x0, v_rl =3D {rl_waiters =3D {tqh_first =
=3D 0x0,
tqh_last =3D 0xfffff802f256c368}, rl_currdep =3D 0x0}, v_cstart =3D 0, v_la=
sta =3D 0,
v_lastw =3D 0, v_clen =3D 0,=20
  v_holdcnt =3D 1, v_usecount =3D 1, v_iflag =3D 0, v_vflag =3D 0, v_mflag =
=3D 0,
v_writecount =3D 0, v_hash =3D 49436353, v_type =3D VREG}
(kgdb)

--=20
You are receiving this mail because:
You are the assignee for the bug.=



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-236220-227-E895PrEUUY>