Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1590811 > unrolled thread

ARM64 perf stacktraces on tracepoint events

Started byJoel Fernandes <joel.opensrc@gmail.com>
First post2017-03-02 04:00 +0100
Last post2017-03-03 01:20 +0100
Articles 3 — 3 participants

Back to article view | Back to linux.kernel


Contents

  ARM64 perf stacktraces on tracepoint events Joel Fernandes <joel.opensrc@gmail.com> - 2017-03-02 04:00 +0100
    Re: ARM64 perf stacktraces on tracepoint events Mark Rutland <mark.rutland@arm.com> - 2017-03-02 14:50 +0100
      Re: ARM64 perf stacktraces on tracepoint events Kim Phillips <kim.phillips@arm.com> - 2017-03-03 01:20 +0100

#1590811 — ARM64 perf stacktraces on tracepoint events

FromJoel Fernandes <joel.opensrc@gmail.com>
Date2017-03-02 04:00 +0100
SubjectARM64 perf stacktraces on tracepoint events
Message-ID<tgp8d-44Y-3@gated-at.bofh.it>
Hi,

On 3.18 kernel running on an arm64 device, I tried running:
perf record -a -g -e sched:sched_wakeup

I was expecting something like the output at:
www.brendangregg.com/perf.html

But I don't see stacktraces, could I be missing any patches you could
point me to? I do see stack traces if I do regular perf profiling
(perf record -F 99 -a -g).

Below is the output I get. Thanks for any insight into this.

Regards,
Joel

sailfish:/data # ./perf report
       # Samples: 22  of event 'sched:sched_wakeup'
# Event count (approx.): 410333
#
# Children      Self  Trace output
# ........  ........
.............................................................
#
    61.29%    61.29%  comm=ksoftirqd/0 pid=3 prio=120 success=1 target_cpu=000
            |
            ---0

    33.25%    33.25%  comm=hw pid=12777 prio=120 success=1 target_cpu=002
            |
            ---0

     2.46%     2.46%  comm=kworker/u8:2 pid=12482 prio=120 success=1
target_cpu=002
            |
            ---0

     1.39%     1.39%  comm=migration/2 pid=21 prio=0 success=1 target_cpu=002
            |
            ---0

[toc] | [next] | [standalone]


#1591082

FromMark Rutland <mark.rutland@arm.com>
Date2017-03-02 14:50 +0100
Message-ID<tgzhf-2VJ-1@gated-at.bofh.it>
In reply to#1590811
[Adding James, Takahiro-san, and Will, for stacktracing and arm64 perf]

On Wed, Mar 01, 2017 at 04:42:17PM -0800, Joel Fernandes wrote:
> Hi,
> 
> On 3.18 kernel running on an arm64 device, I tried running:
> perf record -a -g -e sched:sched_wakeup
> 
> I was expecting something like the output at:
> www.brendangregg.com/perf.html
> 
> But I don't see stacktraces, could I be missing any patches you could
> point me to?

I can't spot much obvious, looking at arm64's stacktrace.c and perf_callchain.c
since v3.18. There's commit:

  9702970c7bd3e2d6 (Revert "ARM64: unwind: Fix PC calculation")

... though that was Cc'd stable.

I can't immediately see why that would truncate unwinding, though I'm also not
sure how perf and ftrace interact here, so I may be missing something obvious.

> I do see stack traces if I do regular perf profiling
> (perf record -F 99 -a -g).

> Below is the output I get. Thanks for any insight into this.
> 
> Regards,
> Joel
> 
> sailfish:/data # ./perf report
>        # Samples: 22  of event 'sched:sched_wakeup'
> # Event count (approx.): 410333
> #
> # Children      Self  Trace output
> # ........  ........
> .............................................................
> #
>     61.29%    61.29%  comm=ksoftirqd/0 pid=3 prio=120 success=1 target_cpu=000
>             |
>             ---0
> 
>     33.25%    33.25%  comm=hw pid=12777 prio=120 success=1 target_cpu=002
>             |
>             ---0
> 
>      2.46%     2.46%  comm=kworker/u8:2 pid=12482 prio=120 success=1
> target_cpu=002
>             |
>             ---0
> 
>      1.39%     1.39%  comm=migration/2 pid=21 prio=0 success=1 target_cpu=002
>             |
>             ---0


FWIW, on a recent HEAD (86292b33d4b79ee0), I see reasonable looking backtraces,
e.g.

    77.48%     0.00%  swapper      [kernel.kallsyms]  [k] do_idle
            |
            ---do_idle
               |          
               |--68.84%--call_cpuidle
               |          cpuidle_enter
               |          cpuidle_enter_state
               |          |          
               |           --61.05%--el1_irq
               |                     gic_handle_irq
               |                     __handle_domain_irq
               |                     irq_exit
               |                     __do_softirq
               |                     |          
               |                     |--22.29%--run_timer_softirq


Thanks,
Mark.

[toc] | [prev] | [next] | [standalone]


#1591572

FromKim Phillips <kim.phillips@arm.com>
Date2017-03-03 01:20 +0100
Message-ID<tgJ6V-1tU-7@gated-at.bofh.it>
In reply to#1591082
On Thu, 2 Mar 2017 10:44:11 +0000
Mark Rutland <mark.rutland@arm.com> wrote:

> [Adding James, Takahiro-san, and Will, for stacktracing and arm64 perf]
> 
> On Wed, Mar 01, 2017 at 04:42:17PM -0800, Joel Fernandes wrote:
> > Hi,
> > 
> > On 3.18 kernel running on an arm64 device, I tried running:
> > perf record -a -g -e sched:sched_wakeup
> > 
> > I was expecting something like the output at:
> > www.brendangregg.com/perf.html
> > 
> > But I don't see stacktraces, could I be missing any patches you could
> > point me to?
> 
> I can't spot much obvious, looking at arm64's stacktrace.c and perf_callchain.c
> since v3.18. There's commit:
> 
>   9702970c7bd3e2d6 (Revert "ARM64: unwind: Fix PC calculation")
> 
> ... though that was Cc'd stable.
> 
> I can't immediately see why that would truncate unwinding, though I'm also not
> sure how perf and ftrace interact here, so I may be missing something obvious.
> 
> > I do see stack traces if I do regular perf profiling
> > (perf record -F 99 -a -g).
> 
> > Below is the output I get. Thanks for any insight into this.
> > 
> > Regards,
> > Joel
> > 
> > sailfish:/data # ./perf report
> >        # Samples: 22  of event 'sched:sched_wakeup'
> > # Event count (approx.): 410333
> > #
> > # Children      Self  Trace output
> > # ........  ........
> > .............................................................
> > #
> >     61.29%    61.29%  comm=ksoftirqd/0 pid=3 prio=120 success=1 target_cpu=000
> >             |
> >             ---0
> > 
> >     33.25%    33.25%  comm=hw pid=12777 prio=120 success=1 target_cpu=002
> >             |
> >             ---0
> > 
> >      2.46%     2.46%  comm=kworker/u8:2 pid=12482 prio=120 success=1
> > target_cpu=002
> >             |
> >             ---0
> > 
> >      1.39%     1.39%  comm=migration/2 pid=21 prio=0 success=1 target_cpu=002
> >             |
> >             ---0
> 
> FWIW, on a recent HEAD (86292b33d4b79ee0), I see reasonable looking backtraces,
> e.g.

I cross-built the perf tool on an Ubuntu 16.10 system, after rewinding
its base linux tree to ~v4.6 (e.g., commit 8beeb00 because it precedes a
perf libunwind series), and still see reasonable output:

#
# Total Lost Samples: 0
#
# Samples: 30  of event 'sched:sched_wakeup'
# Event count (approx.): 30
#
# Children      Self  Trace output                                         
# ........  ........  .....................................................
#
    20.00%    20.00%  comm=rcu_preempt pid=7 prio=120 target_cpu=006
            |
            ---0x807f71c4
               secondary_start_kernel
               cpu_startup_entry
               do_idle
               call_cpuidle
               cpuidle_enter
               cpuidle_enter_state
               el1_irq
               gic_handle_irq
               __handle_domain_irq
               irq_exit
               __do_softirq
               |          
               |--16.67%--run_timer_softirq
               |          expire_timers
               |          call_timer_fn
               |          process_timeout
               |          wake_up_process
               |          try_to_wake_up
               |          ttwu_do_activate
               |          ttwu_do_wakeup
               |          ttwu_do_wakeup
               |          
                --3.33%--rcu_process_callbacks
                          note_gp_changes
                          rcu_gp_kthread_wake
                          swake_up
                          swake_up_locked
                          wake_up_process
                          try_to_wake_up
                          ttwu_do_activate
                          ttwu_do_wakeup
                          ttwu_do_wakeup

I tried to go even further back, e.g., v4.1-rc4-15-g10b48f7 but the
compiler wouldn't build perf any more, e.g.,:

util/event.c:416:2: error: ‘readdir_r’ is deprecated [-Werror=deprecated-declarations]

Is it possible to try a newer perf binary (assuming it's also 3.18
based), or check whether libunwind contains aarch64 support?  Note that
it's possible to 'perf archive' the aarch64 run and run perf report on a
more up-to-date x86 host also.

Thanks,

Kim

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web