lkml.org 
[lkml]   [2016]   [Aug]   [2]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH 05/19] x86/dumpstack: fix function graph tracing stack dump reliability issues
On Tue, Aug 02, 2016 at 07:16:22PM -0400, Steven Rostedt wrote:
> On Tue, 2 Aug 2016 17:13:59 -0500
> Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
>
> > > Then we only need the fp use case when FRAME_POINTER is not set. As
> > > mcount forces FRAME_POINTER, we only need to worry about the fentry
> > > case.
> >
> > Hm, I'm confused. First, I don't see where mcount forces FRAME_POINTER.
>
> Hmm, we should probably force it generally, as gcc itself requires
> mcount to be used with framepointers. -mcount can't be used without
> them.
>
> >
> > Second, I don't see why that even matters. If mcount and frame pointers
> > are enabled, then the 'fp' field of ftrace_ret_stack is needed for the
> > gcc sanity check, right? So we couldn't override 'fp', and the old
> > "stateful index" version of ftrace_graph_ret_addr() would have to be
> > used in the code above for reliable addresses, and we'd still have the
> > same out-of-sync bug.
> >
> > Or am I missing something?
> >
>
> Or I missed something. How did we get out of sync? If we have frame
> pointers, shouldn't the "return_to_handler" be seen as reliable by the
> code (not that we save it as such)? That is, if the frame pointer shows
> that the next function is return_to_handler, then we increment the
> index into ret_stack, otherwise we simply record the return_to_handler
> as a normal "unreliable" function, without any processing of it.
>
> I guess I don't actually understand how the NMI screwed it up, as
> function graph doesn't trace "do_nmi()" itself nor anything before that.
> I'm guessing it really got out of sync because there's a
> "return_to_handler" in the stack that wasn't really called (not a frame
> pointer). The ftrace_graph_ret_addr() will shift the index currently
> regardless if the return_to_handler found is part of a stack frame, or
> just left over in the stack. THAT is why I think it got out of sync.

It's not specific to NMIs. The problem is that dump_trace() is starting
from the frame pointed to by a pt_regs, rather than the current frame.
Instead of starting with the current frame, the first 10 functions on
the stack are skipped by the unwinder, but they're *not* skipped on the
ret_stack. So it starts out out-of-sync.

If it had first initialized the graph index variable to 10 instead of 0
before passing it to ftrace_graph_ret_addr(), it would have worked.

The problem isn't specific to NMIs. It happens anywhere the first few
stack frames are skipped, which is very common. For example:

$ cat /proc/self/stack
[<ffffffff810489a2>] save_stack_trace_tsk+0x22/0x40
[<ffffffff81311a89>] proc_pid_stack+0xb9/0x110
[<ffffffff813127c4>] proc_single_show+0x54/0x80
[<ffffffff812be088>] seq_read+0x108/0x3e0
[<ffffffff812923d7>] __vfs_read+0x37/0x140
[<ffffffff812929d9>] vfs_read+0x99/0x140
[<ffffffff81293f28>] SyS_read+0x58/0xc0
[<ffffffff818af97c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[<ffffffffffffffff>] 0xffffffffffffffff

$ echo function_graph > /sys/kernel/debug/tracing/current_tracer
$ cat /proc/self/stack
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff810394cc>] print_context_stack+0xfc/0x100
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff8103891b>] dump_trace+0x12b/0x350
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff810489a2>] save_stack_trace_tsk+0x22/0x40
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff81311a89>] proc_pid_stack+0xb9/0x110
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff813127c4>] proc_single_show+0x54/0x80
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff812be088>] seq_read+0x108/0x3e0
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff812923d7>] __vfs_read+0x37/0x140
[<ffffffff818b2428>] return_to_handler+0x0/0x27
[<ffffffff812929d9>] vfs_read+0x99/0x140
[<ffffffffffffffff>] 0xffffffffffffffff

In this case, it's offset by two frames. With function graph tracing
enabled, it starts with print_context_stack() instead of
save_stack_trace_tsk(), and it doesn't show the last two frames.

--
Josh

\
 
 \ /
  Last update: 2016-08-03 04:41    [W:0.114 / U:0.164 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site