From owner-freebsd-current@FreeBSD.ORG Sat Aug 1 14:53:10 2009 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 96513106566C; Sat, 1 Aug 2009 14:53:10 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from mail.zoral.com.ua (skuns.zoral.com.ua [91.193.166.194]) by mx1.freebsd.org (Postfix) with ESMTP id EA3428FC15; Sat, 1 Aug 2009 14:53:09 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from deviant.kiev.zoral.com.ua (root@deviant.kiev.zoral.com.ua [10.1.1.148]) by mail.zoral.com.ua (8.14.2/8.14.2) with ESMTP id n71Er2bd004050 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Sat, 1 Aug 2009 17:53:02 +0300 (EEST) (envelope-from kostikbel@gmail.com) Received: from deviant.kiev.zoral.com.ua (kostik@localhost [127.0.0.1]) by deviant.kiev.zoral.com.ua (8.14.3/8.14.3) with ESMTP id n71Er1xR002982; Sat, 1 Aug 2009 17:53:01 +0300 (EEST) (envelope-from kostikbel@gmail.com) Received: (from kostik@localhost) by deviant.kiev.zoral.com.ua (8.14.3/8.14.3/Submit) id n71Er1qF002981; Sat, 1 Aug 2009 17:53:01 +0300 (EEST) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: deviant.kiev.zoral.com.ua: kostik set sender to kostikbel@gmail.com using -f Date: Sat, 1 Aug 2009 17:53:01 +0300 From: Kostik Belousov To: Thomas Backman Message-ID: <20090801145301.GE1884@deviant.kiev.zoral.com.ua> References: <4B49A2A0-2437-48A4-9047-80267BD4148F@exscape.org> Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="JoaBr9Q1T6GV3lOg" Content-Disposition: inline In-Reply-To: <4B49A2A0-2437-48A4-9047-80267BD4148F@exscape.org> User-Agent: Mutt/1.4.2.3i X-Virus-Scanned: clamav-milter 0.95.2 at skuns.kiev.zoral.com.ua X-Virus-Status: Clean X-Spam-Status: No, score=-4.4 required=5.0 tests=ALL_TRUSTED,AWL,BAYES_00 autolearn=ham version=3.2.5 X-Spam-Checker-Version: SpamAssassin 3.2.5 (2008-06-10) on skuns.kiev.zoral.com.ua Cc: freebsd-fs@freebsd.org, FreeBSD current Subject: Re: Samba + ZFS panic w/ DEBUG_VFS_LOCKS X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 01 Aug 2009 14:53:11 -0000 --JoaBr9Q1T6GV3lOg Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable 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 = =20 > some simple media streaming from ZFS would work. It did not; smbd =20 > didn't even start before it panicked... At "Starting smdb" I got the =20 > following panic: >=20 > (Note: I haven't tried without DEBUG_VFS_LOCKS yet. I do suppose that =20 > it's not supposed to panic even with rigorous debugging enabled, =20 > though!) >=20 > 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 =3D 0x801064dac, rsp =3D =20 > 0x7fffffffe5d8, rbp =3D 0x801336480 --- > VOP_PUTPAGES: 0xffffff0007649588 is not exclusive locked but should be > KDB: enter: lock violation >=20 > 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 =3D 0 > KDB: stack backtrace: > Uptime: 17h10m52s > Physical memory: 2034 MB > Dumping 1723 MB: ... >=20 > 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=3D0xffffffff80613fd5 "vfslock", > msg=3D0xa
) at cpufunc.h:63 > #11 0xffffffff803cb3a4 in assert_vop_elocked (vp=3D0xffffff0007649588, > str=3D0xffffffff80642728 "VOP_PUTPAGES") > at /usr/src/sys/kern/vfs_subr.c:3722 > #12 0xffffffff805c80eb in VOP_PUTPAGES_APV (vop=3D0xffffffff807a07c0, = =20 > a=3D0xffffff803eb72730) at vnode_if.c:2664 > #13 0xffffffff80572cd9 in vnode_pager_putpages =20 > (object=3D0xffffff000ee6c000, > m=3D0xffffff803eb72830, count=3D8192, sync=3D12, =20 > rtvals=3D0xffffff803eb727a0) > at vnode_if.h:1169 > #14 0xffffffff8056d601 in vm_pageout_flush (mc=3D0xffffff803eb72830, =20 > count=3D2, > flags=3D12) at vm_pager.h:148 > #15 0xffffffff80568e30 in vm_object_page_collect_flush ( > object=3D0xffffff000ee6c000, p=3DVariable "p" is not available. > ) at /usr/src/sys/vm/vm_object.c:1032 > #16 0xffffffff80569023 in vm_object_page_clean =20 > (object=3D0xffffff000ee6c000, > start=3D0, end=3DVariable "end" is not available. > ) at /usr/src/sys/vm/vm_object.c:844 > #17 0xffffffff803d3bd1 in fsync (td=3D0xffffff0027f45000, uap=3DVariable = =20 > "uap" is not available. > ) > at /usr/src/sys/kern/vfs_syscalls.c:3519#18 0xffffffff80598e7f in =20 > syscall (frame=3D0xffffff803eb72c80) at /usr/src/sys/amd64/amd64/=20 > 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?) >=20 > (kgdb) fr 11 > #11 0xffffffff803cb3a4 in assert_vop_elocked (vp=3D0xffffff0007649588, = =20 > str=3D0xffffffff80642728 "VOP_PUTPAGES") > at /usr/src/sys/kern/vfs_subr.c:3722 > 3722 vfs_badlock("is not exclusive locked but =20 > should be", str, vp); > (kgdb) p *vp > $1 =3D {v_type =3D VREG, v_tag =3D 0xffffffff80b59327 "zfs", v_op =3D =20 > 0xffffffff80b5dee0, v_data =3D 0xffffff00052cb758, > v_mount =3D 0xffffff00018392f0, v_nmntvnodes =3D {tqe_next =3D 0x0, =20 > tqe_prev =3D 0xffffff006895b028}, v_un =3D {vu_mount =3D 0x0, vu_socket = =3D 0x0, > vu_cdev =3D 0x0, vu_fifoinfo =3D 0x0, vu_yield =3D 0}, v_hashlist =3D= =20 > {le_next =3D 0x0, le_prev =3D 0x0}, v_hash =3D 0, v_cache_src =3D { > lh_first =3D 0x0}, v_cache_dst =3D {tqh_first =3D 0x0, tqh_last =3D = =20 > 0xffffff00076495e8}, v_cache_dd =3D 0x0, v_cstart =3D 0, v_lasta =3D 0, > v_lastw =3D 0, v_clen =3D 0, v_lock =3D {lock_object =3D {lo_name =3D = =20 > 0xffffffff80b59327 "zfs", lo_flags =3D 91947008, lo_data =3D 0, > lo_witness =3D 0x0}, lk_lock =3D 17, lk_timo =3D 51, lk_pri =3D 80}= , =20 > v_interlock =3D {lock_object =3D { > lo_name =3D 0xffffffff80614670 "vnode interlock", lo_flags =3D =20 > 16973824, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D 4}, > v_vnlock =3D 0xffffff0007649620, v_holdcnt =3D 3, v_usecount =3D 2, =20 > v_iflag =3D 1024, v_vflag =3D 0, v_writecount =3D 1, v_freelist =3D { > tqe_next =3D 0x0, tqe_prev =3D 0x0}, v_bufobj =3D {bo_mtx =3D =20 > {lock_object =3D {lo_name =3D 0xffffffff80614680 "bufobj interlock", > lo_flags =3D 16973824, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lo= ck =20 > =3D 4}, bo_clean =3D {bv_hd =3D {tqh_first =3D 0x0, > tqh_last =3D 0xffffff00076496c0}, bv_root =3D 0x0, bv_cnt =3D 0},= =20 > bo_dirty =3D {bv_hd =3D {tqh_first =3D 0x0, tqh_last =3D 0xffffff00076496= e0}, > bv_root =3D 0x0, bv_cnt =3D 0}, bo_numoutput =3D 0, bo_flag =3D 0, = =20 > bo_ops =3D 0xffffffff8079d620, bo_bsize =3D 131072, > bo_object =3D 0xffffff000ee6c000, bo_synclist =3D {le_next =3D 0x0, = =20 > le_prev =3D 0x0}, bo_private =3D 0xffffff0007649588, > __bo_vnode =3D 0xffffff0007649588}, v_pollinfo =3D 0x0, v_label =3D = =20 > 0x0, v_lockf =3D 0xffffff000d402600} >=20 > (kgdb) fr 17 > #17 0xffffffff803d3bd1 in fsync (td=3D0xffffff0027f45000, uap=3DVariable = =20 > "uap" is not available. > ) at /usr/src/sys/kern/vfs_syscalls.c:3519 > 3519 vn_finished_write(mp); > (kgdb) p *mp > $2 =3D {mnt_mtx =3D {lock_object =3D {lo_name =3D 0xffffffff80613905 "str= uct =20 > mount mtx", lo_flags =3D 16973824, lo_data =3D 0, lo_witness =3D 0x0}, > mtx_lock =3D 4}, mnt_gen =3D 1, mnt_list =3D {tqe_next =3D =20 > 0xffffff0001bf75e0, tqe_prev =3D 0xffffff0001839608}, mnt_op =3D =20 > 0xffffffff80b5de40, > mnt_vfc =3D 0xffffffff80b5dde0, mnt_vnodecovered =3D =20 > 0xffffff0001ae6000, mnt_syncer =3D 0xffffff0001be2760, mnt_ref =3D 14897,= =20 > mnt_nvnodelist =3D { > tqh_first =3D 0xffffff0001be2b10, tqh_last =3D 0xffffff00076495b0}, = =20 > mnt_nvnodelistsize =3D 7449, mnt_writeopcount =3D 1, > mnt_kern_flag =3D 1610612864, mnt_flag =3D 268439552, mnt_xflag =3D 0, = =20 > mnt_noasync =3D 0, mnt_opt =3D 0xffffff00017f1830, mnt_optnew =3D 0x0, > mnt_maxsymlinklen =3D 0, mnt_stat =3D {f_version =3D 537068824, f_type = =3D =20 > 4, f_flags =3D 268439552, f_bsize =3D 131072, f_iosize =3D 131072, > f_blocks =3D 485196, f_bfree =3D 475793, f_bavail =3D 475793, f_files= =3D =20 > 529171, f_ffree =3D 475793, f_syncwrites =3D 0, f_asyncwrites =3D 0, > f_syncreads =3D 0, f_asyncreads =3D 0, f_spare =3D {0, 0, 0, 0, 0, 0,= =20 > 0, 0, 0, 0}, f_namemax =3D 255, f_owner =3D 0, f_fsid =3D {val =3D {59119= 8578, > -1876274428}}, f_charspare =3D '\0' , =20 > f_fstypename =3D "zfs", '\0' , > f_mntfromname =3D "tank/usr", '\0' , f_mntonname = =20 > =3D "/usr", '\0' }, mnt_cred =3D 0xffffff0001be0e00, > mnt_data =3D 0xffffff0001a89000, mnt_time =3D 0, mnt_iosize_max =3D =20 > 65536, mnt_export =3D 0x0, mnt_label =3D 0x0, mnt_hashseed =3D 2610436692, > mnt_lockref =3D 0, mnt_secondary_writes =3D 0, mnt_secondary_accwrites = =20 > =3D 0, mnt_susp_owner =3D 0x0, mnt_gjprovider =3D 0x0, mnt_explock =3D { > lock_object =3D {lo_name =3D 0xffffffff80613916 "explock", lo_flags = =3D =20 > 91422720, lo_data =3D 0, lo_witness =3D 0x0}, lk_lock =3D 1, lk_timo =3D = 0, > lk_pri =3D 80}} >=20 > # uname -a > FreeBSD chaos.exscape.org 8.0-BETA2 FreeBSD 8.0-BETA2 #7 r195910M: Thu = =20 > Jul 30 19:03:33 CEST 2009 root@chaos.exscape.org:/usr/obj/usr/src/=20 > sys/DTRACE amd64 >=20 > As I said, DEBUG_VFS_LOCKS in enabled. > Should I disabled DEBUG_VFS_LOCKS and consider this "normal" (if it =20 > 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 =20 > samba, nor is any FS below it. Also note that my debugging skills are =20 > 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_put= pages 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 --JoaBr9Q1T6GV3lOg Content-Type: application/pgp-signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (FreeBSD) iEYEARECAAYFAkp0Vs0ACgkQC3+MBN1Mb4iXWQCfSvJ5g6W/YqD+gFMdnJXQ+IX9 /SQAnj+H+cNU8V5EQcOit2OpemYVGycP =j2WY -----END PGP SIGNATURE----- --JoaBr9Q1T6GV3lOg--