From owner-freebsd-hackers@FreeBSD.ORG Wed Apr 7 09:59:34 2010 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 9DA92106566B for ; Wed, 7 Apr 2010 09:59:34 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from mail.zoral.com.ua (mx0.zoral.com.ua [91.193.166.200]) by mx1.freebsd.org (Postfix) with ESMTP id E1DAF8FC15 for ; Wed, 7 Apr 2010 09:59:33 +0000 (UTC) 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 o379xT6q096884 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 7 Apr 2010 12:59:29 +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.4/8.14.4) with ESMTP id o379xSTb012352; Wed, 7 Apr 2010 12:59:28 +0300 (EEST) (envelope-from kostikbel@gmail.com) Received: (from kostik@localhost) by deviant.kiev.zoral.com.ua (8.14.4/8.14.4/Submit) id o379xSef012351; Wed, 7 Apr 2010 12:59:28 +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: Wed, 7 Apr 2010 12:59:28 +0300 From: Kostik Belousov To: Petr Salinger Message-ID: <20100407095928.GG2415@deviant.kiev.zoral.com.ua> References: <20100405185924.GS2415@deviant.kiev.zoral.com.ua> <20100406092429.GV2415@deviant.kiev.zoral.com.ua> <20100406140308.GY2415@deviant.kiev.zoral.com.ua> <20100406140852.GZ2415@deviant.kiev.zoral.com.ua> <20100406144402.GB2415@deviant.kiev.zoral.com.ua> <20100406210321.GE2415@deviant.kiev.zoral.com.ua> Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="uKmZtZ/cAqU8zlON" Content-Disposition: inline In-Reply-To: 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=-3.8 required=5.0 tests=ALL_TRUSTED,AWL,BAYES_00, DNS_FROM_OPENWHOIS autolearn=no version=3.2.5 X-Spam-Checker-Version: SpamAssassin 3.2.5 (2008-06-10) on skuns.kiev.zoral.com.ua Cc: freebsd-hackers@freebsd.org Subject: Re: leak of the vnodes X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 07 Apr 2010 09:59:34 -0000 --uKmZtZ/cAqU8zlON Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Wed, Apr 07, 2010 at 09:00:44AM +0200, Petr Salinger wrote: >=20 >=20 > On Wed, 7 Apr 2010, Kostik Belousov wrote: >=20 > >On Tue, Apr 06, 2010 at 10:01:56PM +0200, Petr Salinger wrote: > >>>Can you try to get a backtrace at the points you have shown me ? > >> > >>All are similar to this, with ptyp5/ptyp6/ptyp7 name changes. > >> > >>a vnode 0xffffff0058978000: tag devfs, type VCHR > >> usecount 1, writecount 1, refcount 2 mountedhere 0xffffff0039cb0c00 > >> flags (VI_DOOMED) > >> lock type devfs: EXCL by thread 0xffffff0039e16760 (pid 31427) > >> dev ptyp5 > >>KDB: stack backtrace: > >>db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > >>vgonel() at vgonel+0x424 > >>vgone() at vgone+0x39 > >>devfs_delete() at devfs_delete+0x1b1 > >>devfs_populate_loop() at devfs_populate_loop+0x228 > >>devfs_populate() at devfs_populate+0x42 > >>devfs_lookup() at devfs_lookup+0x258 > >>VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e > >>lookup() at lookup+0x467 > >>namei() at namei+0x3ea > >>vn_open_cred() at vn_open_cred+0x211 > >>kern_openat() at kern_openat+0x188 > >>syscall() at syscall+0x168 > >>Xfast_syscall() at Xfast_syscall+0xdc > >>--- syscall (5, FreeBSD ELF64, open), rip =3D 0x800622097, rsp =3D > >>0x7fffffffbb88, rbp =3D 0x7fffffffbe30 --- > >>KDB: stack backtrace: > >>db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > >>vgonel() at vgonel+0x39d > >>vgone() at vgone+0x39 > >>devfs_delete() at devfs_delete+0x1b1 > >>devfs_populate_loop() at devfs_populate_loop+0x228 > >>devfs_populate() at devfs_populate+0x42 > >>devfs_lookup() at devfs_lookup+0x258 > >>VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e > >>lookup() at lookup+0x467 > >>namei() at namei+0x3ea > >>vn_open_cred() at vn_open_cred+0x211 > >>kern_openat() at kern_openat+0x188 > >>syscall() at syscall+0x168 > >>Xfast_syscall() at Xfast_syscall+0xdc > >>--- syscall (5, FreeBSD ELF64, open), rip =3D 0x800622097, rsp =3D > >>0x7fffffffbb88, rbp =3D 0x7fffffffbe30 --- > >>a vnode 0xffffff00589b5b40: tag devfs, type VCHR > >> usecount 1, writecount 1, refcount 2 mountedhere 0xffffff0028d75600 > >> flags (VI_DOOMED) > >> lock type devfs: EXCL by thread 0xffffff0028cfb3b0 (pid 4529) > >> dev ptyp6 > >>KDB: stack backtrace: > >>db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > >>vgonel() at vgonel+0x424 > >>vgone() at vgone+0x39 > >>devfs_delete() at devfs_delete+0x1b1 > >>devfs_populate_loop() at devfs_populate_loop+0x228 > >>devfs_populate() at devfs_populate+0x42 > >>devfs_lookup() at devfs_lookup+0x258 > >>VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e > >>lookup() at lookup+0x467 > >>namei() at namei+0x3ea > >>vn_open_cred() at vn_open_cred+0x211 > >>kern_openat() at kern_openat+0x188 > >>syscall() at syscall+0x168 > >>Xfast_syscall() at Xfast_syscall+0xdc > > > >Why do you think that this is the problem ? >=20 > I used the attached diff, with hackish snooping > on allocated/freed memory for vnodes. When the vp pointer have been > logged as active1/active2, it is (much) later shown with > dead_vnodeops in DUMP_VP(). Is there a lot of such /dev/ttyp* vnodes ? This indeed might be suspicious. See below for description of how to check that the vnodes are leaked or not. BTW, the patch is racy, two things may cause the information to be corrupted: 1. Addition to the lbuf[] is not protected, two threads might select the same array element for storing the vnode pointer. 2. Removal from lbuf[] is racy too, since the pointer becomes invalid immediately after uma_zfree(), and can be reused for some other object, in particular, a vnode. Then, the removal from the lbuf[] array might remove active element. >=20 > >One refcount unit is coming from devfs_delete() calling vhold() around > >vgone() to prevent the vnode from disappearing under it. > > > >Second refcount unit comes in pair with use count unit. Use count > >implies refcount, and use count is allocated when vnode is e.g. opened, > >to account for struct file having a reference to struct vnode. > > > >What *might* happen for the device nodes you have shown, is that some > >application has file opened for the node /dev/ttyp*, and then master pty > >device closed. The slave /dev/ttyp* node is destroyed, that you see as > >devfs_populate->devfs_delete() sequence. The vnode will be eventually > >freed when corresponding file is closed. >=20 > >If you can confirm that some process has file opened with the reclaimed > >vnode, then my theory will be confirmed. >=20 > What have to be logged ? Please look at ddb command "show files", implemented in kern/kern_descrip.c, lines 3284-3305 on HEAD. Instead of doing full dump, you can manually inspect the output. Or, you can write some code that would search the suspicious vnodes among the vnodes referenced from the processes opened files. Vnode is probably leaked if use count is > 0 but no process has vnode referenced by struct file. >=20 > >I think there should be something else going on. >=20 > May be both processes share file and memory space (RFMEM). Which "both processes" you are refering to ? Yes, I noted that you use bsd-ish /dev/ttyp*-style pseudoterminals, and I know that glibc/kFreeBSD port uses linuxthreads for threading. --uKmZtZ/cAqU8zlON Content-Type: application/pgp-signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.10 (FreeBSD) iEYEARECAAYFAku8V4AACgkQC3+MBN1Mb4hnSACdEoL0/TbPjd6oxLfJCxxe4zXT cXMAn0Ff2YrqnXO90AMOTK8nJMpMXML3 =wc7E -----END PGP SIGNATURE----- --uKmZtZ/cAqU8zlON--