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


Groups > linux.kernel > #1387061 > unrolled thread

LBR callchains from tracepoints

Started byArnaldo Carvalho de Melo <acme@kernel.org>
First post2016-04-26 03:30 +0200
Last post2016-04-26 21:10 +0200
Articles 5 — 3 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.


Contents

  LBR callchains from tracepoints Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-04-26 03:30 +0200
    Re: LBR callchains from tracepoints Peter Zijlstra <peterz@infradead.org> - 2016-04-26 18:40 +0200
      Re: LBR callchains from tracepoints Alexei Starovoitov <alexei.starovoitov@gmail.com> - 2016-04-26 19:30 +0200
        Re: LBR callchains from tracepoints Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-04-26 20:30 +0200
          Re: LBR callchains from tracepoints Peter Zijlstra <peterz@infradead.org> - 2016-04-26 21:10 +0200

#1387061 — LBR callchains from tracepoints

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-04-26 03:30 +0200
SubjectLBR callchains from tracepoints
Message-ID<rrZZ8-7nE-19@gated-at.bofh.it>
Em Mon, Apr 25, 2016 at 10:03:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> I now need to continue investigation why this doesn't seem to work from
> tracepoints...

Bummer, the changeset (at the end of this message) hasn't any
explanation, is this really impossible? I.e. LBR callstacks from
tracepoints? Even if we set perf_event_attr.exclude_callchain_kernel?

I've read somewhere that LBR wouldn't work for the kernel, but when I
tried, for cycles:ppp I got:

[acme@jouet linux]$ perf record --call-graph lbr usleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.018 MB perf.data (9 samples) ]
[acme@jouet linux]$ perf evlist -v
cycles:ppp: size: 112, { sample_period, sample_freq }: 4000,
sample_type: IP|TID|TIME|CALLCHAIN|PERIOD|BRANCH_STACK, disabled: 1,
inherit: 1, mmap: 1, comm: 1, freq: 1, enable_on_exec: 1, task: 1,
precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec:
1, branch_sample_type: USER|CALL_STACK|NO_FLAGS|NO_CYCLES
[acme@jouet linux]$

-   59.69%  usleep   [kernel]  [k] vma_interval_tree_insert
    →vma_interval_tree_insert  [kernel]
     vma_adjust                [kernel]
     __split_vma.isra.31       [kernel]
     split_vma                 [kernel]
     mprotect_fixup            [kernel]
     sys_mprotect              [kernel]
     entry_SYSCALL_64_fastpath [kernel]
     mprotect                  ld-2.22.so
     _dl_relocate_object       ld-2.22.so
     memcpy@GLIBC_2.2.5        libc-2.22.so
     _dl_relocate_object       ld-2.22.so
     __gettimeofday            libc-2.22.so
     _dl_vdso_vsym             libc-2.22.so
     _dl_lookup_symbol_x       ld-2.22.so

This was done on a Broadwell system (ThinkPad t450s).

- Arnaldo

commit 2481c5fa6db0237e4f0168f88913178b2b495b7c
Author: Stephane Eranian <eranian@google.com>
Date:   Thu Feb 9 23:20:59 2012 +0100

    perf: Disable PERF_SAMPLE_BRANCH_* when not supported
    
    PERF_SAMPLE_BRANCH_* is disabled for:
    
     - SW events (sw counters, tracepoints)
     - HW breakpoints
     - ALL but Intel x86 architecture
     - AMD64 processors
    
    Signed-off-by: Stephane Eranian <eranian@google.com>
    Signed-off-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
    Link: http://lkml.kernel.org/r/1328826068-11713-10-git-send-email-eranian@google.com
    Signed-off-by: Ingo Molnar <mingo@elte.hu>

[toc] | [next] | [standalone]


#1387692

FromPeter Zijlstra <peterz@infradead.org>
Date2016-04-26 18:40 +0200
Message-ID<rsebM-2ma-7@gated-at.bofh.it>
In reply to#1387061
On Mon, Apr 25, 2016 at 10:24:31PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Mon, Apr 25, 2016 at 10:03:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> > I now need to continue investigation why this doesn't seem to work from
> > tracepoints...
> 
> Bummer, the changeset (at the end of this message) hasn't any
> explanation, is this really impossible? I.e. LBR callstacks from
> tracepoints? Even if we set perf_event_attr.exclude_callchain_kernel?

Could maybe be done, but its tricky to implement as the LBR is managed
by the hardware PMU and tracepoints are a software PMU, so we need to
then somehow frob with cross-pmu resources, in a very arch specific way.
And programmability of the hardware PMU will then depend on events
outside of it.

All rather icky.

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


#1387754

FromAlexei Starovoitov <alexei.starovoitov@gmail.com>
Date2016-04-26 19:30 +0200
Message-ID<rseYb-34w-53@gated-at.bofh.it>
In reply to#1387692
On Tue, Apr 26, 2016 at 06:38:28PM +0200, Peter Zijlstra wrote:
> On Mon, Apr 25, 2016 at 10:24:31PM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Mon, Apr 25, 2016 at 10:03:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> > > I now need to continue investigation why this doesn't seem to work from
> > > tracepoints...
> > 
> > Bummer, the changeset (at the end of this message) hasn't any
> > explanation, is this really impossible? I.e. LBR callstacks from
> > tracepoints? Even if we set perf_event_attr.exclude_callchain_kernel?
> 
> Could maybe be done, but its tricky to implement as the LBR is managed
> by the hardware PMU and tracepoints are a software PMU, so we need to
> then somehow frob with cross-pmu resources, in a very arch specific way.
> And programmability of the hardware PMU will then depend on events
> outside of it.

btw we're thinking to add support for lbr to bpf, so that from the program
we can get accurate and fast stacks. That's especially important for user
space stacks. No clear idea how to do it yet, but it would be really useful.

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


#1387811

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-04-26 20:30 +0200
Message-ID<rsfUf-3TD-41@gated-at.bofh.it>
In reply to#1387754
Em Tue, Apr 26, 2016 at 10:26:32AM -0700, Alexei Starovoitov escreveu:
> On Tue, Apr 26, 2016 at 06:38:28PM +0200, Peter Zijlstra wrote:
> > On Mon, Apr 25, 2016 at 10:24:31PM -0300, Arnaldo Carvalho de Melo wrote:
> > > Em Mon, Apr 25, 2016 at 10:03:58PM -0300, Arnaldo Carvalho de Melo escreveu:
> > > > I now need to continue investigation why this doesn't seem to work from
> > > > tracepoints...

> > > Bummer, the changeset (at the end of this message) hasn't any
> > > explanation, is this really impossible? I.e. LBR callstacks from
> > > tracepoints? Even if we set perf_event_attr.exclude_callchain_kernel?

> > Could maybe be done, but its tricky to implement as the LBR is managed
> > by the hardware PMU and tracepoints are a software PMU, so we need to
> > then somehow frob with cross-pmu resources, in a very arch specific way.
> > And programmability of the hardware PMU will then depend on events
> > outside of it.
 
> btw we're thinking to add support for lbr to bpf, so that from the program
> we can get accurate and fast stacks. That's especially important for user
> space stacks. No clear idea how to do it yet, but it would be really useful.

Yeah, and that already works in perf, its just that it doesn't work from some
points (PERF_TYPE_SOFTWARE, PERF_TYPE_TRACEPOINT, etc), as described in the
changeset I mentioned.

'perf trace --call-graph lbr' doesn't work right now even with it
interested only in the user space bits, i.e. setting
perf_event_attr.exclude_callchain_kernel.

  # perf trace --call-graph dwarf

works, but that, as you mention, really isn't "fast" and sometimes not
accurate, or at least wasn't with broken toolchains.

Example of mixed strace-like with userspace-only DWARF callchains (would be
lovely if this was with LBR, huh?) plus fp callchains for the
sched:sched_switch tracepoint plus LBR callchains for a hardware event, cycles,
look further below for the reason of the broken timestamps for
PERF_TYPE_HARDWARE events:

  # perf trace -e nanosleep --event sched:sched_switch/call-graph=fp/ --ev cycles/call-graph=lbr,period=100/ usleep 1
18446744073709.551 (         ): cycles/call-graph=lbr,period=100/:)
                                       __intel_pmu_enable_all+0xfe200080 ([kernel.kallsyms])
                                       intel_pmu_enable_all+0xfe200010 ([kernel.kallsyms])
                                       x86_pmu_enable+0xfe200271 ([kernel.kallsyms])
                                       perf_pmu_enable.part.81+0xfe200007 ([kernel.kallsyms])
                                       ctx_resched+0xfe20007a ([kernel.kallsyms])
                                       perf_event_exec+0xfe20011d ([kernel.kallsyms])
                                       setup_new_exec+0xfe20006f ([kernel.kallsyms])
                                       load_elf_binary+0xfe2003e3 ([kernel.kallsyms])
                                       search_binary_handler+0xfe20009e ([kernel.kallsyms])
                                       do_execveat_common.isra.38+0xfe20052c ([kernel.kallsyms])
                                       sys_execve+0xfe20003a ([kernel.kallsyms])
                                       do_syscall_64+0xfe200062 ([kernel.kallsyms])
                                       return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                                       [0] ([unknown])
     0.310 ( 0.006 ms): usleep/20951 nanosleep(rqtp: 0x7ffda8904500       ) ...
     0.310 (         ): sched:sched_switch:usleep:20951 [120] S ==> swapper/3:0 [120])
                                       __schedule+0xfe200402 ([kernel.kallsyms])
                                       schedule+0xfe200035 ([kernel.kallsyms])
                                       do_nanosleep+0xfe20006f ([kernel.kallsyms])
                                       hrtimer_nanosleep+0xfe2000dc ([kernel.kallsyms])
                                       sys_nanosleep+0xfe20007a ([kernel.kallsyms])
                                       do_syscall_64+0xfe200062 ([kernel.kallsyms])
                                       return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                                       __nanosleep+0xffff00bfad62c010 (/usr/lib64/libc-2.22.so)
18446679523046.461 (         ): cycles/call-graph=lbr,period=100/:)
                                       perf_pmu_enable.part.81+0xfe200007 ([kernel.kallsyms])
                                       __perf_event_task_sched_in+0xfe2001ad ([kernel.kallsyms])
                                       finish_task_switch+0xfe200156 ([kernel.kallsyms])
                                       __schedule+0xfe200397 ([kernel.kallsyms])
                                       schedule+0xfe200035 ([kernel.kallsyms])
                                       do_nanosleep+0xfe20006f ([kernel.kallsyms])
                                       hrtimer_nanosleep+0xfe2000dc ([kernel.kallsyms])
                                       sys_nanosleep+0xfe20007a ([kernel.kallsyms])
                                       do_syscall_64+0xfe200062 ([kernel.kallsyms])
                                       return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                                       [0] ([unknown])
     0.377 ( 0.073 ms): usleep/20951  ... [continued]: nanosleep()) = 0
  [root@jouet ~]# 


perf_event_attr:
  type                             0 (PERF_TYPE_HARDWARE)
  config                           0 (PERF_COUNT_HW_CPU_CYCLES)
  size                             112
  { sample_period, sample_freq }   100
  sample_type                      IP|TID|CALLCHAIN|BRANCH_STACK|IDENTIFIER
  read_format                      ID
  disabled                         1
  inherit                          1
  enable_on_exec                   1
  sample_id_all                    1
  exclude_guest                    1
  { wakeup_events, wakeup_watermark } 1
  branch_sample_type               USER|CALL_STACK|NO_FLAGS|NO_CYCLES

missing PERF_SAMPLE_TIME, will fix.

- Arnaldo

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


#1387915

FromPeter Zijlstra <peterz@infradead.org>
Date2016-04-26 21:10 +0200
Message-ID<rsgwV-4xy-9@gated-at.bofh.it>
In reply to#1387811
On Tue, Apr 26, 2016 at 03:20:32PM -0300, Arnaldo Carvalho de Melo wrote:
> Yeah, and that already works in perf, its just that it doesn't work from some
> points (PERF_TYPE_SOFTWARE, PERF_TYPE_TRACEPOINT, etc), as described in the
> changeset I mentioned.

Look at it the other way around, it _only_ works for intel cpu events,
_nothing_ else.

There is only a single PMU that supports LBR callgraph thingies, all the
others do not.

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web