Re: [PATCH V5 1/3] riscv: Add perf callchain support

2019-08-26 Thread Guo Ren
We need know the values of *regs, eg: regs->sepc, regs->ra, regs->fp,
regs->sp, regs->tp

void perf_callchain_kernel(struct perf_callchain_entry_ctx *entry,
   struct pt_regs *regs)
{
...
 walk_stackframe(&fr, entry);

// May be we could detect error here and print the regs' value
}

On Mon, Aug 26, 2019 at 4:03 PM Greentime Hu  wrote:
>
> Hi Guo,
>
> Guo Ren  於 2019年8月24日 週六 上午8:54寫道:
> >
> > Please check CONFIG_FRAME_POINTER
> >
> > 1 *frame = *((struct stackframe *)frame->fp - 1);
> > This code is origionally from riscv/kernel/stacktrace.c: walk_stackframe
> >
> > In linux/Makefile it'll involve the options for gcc to definitely
> > store ra & prev_fp in fp pointer.
> > ifdef CONFIG_FRAME_POINTER
> > KBUILD_CFLAGS += -fno-omit-frame-pointer -fno-optimize-sibling-calls
> >
> > So --call-graph fp need depends on CONFIG_FRAME_POINTER.
> >
>
> I am pretty sure CONFIG_FRAME_POINTER is Y
> # zcat /proc/config.gz |grep CONFIG_FRAME_POINTER
> CONFIG_FRAME_POINTER=y
>
> This is not going to go wrong every time, the probability of error is
> about one tenth or one quarter. randomly
> There may be some conditions that we have not considered.
>
> I add one more condition to check if it is a valid virtual address and
> it( ./perf record -e cpu-clock --call-graph fp ls) passes 1000 times
> without failure in Unleashed board based on 5.3-rc5.
> Here is my patch. Please have  a look at it. I am not sure if it is a
> good solution.
>
> diff --git a/arch/riscv/kernel/perf_callchain.c
> b/arch/riscv/kernel/perf_callchain.c
> index d75d15c13dc7..4717942435df 100644
> --- a/arch/riscv/kernel/perf_callchain.c
> +++ b/arch/riscv/kernel/perf_callchain.c
> @@ -18,6 +18,8 @@ static int unwind_frame_kernel(struct stackframe *frame)
> return -EPERM;
> if (frame->fp < CONFIG_PAGE_OFFSET)
> return -EPERM;
> +   if (!virt_addr_valid(frame->fp))
> +   return -EPERM;
>
> *frame = *((struct stackframe *)frame->fp - 1);
> if (__kernel_text_address(frame->ra)) {
>
> It could catch cases called in this way.
>
> [ 1381.936586] frame->fp=:00547550
> [ 1382.038542] CPU: 1 PID: 135 Comm: ls Not tainted
> 5.3.0-rc5-3-gb008f6bcd67c-dirty #14
> [ 1382.307440] Call Trace:
> [ 1382.388947] [] walk_stackframe+0x0/0x9a
> [ 1382.568053] [] show_stack+0x2a/0x34
> [ 1382.735960] [] dump_stack+0x62/0x7c
> [ 1382.903863] [] perf_callchain_kernel+0xd8/0x102
> [ 1383.106558] [] get_perf_callchain+0x136/0x1f2
> [ 1383.303128] [] perf_callchain+0x52/0x6e
> [ 1383.482553] [] perf_prepare_sample+0x6e/0x476
> [ 1383.679357] [] perf_event_output_forward+0x1c/0x50
> [ 1383.890633] [] __perf_event_overflow+0x6a/0xa4
> [ 1384.090279] [] perf_swevent_hrtimer+0xba/0x106
> [ 1384.290094] [] __hrtimer_run_queues+0x84/0x108
> [ 1384.489694] [] hrtimer_interrupt+0xca/0x1ce
> [ 1384.680974] [] riscv_timer_interrupt+0x32/0x3a
> [ 1384.880449] [] do_IRQ+0x64/0xbe
> [ 1385.036698] [] ret_from_exception+0x0/0xc
>
> [13915.697989] frame->fp=:f000
> [13915.799937] CPU: 2 PID: 663 Comm: ls Not tainted
> 5.3.0-rc5-3-gb008f6bcd67c-dirty #14
> [13916.068832] Call Trace:
> [13916.150380] [] walk_stackframe+0x0/0x9a
> [13916.329450] [] show_stack+0x2a/0x34
> [13916.497360] [] dump_stack+0x62/0x7c
> [13916.665265] [] perf_callchain_kernel+0xd8/0x102
> [13916.867949] [] get_perf_callchain+0x136/0x1f2
> [13917.064526] [] perf_callchain+0x52/0x6e
> [13917.243950] [] perf_prepare_sample+0x6e/0x476
> [13917.440759] [] perf_event_output_forward+0x1c/0x50
> [13917.652021] [] __perf_event_overflow+0x6a/0xa4
> [13917.851683] [] perf_swevent_hrtimer+0xba/0x106
> [13918.051494] [] __hrtimer_run_queues+0x84/0x108
> [13918.251094] [] hrtimer_interrupt+0xca/0x1ce
> [13918.442379] [] riscv_timer_interrupt+0x32/0x3a
> [13918.641840] [] do_IRQ+0x64/0xbe
> [13918.798082] [] ret_from_exception+0x0/0xc



-- 
Best Regards
 Guo Ren

ML: https://lore.kernel.org/linux-csky/


Re: [PATCH V5 1/3] riscv: Add perf callchain support

2019-08-26 Thread Greentime Hu
Hi Guo,

Guo Ren  於 2019年8月24日 週六 上午8:54寫道:
>
> Please check CONFIG_FRAME_POINTER
>
> 1 *frame = *((struct stackframe *)frame->fp - 1);
> This code is origionally from riscv/kernel/stacktrace.c: walk_stackframe
>
> In linux/Makefile it'll involve the options for gcc to definitely
> store ra & prev_fp in fp pointer.
> ifdef CONFIG_FRAME_POINTER
> KBUILD_CFLAGS += -fno-omit-frame-pointer -fno-optimize-sibling-calls
>
> So --call-graph fp need depends on CONFIG_FRAME_POINTER.
>

I am pretty sure CONFIG_FRAME_POINTER is Y
# zcat /proc/config.gz |grep CONFIG_FRAME_POINTER
CONFIG_FRAME_POINTER=y

This is not going to go wrong every time, the probability of error is
about one tenth or one quarter. randomly
There may be some conditions that we have not considered.

I add one more condition to check if it is a valid virtual address and
it( ./perf record -e cpu-clock --call-graph fp ls) passes 1000 times
without failure in Unleashed board based on 5.3-rc5.
Here is my patch. Please have  a look at it. I am not sure if it is a
good solution.

diff --git a/arch/riscv/kernel/perf_callchain.c
b/arch/riscv/kernel/perf_callchain.c
index d75d15c13dc7..4717942435df 100644
--- a/arch/riscv/kernel/perf_callchain.c
+++ b/arch/riscv/kernel/perf_callchain.c
@@ -18,6 +18,8 @@ static int unwind_frame_kernel(struct stackframe *frame)
return -EPERM;
if (frame->fp < CONFIG_PAGE_OFFSET)
return -EPERM;
+   if (!virt_addr_valid(frame->fp))
+   return -EPERM;

*frame = *((struct stackframe *)frame->fp - 1);
if (__kernel_text_address(frame->ra)) {

It could catch cases called in this way.

[ 1381.936586] frame->fp=:00547550
[ 1382.038542] CPU: 1 PID: 135 Comm: ls Not tainted
5.3.0-rc5-3-gb008f6bcd67c-dirty #14
[ 1382.307440] Call Trace:
[ 1382.388947] [] walk_stackframe+0x0/0x9a
[ 1382.568053] [] show_stack+0x2a/0x34
[ 1382.735960] [] dump_stack+0x62/0x7c
[ 1382.903863] [] perf_callchain_kernel+0xd8/0x102
[ 1383.106558] [] get_perf_callchain+0x136/0x1f2
[ 1383.303128] [] perf_callchain+0x52/0x6e
[ 1383.482553] [] perf_prepare_sample+0x6e/0x476
[ 1383.679357] [] perf_event_output_forward+0x1c/0x50
[ 1383.890633] [] __perf_event_overflow+0x6a/0xa4
[ 1384.090279] [] perf_swevent_hrtimer+0xba/0x106
[ 1384.290094] [] __hrtimer_run_queues+0x84/0x108
[ 1384.489694] [] hrtimer_interrupt+0xca/0x1ce
[ 1384.680974] [] riscv_timer_interrupt+0x32/0x3a
[ 1384.880449] [] do_IRQ+0x64/0xbe
[ 1385.036698] [] ret_from_exception+0x0/0xc

[13915.697989] frame->fp=:f000
[13915.799937] CPU: 2 PID: 663 Comm: ls Not tainted
5.3.0-rc5-3-gb008f6bcd67c-dirty #14
[13916.068832] Call Trace:
[13916.150380] [] walk_stackframe+0x0/0x9a
[13916.329450] [] show_stack+0x2a/0x34
[13916.497360] [] dump_stack+0x62/0x7c
[13916.665265] [] perf_callchain_kernel+0xd8/0x102
[13916.867949] [] get_perf_callchain+0x136/0x1f2
[13917.064526] [] perf_callchain+0x52/0x6e
[13917.243950] [] perf_prepare_sample+0x6e/0x476
[13917.440759] [] perf_event_output_forward+0x1c/0x50
[13917.652021] [] __perf_event_overflow+0x6a/0xa4
[13917.851683] [] perf_swevent_hrtimer+0xba/0x106
[13918.051494] [] __hrtimer_run_queues+0x84/0x108
[13918.251094] [] hrtimer_interrupt+0xca/0x1ce
[13918.442379] [] riscv_timer_interrupt+0x32/0x3a
[13918.641840] [] do_IRQ+0x64/0xbe
[13918.798082] [] ret_from_exception+0x0/0xc


Re: [PATCH V5 1/3] riscv: Add perf callchain support

2019-08-23 Thread Guo Ren
Please check CONFIG_FRAME_POINTER

1 *frame = *((struct stackframe *)frame->fp - 1);
This code is origionally from riscv/kernel/stacktrace.c: walk_stackframe

In linux/Makefile it'll involve the options for gcc to definitely
store ra & prev_fp in fp pointer.
ifdef CONFIG_FRAME_POINTER
KBUILD_CFLAGS += -fno-omit-frame-pointer -fno-optimize-sibling-calls

So --call-graph fp need depends on CONFIG_FRAME_POINTER.

On Fri, Aug 23, 2019 at 4:56 PM Greentime Hu  wrote:
>
> Hi Mao,
>
> Mao Han  於 2019年8月23日 週五 下午2:16寫道:
>
> >
> > This patch add support for perf callchain sampling on riscv platform.
> > The return address of leaf function is retrieved from pt_regs as
> > it is not saved in the outmost frame.
> >
> > Signed-off-by: Mao Han 
> > Cc: Paul Walmsley 
> > Cc: Greentime Hu 
> > Cc: Palmer Dabbelt 
> > Cc: linux-riscv 
> > Cc: Christoph Hellwig 
> > Cc: Guo Ren 
> > ---
> >  arch/riscv/Makefile|   3 +
> >  arch/riscv/kernel/Makefile |   3 +-
> >  arch/riscv/kernel/perf_callchain.c | 115 
> > +
> >  3 files changed, 120 insertions(+), 1 deletion(-)
> >  create mode 100644 arch/riscv/kernel/perf_callchain.c
>
> I just tested "./perf record -e cpu-clock --call-graph fp ls" on
> Unleashed board and I got this failure.
> I take a look at it. It seem failed in here. Do you have any idea?
> It seems fine in Qemu.
>
> 1 *frame = *((struct stackframe *)frame->fp - 1);
> ffe0001a198c: 00863a83 ld s5,8(a2)
> ffe0001a1990: ff093903 ld s2,-16(s2)
>
> ./perf record -e cpu-clock --call-graph fp ls
> [ 9619.423884] hrtimer: interrupt took 733000 ns
> [ 9619.977017] Unable to handle kernel paging request at virtual
> address ff94
> [ 9620.214736] Oops [#1]
> [ 9620.289893] Modules linked in:
> [ 9620.391378] CPU: 0 PID: 264 Comm: ls Not tainted
> 5.3.0-rc5-3-gb008f6bcd67c #4
> [ 9620.640176] sepc: ffe0001a198c ra : ffe0001a199a sp :
> ffe93720
> [ 9620.880366] gp : ffe00097dad8 tp : ffe82e40 t0 : 
> 00046000
> [ 9621.120564] t1 : 0002 t2 : 0007 s0 : 
> ffe93760
> [ 9621.360768] s1 : ffe93788 a0 : 0003 a1 : 
> 
> [ 9621.600991] a2 : ff8c a3 : 1fa0 a4 : 
> 0010
> [ 9621.841181] a5 : 0002 a6 : 0001 a7 : 
> ffe079b34e10
> [ 9622.081400] s2 : ff9c s3 : ffe0 s4 : 
> 1ff8
> [ 9622.321618] s5 : ffe93da0 s6 : ffe00097d540 s7 : 
> ffe07a1517a0
> [ 9622.561811] s8 : 08bf01c7ff60 s9 : ffe000235b2a s10: 
> 00020120
> [ 9622.802015] s11: 0001 t3 : ffe079b34e00 t4 : 
> 0001
> [ 9623.042194] t5 : 0008 t6 : ffe0009208d0
> [ 9623.218785] sstatus: 00020100 sbadaddr: ff94
> scause: 000d
> [ 9623.490850] ---[ end trace 49043f28e856d84d ]---
> [ 9623.644217] Kernel panic - not syncing: Fatal exception in interrupt
> [ 9623.855470] SMP: stopping secondary CPUs
> [ 9623.985955] ---[ end Kernel panic - not syncing: Fatal exception in
> interrupt ]---



-- 
Best Regards
 Guo Ren

ML: https://lore.kernel.org/linux-csky/


Re: [PATCH V5 1/3] riscv: Add perf callchain support

2019-08-23 Thread Greentime Hu
Hi Mao,

Mao Han  於 2019年8月23日 週五 下午2:16寫道:

>
> This patch add support for perf callchain sampling on riscv platform.
> The return address of leaf function is retrieved from pt_regs as
> it is not saved in the outmost frame.
>
> Signed-off-by: Mao Han 
> Cc: Paul Walmsley 
> Cc: Greentime Hu 
> Cc: Palmer Dabbelt 
> Cc: linux-riscv 
> Cc: Christoph Hellwig 
> Cc: Guo Ren 
> ---
>  arch/riscv/Makefile|   3 +
>  arch/riscv/kernel/Makefile |   3 +-
>  arch/riscv/kernel/perf_callchain.c | 115 
> +
>  3 files changed, 120 insertions(+), 1 deletion(-)
>  create mode 100644 arch/riscv/kernel/perf_callchain.c

I just tested "./perf record -e cpu-clock --call-graph fp ls" on
Unleashed board and I got this failure.
I take a look at it. It seem failed in here. Do you have any idea?
It seems fine in Qemu.

1 *frame = *((struct stackframe *)frame->fp - 1);
ffe0001a198c: 00863a83 ld s5,8(a2)
ffe0001a1990: ff093903 ld s2,-16(s2)

./perf record -e cpu-clock --call-graph fp ls
[ 9619.423884] hrtimer: interrupt took 733000 ns
[ 9619.977017] Unable to handle kernel paging request at virtual
address ff94
[ 9620.214736] Oops [#1]
[ 9620.289893] Modules linked in:
[ 9620.391378] CPU: 0 PID: 264 Comm: ls Not tainted
5.3.0-rc5-3-gb008f6bcd67c #4
[ 9620.640176] sepc: ffe0001a198c ra : ffe0001a199a sp :
ffe93720
[ 9620.880366] gp : ffe00097dad8 tp : ffe82e40 t0 : 00046000
[ 9621.120564] t1 : 0002 t2 : 0007 s0 : ffe93760
[ 9621.360768] s1 : ffe93788 a0 : 0003 a1 : 
[ 9621.600991] a2 : ff8c a3 : 1fa0 a4 : 0010
[ 9621.841181] a5 : 0002 a6 : 0001 a7 : ffe079b34e10
[ 9622.081400] s2 : ff9c s3 : ffe0 s4 : 1ff8
[ 9622.321618] s5 : ffe93da0 s6 : ffe00097d540 s7 : ffe07a1517a0
[ 9622.561811] s8 : 08bf01c7ff60 s9 : ffe000235b2a s10: 00020120
[ 9622.802015] s11: 0001 t3 : ffe079b34e00 t4 : 0001
[ 9623.042194] t5 : 0008 t6 : ffe0009208d0
[ 9623.218785] sstatus: 00020100 sbadaddr: ff94
scause: 000d
[ 9623.490850] ---[ end trace 49043f28e856d84d ]---
[ 9623.644217] Kernel panic - not syncing: Fatal exception in interrupt
[ 9623.855470] SMP: stopping secondary CPUs
[ 9623.985955] ---[ end Kernel panic - not syncing: Fatal exception in
interrupt ]---