From owner-freebsd-fs@FreeBSD.ORG Tue Feb 19 08:20:40 2013 Return-Path: Delivered-To: fs@freebsd.org Received: from mx1.freebsd.org (mx1.FreeBSD.org [8.8.178.115]) by hub.freebsd.org (Postfix) with ESMTP id A0A2C30B for ; Tue, 19 Feb 2013 08:20:40 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1]) by mx1.freebsd.org (Postfix) with ESMTP id DAFAD634 for ; Tue, 19 Feb 2013 08:20:39 +0000 (UTC) Received: from tom.home (kostik@localhost [127.0.0.1]) by kib.kiev.ua (8.14.6/8.14.6) with ESMTP id r1J8KQ07054222; Tue, 19 Feb 2013 10:20:26 +0200 (EET) (envelope-from kostikbel@gmail.com) DKIM-Filter: OpenDKIM Filter v2.7.4 kib.kiev.ua r1J8KQ07054222 Received: (from kostik@localhost) by tom.home (8.14.6/8.14.6/Submit) id r1J8KQAP054221; Tue, 19 Feb 2013 10:20:26 +0200 (EET) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com using -f Date: Tue, 19 Feb 2013 10:20:26 +0200 From: Konstantin Belousov To: Alfred Perlstein Subject: Re: Advisory lock crashes. Message-ID: <20130219082026.GY2598@kib.kiev.ua> References: <512324F2.4060707@ixsystems.com> <20130219073256.GV2598@kib.kiev.ua> <512332B3.10400@ixsystems.com> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="DejVYFcqCV4p9T4J" Content-Disposition: inline In-Reply-To: <512332B3.10400@ixsystems.com> User-Agent: Mutt/1.5.21 (2010-09-15) X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no version=3.3.2 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on tom.home Cc: Xin Li , fs@freebsd.org X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 19 Feb 2013 08:20:40 -0000 --DejVYFcqCV4p9T4J Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Tue, Feb 19, 2013 at 12:07:15AM -0800, Alfred Perlstein wrote: > On 2/18/13 11:32 PM, Konstantin Belousov wrote: > > On Mon, Feb 18, 2013 at 11:08:34PM -0800, Alfred Perlstein wrote: > >> Hello Konstantin & Doug, > >> > >> We're getting a few crashes in what looks to be kern_lockf.c: > >> > >> fault address here is 0x360 which appears to mean that the "sx" owner > >> thread is NULL > > What is the version of FreeBSD ? > This is a releng 9.0 system. (note, we have the most up to date version= =20 > of this file with the exception of a cosmetic diff for MALLOC defines). My suspicion is that the issue is not in the kern_lockf.c at all, rather it is a bug in the vnode lifetime management in the filesystem code. If true, the absense of the changes in the kern_lockf.c does not matter, but the changes in ZFS do. AFAIR, there were a lot of fixes in this area for ZFS, done by avg. >=20 > > What is the filesystem owning the file which was advlocked ? > I'm pretty sure that is going to be ZFS. >=20 > > Show the line number for lf_advlockasync+0x5d7. >=20 > > (kgdb) list *(lf_advlockasync+0x5d7) > > 0xffffffff80604fc7 is in lf_advlockasync (sx.h:152). > > 147 { > > 148 uintptr_t tid =3D (uintptr_t)td; > > 149 int error =3D 0; > > 150 > > 151 if (!atomic_cmpset_acq_ptr(&sx->sx_lock,=20 > > SX_LOCK_UNLOCKED, tid)) > > 152 error =3D _sx_xlock_hard(sx, tid, opts, file, l= ine); > > 153 else > > 154 LOCKSTAT_PROFILE_OBTAIN_LOCK_SUCCESS(LS_SX_XLOCK_ACQUIRE, > > 155 sx, 0, 0, file, line); > > 156 > That may not be helpful so I've included this: > /usr/home/alfred # bc > ibase=3D16 > 5D7 > 1495 >=20 > (kgdb) disasse lf_advlockasync > Dump of assembler code for function lf_advlockasync: > 0xffffffff806049f0 : push %rbp > 0xffffffff806049f1 : mov %rdx,%rcx > > 0xffffffff80604f70 : mov -0x80(%rbp),%rdi > > 0xffffffff80604f74 : xor %ecx,%ecx > > 0xffffffff80604f76 : xor %edx,%edx > > 0xffffffff80604f78 : mov %rbx,%rsi > > 0xffffffff80604f7b : callq=20 > > 0xffffffff806246d0 <_sx_xunlock_hard> > > 0xffffffff80604f80 : jmpq=20 > > 0xffffffff80604c53 > > 0xffffffff80604f85 : mov -0x58(%rbp),%rcx > > 0xffffffff80604f89 : xor %r12d,%r12d > > 0xffffffff80604f8c : mov 0x18(%rcx),%edi > > 0xffffffff80604f8f : callq=20 > > 0xffffffff80603b90 > > 0xffffffff80604f94 : jmpq=20 > > 0xffffffff80604c70 > > 0xffffffff80604f99 : lea 0xc8(%r13),%rdi > > 0xffffffff80604fa0 : xor %r8d,%r8d > > 0xffffffff80604fa3 : xor %ecx,%ecx > > 0xffffffff80604fa5 : xor %edx,%edx > > 0xffffffff80604fa7 : mov %rbx,%rsi > > 0xffffffff80604faa : callq=20 > > 0xffffffff8060a1f0 <_mtx_lock_sleep> > > 0xffffffff80604faf : jmpq=20 > > 0xffffffff80604f2e > > 0xffffffff80604fb4 : mov -0x80(%rbp),%rdi > > 0xffffffff80604fb8 : xor %r8d,%r8d > > 0xffffffff80604fbb : xor %ecx,%ecx > > 0xffffffff80604fbd : xor %edx,%edx > > 0xffffffff80604fbf : mov %rbx,%rsi > > 0xffffffff80604fc2 : callq=20 > > 0xffffffff80624210 <_sx_xlock_hard> > > 0xffffffff80604fc7 : jmpq=20 > > 0xffffffff80604f15 > > 0xffffffff80604fcc : lea 0xc8(%r13),%rdi > > 0xffffffff80604fd3 : xor %ecx,%ecx > > 0xffffffff80604fd5 : xor %edx,%edx > > 0xffffffff80604fd7 : xor %esi,%esi > > 0xffffffff80604fd9 : callq=20 > > 0xffffffff8060a040 <_mtx_unlock_sleep> > > 0xffffffff80604fde : jmpq=20 > > 0xffffffff80604f5c > > 0xffffffff80604fe3 : mov %r15,(%rcx) > > 0xffffffff80604fe6 : mov %r15,%r14 > > 0xffffffff80604fe9 : mov %gs:0x0,%rax > > 0xffffffff80604ff2 : lock cmpxchg=20 > > %rbx,0xe0(%r13) This is not helpful too, you demonstrated the inlined part of the sx_lock(). I need to understand which sx caused the issue, state->ls_lock (and then it is related to the vnode life), or lf_lock_states_lock. Either the logic of the assembler should be analyzed to decipher which lock is it, or try to list more lines around the reported address, to see which sx_xlock() line is there. >=20 >=20 > > > > No, I never saw nothing similar in last 3 years. >=20 > Yes, I'd suspect we'd all see more things here. We're very much capable= =20 > of adding instrumentation to the OS/kernel to help track this down if=20 > you have ideas. INVARIANTS, DIAGNOSTIC, DEBUG_VFS_LOCK. What is needed is the printout of *vp involved in the panic. >=20 > -Alfred >=20 >=20 > >> db> bt > >> Tracing pid 5099 tid 101614 td 0xfffffe005d54e8c0 > >> _sx_xlock_hard() at _sx_xlock_hard+0xb3 > >> lf_advlockasync() at lf_advlockasync+0x5d7 > >> lf_advlock() at lf_advlock+0x47 > >> vop_stdadvlock() at vop_stdadvlock+0xb3 > >> VOP_ADVLOCK_APV() at VOP_ADVLOCK_APV+0x4a > >> closef() at closef+0x352 > >> kern_close() at kern_close+0x172 > >> amd64_syscall() at amd64_syscall+0x58a > >> Xfast_syscall() at Xfast_syscall+0xf7 > >> --- syscall (6, FreeBSD ELF64, sys_close), rip =3D 0x8011651fc, rsp = =3D 0x7fffffbfdd58, rbp =3D 0x807c3d6c0 --- > >> > >> (kgdb) list *(_sx_xlock_hard+0xb3) > >> 0xffffffff806242c3 is in _sx_xlock_hard > >> (/usr/home/jpaetzel/9.0.6-RELEASE-p1/FreeBSD/src/sys/kern/kern_sx.c:51= 4). > >> 509 x =3D sx->sx_lock; > >> 510 if ((sx->lock_object.lo_flags & SX_NOADAPTIVE) > >> =3D=3D 0) { > >> 511 if ((x & SX_LOCK_SHARED) =3D=3D 0) { > >> 512 x =3D SX_OWNER(x); > >> 513 owner =3D (struct thread *)x; > >> 514 if (TD_IS_RUNNING(owner)) { > >> 515 if > >> (LOCK_LOG_TEST(&sx->lock_object, 0)) > >> 516 CTR3(KTR_LOCK, > >> 517 "%s: spinning on %p > >> held by %p", > >> 518 __func__, sx, owner); > >> > >> > >> Another panic here, which we have less information is attached as an i= mage. > >> > >> We're looking at using some INVARIANTS and WITNESS kernels, but was > >> wondering if y'all had any other suggestions to use please? > >> > >> thank you, > >> -Alfred > > --DejVYFcqCV4p9T4J Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.19 (FreeBSD) iQIcBAEBAgAGBQJRIzXJAAoJEJDCuSvBvK1B7jUQAJQadXQ7Z6dMDtZ/zEnFv0kJ 3r9OGt5zg3vX71XPug/4FqjBjkbGh6d2IeT/how1u/OL37iRjdc7tLKIkjM/VEJp XaMOIvG2k7MtUOPF9jd2g74DdSdB6zA56I0tdVpKbEQ1ea0t3/Zwxhz4ERBPGIVH VBVlblLV5kAlTivC2EeoZfc390sCFRY3TINBuTPYQkuqvHgI2YIoMH9MSdi4Yenr pkJKTaHL0zTYDnybcgMcqdb7GoNjHDiqMamXgdKdgvfKYT7qgMwte0yUHoUGk994 jBgaa1KOYJCCm1cbpzp0FowMs9b6rQ6aWIF0ZOdV7B0IRgPWvxs3lu6okUU29YZF cdvCpRLyJPxx+47zgZrhrlxlsHLj/09SvYkyB12iW7BVgf03jIbpHm7+dBBjGxvV ovHuv5/hwYNAbZuteE0nctQAp8Qdfd0UcknCe1IL6/S4BWFO4ftIw+MIk+NAS/dA ihN4XNBOe9+3DkSPQydJ6efwDiGlo9W+S1r0P/8rbBSuadk5NCG8Y3/7EV4rIIVw NHu7I0MtHpHSPxGkM/NvaawHl9QjqVx+uCitlzEUex5uGJep2ujifEvTB5Fkd+sr pxcYVEOEdoOKVI3LMqAOe7Rz7W//vplxFZs7O3Nakn/xGtecftusXoDwPjFVsZX/ c1clMBwyUukYuiGP3z6U =HbNy -----END PGP SIGNATURE----- --DejVYFcqCV4p9T4J--