From owner-freebsd-fs@FreeBSD.ORG Sat Aug 1 10:57:38 2009 Return-Path: Delivered-To: freebsd-fs@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 96EA1106564A; Sat, 1 Aug 2009 10:57:38 +0000 (UTC) (envelope-from serenity@exscape.org) Received: from ch-smtp01.sth.basefarm.net (ch-smtp01.sth.basefarm.net [80.76.149.212]) by mx1.freebsd.org (Postfix) with ESMTP id 058B18FC18; Sat, 1 Aug 2009 10:57:37 +0000 (UTC) (envelope-from serenity@exscape.org) Received: from c83-253-252-234.bredband.comhem.se ([83.253.252.234]:46264 helo=mx.exscape.org) by ch-smtp01.sth.basefarm.net with esmtp (Exim 4.68) (envelope-from ) id 1MXCHN-0007FP-3e; Sat, 01 Aug 2009 12:57:35 +0200 Received: from [192.168.1.5] (macbookpro [192.168.1.5]) (using TLSv1 with cipher AES128-SHA (128/128 bits)) (No client certificate requested) by mx.exscape.org (Postfix) with ESMTPSA id D96ACEE65E; Sat, 1 Aug 2009 12:57:31 +0200 (CEST) Message-Id: <4B49A2A0-2437-48A4-9047-80267BD4148F@exscape.org> From: Thomas Backman To: freebsd-fs@freebsd.org, FreeBSD current Content-Type: text/plain; charset=US-ASCII; format=flowed; delsp=yes Content-Transfer-Encoding: 7bit Mime-Version: 1.0 (Apple Message framework v935.3) Date: Sat, 1 Aug 2009 12:57:29 +0200 X-Mailer: Apple Mail (2.935.3) X-Originating-IP: 83.253.252.234 X-Scan-Result: No virus found in message 1MXCHN-0007FP-3e. X-Scan-Signature: ch-smtp01.sth.basefarm.net 1MXCHN-0007FP-3e 0305009ebe3e710f7c1f36d3eddd9cd9 Cc: Subject: Samba + ZFS panic w/ DEBUG_VFS_LOCKS X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 01 Aug 2009 10:57:39 -0000 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
) 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' , f_fstypename = "zfs", '\0' , f_mntfromname = "tank/usr", '\0' , f_mntonname = "/usr", '\0' }, 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@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