[PATCH] s390:ftrace: add save_stack_trace_regs()

[PATCH] s390:ftrace: add save_stack_trace_regs()

[Pratyush Anand]

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

Without this we see following warning:
"save_stack_trace_regs() not implemented yet."
when we execute:
echo stacktrace > /sys/kernel/debug/tracing/trace_options
echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable

Reported-by: Chunyu Hu <chuhu@redhat.com>
Signed-off-by: Pratyush Anand <panand@redhat.com>
---
 arch/s390/kernel/stacktrace.c | 13 +++++++++++++
 1 file changed, 13 insertions(+)

diff --git a/arch/s390/kernel/stacktrace.c b/arch/s390/kernel/stacktrace.c
index 1785cd82253c..586da400f931 100644
--- a/arch/s390/kernel/stacktrace.c
+++ b/arch/s390/kernel/stacktrace.c
@@ -94,3 +94,16 @@ void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
 		trace->entries[trace->nr_entries++] = ULONG_MAX;
 }
 EXPORT_SYMBOL_GPL(save_stack_trace_tsk);
+
+void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
+{
+	unsigned long sp, low, high;
+
+	sp = kernel_stack_pointer(regs);
+	low = (unsigned long) task_stack_page(current);
+	high = (unsigned long) task_pt_regs(current);
+	save_context_stack(trace, sp, low, high, 0);
+	if (trace->nr_entries < trace->max_entries)
+		trace->entries[trace->nr_entries++] = ULONG_MAX;
+}
+EXPORT_SYMBOL_GPL(save_stack_trace_regs);
-- 
2.5.0

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 10:50:28AM +0530, Pratyush Anand wrote:
> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can
> be obtained.
> 
> Without this we see following warning:
> "save_stack_trace_regs() not implemented yet."
> when we execute:
> echo stacktrace > /sys/kernel/debug/tracing/trace_options
> echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
> echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
> 
> Reported-by: Chunyu Hu <chuhu@redhat.com>
> Signed-off-by: Pratyush Anand <panand@redhat.com>
> ---
>  arch/s390/kernel/stacktrace.c | 13 +++++++++++++
>  1 file changed, 13 insertions(+)
> 
> diff --git a/arch/s390/kernel/stacktrace.c b/arch/s390/kernel/stacktrace.c
> index 1785cd82253c..586da400f931 100644
> --- a/arch/s390/kernel/stacktrace.c
> +++ b/arch/s390/kernel/stacktrace.c
> @@ -94,3 +94,16 @@ void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
>  		trace->entries[trace->nr_entries++] = ULONG_MAX;
>  }
>  EXPORT_SYMBOL_GPL(save_stack_trace_tsk);
> +
> +void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
> +{
> +	unsigned long sp, low, high;
> +
> +	sp = kernel_stack_pointer(regs);
> +	low = (unsigned long) task_stack_page(current);
> +	high = (unsigned long) task_pt_regs(current);
> +	save_context_stack(trace, sp, low, high, 0);
> +	if (trace->nr_entries < trace->max_entries)
> +		trace->entries[trace->nr_entries++] = ULONG_MAX;
> +}
> +EXPORT_SYMBOL_GPL(save_stack_trace_regs);

Thanks. I just figured out that the ftrace stack tracer doesn't work at all
anymore on s390.  I will apply your patch after I fixed that. ;)

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 09:54:47AM +0100, Heiko Carstens wrote:
> On Fri, Jan 29, 2016 at 10:50:28AM +0530, Pratyush Anand wrote:
> > Implement save_stack_trace_regs, so that stacktrace of a kprobe events can
> > be obtained.
> > 
> > Without this we see following warning:
> > "save_stack_trace_regs() not implemented yet."
> > when we execute:
> > echo stacktrace > /sys/kernel/debug/tracing/trace_options
> > echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
> > echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
> > 
> > Reported-by: Chunyu Hu <chuhu@redhat.com>
> > Signed-off-by: Pratyush Anand <panand@redhat.com>
> > ---
> 
> Thanks. I just figured out that the ftrace stack tracer doesn't work at all
> anymore on s390.  I will apply your patch after I fixed that. ;)

Surpringly it wasn't one of my own patches which broke the stack tracer on
s390, but one from Steven:

72ac426a5bb0 ("tracing: Clean up stack tracing and fix fentry updates")

Now I only need to figure out why :)

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Steven Rostedt]

On Fri, 29 Jan 2016 13:57:49 +0100
Heiko Carstens <heiko.carstens@de.ibm.com> wrote:

> Surpringly it wasn't one of my own patches which broke the stack tracer on
> s390, but one from Steven:
> 
> 72ac426a5bb0 ("tracing: Clean up stack tracing and fix fentry updates")
> 
> Now I only need to figure out why :)

Try this one?

  7717c6be699975f6733d278b13b7c4295d73caf6
  tracing: Fix stacktrace skip depth in trace_buffer_unlock_commit_regs()

Or at the very least, merge with Linus's latest and see if something
else doesn't fix it.

-- Steve

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 08:59:36AM -0500, Steven Rostedt wrote:
> On Fri, 29 Jan 2016 13:57:49 +0100
> Heiko Carstens <heiko.carstens@de.ibm.com> wrote:
> 
> > Surpringly it wasn't one of my own patches which broke the stack tracer on
> > s390, but one from Steven:
> > 
> > 72ac426a5bb0 ("tracing: Clean up stack tracing and fix fentry updates")
> > 
> > Now I only need to figure out why :)
> 
> Try this one?
> 
>   7717c6be699975f6733d278b13b7c4295d73caf6
>   tracing: Fix stacktrace skip depth in trace_buffer_unlock_commit_regs()
> 
> Or at the very least, merge with Linus's latest and see if something
> else doesn't fix it.

No, that doesn't fix it (current Linus' master):

# uname -a
Linux p2345007 4.5.0-rc1-00032-g26cd83670f2f #26 SMP Fri Jan 29 15:39:47 CET 2016 s390x s390x s390x GNU/Linux

# cat stack_max_size 
4496

# cat stack_trace
        Depth    Size   Location    (0 entries)
        -----    ----   --------

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Steven Rostedt]

On Fri, 29 Jan 2016 15:45:22 +0100
Heiko Carstens <heiko.carstens@de.ibm.com> wrote:

> On Fri, Jan 29, 2016 at 08:59:36AM -0500, Steven Rostedt wrote:
> > On Fri, 29 Jan 2016 13:57:49 +0100
> > Heiko Carstens <heiko.carstens@de.ibm.com> wrote:
> >   
> > > Surpringly it wasn't one of my own patches which broke the stack tracer on
> > > s390, but one from Steven:
> > > 
> > > 72ac426a5bb0 ("tracing: Clean up stack tracing and fix fentry updates")
> > > 
> > > Now I only need to figure out why :)  
> > 
> > Try this one?
> > 
> >   7717c6be699975f6733d278b13b7c4295d73caf6
> >   tracing: Fix stacktrace skip depth in trace_buffer_unlock_commit_regs()
> > 
> > Or at the very least, merge with Linus's latest and see if something
> > else doesn't fix it.  
> 
> No, that doesn't fix it (current Linus' master):
> 
> # uname -a
> Linux p2345007 4.5.0-rc1-00032-g26cd83670f2f #26 SMP Fri Jan 29 15:39:47 CET 2016 s390x s390x s390x GNU/Linux
> 
> # cat stack_max_size 
> 4496
> 
> # cat stack_trace
>         Depth    Size   Location    (0 entries)
>         -----    ----   --------

Ah this stack trace. This is different than what Pratyush Anand is
fixing. This is the stack tracer which uses function tracing. The other
fix is to deal with stack traces from events, specifically kprobes. As
he stated, you test with:

# echo stacktrace > /sys/kernel/debug/tracing/trace_options
# echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
# echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable

But anyway, I'm curious, does this fix the issue for you?

-- Steve

diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
index dda9e6742950..db1c26c385c7 100644
--- a/kernel/trace/trace_stack.c
+++ b/kernel/trace/trace_stack.c
@@ -125,6 +125,9 @@ check_stack(unsigned long ip, unsigned long *stack)
 			break;
 	}
 
+	if (i == stack_trace_max.nr_entries)
+		i = 0;
+
 	/*
 	 * Now find where in the stack these are.
 	 */

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 10:22:41AM -0500, Steven Rostedt wrote:
> > No, that doesn't fix it (current Linus' master):
> > 
> > # uname -a
> > Linux p2345007 4.5.0-rc1-00032-g26cd83670f2f #26 SMP Fri Jan 29 15:39:47 CET 2016 s390x s390x s390x GNU/Linux
> > 
> > # cat stack_max_size 
> > 4496
> > 
> > # cat stack_trace
> >         Depth    Size   Location    (0 entries)
> >         -----    ----   --------
> 
> Ah this stack trace. This is different than what Pratyush Anand is
> fixing. This is the stack tracer which uses function tracing. The other
> fix is to deal with stack traces from events, specifically kprobes. As
> he stated, you test with:
> 
> # echo stacktrace > /sys/kernel/debug/tracing/trace_options
> # echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
> # echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable

Yes, I was aware of that, however the output of the trace file looked like
this:

            bash-1516  [003] d.s.    44.002233: p_kfree_0: (kfree+0x0/0x1a8)
            bash-1516  [003] d.s.    44.002233: <stack trace>
            bash-1540  [000] d...    44.002335: p_kfree_0: (kfree+0x0/0x1a8)
            bash-1540  [000] d...    44.002336: <stack trace>
            bash-1540  [000] d...    44.002338: p_kfree_0: (kfree+0x0/0x1a8)
            bash-1540  [000] d...    44.002338: <stack trace>

Which made me check the stack tracer which did not work anymore.

> But anyway, I'm curious, does this fix the issue for you?
> 
> -- Steve
> 
> diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
> index dda9e6742950..db1c26c385c7 100644
> --- a/kernel/trace/trace_stack.c
> +++ b/kernel/trace/trace_stack.c
> @@ -125,6 +125,9 @@ check_stack(unsigned long ip, unsigned long *stack)
>  			break;
>  	}
> 
> +	if (i == stack_trace_max.nr_entries)
> +		i = 0;
> +

With this patch the trace file now contains:

            bash-1543  [001] d...    31.273255: p_kfree_0: (kfree+0x0/0x1c0)
            bash-1543  [001] d...    31.273256: <stack trace>
 => pipe_release
 => __fput
 => task_work_run
 => do_notify_resume
 => system_call
            bash-1543  [001] d...    31.273400: p_kfree_0: (kfree+0x0/0x1c0)
            bash-1543  [001] d...    31.273400: <stack trace>
 => load_elf_binary
 => search_binary_handler
 => do_execveat_common.isra.14
 => SyS_execve
 => system_call

Which looks much better. The stack tracer also works again!

If the above is supposed to be the final fix, please feel free to add

Tested-by: Heiko Carstens <heiko.carstens@de.ibm.com>

Thanks a lot, Steven!

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Steven Rostedt]

On Fri, 29 Jan 2016 17:49:18 +0100
Heiko Carstens <heiko.carstens@de.ibm.com> wrote:
 
> Which looks much better. The stack tracer also works again!

Great! Although, it shouldn't have affected the stack tracing of kprobe
events :-/

Although the previous commit I showed would.

> 
> If the above is supposed to be the final fix, please feel free to add

I just need to add some comments to it, but the code will be the same.

> 
> Tested-by: Heiko Carstens <heiko.carstens@de.ibm.com>

Thanks!

-- Steve

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 11:56:59AM -0500, Steven Rostedt wrote:
> On Fri, 29 Jan 2016 17:49:18 +0100
> Heiko Carstens <heiko.carstens@de.ibm.com> wrote:
>  
> > Which looks much better. The stack tracer also works again!
> 
> Great! Although, it shouldn't have affected the stack tracing of kprobe
> events :-/

Yes, you're absolutely right. I mixed up my trees (one 4.4 based and one
Linus' master).

> Although the previous commit I showed would.

So, the save_stack_trace_regs() patch from Pratyush does work
out-of-the-box on Linus' master tree and the stack tracer only if your
additional patch is applied.

Sorry for the confusion!

Re: [PATCH] s390:ftrace: add save_stack_trace_regs()

[Heiko Carstens]

On Fri, Jan 29, 2016 at 10:50:28AM +0530, Pratyush Anand wrote:
> Implement save_stack_trace_regs, so that stacktrace of a kprobe events can
> be obtained.
> 
> Without this we see following warning:
> "save_stack_trace_regs() not implemented yet."
> when we execute:
> echo stacktrace > /sys/kernel/debug/tracing/trace_options
> echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events
> echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
> 
> Reported-by: Chunyu Hu <chuhu@redhat.com>
> Signed-off-by: Pratyush Anand <panand@redhat.com>
> ---
>  arch/s390/kernel/stacktrace.c | 13 +++++++++++++
>  1 file changed, 13 insertions(+)
> 
> diff --git a/arch/s390/kernel/stacktrace.c b/arch/s390/kernel/stacktrace.c
> index 1785cd82253c..586da400f931 100644
> --- a/arch/s390/kernel/stacktrace.c
> +++ b/arch/s390/kernel/stacktrace.c
> @@ -94,3 +94,16 @@ void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
>  		trace->entries[trace->nr_entries++] = ULONG_MAX;
>  }
>  EXPORT_SYMBOL_GPL(save_stack_trace_tsk);
> +
> +void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
> +{
> +	unsigned long sp, low, high;
> +
> +	sp = kernel_stack_pointer(regs);
> +	low = (unsigned long) task_stack_page(current);
> +	high = (unsigned long) task_pt_regs(current);
> +	save_context_stack(trace, sp, low, high, 0);
> +	if (trace->nr_entries < trace->max_entries)
> +		trace->entries[trace->nr_entries++] = ULONG_MAX;
> +}
> +EXPORT_SYMBOL_GPL(save_stack_trace_regs);

While playing around with this, I discovered a couple of bugs in our
stacktrace code. However this patch is also not correct, since it will save
a stacktrace only if being called in process context, but not for interrupt
context.
I will fix this within this patch.