Date: Tue, 19 Feb 2013 00:07:15 -0800 From: Alfred Perlstein <alfred@ixsystems.com> To: Konstantin Belousov <kostikbel@gmail.com> Cc: Xin Li <delphij@delphij.net>, fs@freebsd.org Subject: Re: Advisory lock crashes. Message-ID: <512332B3.10400@ixsystems.com> In-Reply-To: <20130219073256.GV2598@kib.kiev.ua> References: <512324F2.4060707@ixsystems.com> <20130219073256.GV2598@kib.kiev.ua>
next in thread | previous in thread | raw e-mail | index | archive | help
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
of this file with the exception of a cosmetic diff for MALLOC defines).
> What is the filesystem owning the file which was advlocked ?
I'm pretty sure that is going to be ZFS.
> Show the line number for lf_advlockasync+0x5d7.
> (kgdb) list *(lf_advlockasync+0x5d7)
> 0xffffffff80604fc7 is in lf_advlockasync (sx.h:152).
> 147 {
> 148 uintptr_t tid = (uintptr_t)td;
> 149 int error = 0;
> 150
> 151 if (!atomic_cmpset_acq_ptr(&sx->sx_lock,
> SX_LOCK_UNLOCKED, tid))
> 152 error = _sx_xlock_hard(sx, tid, opts, file, line);
> 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=16
5D7
1495
(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
> 0xffffffff806246d0 <_sx_xunlock_hard>
> 0xffffffff80604f80 <lf_advlockasync+1424>: jmpq
> 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
> 0xffffffff80603b90 <lf_clearremotesys>
> 0xffffffff80604f94 <lf_advlockasync+1444>: jmpq
> 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
> 0xffffffff8060a1f0 <_mtx_lock_sleep>
> 0xffffffff80604faf <lf_advlockasync+1471>: jmpq
> 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
> 0xffffffff80624210 <_sx_xlock_hard>
> 0xffffffff80604fc7 <lf_advlockasync+1495>: jmpq
> 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
> 0xffffffff8060a040 <_mtx_unlock_sleep>
> 0xffffffff80604fde <lf_advlockasync+1518>: jmpq
> 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
> %rbx,0xe0(%r13)
>
> No, I never saw nothing similar in last 3 years.
Yes, I'd suspect we'd all see more things here. We're very much capable
of adding instrumentation to the OS/kernel to help track this down if
you have ideas.
-Alfred
>> 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 = 0x8011651fc, rsp = 0x7fffffbfdd58, rbp = 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:514).
>> 509 x = sx->sx_lock;
>> 510 if ((sx->lock_object.lo_flags & SX_NOADAPTIVE)
>> == 0) {
>> 511 if ((x & SX_LOCK_SHARED) == 0) {
>> 512 x = SX_OWNER(x);
>> 513 owner = (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 image.
>>
>> 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
>
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?512332B3.10400>