mirror of https://lore.kernel.org/lkml/
 help / color / mirror / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: LKML <linux-kernel@vger.kernel.org>
Cc: Josh Poimboeuf <jpoimboe@redhat.com>,
	Ingo Molnar <mingo@kernel.org>,
	Thomas Gleixner <tglx@linutronix.de>,
	Andrew Morton <akpm@linux-foundation.org>,
	x86@kernel.org, Linus Torvalds <torvalds@linux-foundation.org>
Subject: [RFC][PATCH][REGRESSION FIX] x86/ftrace: Add ORC annotation to 64 bit ftrace assembly
Date: Fri, 22 Dec 2017 13:18:41 -0500	[thread overview]
Message-ID: <20171222131841.4564c975@gandalf.local.home> (raw)

From: Steven Rostedt (VMware) <rostedt@goodmis.org>

While doing some debugging, I kicked off the stacktrace trigger, to see
what was doing stacktraces in my code (it was causing a lot of noise in
my function traces).

I ran:

  # trace-cmd record -p function -l save_stack_trace -l save_stack_trace:stacktrace

And took a look at the trace, but all I found was this:

trace-cm-1326    0d..2   107.791049: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791077: kernel_stack:         <stack trace>
trace-cm-1326    0...2   107.791084: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791091: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791097: kernel_stack:         <stack trace>
trace-cm-1326    0...2   107.791102: kernel_stack:         <stack trace>
trace-cm-1326    0d..4   107.791109: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791116: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791120: kernel_stack:         <stack trace>
trace-cm-1326    0...2   107.791125: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791133: kernel_stack:         <stack trace>
trace-cm-1326    0d..2   107.791140: kernel_stack:         <stack trace>
trace-cm-1326    0...2   107.791145: kernel_stack:         <stack trace>
trace-cm-1326    0d..4   107.791157: kernel_stack:         <stack trace>
[...]

This was not very useful. I kicked off a bisect to see where it broke,
because it was working fine in 4.14, and this is a new regression in
the 4.15 rc cycle.

The culprit ended up being:

fc72ae40e30 "x86/unwind: Make CONFIG_UNWINDER_ORC=y the default in
kconfig for 64-bit"

As I find this to be a useful option, I don't want to revert it, so I
looked at how to make ftrace work with this new unwinder. I came up
with this solution. I'm not sure it is correct, but now my traces look
like this (and objtool check doesn't complain):


splice-t-1301    0d..1   203.199356: function:             save_stack_trace
splice-t-1301    0d..2   203.199365: kernel_stack:         <stack trace>
=> ___slab_alloc (ffffffff81221c5d)
=> __slab_alloc.isra.81 (ffffffff81221d08)
=> kmem_cache_alloc (ffffffff812227ce)
=> getname_flags (ffffffff8124d49a)
=> SyS_execve (ffffffff812459f2)
=> do_syscall_64 (ffffffff8100394c)
=> return_from_SYSCALL_64 (ffffffff817c2dd8)
splice-t-1301    0d..1   203.199379: function:             save_stack_trace
splice-t-1301    0d..2   203.199382: kernel_stack:         <stack trace>
=> ___slab_alloc (ffffffff81221c5d)
=> __slab_alloc.isra.81 (ffffffff81221d08)
=> kmem_cache_alloc (ffffffff812227ce)
=> create_object (ffffffff81237593)
=> kmem_cache_alloc (ffffffff81222795)
=> getname_flags (ffffffff8124d49a)
=> SyS_execve (ffffffff812459f2)
=> do_syscall_64 (ffffffff8100394c)
=> return_from_SYSCALL_64 (ffffffff817c2dd8)
splice-t-1301    0...1   203.199385: function:             save_stack_trace
splice-t-1301    0...2   203.199387: kernel_stack:         <stack trace>
=> getname_flags (ffffffff8124d49a)
=> SyS_execve (ffffffff812459f2)
=> do_syscall_64 (ffffffff8100394c)
=> return_from_SYSCALL_64 (ffffffff817c2dd8)
splice-t-1301    0d..1   203.199392: function:             save_stack_trace
splice-t-1301    0d..2   203.199395: kernel_stack:         <stack trace>
=> ___slab_alloc (ffffffff81221c5d)
=> __slab_alloc.isra.81 (ffffffff81221d08)
=> kmem_cache_alloc_trace (ffffffff81222568)
=> do_execveat_common.isra.34 (ffffffff81245171)
=> SyS_execve (ffffffff81245a0c)
=> do_syscall_64 (ffffffff8100394c)
=> return_from_SYSCALL_64 (ffffffff817c2dd8)

P.S. the culprit was SLAB_DEBUG that was doing the stack traces

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
diff --git a/arch/x86/kernel/Makefile b/arch/x86/kernel/Makefile
index 81bb565f4497..5d9eb722a04e 100644
--- a/arch/x86/kernel/Makefile
+++ b/arch/x86/kernel/Makefile
@@ -29,7 +29,6 @@ KASAN_SANITIZE_stacktrace.o				:= n
 KASAN_SANITIZE_paravirt.o				:= n
 
 OBJECT_FILES_NON_STANDARD_relocate_kernel_$(BITS).o	:= y
-OBJECT_FILES_NON_STANDARD_ftrace_$(BITS).o		:= y
 OBJECT_FILES_NON_STANDARD_test_nx.o			:= y
 OBJECT_FILES_NON_STANDARD_paravirt_patch_$(BITS).o	:= y
 
diff --git a/arch/x86/kernel/ftrace_64.S b/arch/x86/kernel/ftrace_64.S
index c832291d948a..6ab3308d632a 100644
--- a/arch/x86/kernel/ftrace_64.S
+++ b/arch/x86/kernel/ftrace_64.S
@@ -4,6 +4,7 @@
  */
 
 #include <linux/linkage.h>
+#include <asm/unwind_hints.h>
 #include <asm/ptrace.h>
 #include <asm/ftrace.h>
 #include <asm/export.h>
@@ -148,9 +149,10 @@ EXPORT_SYMBOL(mcount)
 
 ENTRY(function_hook)
 	retq
-END(function_hook)
+ENDPROC(function_hook)
 
 ENTRY(ftrace_caller)
+	UNWIND_HINT_FUNC
 	/* save_mcount_regs fills in first two parameters */
 	save_mcount_regs
 
@@ -165,6 +167,7 @@ GLOBAL(ftrace_call)
 	call ftrace_stub
 
 	restore_mcount_regs
+	UNWIND_HINT_FUNC
 
 	/*
 	 * The copied trampoline must call ftrace_epilogue as it
@@ -187,11 +190,13 @@ WEAK(ftrace_stub)
 END(ftrace_caller)
 
 ENTRY(ftrace_regs_caller)
+	UNWIND_HINT_FUNC
 	/* Save the current flags before any operations that can change them */
 	pushfq
 
 	/* added 8 bytes to save flags */
 	save_mcount_regs 8
+	UNWIND_HINT_REGS
 	/* save_mcount_regs fills in first two parameters */
 
 GLOBAL(ftrace_regs_caller_op_ptr)
@@ -241,6 +246,7 @@ GLOBAL(ftrace_regs_call)
 	movq RBX(%rsp), %rbx
 
 	restore_mcount_regs
+	UNWIND_HINT_FUNC
 
 	/* Restore flags */
 	popfq
@@ -296,6 +302,7 @@ END(function_hook)
 
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
 ENTRY(ftrace_graph_caller)
+	UNWIND_HINT_FUNC
 	/* Saves rbp into %rdx and fills first parameter  */
 	save_mcount_regs
 
@@ -311,11 +318,13 @@ ENTRY(ftrace_graph_caller)
 	call	prepare_ftrace_return
 
 	restore_mcount_regs
+	UNWIND_HINT_FUNC
 
 	retq
 END(ftrace_graph_caller)
 
 GLOBAL(return_to_handler)
+	UNWIND_HINT_EMPTY
 	subq  $24, %rsp
 
 	/* Save the return values */

             reply	other threads:[~2017-12-22 18:18 UTC|newest]

Thread overview: 6+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-12-22 18:18 Steven Rostedt [this message]
2017-12-22 18:30 ` Josh Poimboeuf
2017-12-22 18:38   ` Steven Rostedt
2017-12-23  2:43     ` Josh Poimboeuf
2017-12-23  5:51       ` Steven Rostedt
2018-01-23  4:07       ` [PATCH] x86/ftrace: Fix ORC unwinding from ftrace handlers Josh Poimboeuf

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20171222131841.4564c975@gandalf.local.home \
    --to=rostedt@goodmis.org \
    --cc=akpm@linux-foundation.org \
    --cc=jpoimboe@redhat.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@kernel.org \
    --cc=tglx@linutronix.de \
    --cc=torvalds@linux-foundation.org \
    --cc=x86@kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox

all inboxes | Powered by JetHome®