Samba + ZFS panic w/ DEBUG_VFS_LOCKS

From: Thomas Backman <serenity_at_exscape.org>
Date: Sat, 1 Aug 2009 12:57:29 +0200
I just installed samba (ports/net/samba3) on my test machine to see if  
some simple media streaming from ZFS would work. It did not; smbd  
didn't even start before it panicked... At "Starting smdb" I got the  
following panic:

(Note: I haven't tried without DEBUG_VFS_LOCKS yet. I do suppose that  
it's not supposed to panic even with rigorous debugging enabled,  
though!)

Unread portion of the kernel message buffer:
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
vfs_badlock() at vfs_badlock+0x95
assert_vop_elocked() at assert_vop_elocked+0x64
VOP_PUTPAGES_APV() at VOP_PUTPAGES_APV+0x5b
vnode_pager_putpages() at vnode_pager_putpages+0xa9
vm_pageout_flush() at vm_pageout_flush+0xd1
vm_object_page_collect_flush() at vm_object_page_collect_flush+0x2f0
vm_object_page_clean() at vm_object_page_clean+0x143
fsync() at fsync+0x121
syscall() at syscall+0x28f
Xfast_syscall() at Xfast_syscall+0xe1
--- syscall (95, FreeBSD ELF64, fsync), rip = 0x801064dac, rsp =  
0x7fffffffe5d8, rbp = 0x801336480 ---
VOP_PUTPAGES: 0xffffff0007649588 is not exclusive locked but should be
KDB: enter: lock violation

0xffffff0007649588: tag zfs, type VREG
     usecount 2, writecount 1, refcount 3 mountedhere 0
     flags (VI_OBJDIRTY)
     v_object 0xffffff000ee6c000 ref 1 pages 2
     lock type zfs: SHARED (count 1)
panic: from debugger
cpuid = 0
KDB: stack backtrace:
Uptime: 17h10m52s
Physical memory: 2034 MB
Dumping 1723 MB: ...

     at /usr/src/sys/amd64/amd64/trap.c:613
#9  0xffffffff8057eda7 in calltrap ()
     at /usr/src/sys/amd64/amd64/exception.S:224
#10 0xffffffff8036c8ad in kdb_enter (why=0xffffffff80613fd5 "vfslock",
     msg=0xa <Address 0xa out of bounds>) at cpufunc.h:63
#11 0xffffffff803cb3a4 in assert_vop_elocked (vp=0xffffff0007649588,
     str=0xffffffff80642728 "VOP_PUTPAGES")
     at /usr/src/sys/kern/vfs_subr.c:3722
#12 0xffffffff805c80eb in VOP_PUTPAGES_APV (vop=0xffffffff807a07c0,     
a=0xffffff803eb72730) at vnode_if.c:2664
#13 0xffffffff80572cd9 in vnode_pager_putpages  
(object=0xffffff000ee6c000,
     m=0xffffff803eb72830, count=8192, sync=12,  
rtvals=0xffffff803eb727a0)
     at vnode_if.h:1169
#14 0xffffffff8056d601 in vm_pageout_flush (mc=0xffffff803eb72830,  
count=2,
     flags=12) at vm_pager.h:148
#15 0xffffffff80568e30 in vm_object_page_collect_flush (
     object=0xffffff000ee6c000, p=Variable "p" is not available.
) at /usr/src/sys/vm/vm_object.c:1032
#16 0xffffffff80569023 in vm_object_page_clean  
(object=0xffffff000ee6c000,
     start=0, end=Variable "end" is not available.
) at /usr/src/sys/vm/vm_object.c:844
#17 0xffffffff803d3bd1 in fsync (td=0xffffff0027f45000, uap=Variable  
"uap" is not available.
)
     at /usr/src/sys/kern/vfs_syscalls.c:3519#18 0xffffffff80598e7f in  
syscall (frame=0xffffff803eb72c80)    at /usr/src/sys/amd64/amd64/ 
trap.c:984#19 0xffffffff8057f081 in Xfast_syscall ()
     at /usr/src/sys/amd64/amd64/exception.S:373
#20 0x0000000801064dac in ?? ()
Previous frame inner to this frame (corrupt stack?)

(kgdb) fr 11
#11 0xffffffff803cb3a4 in assert_vop_elocked (vp=0xffffff0007649588,  
str=0xffffffff80642728 "VOP_PUTPAGES")
     at /usr/src/sys/kern/vfs_subr.c:3722
3722                    vfs_badlock("is not exclusive locked but  
should be", str, vp);
(kgdb) p *vp
$1 = {v_type = VREG, v_tag = 0xffffffff80b59327 "zfs", v_op =  
0xffffffff80b5dee0, v_data = 0xffffff00052cb758,
   v_mount = 0xffffff00018392f0, v_nmntvnodes = {tqe_next = 0x0,  
tqe_prev = 0xffffff006895b028}, v_un = {vu_mount = 0x0, vu_socket = 0x0,
     vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist =  
{le_next = 0x0, le_prev = 0x0}, v_hash = 0, v_cache_src = {
     lh_first = 0x0}, v_cache_dst = {tqh_first = 0x0, tqh_last =  
0xffffff00076495e8}, v_cache_dd = 0x0, v_cstart = 0, v_lasta = 0,
   v_lastw = 0, v_clen = 0, v_lock = {lock_object = {lo_name =  
0xffffffff80b59327 "zfs", lo_flags = 91947008, lo_data = 0,
       lo_witness = 0x0}, lk_lock = 17, lk_timo = 51, lk_pri = 80},  
v_interlock = {lock_object = {
       lo_name = 0xffffffff80614670 "vnode interlock", lo_flags =  
16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4},
   v_vnlock = 0xffffff0007649620, v_holdcnt = 3, v_usecount = 2,  
v_iflag = 1024, v_vflag = 0, v_writecount = 1, v_freelist = {
     tqe_next = 0x0, tqe_prev = 0x0}, v_bufobj = {bo_mtx =  
{lock_object = {lo_name = 0xffffffff80614680 "bufobj interlock",
         lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock  
= 4}, bo_clean = {bv_hd = {tqh_first = 0x0,
         tqh_last = 0xffffff00076496c0}, bv_root = 0x0, bv_cnt = 0},  
bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff00076496e0},
       bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0,  
bo_ops = 0xffffffff8079d620, bo_bsize = 131072,
     bo_object = 0xffffff000ee6c000, bo_synclist = {le_next = 0x0,  
le_prev = 0x0}, bo_private = 0xffffff0007649588,
     __bo_vnode = 0xffffff0007649588}, v_pollinfo = 0x0, v_label =  
0x0, v_lockf = 0xffffff000d402600}

(kgdb) fr 17
#17 0xffffffff803d3bd1 in fsync (td=0xffffff0027f45000, uap=Variable  
"uap" is not available.
) at /usr/src/sys/kern/vfs_syscalls.c:3519
3519            vn_finished_write(mp);
(kgdb) p *mp
$2 = {mnt_mtx = {lock_object = {lo_name = 0xffffffff80613905 "struct  
mount mtx", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0},
     mtx_lock = 4}, mnt_gen = 1, mnt_list = {tqe_next =  
0xffffff0001bf75e0, tqe_prev = 0xffffff0001839608}, mnt_op =  
0xffffffff80b5de40,
   mnt_vfc = 0xffffffff80b5dde0, mnt_vnodecovered =  
0xffffff0001ae6000, mnt_syncer = 0xffffff0001be2760, mnt_ref = 14897,  
mnt_nvnodelist = {
     tqh_first = 0xffffff0001be2b10, tqh_last = 0xffffff00076495b0},  
mnt_nvnodelistsize = 7449, mnt_writeopcount = 1,
   mnt_kern_flag = 1610612864, mnt_flag = 268439552, mnt_xflag = 0,  
mnt_noasync = 0, mnt_opt = 0xffffff00017f1830, mnt_optnew = 0x0,
   mnt_maxsymlinklen = 0, mnt_stat = {f_version = 537068824, f_type =  
4, f_flags = 268439552, f_bsize = 131072, f_iosize = 131072,
     f_blocks = 485196, f_bfree = 475793, f_bavail = 475793, f_files =  
529171, f_ffree = 475793, f_syncwrites = 0, f_asyncwrites = 0,
     f_syncreads = 0, f_asyncreads = 0, f_spare = {0, 0, 0, 0, 0, 0,  
0, 0, 0, 0}, f_namemax = 255, f_owner = 0, f_fsid = {val = {591198578,
         -1876274428}}, f_charspare = '\0' <repeats 79 times>,  
f_fstypename = "zfs", '\0' <repeats 12 times>,
     f_mntfromname = "tank/usr", '\0' <repeats 79 times>, f_mntonname  
= "/usr", '\0' <repeats 83 times>}, mnt_cred = 0xffffff0001be0e00,
   mnt_data = 0xffffff0001a89000, mnt_time = 0, mnt_iosize_max =  
65536, mnt_export = 0x0, mnt_label = 0x0, mnt_hashseed = 2610436692,
   mnt_lockref = 0, mnt_secondary_writes = 0, mnt_secondary_accwrites  
= 0, mnt_susp_owner = 0x0, mnt_gjprovider = 0x0, mnt_explock = {
     lock_object = {lo_name = 0xffffffff80613916 "explock", lo_flags =  
91422720, lo_data = 0, lo_witness = 0x0}, lk_lock = 1, lk_timo = 0,
     lk_pri = 80}}

# uname -a
FreeBSD chaos.exscape.org 8.0-BETA2 FreeBSD 8.0-BETA2 #7 r195910M: Thu  
Jul 30 19:03:33 CEST 2009     root_at_chaos.exscape.org:/usr/obj/usr/src/ 
sys/DTRACE  amd64

As I said, DEBUG_VFS_LOCKS in enabled.
Should I disabled DEBUG_VFS_LOCKS and consider this "normal" (if it  
doesn't still panic, that is), or is this a real issue?
(Note that while *mp points to /usr, FWIW, /usr is not shared by  
samba, nor is any FS below it. Also note that my debugging skills are  
at an early stage... so the info provided may be useless.)

Regards,
Thomas
Received on Sat Aug 01 2009 - 08:57:38 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:53 UTC