From owner-freebsd-current@FreeBSD.ORG Thu Jun 16 09:05:18 2005 Return-Path: X-Original-To: freebsd-current@FreeBSD.org Delivered-To: freebsd-current@FreeBSD.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id B229C16A41C; Thu, 16 Jun 2005 09:05:18 +0000 (GMT) (envelope-from delphij@frontfree.net) Received: from tarsier.geekcn.org (tarsier.geekcn.org [210.51.165.229]) by mx1.FreeBSD.org (Postfix) with ESMTP id E5F0A43D1F; Thu, 16 Jun 2005 09:05:17 +0000 (GMT) (envelope-from delphij@frontfree.net) Received: from beastie.frontfree.net (unknown [219.239.99.7]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by tarsier.geekcn.org (Postfix) with ESMTP id 04BAAEB14C4; Thu, 16 Jun 2005 17:05:10 +0800 (CST) Received: from localhost (localhost.frontfree.net [127.0.0.1]) by beastie.frontfree.net (Postfix) with ESMTP id 81AFD131FDA; Thu, 16 Jun 2005 17:04:27 +0800 (CST) Received: from beastie.frontfree.net ([127.0.0.1]) by localhost (beastie.frontfree.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 40094-07; Thu, 16 Jun 2005 17:04:20 +0800 (CST) Received: from [10.217.12.87] (unknown [61.135.152.194]) (using TLSv1 with cipher RC4-MD5 (128/128 bits)) (No client certificate requested) by beastie.frontfree.net (Postfix) with ESMTP id 770E3131336; Thu, 16 Jun 2005 17:04:18 +0800 (CST) From: Xin LI To: freebsd-current@FreeBSD.org Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="=-Q8RPkZo9v1VhNPn5u4st" Organization: The FreeBSD Simplified Chinese Project Date: Thu, 16 Jun 2005 17:04:11 +0800 Message-Id: <1118912651.860.17.camel@spirit> Mime-Version: 1.0 X-Mailer: Evolution 2.2.3 FreeBSD GNOME Team Port X-Virus-Scanned: amavisd-new at frontfree.net Cc: jeff@FreeBSD.org Subject: Recent VFS locking vs kqueue X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: delphij@delphij.net List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 16 Jun 2005 09:05:18 -0000 --=-Q8RPkZo9v1VhNPn5u4st Content-Type: text/plain Content-Transfer-Encoding: quoted-printable Hi, Jeff and -current@, With a fresh -CURRENT kernel (today's source) I got the following messages from console and /var/log/messages on my laptop, with a "cvs -R up -PdA 2>/dev/null" running on one console (which results in disk/fs activities) and "tail -F /var/log/messages" (which uses kqueue events). The kernel is built with ULE scheduler, PREEMPTION+FULL_PREEMPTION enabled, and all debugging options, like INVARIANTS and WITESS turned on. BTW. I have found something that can lead to panic: Negative nice count, which indicates that there are some races in our code, but it seems that the bug is not easy to exercise. Will report more information/patches once I got some findings. Thanks in advance! Jun 16 16:44:09 spirit kernel: Acquiring lockmgr lock "ufs" with the following non-sleepable locks held: Jun 16 16:44:09 spirit kernel: exclusive sleep mutex kqueue r =3D 0 (0xc1b60a00) locked @ /usr/src/sys/kern/kern_event.c:1524 Jun 16 16:44:09 spirit kernel: exclusive sleep mutex vnode pollinfo r =3D 0 (0xc2074000) locked @ /usr/src/sys/kern/kern_event.c:1512 Jun 16 16:44:09 spirit kernel: KDB: stack backtrace: Jun 16 16:44:09 spirit kernel: kdb_backtrace(2,3001,c1a8e29c,c17fdaf0,de75aa08) at kdb_backtrace+0x29 Jun 16 16:44:09 spirit kernel: witness_warn(5,c06df974,c067daa2,c06867e6) at witness_warn+0x18e Jun 16 16:44:09 spirit kernel: lockmgr(c1a8e278,3001,c1a8e29c,c17fdaf0,de75aa34) at lockmgr+0x8d Jun 16 16:44:09 spirit kernel: vop_stdlock(de75aa78,c06c8be0,de75aa78,de75aa44,c05ee068) at vop_stdlock +0x1e Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c92e0,de75aa78,de75aa58,c0653697,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: ffs_lock(de75aa78,1001,c1a8e220,de75aa94,c0576628) at ffs_lock+0x10 Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c8be0,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: vn_lock(c1a8e220,1001,c17fdaf0) at vn_lock+0xa8 Jun 16 16:44:09 spirit kernel: filt_vfsread(c1ae4c7c,6) at filt_vfsread +0x3a Jun 16 16:44:09 spirit kernel: knote(c2074030,6,0) at knote+0x90 Jun 16 16:44:09 spirit kernel: VOP_WRITE_APV(c06c8be0,de75ac40) at VOP_WRITE_APV+0x18c Jun 16 16:44:09 spirit kernel: vn_write(c17c3360,c1e50580,c157bd80,0,c17fdaf0) at vn_write+0x1ea Jun 16 16:44:09 spirit kernel: kern_writev(c17fdaf0,9,c1e50580,c1e50580,0) at kern_writev+0x8e Jun 16 16:44:09 spirit kernel: writev(c17fdaf0,de75ad04,3,43,246) at writev+0x30 Jun 16 16:44:09 spirit kernel: syscall(bfbf003b,bfbf003b,bfbf003b,8056cdb,bfbfd5d0) at syscall+0x22f Jun 16 16:44:09 spirit kernel: Xint0x80_syscall() at Xint0x80_syscall +0x1f Jun 16 16:44:09 spirit kernel: --- syscall (121, FreeBSD ELF32, writev), eip =3D 0x280c8d4b, esp =3D 0xbfbfceec, ebp =3D 0xbfbfd5f8 --- Jun 16 16:44:09 spirit kernel: Acquiring lockmgr lock "ufs" with the following non-sleepable locks held: Jun 16 16:44:09 spirit kernel: exclusive sleep mutex kqueue r =3D 0 (0xc1b60a00) locked @ /usr/src/sys/kern/kern_event.c:1524 Jun 16 16:44:09 spirit kernel: exclusive sleep mutex vnode pollinfo r =3D 0 (0xc2074000) locked @ /usr/src/sys/kern/kern_event.c:1512 Jun 16 16:44:09 spirit kernel: KDB: stack backtrace: Jun 16 16:44:09 spirit kernel: kdb_backtrace(2,3001,c1a8e29c,c17fdaf0,de75aa08) at kdb_backtrace+0x29 Jun 16 16:44:09 spirit kernel: witness_warn(5,c06df974,c067daa2,c06867e6) at witness_warn+0x18e Jun 16 16:44:09 spirit kernel: lockmgr(c1a8e278,3001,c1a8e29c,c17fdaf0,de75aa34) at lockmgr+0x8d Jun 16 16:44:09 spirit kernel: vop_stdlock(de75aa78,c06c8be0,de75aa78,de75aa44,c05ee068) at vop_stdlock +0x1e Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c92e0,de75aa78,de75aa58,c0653697,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: ffs_lock(de75aa78,1001,c1a8e220,de75aa94,c0576628) at ffs_lock+0x10 Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c8be0,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: vn_lock(c1a8e220,1001,c17fdaf0) at vn_lock+0xa8 Jun 16 16:44:09 spirit kernel: filt_vfsread(c1ae4c7c,6) at filt_vfsread +0x3a Jun 16 16:44:09 spirit kernel: knote(c2074030,6,0) at knote+0x90 Jun 16 16:44:09 spirit kernel: VOP_WRITE_APV(c06c8be0,de75ac40) at VOP_WRITE_APV+0x18c Jun 16 16:44:09 spirit kernel: vn_write(c17c3360,c1e51480,c157bd80,0,c17fdaf0) at vn_write+0x1ea Jun 16 16:44:09 spirit kernel: kern_writev(c17fdaf0,9,c1e51480,c1e51480,0) at kern_writev+0x8e Jun 16 16:44:09 spirit kernel: writev(c17fdaf0,de75ad04,3,45,246) at writev+0x30 Jun 16 16:44:09 spirit kernel: syscall(bfbf003b,bfbf003b,bfbf003b,8056cdb,bfbfd5d0) at syscall+0x22f Jun 16 16:44:09 spirit kernel: Xint0x80_syscall() at Xint0x80_syscall +0x1f Jun 16 16:44:09 spirit kernel: --- syscall (121, FreeBSD ELF32, writev), eip =3D 0x280c8d4b, esp =3D 0xbfbfceec, ebp =3D 0xbfbfd5f8 --- Jun 16 16:44:09 spirit kernel: Acquiring lockmgr lock "ufs" with the following non-sleepable locks held: Jun 16 16:44:09 spirit kernel: exclusive sleep mutex kqueue r =3D 0 (0xc1b60a00) locked @ /usr/src/sys/kern/kern_event.c:1524 Jun 16 16:44:09 spirit kernel: exclusive sleep mutex vnode pollinfo r =3D 0 (0xc2074000) locked @ /usr/src/sys/kern/kern_event.c:1512 Jun 16 16:44:09 spirit kernel: KDB: stack backtrace: Jun 16 16:44:09 spirit kernel: kdb_backtrace(2,3001,c1a8e29c,c17fdaf0,de75aa08) at kdb_backtrace+0x29 Jun 16 16:44:09 spirit kernel: witness_warn(5,c06df974,c067daa2,c06867e6) at witness_warn+0x18e Jun 16 16:44:09 spirit kernel: lockmgr(c1a8e278,3001,c1a8e29c,c17fdaf0,de75aa34) at lockmgr+0x8d Jun 16 16:44:09 spirit kernel: vop_stdlock(de75aa78,c06c8be0,de75aa78,de75aa44,c05ee068) at vop_stdlock +0x1e Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c92e0,de75aa78,de75aa58,c0653697,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: ffs_lock(de75aa78,1001,c1a8e220,de75aa94,c0576628) at ffs_lock+0x10 Jun 16 16:44:09 spirit kernel: VOP_LOCK_APV(c06c8be0,de75aa78) at VOP_LOCK_APV+0x87 Jun 16 16:44:09 spirit kernel: vn_lock(c1a8e220,1001,c17fdaf0) at vn_lock+0xa8 Jun 16 16:44:09 spirit kernel: filt_vfsread(c1ae4c7c,6) at filt_vfsread +0x3a Jun 16 16:44:09 spirit kernel: knote(c2074030,6,0) at knote+0x90 Jun 16 16:44:09 spirit kernel: VOP_WRITE_APV(c06c8be0,de75ac40) at VOP_WRITE_APV+0x18c Jun 16 16:44:09 spirit kernel: vn_write(c17c3360,c1bafe80,c157bd80,0,c17fdaf0) at vn_write+0x1ea Jun 16 16:44:09 spirit kernel: kern_writev(c17fdaf0,9,c1bafe80,c1bafe80,0) at kern_writev+0x8e Jun 16 16:44:09 spirit kernel: writev(c17fdaf0,de75ad04,3,47,246) at writev+0x30 Jun 16 16:44:09 spirit kernel: syscall(bfbf003b,bfbf003b,bfbf003b,8056cdb,bfbfd5d0) at syscall+0x22f Jun 16 16:44:09 spirit kernel: Xint0x80_syscall() at Xint0x80_syscall +0x1f Jun 16 16:44:09 spirit kernel: --- syscall (121, FreeBSD ELF32, writev), eip =3D 0x280c8d4b, esp =3D 0xbfbfceec, ebp =3D 0xbfbfd5f8 --- Cheers, --=20 Xin LI http://www.delphij.net/ --=-Q8RPkZo9v1VhNPn5u4st Content-Type: application/pgp-signature; name=signature.asc Content-Description: This is a digitally signed message part -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.1 (FreeBSD) iD8DBQBCsUCL/cVsHxFZiIoRAiovAJ9T2Drjtn7i73zHz9MyBBAwBCAPHQCfReFp numYkjMaT5OkUidVNmAsvjw= =czZG -----END PGP SIGNATURE----- --=-Q8RPkZo9v1VhNPn5u4st--