Re: Samba + ZFS panic w/ DEBUG_VFS_LOCKS

From: Kostik Belousov <kostikbel_at_gmail.com>
Date: Sat, 1 Aug 2009 17:53:01 +0300
On Sat, Aug 01, 2009 at 12:57:29PM +0200, Thomas Backman wrote:
> 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.)

It does not matter whether the zfs is accessed by samba. Panic
happens when you do fsync(2) on a vnode that has its vm object
marked as dirty, and VFS_DEBUG_LOCKS is configured.

The workaround is to disable VFS_DEBUG_LOCKS. Since vnode_pager_generic_putpages seems to work with shared vnode lock as far as VOP_WRITE works right with shared lock, change sys/kern/vnode_if.src, line 475 from
%% putpages	vp	E E E
to
%% putpages	vp	L L L

Received on Sat Aug 01 2009 - 12:53:10 UTC

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