From: Arnaldo Carvalho de Melo <acme@kernel.org>
To: Andi Kleen <andi@firstfloor.org>
Cc: Christian Convey <christian.convey@gmail.com>,
linux-perf-users@vger.kernel.org
Subject: Re: newbie question: tracing userspace call/return sequences
Date: Fri, 6 Jan 2017 16:23:12 -0300 [thread overview]
Message-ID: <20170106192312.GQ27864@kernel.org> (raw)
In-Reply-To: <87zij4nhvk.fsf@firstfloor.org>
Em Fri, Jan 06, 2017 at 10:49:35AM -0800, Andi Kleen escreveu:
> Christian Convey <christian.convey@gmail.com> writes:
> >
> > Any suggestions for a good/better way to pull this off?
>
> Use the right tool for the job.
>
> On Intel, use a Broadwell or Skylake or Goldmont and use processor trace.
>
> perf record -e intel_pt//u foo
> perf script --itrace=cr
Does that already works while VT-x is in use?
[root@jouet ~]# grep "model name" /proc/cpuinfo
model name : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
model name : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
model name : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
model name : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
[root@jouet ~]#
So Broadwell:
[root@jouet ~]# perf record -e intel_pt//u ls
Dockerfile perf.data perf.data.old
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.044 MB perf.data ]
[root@jouet ~]# perf script --itrace=cr
[root@jouet ~]#
As soon as I stop a VM:
[root@jouet ~]# perf script --itrace=cr | wc -l
14644
[root@jouet ~]# perf script --itrace=cr | tail
ls 6527 [3] 6255.381805: 1 branches:u: 7fd672d97ae0 __do_global_dtors_aux (/usr/lib64/libpthread-2.24.so) => 7fd673c2a18a _dl_fini (/usr/lib64/ld-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd673c2a1a6 _dl_fini (/usr/lib64/ld-2.24.so) => 7fd672da4da4 _fini (/usr/lib64/libpthread-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd672da4dac _fini (/usr/lib64/libpthread-2.24.so) => 7fd673c2a1a8 _dl_fini (/usr/lib64/ld-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd673c2a38e _dl_fini (/usr/lib64/ld-2.24.so) => 7fd673461410 __run_exit_handlers (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734613b0 __run_exit_handlers (/usr/lib64/libc-2.24.so) => 7fd6734a5a30 _IO_cleanup (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734a5a40 _IO_cleanup (/usr/lib64/libc-2.24.so) => 7fd6734a56e0 _IO_flush_all_lockp (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734a594f _IO_flush_all_lockp (/usr/lib64/libc-2.24.so) => 7fd6734a5a45 _IO_cleanup (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734a5b99 _IO_cleanup (/usr/lib64/libc-2.24.so) => 7fd6734613b3 __run_exit_handlers (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734613be __run_exit_handlers (/usr/lib64/libc-2.24.so) => 7fd6734f3c30 _exit (/usr/lib64/libc-2.24.so)
ls 6527 [3] 6255.381805: 1 branches:u: 7fd6734f3c66 _exit (/usr/lib64/libc-2.24.so) => 0 [unknown] ([unknown])
[root@jouet ~]#
Using -F and callident it get even better :-)
[root@jouet ~]# perf script -F callindent,time,comm,pid,sym,ip,addr,flags,cpu --itrace=cr | head -40
ls 6527 [3] 6255.380814: tr strt _start 0 [unknown] => 7fd673c19cd0 _start
ls 6527 [3] 6255.380814: tr end _start 7fd673c19cd0 _start => 0 [unknown]
ls 6527 [3] 6255.380817: tr strt _start 0 [unknown] => 7fd673c19cd0 _start
ls 6527 [3] 6255.380817: call _dl_start 7fd673c19cd3 _start => 7fd673c1dce0 _dl_start
ls 6527 [3] 6255.380817: tr end _dl_start 7fd673c1dcff _dl_start => 0 [unknown]
ls 6527 [3] 6255.380818: tr strt _dl_start 0 [unknown] => 7fd673c1dcff _dl_start
ls 6527 [3] 6255.380818: tr end _dl_start 7fd673c1dd06 _dl_start => 0 [unknown]
ls 6527 [3] 6255.380822: tr strt _dl_start 0 [unknown] => 7fd673c1dd06 _dl_start
ls 6527 [3] 6255.380822: tr end _dl_start 7fd673c1e0e0 _dl_start => 0 [unknown]
ls 6527 [3] 6255.380824: tr strt _dl_start 0 [unknown] => 7fd673c1e0e0 _dl_start
ls 6527 [3] 6255.380824: call _dl_setup_hash 7fd673c1df03 _dl_start => 7fd673c24c10 _dl_setup_hash
ls 6527 [3] 6255.380824: return _dl_setup_hash 7fd673c24c6d _dl_setup_hash => 7fd673c1df08 _dl_start
ls 6527 [3] 6255.380824: call _dl_sysdep_start 7fd673c1df63 _dl_start => 7fd673c32710 _dl_sysdep_start
ls 6527 [3] 6255.380824: tr end _dl_sysdep_start 7fd673c32743 _dl_sysdep_start => 0 [unknown]
ls 6527 [3] 6255.380827: tr strt _dl_sysdep_start 0 [unknown] => 7fd673c32743 _dl_sysdep_start
ls 6527 [3] 6255.380827: call brk 7fd673c329d0 _dl_sysdep_start => 7fd673c33890 brk
ls 6527 [3] 6255.380827: syscall 7fd673c33897 brk => 0 [unknown]
ls 6527 [3] 6255.380828: tr strt brk 0 [unknown] => 7fd673c33899 brk
ls 6527 [3] 6255.380828: return brk 7fd673c338b2 brk => 7fd673c329d5 _dl_sysdep_start
ls 6527 [3] 6255.380828: call get_common_indeces.constprop.1 7fd673c32c2f _dl_sysdep_start => 7fd673c325e0 get_common_indeces.constprop.1
ls 6527 [3] 6255.380828: return get_common_indeces.constprop.1 7fd673c326c3 get_common_indeces.constprop.1 => 7fd673c32c34 _dl_sysdep_start
ls 6527 [3] 6255.380828: call strlen 7fd673c32aed _dl_sysdep_start => 7fd673c36400 strlen
ls 6527 [3] 6255.380828: return strlen 7fd673c36439 strlen => 7fd673c32af2 _dl_sysdep_start
ls 6527 [3] 6255.380828: call sbrk 7fd673c32afb _dl_sysdep_start => 7fd673c338e0 sbrk
ls 6527 [3] 6255.380828: return sbrk 7fd673c3392e sbrk => 7fd673c32b00 _dl_sysdep_start
ls 6527 [3] 6255.380828: call dl_main 7fd673c32b2c _dl_sysdep_start => 7fd673c1a9a0 dl_main
ls 6527 [3] 6255.380828: call _dl_next_ld_env_entry 7fd673c1aa6c dl_main => 7fd673c33110 _dl_next_ld_env_entry
ls 6527 [3] 6255.380828: return _dl_next_ld_env_entry 7fd673c33150 _dl_next_ld_env_entry => 7fd673c1aa71 dl_main
ls 6527 [3] 6255.380828: call _dl_new_object 7fd673c1ae4f dl_main => 7fd673c24d50 _dl_new_object
ls 6527 [3] 6255.380828: call strlen 7fd673c24d77 _dl_new_object => 7fd673c36400 strlen
ls 6527 [3] 6255.380828: return strlen 7fd673c36439 strlen => 7fd673c24d7c _dl_new_object
ls 6527 [3] 6255.380828: call 7fd673c19ab0 7fd673c24dd1 _dl_new_object => 7fd673c19ab0 [unknown]
ls 6527 [3] 6255.380828: return __libc_memalign 7fd673c332a9 __libc_memalign => 7fd673c24dd6 _dl_new_object
ls 6527 [3] 6255.380828: call memmove 7fd673c24e13 _dl_new_object => 7fd673c36f20 memmove
ls 6527 [3] 6255.380828: return memmove 7fd673c36f56 memmove => 7fd673c24e18 _dl_new_object
ls 6527 [3] 6255.380828: return _dl_new_object 7fd673c24fc8 _dl_new_object => 7fd673c1ae54 dl_main
ls 6527 [3] 6255.380828: call _dl_add_to_namespace_list 7fd673c1ae88 dl_main => 7fd673c24cc0 _dl_add_to_namespace_list
ls 6527 [3] 6255.380828: call rtld_lock_default_lock_recursive 7fd673c24cd1 _dl_add_to_namespace_list => 7fd673c19d30 rtld_lock_default_lock_recursive
ls 6527 [3] 6255.380828: return rtld_lock_default_lock_recursive 7fd673c19d34 rtld_lock_default_lock_recursive => 7fd673c24cd7 _dl_add_to_namespace_list
ls 6527 [3] 6255.380828: return rtld_lock_default_unlock_recursive 7fd673c19d44 rtld_lock_default_unlock_recursive => 7fd673c1ae8d dl_main
[root@jouet ~]#
- Arnaldo
next prev parent reply other threads:[~2017-01-06 19:23 UTC|newest]
Thread overview: 18+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-01-06 3:49 newbie question: tracing userspace call/return sequences Christian Convey
2017-01-06 10:16 ` Milian Wolff
2017-01-06 20:05 ` Christian Convey
2017-01-07 23:44 ` Masami Hiramatsu
2017-01-09 15:19 ` Christian Convey
2017-01-09 17:03 ` Naveen N. Rao
2017-01-09 17:59 ` Christian Convey
2017-01-10 0:25 ` Masami Hiramatsu
2017-01-10 2:32 ` Christian Convey
2017-01-06 18:49 ` Andi Kleen
2017-01-06 19:07 ` Christian Convey
2017-01-07 4:37 ` Namhyung Kim
2017-01-07 18:26 ` Christian Convey
2017-01-07 19:08 ` Andi Kleen
2017-01-08 8:08 ` Namhyung Kim
2017-01-06 19:23 ` Arnaldo Carvalho de Melo [this message]
2017-01-09 17:20 ` Frank Ch. Eigler
2017-01-09 18:08 ` Christian Convey
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20170106192312.GQ27864@kernel.org \
--to=acme@kernel.org \
--cc=andi@firstfloor.org \
--cc=christian.convey@gmail.com \
--cc=linux-perf-users@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).