[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[Pratyush Anand]

Implement save_stack_trace_regs, so that stacktrace of a kprobe events can be
obtained.

Signed-off-by: Pratyush Anand <panand@redhat.com>
---
V1 to V2: Rebased to latest kernel.

I see following stack trace for kprobe at xhci_irq():

echo stacktrace > /sys/kernel/debug/tracing/trace_options
echo "p xhci_irq" > /sys/kernel/debug/tracing/kprobe_events
echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
more /sys/kernel/debug/tracing/trace

          <idle>-0     [004] d.h.  1356.000496: p_xhci_irq_0:(xhci_irq+0x0/0x9ac)
          <idle>-0     [004] d.h.  1356.000497: <stack trace>
 => xhci_irq
 => __handle_irq_event_percpu
 => handle_irq_event_percpu
 => handle_irq_event
 => handle_fasteoi_irq
 => generic_handle_irq
 => __handle_domain_irq
 => gic_handle_irq
 => el1_irq
 => arch_cpu_idle
 => default_idle_call
 => cpu_startup_entry
 => secondary_start_kernel
 =>
 
 arch/arm64/kernel/stacktrace.c | 18 ++++++++++++++++++
 1 file changed, 18 insertions(+)

diff --git a/arch/arm64/kernel/stacktrace.c b/arch/arm64/kernel/stacktrace.c
index d9751a4769e7..bd6d9d8087f0 100644
--- a/arch/arm64/kernel/stacktrace.c
+++ b/arch/arm64/kernel/stacktrace.c
@@ -152,6 +152,24 @@ static int save_trace(struct stackframe *frame, void *d)
 	return trace->nr_entries >= trace->max_entries;
 }
 
+void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
+{
+	struct stack_trace_data data;
+	struct stackframe frame;
+
+	data.trace = trace;
+	data.skip = trace->skip;
+	data.no_sched_functions = 0;
+
+	frame.fp = regs->regs[29];
+	frame.sp = regs->sp;
+	frame.pc = regs->pc;
+
+	walk_stackframe(current, &frame, save_trace, &data);
+	if (trace->nr_entries < trace->max_entries)
+		trace->entries[trace->nr_entries++] = ULONG_MAX;
+}
+
 void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
 {
 	struct stack_trace_data data;
-- 
2.7.4

[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[David Long]

On 09/01/2016 09:35 AM, Pratyush Anand wrote:
> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can be
> obtained.
>
> Signed-off-by: Pratyush Anand <panand@redhat.com>
> ---
> V1 to V2: Rebased to latest kernel.
>
> I see following stack trace for kprobe at xhci_irq():
>
> echo stacktrace > /sys/kernel/debug/tracing/trace_options
> echo "p xhci_irq" > /sys/kernel/debug/tracing/kprobe_events
> echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
> more /sys/kernel/debug/tracing/trace
>
>            <idle>-0     [004] d.h.  1356.000496: p_xhci_irq_0:(xhci_irq+0x0/0x9ac)
>            <idle>-0     [004] d.h.  1356.000497: <stack trace>
>   => xhci_irq
>   => __handle_irq_event_percpu
>   => handle_irq_event_percpu
>   => handle_irq_event
>   => handle_fasteoi_irq
>   => generic_handle_irq
>   => __handle_domain_irq
>   => gic_handle_irq
>   => el1_irq
>   => arch_cpu_idle
>   => default_idle_call
>   => cpu_startup_entry
>   => secondary_start_kernel
>   =>
>
>   arch/arm64/kernel/stacktrace.c | 18 ++++++++++++++++++
>   1 file changed, 18 insertions(+)
>
> diff --git a/arch/arm64/kernel/stacktrace.c b/arch/arm64/kernel/stacktrace.c
> index d9751a4769e7..bd6d9d8087f0 100644
> --- a/arch/arm64/kernel/stacktrace.c
> +++ b/arch/arm64/kernel/stacktrace.c
> @@ -152,6 +152,24 @@ static int save_trace(struct stackframe *frame, void *d)
>   	return trace->nr_entries >= trace->max_entries;
>   }
>
> +void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
> +{
> +	struct stack_trace_data data;
> +	struct stackframe frame;
> +
> +	data.trace = trace;
> +	data.skip = trace->skip;
> +	data.no_sched_functions = 0;
> +
> +	frame.fp = regs->regs[29];
> +	frame.sp = regs->sp;
> +	frame.pc = regs->pc;

Interesting that arm64 does not define an "lr" field in struct 
stackframe like 32-bit arm does.

> +
> +	walk_stackframe(current, &frame, save_trace, &data);
> +	if (trace->nr_entries < trace->max_entries)
> +		trace->entries[trace->nr_entries++] = ULONG_MAX;
> +}
> +
>   void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
>   {
>   	struct stack_trace_data data;
>

Looks OK to me.  I successfully (if briefly) tested it with v4.8-rc4 on 
hikey.

Thanks,
-dl

[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[James Morse]

Hi Pratyush,

On 01/09/16 14:35, Pratyush Anand wrote:
> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can be
> obtained.

Hmm, kconfig enables 'CONFIG_KPROBE_EVENT' if we select KPROBES and FTRACE, this
calls save_stack_trace_regs(), which we haven't implemented, giving:
[  373.406982] save_stack_trace_regs() not implemented yet.
[  373.413020] ------------[ cut here ]------------
[  373.417601] WARNING: CPU: 1 PID: 0 at ../kernel/stacktrace.c:74 save_stack_tr
ace_regs+0x3c/0x48
[  373.426212] Modules linked in:
[  373.429238]
[  373.430716] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.8.0-rc4-dirty #5128
[  373.437606] Hardware name: ARM Juno development board (r1) (DT)
[  373.443466] task: ffff800975dd1900 task.stack: ffff800975ddc000
[  373.449327] PC is at save_stack_trace_regs+0x3c/0x48
[  373.454242] LR is at save_stack_trace_regs+0x3c/0x48
[  373.459156] pc : [<ffff000008126c64>] lr : [<ffff000008126c64>] pstate: 600003c5
[  373.466476] sp : ffff80097ef52c00

[  373.554836] Call trace:
[  373.641153] [<ffff000008126c64>] save_stack_trace_regs+0x3c/0x48
[  373.647104] [<ffff00000817a0b0>] __ftrace_trace_stack+0x168/0x208
[  373.653138] [<ffff00000817ad40>] trace_buffer_unlock_commit_regs+0x5c/0x7c
[  373.659946] [<ffff00000818d57c>] kprobe_trace_func+0x308/0x3d8
[  373.665721] [<ffff00000818defc>] kprobe_dispatcher+0x58/0x60
[  373.671327] [<ffff0000088d8cfc>] kprobe_breakpoint_handler+0xbc/0x18c
[  373.677705] [<ffff0000080851b8>] brk_handler+0x50/0x90
[  373.682792] [<ffff000008081300>] do_debug_exception+0x50/0xbc


I guess hitting a WARN_ONCE() while using a 'kernel hacking' feature isn't
serious enough to make this a fix.


> diff --git a/arch/arm64/kernel/stacktrace.c b/arch/arm64/kernel/stacktrace.c
> index d9751a4769e7..bd6d9d8087f0 100644
> --- a/arch/arm64/kernel/stacktrace.c
> +++ b/arch/arm64/kernel/stacktrace.c
> @@ -152,6 +152,24 @@ static int save_trace(struct stackframe *frame, void *d)
>  	return trace->nr_entries >= trace->max_entries;
>  }
>  
> +void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
> +{
> +	struct stack_trace_data data;
> +	struct stackframe frame;
> +
> +	data.trace = trace;
> +	data.skip = trace->skip;
> +	data.no_sched_functions = 0;
> +
> +	frame.fp = regs->regs[29];
> +	frame.sp = regs->sp;
> +	frame.pc = regs->pc;

What happens when a kprobe-event runs over a frame the function graph tracer has
meddled with? You need:

#ifdef CONFIG_FUNCTION_GRAPH_TRACER
	frame.graph = current->curr_ret_stack;
#endif

> +
> +	walk_stackframe(current, &frame, save_trace, &data);
> +	if (trace->nr_entries < trace->max_entries)
> +		trace->entries[trace->nr_entries++] = ULONG_MAX;
> +}
> +
>  void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
>  {
>  	struct stack_trace_data data;
> 

Reviewed-by: James Morse <james.morse@arm.com>


Thanks,

James

[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[James Morse]

On 02/09/16 11:50, James Morse wrote:
> Hi Pratyush,
> 
> On 01/09/16 14:35, Pratyush Anand wrote:
>> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can be
>> obtained.
> 
> Hmm, kconfig enables 'CONFIG_KPROBE_EVENT' if we select KPROBES and FTRACE, this
> calls save_stack_trace_regs(), which we haven't implemented, giving:
> [  373.406982] save_stack_trace_regs() not implemented yet.
> [  373.413020] ------------[ cut here ]------------
> [  373.417601] WARNING: CPU: 1 PID: 0 at ../kernel/stacktrace.c:74 save_stack_tr
> ace_regs+0x3c/0x48
> [  373.426212] Modules linked in:
> [  373.429238]
> [  373.430716] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.8.0-rc4-dirty #5128
> [  373.437606] Hardware name: ARM Juno development board (r1) (DT)
> [  373.443466] task: ffff800975dd1900 task.stack: ffff800975ddc000
> [  373.449327] PC is at save_stack_trace_regs+0x3c/0x48
> [  373.454242] LR is at save_stack_trace_regs+0x3c/0x48
> [  373.459156] pc : [<ffff000008126c64>] lr : [<ffff000008126c64>] pstate: 600003c5
> [  373.466476] sp : ffff80097ef52c00
> 
> [  373.554836] Call trace:
> [  373.641153] [<ffff000008126c64>] save_stack_trace_regs+0x3c/0x48
> [  373.647104] [<ffff00000817a0b0>] __ftrace_trace_stack+0x168/0x208
> [  373.653138] [<ffff00000817ad40>] trace_buffer_unlock_commit_regs+0x5c/0x7c
> [  373.659946] [<ffff00000818d57c>] kprobe_trace_func+0x308/0x3d8
> [  373.665721] [<ffff00000818defc>] kprobe_dispatcher+0x58/0x60
> [  373.671327] [<ffff0000088d8cfc>] kprobe_breakpoint_handler+0xbc/0x18c
> [  373.677705] [<ffff0000080851b8>] brk_handler+0x50/0x90
> [  373.682792] [<ffff000008081300>] do_debug_exception+0x50/0xbc
> 
> 
> I guess hitting a WARN_ONCE() while using a 'kernel hacking' feature isn't
> serious enough to make this a fix.
> 

I wasn't clear enough with the above: this patch is fixing this WARN_ON(), it
may be worth mentioning that in the commit message...



Thanks,

James

[PATCH V2] arm64:ftrace: add save_stack_trace_regs()

[Will Deacon]

On Fri, Sep 02, 2016 at 11:56:39AM +0100, James Morse wrote:
> On 02/09/16 11:50, James Morse wrote:
> > Hi Pratyush,
> > 
> > On 01/09/16 14:35, Pratyush Anand wrote:
> >> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can be
> >> obtained.
> > 
> > Hmm, kconfig enables 'CONFIG_KPROBE_EVENT' if we select KPROBES and FTRACE, this
> > calls save_stack_trace_regs(), which we haven't implemented, giving:
> > [  373.406982] save_stack_trace_regs() not implemented yet.
> > [  373.413020] ------------[ cut here ]------------
> > [  373.417601] WARNING: CPU: 1 PID: 0 at ../kernel/stacktrace.c:74 save_stack_tr
> > ace_regs+0x3c/0x48
> > [  373.426212] Modules linked in:
> > [  373.429238]
> > [  373.430716] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.8.0-rc4-dirty #5128
> > [  373.437606] Hardware name: ARM Juno development board (r1) (DT)
> > [  373.443466] task: ffff800975dd1900 task.stack: ffff800975ddc000
> > [  373.449327] PC is at save_stack_trace_regs+0x3c/0x48
> > [  373.454242] LR is at save_stack_trace_regs+0x3c/0x48
> > [  373.459156] pc : [<ffff000008126c64>] lr : [<ffff000008126c64>] pstate: 600003c5
> > [  373.466476] sp : ffff80097ef52c00
> > 
> > [  373.554836] Call trace:
> > [  373.641153] [<ffff000008126c64>] save_stack_trace_regs+0x3c/0x48
> > [  373.647104] [<ffff00000817a0b0>] __ftrace_trace_stack+0x168/0x208
> > [  373.653138] [<ffff00000817ad40>] trace_buffer_unlock_commit_regs+0x5c/0x7c
> > [  373.659946] [<ffff00000818d57c>] kprobe_trace_func+0x308/0x3d8
> > [  373.665721] [<ffff00000818defc>] kprobe_dispatcher+0x58/0x60
> > [  373.671327] [<ffff0000088d8cfc>] kprobe_breakpoint_handler+0xbc/0x18c
> > [  373.677705] [<ffff0000080851b8>] brk_handler+0x50/0x90
> > [  373.682792] [<ffff000008081300>] do_debug_exception+0x50/0xbc
> > 
> > 
> > I guess hitting a WARN_ONCE() while using a 'kernel hacking' feature isn't
> > serious enough to make this a fix.
> > 
> 
> I wasn't clear enough with the above: this patch is fixing this WARN_ON(), it
> may be worth mentioning that in the commit message...

Yup, please stick that in the commit message without the timestamps and
the addresses, then repost with the CONFIG_FUNCTION_GRAPH_TRACER fixup,
Dave's tested-by and James' ack.

Will