Re: [PATCH] arm64: ftrace: use HAVE_FUNCTION_GRAPH_RET_ADDR_PTR
From: Mark Rutland <mark.rutland@arm.com>
Date: 2021-10-28 13:47:27
Hi Will, Looks like there are a bunch of things that warrant a v2, so I'll go prepare that. It also seems there are some latent issue hit by the ftrace selftests, which I'm taking a look at now. On Thu, Oct 28, 2021 at 09:52:25AM +0100, Will Deacon wrote:
On Wed, Oct 27, 2021 at 02:25:28PM +0100, Mark Rutland wrote:quoted
When CONFIG_FUNCTION_GRAPH_TRACER is selected, and the function graph:Weird ':' on the end of "graph"
Whoops; I'll go fix that with the other typos. [...]
quoted
The underlying problem is that ftrace_graph_get_ret_stack() takes an index offset from the most recent entry added to the fgraph return stack. We start an unwind at offset 0, and increment the offset each time we encounter a rewritten return address (i.e. when we see `return_to_handler`). This is broken in two cases: 1) Between creating a pt_regs and starting the unwind, function calls may place entries on the stack, leaving an abitrary offset which we can only determine by performing a full unwind from the caller of the unwind code (and relying on none of the unwind code being instrumented). While this initial unwind is open-coded in dump_backtrace(), this is not performed for other unwinders such as perf_callchain_kernel().What is the user-visible impact of this?
Kernel callchains reported by perf may contain erroneous entries. Case 2 means that dump_backtrace() may report entries in the wrong location in some cases. I'll see if I can get a clear example to put in the commit message, and I'll explicitly mention those cases. [...]
quoted
This doesn't fix the issue of skipping a live LR at an exception boundary, which is a more general problem and requires more substantial rework. Note that were we to consume the LR in all cases this would inwould in?quoted
warnings where the interrupted context's LR contains `return_to_handler`, but the FP has been altered, e.g. | func: | <--- ftrace entry ---> // logs FP & LR, rewrites FP | STP FP, LR, [SP, #-16]! | MOV FP, SP | <--- INTERRUPT ---> ... as ftrace_graph_get_ret_stack() fill not find a matching entry, triggering the WARN_ON_ONCE() in unwind_frame().Did you run the ftrace selftests with this? If not, please can you do it?
I had not; I'd done a bunch of ad-hoc testing to deliberately trigger the
failing cases with a magic-sysrq backtrace (with that unwinder patched to start
from the regs).
I had a go with the selftests and there are some latent issues which show up on
a pristine v5.15-rc4 (or v5.15-rc7), using defconfig + the ftrace selftest
config fragment, including an OOM that could be a memory leak.
I see the following warning:
| [15] Generic dynamic event - check if duplicate events are caught
| ------------[ cut here ]------------
| WARNING: CPU: 24 PID: 912 at kernel/trace/trace_eprobe.c:853 __trace_eprobe_create+0x3ec/0x71c
| Modules linked in:
| CPU: 24 PID: 912 Comm: ftracetest Not tainted 5.15.0-rc4 #1
| Hardware name: linux,dummy-virt (DT)
| pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
| pc : __trace_eprobe_create+0x3ec/0x71c
| lr : __trace_eprobe_create+0x3ec/0x71c
| sp : ffff80001370bb60
| x29: ffff80001370bb60 x28: ffff5ee1944cc299 x27: ffff80001370bc28
| x26: 00000000000001c8 x25: ffffa8db50eece78 x24: 0000000000000010
| x23: ffffa8db50eece48 x22: 00000000ffffffed x21: 0000000000000003
| x20: ffff5ee1944cc008 x19: ffffa8db4fd2e398 x18: 0000000000000000
| x17: 7473753a29656d61 x16: 6e656c6966242830 x15: 2b3d656c69662074
| x14: 616e65706f5f7265 x13: 676e69727473753a x12: 29656d616e656c69
| x11: 0000000000000003 x10: 0101010101010101 x9 : ffffa8db4edda690
| x8 : 7f7f7f7f7f7f7f7f x7 : 726b6b6062727872 x6 : 1a171a17020d001f
| x5 : 1f000d02171a171a x4 : ffff5ee18d2b3900 x3 : ffffa8db50eece48
| x2 : 0000000000000000 x1 : ffff5ee18d2b3900 x0 : ffff5ee18d2b3900
| Call trace:
| __trace_eprobe_create+0x3ec/0x71c
| trace_probe_create+0x90/0xb0
| eprobe_dyn_event_create+0x1c/0x30
| create_dyn_event+0x74/0x114
| trace_parse_run_command+0x104/0x7d0
| dyn_event_write+0x1c/0x30
| vfs_write+0xfc/0x290
| ksys_write+0x74/0x100
| __arm64_sys_write+0x28/0x3c
| invoke_syscall+0x50/0x120
| el0_svc_common.constprop.0+0x104/0x124
| do_el0_svc+0x34/0x9c
| el0_svc+0x2c/0x90
| el0t_64_sync_handler+0xa8/0x12c
| el0t_64_sync+0x1a0/0x1a4
| ---[ end trace 24f9a9e45b173e0b ]---
| [FAIL]
That seems to be the following in __trace_eprobe_create():
| mutex_lock(&event_mutex);
| event_call = find_and_get_event(sys_name, sys_event);
| ep = alloc_event_probe(group, event, event_call, argc - 2);
| mutex_unlock(&event_mutex);
|
| if (IS_ERR(ep)) {
| ret = PTR_ERR(ep);
| /* This must return -ENOMEM, else there is a bug */
| WARN_ON_ONCE(ret != -ENOMEM);
| ep = NULL;
| goto error;
| }
... but I haven't yet dug into exactly why that's returning an
unexpected error code.
Later the tests hang in:
| [19] event tracing - enable/disable with subsystem level files
... and from trying:
| # ./ftracetest -vvv test.d/event/subsystem-enable.tc
... it seems to hang after the usual reset, on the first part of the
test, with the last output being:
| + . /root/ftrace/test.d/event/subsystem-enable.tc
| ++ echo 'sched:*'
| ++ yield
| ++ ping 127.0.0.1 -c 1
| PING 127.0.0.1 (127.0.0.1): 56 data bytes
| 64 bytes from 127.0.0.1: seq=0 ttl=64 time=2.442 ms
|
| --- 127.0.0.1 ping statistics ---
| 1 packets transmitted, 1 packets received, 0% packet loss
| round-trip min/avg/max = 2.442/2.442/2.442 ms
| +++ cat trace
| +++ grep -v '^#'
| +++ awk '{ print $5 }'
| +++ sort -u
| +++ wc -l
I'll see if I can figure out what's actually blocking, and see if the
remaining tests work.
quoted
Signed-off-by: Mark Rutland <mark.rutland@arm.com> Cc: Catalin Marinas <catalin.marinas@arm.com> Cc: Madhavan T. Venkataraman <redacted> Cc: Mark Brown <broonie@kernel.org> Cc: Will Deacon <will@kernel.org>(Adding rostedt FYI)
I'll add Steve to the Cc list for v2.
quoted
--- arch/arm64/include/asm/ftrace.h | 11 +++++++++++ arch/arm64/include/asm/stacktrace.h | 6 ------ arch/arm64/kernel/ftrace.c | 6 +++--- arch/arm64/kernel/stacktrace.c | 12 +++++------- 4 files changed, 19 insertions(+), 16 deletions(-) I spotted this latent issue when reviewing Madhavan's stack tracing rework: https://lore.kernel.org/r/20211015025847.17694-1-madvenka@linux.microsoft.com (local) This supercedes the initial version I posted as an inline reply in: https://lore.kernel.org/r/20211025164925.GB2001@C02TD0UTHF1T.local (local)Please add a Link: tag referring to this.
Just to check, does that need to be a Link tag, or is it fine to do that inline as: | This supersedes an initial version posted as an inline reply in: | | https://lore.kernel.org/r/20211025164925.GB2001@C02TD0UTHF1T.local (local) ... which is a bit clearer than saying which link to look at when there are multiple. ... and should I drop the v1 link in there too?
quoted
I believe we will need this as a prerequisite for other cleanups in that series. As it fixes an existing bug I'm posting it on its own. Mark.diff --git a/arch/arm64/include/asm/ftrace.h b/arch/arm64/include/asm/ftrace.h index 91fa4baa1a93..c96d47cb8f46 100644 --- a/arch/arm64/include/asm/ftrace.h +++ b/arch/arm64/include/asm/ftrace.h@@ -12,6 +12,17 @@ #define HAVE_FUNCTION_GRAPH_FP_TEST +/* + * HAVE_FUNCTION_GRAPH_RET_ADDR_PTR means that the architecture can provide a + * "return address pointer" which can be used to uniquely identify a return + * address which has been overwritten. + * + * On arm64 we use the address of the caller's frame record, which remains the + * same for the lifetime of the instrumented function, unlike the return + * address in the LR. + */ +#define HAVE_FUNCTION_GRAPH_RET_ADDR_PTR + #ifdef CONFIG_DYNAMIC_FTRACE_WITH_REGS #define ARCH_SUPPORTS_FTRACE_OPS 1 #elsediff --git a/arch/arm64/include/asm/stacktrace.h b/arch/arm64/include/asm/stacktrace.h index 8aebc00c1718..9a319eca5cab 100644 --- a/arch/arm64/include/asm/stacktrace.h +++ b/arch/arm64/include/asm/stacktrace.h@@ -46,9 +46,6 @@ struct stack_info { * @prev_type: The type of stack this frame record was on, or a synthetic * value of STACK_TYPE_UNKNOWN. This is used to detect a * transition from one stack to another. - * - * @graph: When FUNCTION_GRAPH_TRACER is selected, holds the index of a - * replacement lr value in the ftrace graph stack. */ struct stackframe { unsigned long fp;@@ -56,9 +53,6 @@ struct stackframe { DECLARE_BITMAP(stacks_done, __NR_STACK_TYPES); unsigned long prev_fp; enum stack_type prev_type; -#ifdef CONFIG_FUNCTION_GRAPH_TRACER - int graph; -#endif }; extern int unwind_frame(struct task_struct *tsk, struct stackframe *frame);diff --git a/arch/arm64/kernel/ftrace.c b/arch/arm64/kernel/ftrace.c index 7f467bd9db7a..3e5d0ed63eb7 100644 --- a/arch/arm64/kernel/ftrace.c +++ b/arch/arm64/kernel/ftrace.c@@ -249,8 +249,6 @@ int __init ftrace_dyn_arch_init(void) * on the way back to parent. For this purpose, this function is called * in _mcount() or ftrace_caller() to replace return address (*parent) on * the call stack to return_to_handler. - * - * Note that @frame_pointer is used only for sanity check later. */ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent, unsigned long frame_pointer)@@ -268,8 +266,10 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent, */ old = *parent; - if (!function_graph_enter(old, self_addr, frame_pointer, NULL)) + if (!function_graph_enter(old, self_addr, frame_pointer, + (void *)frame_pointer)) { *parent = return_hooker; + } } #ifdef CONFIG_DYNAMIC_FTRACEdiff --git a/arch/arm64/kernel/stacktrace.c b/arch/arm64/kernel/stacktrace.c index 8982a2b78acf..749b680b4999 100644 --- a/arch/arm64/kernel/stacktrace.c +++ b/arch/arm64/kernel/stacktrace.c@@ -38,9 +38,6 @@ void start_backtrace(struct stackframe *frame, unsigned long fp, { frame->fp = fp; frame->pc = pc; -#ifdef CONFIG_FUNCTION_GRAPH_TRACER - frame->graph = 0; -#endif /* * Prime the first unwind.@@ -116,17 +113,18 @@ int notrace unwind_frame(struct task_struct *tsk, struct stackframe *frame) #ifdef CONFIG_FUNCTION_GRAPH_TRACER if (tsk->ret_stack && (ptrauth_strip_insn_pac(frame->pc) == (unsigned long)return_to_handler)) { - struct ftrace_ret_stack *ret_stack; + unsigned long orig_pc; /* * This is a case where function graph tracer has * modified a return address (LR) in a stack frame * to hook a function return. * So replace it to an original value. */ - ret_stack = ftrace_graph_get_ret_stack(tsk, frame->graph++); - if (WARN_ON_ONCE(!ret_stack)) + orig_pc = ftrace_graph_ret_addr(tsk, NULL, frame->pc, + (void *)frame->fp);Should we be using ptrauth_strip_insn_pac(frame->pc) again here? ftrace_graph_ret_addr() appears to repeat the comparison against return_to_handler.
Yes, that'll need the stripped pointer, and I had not tested with PAC.
Given we unconditionally strip the PAC immediately after the
CONFIG_FUNCTION_GRAPH_TRACER, it'd be simpler to pull that up, i.e. as a fixup:
| diff --git a/arch/arm64/kernel/stacktrace.c b/arch/arm64/kernel/stacktrace.c
| index 749b680b4999..13ea4e4a4d27 100644
| --- a/arch/arm64/kernel/stacktrace.c
| +++ b/arch/arm64/kernel/stacktrace.c
| @@ -110,9 +110,11 @@ int notrace unwind_frame(struct task_struct *tsk, struct stackframe *frame)
| frame->prev_fp = fp;
| frame->prev_type = info.type;
|
| + frame->pc = ptrauth_strip_insn_pac(frame->pc);
| +
| #ifdef CONFIG_FUNCTION_GRAPH_TRACER
| if (tsk->ret_stack &&
| - (ptrauth_strip_insn_pac(frame->pc) == (unsigned long)return_to_handler)) {
| + (frame->pc == (unsigned long)return_to_handler)) {
| unsigned long orig_pc;
| /*
| * This is a case where function graph tracer has
| @@ -128,8 +130,6 @@ int notrace unwind_frame(struct task_struct *tsk, struct stackframe *frame)
| }
| #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
|
| - frame->pc = ptrauth_strip_insn_pac(frame->pc);
| -
| return 0;
| }
| NOKPROBE_SYMBOL(unwind_frame);
I'll spin a v2 with that and the commit message cleanups.
quoted
+ if (WARN_ON_ONCE(frame->pc == orig_pc)) return -EINVAL; - frame->pc = ret_stack->ret; + frame->pc = orig_pc; } #endif /* CONFIG_FUNCTION_GRAPH_TRACER */This will conflict (trivially) with the kretprobe stuff in -next but might be worth routing via the tracing tree anyway. Will
_______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel