Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 28 Nov 2017 13:37:55 -0700
From:      Alan Somers <asomers@freebsd.org>
To:        Peter Holm <peter@holm.cc>
Cc:        Mateusz Guzik <mjguzik@gmail.com>, Mateusz Guzik <mjg@freebsd.org>,  "src-committers@freebsd.org" <src-committers@freebsd.org>,  "svn-src-all@freebsd.org" <svn-src-all@freebsd.org>,  "svn-src-head@freebsd.org" <svn-src-head@freebsd.org>
Subject:   Re: svn commit: r326200 - head/sys/kern
Message-ID:  <CAOtMX2hpG44t=djBsO4%2BxfvYuA0TY2%2BTkueZ9UgFJiN=1MGvbw@mail.gmail.com>
In-Reply-To: <20171127064940.GA91390@x2.osted.lan>
References:  <201711252049.vAPKnRaA026691@repo.freebsd.org> <20171126064927.GA68986@x2.osted.lan> <CAGudoHGzi08_Th3DDkyMSWG006akL=fhF08SfZzgE2CBCA1H4Q@mail.gmail.com> <20171127064940.GA91390@x2.osted.lan>

next in thread | previous in thread | raw e-mail | index | archive | help
On Sun, Nov 26, 2017 at 11:49 PM, Peter Holm <peter@holm.cc> wrote:
> On Sun, Nov 26, 2017 at 10:11:21PM +0100, Mateusz Guzik wrote:
>> On Sun, Nov 26, 2017 at 7:49 AM, Peter Holm <peter@holm.cc> wrote:
>>
>> > On Sat, Nov 25, 2017 at 08:49:27PM +0000, Mateusz Guzik wrote:
>> > > Author: mjg
>> > > Date: Sat Nov 25 20:49:27 2017
>> > > New Revision: 326200
>> > > URL: https://svnweb.freebsd.org/changeset/base/326200
>> > >
>> > > Log:
>> > >   Add the missing lockstat check for thread lock.
>> > >
>> > > Modified:
>> > >   head/sys/kern/kern_mutex.c
>> > >
>> > > Modified: head/sys/kern/kern_mutex.c
>> > > ============================================================
>> > ==================
>> > > --- head/sys/kern/kern_mutex.c        Sat Nov 25 20:37:13 2017
>> > (r326199)
>> >
>> > Hi Mateusz,
>> >
>> > Could this be yours?
>> >
>> > spin lock 0xffffffff81ddc100 (turnstile chain) held by 0xfffff80014e57000
>> > (tid 100277) too long
>> > panic: spin lock held too long
>> > cpuid = 20
>> > time = 1511677687
>> > KDB: stack backtrace:
>> > db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame
>> > 0xfffffe104f86ea40
>> > vpanic() at vpanic+0x268/frame 0xfffffe104f86eb10
>> > kproc_shutdown() at kproc_shutdown/frame 0xfffffe104f86eb70
>> > _mtx_lock_spin_failed() at _mtx_lock_spin_failed+0x87/frame
>> > 0xfffffe104f86eba0
>> > _mtx_lock_spin_cookie() at _mtx_lock_spin_cookie+0x4ba/frame
>> > 0xfffffe104f86ed10
>> > __mtx_lock_spin_flags() at __mtx_lock_spin_flags+0x21f/frame
>> > 0xfffffe104f86edb0
>> > turnstile_trywait() at turnstile_trywait+0x32/frame 0xfffffe104f86edd0
>> > __rw_rlock_hard() at __rw_rlock_hard+0x118/frame 0xfffffe104f86ee60
>> > __rw_rlock_int() at __rw_rlock_int+0xd5/frame 0xfffffe104f86ee90
>> > getblk() at getblk+0xdb/frame 0xfffffe104f86ef40
>> > breadn_flags() at breadn_flags+0x6e/frame 0xfffffe104f86eff0
>> > ffs_getcg() at ffs_getcg+0x20d/frame 0xfffffe104f86f0d0
>> > ffs_nodealloccg() at ffs_nodealloccg+0xd0/frame 0xfffffe104f86f210
>> > ffs_hashalloc() at ffs_hashalloc+0xb7/frame 0xfffffe104f86f290
>> > ffs_valloc() at ffs_valloc+0x1c1/frame 0xfffffe104f86f390
>> > ufs_makeinode() at ufs_makeinode+0xba/frame 0xfffffe104f86f520
>> > ufs_create() at ufs_create+0x34/frame 0xfffffe104f86f540
>> > VOP_CREATE_APV() at VOP_CREATE_APV+0x241/frame 0xfffffe104f86f5c0
>> > VOP_CREATE() at VOP_CREATE+0x59/frame 0xfffffe104f86f620
>> > vn_open_cred() at vn_open_cred+0x311/frame 0xfffffe104f86f770
>> > vn_open() at vn_open+0x4c/frame 0xfffffe104f86f7b0
>> > kern_openat() at kern_openat+0x212/frame 0xfffffe104f86f920
>> > syscallenter() at syscallenter+0x4e4/frame 0xfffffe104f86f9f0
>> > amd64_syscall() at amd64_syscall+0x4d/frame 0xfffffe104f86fab0
>> >
>> > https://people.freebsd.org/~pho/stress/log/mateusz004.txt
>> >
>> > - Peter
>> >
>>
>> Fixed in r326237.
>>
>
> Yes, that fixed the issue reported.
> After some more tests I got this one:
>
> 20171127 01:19:57 all (31/561): mkfifo2c.sh
> spin lock 0xffffffff81edace0 (smp rendezvous) held by 0xfffff80d2ae31000 (tid 100529) too long
> panic: spin lock held too long
> cpuid = 14
> time = 1511742163
> KDB: stack backtrace:
> db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe105096c0b0
> vpanic() at vpanic+0x19c/frame 0xfffffe105096c130
> panic() at panic+0x43/frame 0xfffffe105096c190
> _mtx_lock_spin_cookie() at _mtx_lock_spin_cookie+0x352/frame 0xfffffe105096c200
> __mtx_lock_spin_flags() at __mtx_lock_spin_flags+0xd8/frame 0xfffffe105096c240
> smp_targeted_tlb_shootdown() at smp_targeted_tlb_shootdown+0xd7/frame 0xfffffe105096c2c0
> smp_masked_invlpg_range() at smp_masked_invlpg_range+0x50/frame 0xfffffe105096c2f0
> pmap_invalidate_range() at pmap_invalidate_range+0x1f4/frame 0xfffffe105096c340
> allocbuf() at allocbuf+0x107/frame 0xfffffe105096c3b0
> brelse() at brelse+0x219/frame 0xfffffe105096c400
> trunc_dependencies() at trunc_dependencies+0x745/frame 0xfffffe105096c4a0
> softdep_setup_freeblocks() at softdep_setup_freeblocks+0x7b4/frame 0xfffffe105096c510
> ffs_truncate() at ffs_truncate+0x6b8/frame 0xfffffe105096c700
> ufs_inactive() at ufs_inactive+0x1cb/frame 0xfffffe105096c740
> VOP_INACTIVE_APV() at VOP_INACTIVE_APV+0xfd/frame 0xfffffe105096c770
> vinactive() at vinactive+0xe3/frame 0xfffffe105096c7c0
> vputx() at vputx+0x31e/frame 0xfffffe105096c820
> kern_rmdirat() at kern_rmdirat+0x1c9/frame 0xfffffe105096c980
> amd64_syscall() at amd64_syscall+0x7ab/frame 0xfffffe105096cab0
>
> Not so much more info here, I'm afraid:
> https://people.freebsd.org/~pho/stress/log/mateusz005.txt
>
> --
> Peter

I'm seeing a similar panic, at r326314:

panic: spin lock held too long
cpuid = 3
time = 1511900768
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe0b58bcef00
vpanic() at vpanic+0x19c/frame 0xfffffe0b58bcef80
panic() at panic+0x43/frame 0xfffffe0b58bcefe0
_mtx_lock_spin_cookie() at _mtx_lock_spin_cookie+0x352/frame 0xfffffe0b58bcf050
__mtx_lock_spin_flags() at __mtx_lock_spin_flags+0xd8/frame 0xfffffe0b58bcf090
smp_targeted_tlb_shootdown() at smp_targeted_tlb_shootdown+0xd7/frame
0xfffffe0b58bcf110
smp_masked_invlpg_range() at smp_masked_invlpg_range+0x50/frame
0xfffffe0b58bcf140
pmap_invalidate_range() at pmap_invalidate_range+0x1f4/frame 0xfffffe0b58bcf190
vm_thread_stack_dispose() at vm_thread_stack_dispose+0x2f/frame
0xfffffe0b58bcf1e0
thread_free() at thread_free+0x39/frame 0xfffffe0b58bcf200
thread_reap() at thread_reap+0x9e/frame 0xfffffe0b58bcf220
thread_alloc() at thread_alloc+0xf/frame 0xfffffe0b58bcf240
kthread_add() at kthread_add+0x43/frame 0xfffffe0b58bcf2e0
_taskqueue_start_threads() at _taskqueue_start_threads+0xde/frame
0xfffffe0b58bcf370
taskqueue_start_threads() at taskqueue_start_threads+0x3f/frame
0xfffffe0b58bcf3d0
taskq_create_proc() at taskq_create_proc+0x92/frame 0xfffffe0b58bcf400
spa_activate() at spa_activate+0x372/frame 0xfffffe0b58bcf4a0
spa_open_common() at spa_open_common+0xd2/frame 0xfffffe0b58bcf510
spa_get_stats() at spa_get_stats+0x4f/frame 0xfffffe0b58bcf6f0
zfs_ioc_pool_stats() at zfs_ioc_pool_stats+0x25/frame 0xfffffe0b58bcf730
zfsdev_ioctl() at zfsdev_ioctl+0x766/frame 0xfffffe0b58bcf7e0
devfs_ioctl() at devfs_ioctl+0xcb/frame 0xfffffe0b58bcf830
VOP_IOCTL_APV() at VOP_IOCTL_APV+0xd9/frame 0xfffffe0b58bcf860
vn_ioctl() at vn_ioctl+0x124/frame 0xfffffe0b58bcf970
devfs_ioctl_f() at devfs_ioctl_f+0x1f/frame 0xfffffe0b58bcf990
kern_ioctl() at kern_ioctl+0x2c4/frame 0xfffffe0b58bcf9f0
sys_ioctl() at sys_ioctl+0x15c/frame 0xfffffe0b58bcfac0
amd64_syscall() at amd64_syscall+0x79b/frame 0xfffffe0b58bcfbf0
Xfast_syscall() at Xfast_syscall+0xfb/frame 0xfffffe0b58bcfbf0



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAOtMX2hpG44t=djBsO4%2BxfvYuA0TY2%2BTkueZ9UgFJiN=1MGvbw>