Date: Tue, 19 Feb 2013 10:20:26 +0200 From: Konstantin Belousov <kostikbel@gmail.com> To: Alfred Perlstein <alfred@ixsystems.com> Cc: Xin Li <delphij@delphij.net>, fs@freebsd.org Subject: Re: Advisory lock crashes. Message-ID: <20130219082026.GY2598@kib.kiev.ua> In-Reply-To: <512332B3.10400@ixsystems.com> References: <512324F2.4060707@ixsystems.com> <20130219073256.GV2598@kib.kiev.ua> <512332B3.10400@ixsystems.com>
next in thread | previous in thread | raw e-mail | index | archive | help
--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 <lf_advlockasync+0>: push %rbp
> 0xffffffff806049f1 <lf_advlockasync+1>: mov %rdx,%rcx
> > 0xffffffff80604f70 <lf_advlockasync+1408>: mov -0x80(%rbp),%rdi
> > 0xffffffff80604f74 <lf_advlockasync+1412>: xor %ecx,%ecx
> > 0xffffffff80604f76 <lf_advlockasync+1414>: xor %edx,%edx
> > 0xffffffff80604f78 <lf_advlockasync+1416>: mov %rbx,%rsi
> > 0xffffffff80604f7b <lf_advlockasync+1419>: callq=20
> > 0xffffffff806246d0 <_sx_xunlock_hard>
> > 0xffffffff80604f80 <lf_advlockasync+1424>: jmpq=20
> > 0xffffffff80604c53 <lf_advlockasync+611>
> > 0xffffffff80604f85 <lf_advlockasync+1429>: mov -0x58(%rbp),%rcx
> > 0xffffffff80604f89 <lf_advlockasync+1433>: xor %r12d,%r12d
> > 0xffffffff80604f8c <lf_advlockasync+1436>: mov 0x18(%rcx),%edi
> > 0xffffffff80604f8f <lf_advlockasync+1439>: callq=20
> > 0xffffffff80603b90 <lf_clearremotesys>
> > 0xffffffff80604f94 <lf_advlockasync+1444>: jmpq=20
> > 0xffffffff80604c70 <lf_advlockasync+640>
> > 0xffffffff80604f99 <lf_advlockasync+1449>: lea 0xc8(%r13),%rdi
> > 0xffffffff80604fa0 <lf_advlockasync+1456>: xor %r8d,%r8d
> > 0xffffffff80604fa3 <lf_advlockasync+1459>: xor %ecx,%ecx
> > 0xffffffff80604fa5 <lf_advlockasync+1461>: xor %edx,%edx
> > 0xffffffff80604fa7 <lf_advlockasync+1463>: mov %rbx,%rsi
> > 0xffffffff80604faa <lf_advlockasync+1466>: callq=20
> > 0xffffffff8060a1f0 <_mtx_lock_sleep>
> > 0xffffffff80604faf <lf_advlockasync+1471>: jmpq=20
> > 0xffffffff80604f2e <lf_advlockasync+1342>
> > 0xffffffff80604fb4 <lf_advlockasync+1476>: mov -0x80(%rbp),%rdi
> > 0xffffffff80604fb8 <lf_advlockasync+1480>: xor %r8d,%r8d
> > 0xffffffff80604fbb <lf_advlockasync+1483>: xor %ecx,%ecx
> > 0xffffffff80604fbd <lf_advlockasync+1485>: xor %edx,%edx
> > 0xffffffff80604fbf <lf_advlockasync+1487>: mov %rbx,%rsi
> > 0xffffffff80604fc2 <lf_advlockasync+1490>: callq=20
> > 0xffffffff80624210 <_sx_xlock_hard>
> > 0xffffffff80604fc7 <lf_advlockasync+1495>: jmpq=20
> > 0xffffffff80604f15 <lf_advlockasync+1317>
> > 0xffffffff80604fcc <lf_advlockasync+1500>: lea 0xc8(%r13),%rdi
> > 0xffffffff80604fd3 <lf_advlockasync+1507>: xor %ecx,%ecx
> > 0xffffffff80604fd5 <lf_advlockasync+1509>: xor %edx,%edx
> > 0xffffffff80604fd7 <lf_advlockasync+1511>: xor %esi,%esi
> > 0xffffffff80604fd9 <lf_advlockasync+1513>: callq=20
> > 0xffffffff8060a040 <_mtx_unlock_sleep>
> > 0xffffffff80604fde <lf_advlockasync+1518>: jmpq=20
> > 0xffffffff80604f5c <lf_advlockasync+1388>
> > 0xffffffff80604fe3 <lf_advlockasync+1523>: mov %r15,(%rcx)
> > 0xffffffff80604fe6 <lf_advlockasync+1526>: mov %r15,%r14
> > 0xffffffff80604fe9 <lf_advlockasync+1529>: mov %gs:0x0,%rax
> > 0xffffffff80604ff2 <lf_advlockasync+1538>: 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--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20130219082026.GY2598>