lkml.org 
[lkml]   [2013]   [Dec]   [10]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: process 'stuck' at exit.
From
Date
On Tue, 2013-12-10 at 10:40 -0800, Linus Torvalds wrote:
> Hmm. Looks like the futex code is somehow stuck in a loop, calling
> get_user_pages_fast().
>
> The futex code itself is apparently so low-overhead that it doesn't
> show up in your 'perf top' report (which is dominated by all the
> expensive debug things that get_user_pages_fast() etc ends up doing),
> but that's the only looping I can see. Perhaps the "goto again" case
> for transparent huge pages in get_futex_key()? Or the
> "retry[_private]" cases in futex_requeue()? Some error condition that
> causes us to retry forever, rather than returning the error code?
>
> Added a few more people to the cc.. Ideas?
>
> Linus
>
>
> On Tue, Dec 10, 2013 at 7:47 AM, Dave Jones <davej@redhat.com> wrote:
> > I woke up to find my fuzzer in a curious state.
> >
> > 1121 pts/5 SN+ 0:00 | \_ ../trinity -q -l off -N 999999 -C 42
> > 1130 pts/5 SN+ 0:01 | \_ ../trinity -q -l off -N 999999 -C 42
> > 1131 pts/5 SN+ 0:17 | \_ ../trinity -q -l off -N 999999 -C 42
> > 10818 ? RNs 21115152:53 | \_ ../trinity -q -l off -N 999999 -C 42
> >
> > (ignore the first 3 pids, they're waiting on 10818, which is the interesting one)
> >
> > It's completed its run of 999999 syscalls, and looking at tmux, it tried to exit.
> >
> > /proc/10818/stack just shows
> >
> > [<ffffffffffffffff>] 0xffffffffffffffff
> >
> > Top reports a core is spinning in the kernel 100%, so I ran perf top -a
> > and saw..
> >
> > 8.63% [kernel] [k] trace_hardirqs_off_caller
> > 7.68% [kernel] [k] __lock_acquire
> > 5.35% [kernel] [k] gup_huge_pmd
> > 5.31% [kernel] [k] put_compound_page
> > 4.93% [kernel] [k] gup_pud_range
> > 4.76% [kernel] [k] trace_hardirqs_on_caller
> > 4.58% [kernel] [k] get_user_pages_fast
> > 4.00% [kernel] [k] debug_smp_processor_id
> > 4.00% [kernel] [k] lock_is_held
> > 3.73% [kernel] [k] lock_acquired
> > 3.67% [kernel] [k] lock_release
> >
> >
> > sysrq-t shows..
> >
> > trinity-child27 R running task 5520 10818 1131 0x00080004
> > 0000000000000000 ffff8801b0ef4170 000000000000032c ffff8801b609e108
> > 0000000000000000 ffff880160d21c30 ffffffff810ad895 ffffffff817587a0
> > ffff8801b0ef4170 ffff8801b609e0a8 ffff8801b609e000 ffff880160d21d50
> > Call Trace:
> > [<ffffffff817587a0>] ? retint_restore_args+0xe/0xe
> > [<ffffffff8132af0e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
> > [<ffffffff8100b184>] ? native_sched_clock+0x24/0x80
> > [<ffffffff8109624f>] ? local_clock+0xf/0x50
> > [<ffffffff810aa27e>] ? put_lock_stats.isra.28+0xe/0x30
> > [<ffffffff8103edd0>] ? gup_pud_range+0x170/0x190
> > [<ffffffff8103f0d5>] ? get_user_pages_fast+0x1a5/0x1c0
> > [<ffffffff810ad1f5>] ? trace_hardirqs_on_caller+0x115/0x1e0
> > [<ffffffff810a8a2f>] ? up_read+0x1f/0x40
> > [<ffffffff8103f0d5>] ? get_user_pages_fast+0x1a5/0x1c0
> > [<ffffffff8115f76c>] ? put_page+0x3c/0x50
> > [<ffffffff810dd525>] ? get_futex_key+0xd5/0x2c0
> > [<ffffffff810df18a>] ? futex_requeue+0xfa/0x9c0
> > [<ffffffff810e019e>] ? do_futex+0xae/0xc80
> > [<ffffffff810aa27e>] ? put_lock_stats.isra.28+0xe/0x30
> > [<ffffffff810aa7de>] ? lock_release_holdtime.part.29+0xee/0x170
> > [<ffffffff8114f16e>] ? context_tracking_user_exit+0x4e/0x190
> > [<ffffffff810ad1f5>] ? trace_hardirqs_on_caller+0x115/0x1e0
> > [<ffffffff810e0de1>] ? SyS_futex+0x71/0x150
> > [<ffffffff81010a45>] ? syscall_trace_enter+0x145/0x2a0
> > [<ffffffff81760be4>] ? tracesys+0xdd/0xe2
> >

Hi Dave,

Can you get us an idea of the arguments trinity is tossing into
SYS_futex?

Op code? Would help to know if this was requeue_pi for example.
Type of memory being used for the uaddr?

I see futex_requeue in the stack, which means the opcode is one of:

FUTEX_REQUEUE
FUTEX_CMP_REQUEUE
FUTEX_CMP_REQUEUE_PI

FUTEX_REQUEUE has a known issue and was replaced with FUTEX_CMP_REQUEUE,
for details, test cases, and an analysis see the historic tree:

commit 9b91d73bde9d68800f9e5c338c0cf9d0fe3bc862
Author: Andrew Morton <akpm@osdl.org>
Date: 2004-05-31

[PATCH] Add FUTEX_CMP_REQUEUE futex op

Specifically:
http://listman.redhat.com/archives/phil-list/2004-May/msg00023.html


Trinity is going to trigger hangs in futexes just by it's very nature,
but I believe you have watchdogs in place to kill such malformed tests
after a timeout?

I'll keep digging.

--
Darren Hart
Intel Open Source Technology Center
Yocto Project - Linux Kernel




\
 
 \ /
  Last update: 2013-12-10 22:21    [W:0.108 / U:1.916 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site