Re: [PATCHv3 00/12] perf tools: Display eBPF code in intel_pt trace

From: Jiri Olsa
Date: Fri May 31 2019 - 05:23:39 EST

On Thu, May 30, 2019 at 10:05:10PM +0800, Leo Yan wrote:
> Hi Arnaldo,
>
> On Thu, May 30, 2019 at 10:36:45AM -0300, Arnaldo Carvalho de Melo wrote:
>
> [...]
>
> > One other way of testing this:
> >
> > I used perf trace's use of BPF, using:
> >
> > [root@quaco ~]# cat ~/.perfconfig
> > [llvm]
> > dump-obj = true
> > clang-opt = -g
> > [trace]
> > add_events = /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c
> > show_zeros = yes
> > show_duration = no
> > no_inherit = yes
> > show_timestamp = no
> > show_arg_names = no
> > args_alignment = 40
> > show_prefix = yes
> >
> > For arm64 this needs fixing, tools/perf/examples/bpf/augmented_raw_syscalls.c
> > (its in the kernel sources) is still hard coded for x86_64 syscall numbers :-\
>
> Thanks a lot for sharing this, I will test with this method and let you
> and Jiri know the result in tomorrow.

it's always battle of having too much data but caturing everything,
versus having reasonable data size and being lucky to hit the trace ;-)

with sampling on high freq and 1 second trace in another terminal
I got the trace below:

jirka


---
terminal 1:
# sampleip -F 1000 20

terminal2:
# perf-with-kcore record pt -e intel_pt//k -m100M,100M -C 1 -- sleep 1
# perf-with-kcore script pt --call-trace
...
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __perf_event_overflow
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __perf_event_account_interrupt
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __x86_indirect_thunk_rax
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __x86_indirect_thunk_rax
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __x86_indirect_thunk_rax
swapper 0 [001] 85820.051207146: ([kernel.kallsyms] ) __x86_indirect_thunk_rax
swapper 0 [001] 85820.051207467: (bpf_prog_19578a12836c4115 ) __htab_map_lookup_elem
swapper 0 [001] 85820.051207788: ([kernel.kallsyms] ) memcmp
...
# perf-with-kcore script pt --insn-trace --xed
...
swapper 0 [001] 85820.051207467: ffffffff90c00c40 __x86_indirect_thunk_rax+0x10 ([kernel.kallsyms]) retq
swapper 0 [001] 85820.051207467: ffffffffc0557710 bpf_prog_19578a12836c4115+0x0 (bpf_prog_19578a12836c4115) pushq %rbp
swapper 0 [001] 85820.051207467: ffffffffc0557711 bpf_prog_19578a12836c4115+0x1 (bpf_prog_19578a12836c4115) mov %rsp, %rbp
swapper 0 [001] 85820.051207467: ffffffffc0557714 bpf_prog_19578a12836c4115+0x4 (bpf_prog_19578a12836c4115) sub $0x38, %rsp
swapper 0 [001] 85820.051207467: ffffffffc055771b bpf_prog_19578a12836c4115+0xb (bpf_prog_19578a12836c4115) sub $0x28, %rbp
swapper 0 [001] 85820.051207467: ffffffffc055771f bpf_prog_19578a12836c4115+0xf (bpf_prog_19578a12836c4115) movq %rbx, (%rbp)
swapper 0 [001] 85820.051207467: ffffffffc0557723 bpf_prog_19578a12836c4115+0x13 (bpf_prog_19578a12836c4115) movq %r13, 0x8(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc0557727 bpf_prog_19578a12836c4115+0x17 (bpf_prog_19578a12836c4115) movq %r14, 0x10(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc055772b bpf_prog_19578a12836c4115+0x1b (bpf_prog_19578a12836c4115) movq %r15, 0x18(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc055772f bpf_prog_19578a12836c4115+0x1f (bpf_prog_19578a12836c4115) xor %eax, %eax
swapper 0 [001] 85820.051207467: ffffffffc0557731 bpf_prog_19578a12836c4115+0x21 (bpf_prog_19578a12836c4115) movq %rax, 0x20(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc0557735 bpf_prog_19578a12836c4115+0x25 (bpf_prog_19578a12836c4115) mov $0x1, %esi
swapper 0 [001] 85820.051207467: ffffffffc055773a bpf_prog_19578a12836c4115+0x2a (bpf_prog_19578a12836c4115) movl %esi, -0xc(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc055773d bpf_prog_19578a12836c4115+0x2d (bpf_prog_19578a12836c4115) movq (%rdi), %rdi
swapper 0 [001] 85820.051207467: ffffffffc0557741 bpf_prog_19578a12836c4115+0x31 (bpf_prog_19578a12836c4115) movq 0x80(%rdi), %rdi
swapper 0 [001] 85820.051207467: ffffffffc0557748 bpf_prog_19578a12836c4115+0x38 (bpf_prog_19578a12836c4115) movq %rdi, -0x8(%rbp)
swapper 0 [001] 85820.051207467: ffffffffc055774c bpf_prog_19578a12836c4115+0x3c (bpf_prog_19578a12836c4115) mov %rbp, %rsi
swapper 0 [001] 85820.051207467: ffffffffc055774f bpf_prog_19578a12836c4115+0x3f (bpf_prog_19578a12836c4115) add $0xfffffffffffffff8, %rsi
swapper 0 [001] 85820.051207467: ffffffffc0557753 bpf_prog_19578a12836c4115+0x43 (bpf_prog_19578a12836c4115) mov $0xffff9ac0b2926000, %rdi
swapper 0 [001] 85820.051207467: ffffffffc055775d bpf_prog_19578a12836c4115+0x4d (bpf_prog_19578a12836c4115) callq 0xffffffff901fde70
swapper 0 [001] 85820.051207467: ffffffff901fde70 __htab_map_lookup_elem+0x0 ([kernel.kallsyms]) nopl %eax, (%rax,%rax,1)
swapper 0 [001] 85820.051207467: ffffffff901fde75 __htab_map_lookup_elem+0x5 ([kernel.kallsyms]) pushq %rbx
swapper 0 [001] 85820.051207467: ffffffff901fde76 __htab_map_lookup_elem+0x6 ([kernel.kallsyms]) movl 0x1c(%rdi), %r9d
swapper 0 [001] 85820.051207467: ffffffff901fde7a __htab_map_lookup_elem+0xa ([kernel.kallsyms]) mov %rsi, %rdx
swapper 0 [001] 85820.051207467: ffffffff901fde7d __htab_map_lookup_elem+0xd ([kernel.kallsyms]) movl 0x214(%rdi), %ecx
swapper 0 [001] 85820.051207467: ffffffff901fde83 __htab_map_lookup_elem+0x13 ([kernel.kallsyms]) mov %rdx, %r10
swapper 0 [001] 85820.051207467: ffffffff901fde86 __htab_map_lookup_elem+0x16 ([kernel.kallsyms]) mov %r9d, %r8d
swapper 0 [001] 85820.051207467: ffffffff901fde89 __htab_map_lookup_elem+0x19 ([kernel.kallsyms]) add %r9d, %ecx
swapper 0 [001] 85820.051207467: ffffffff901fde8c __htab_map_lookup_elem+0x1c ([kernel.kallsyms]) leal -0x21524111(%rcx), %ebx
swapper 0 [001] 85820.051207467: ffffffff901fde92 __htab_map_lookup_elem+0x22 ([kernel.kallsyms]) mov %ebx, %esi
...