From: Arnaldo Carvalho de Melo <acme@kernel.org>
To: Milian Wolff <milian.wolff@kdab.com>
Cc: perf group <linux-perf-users@vger.kernel.org>
Subject: Re: perf trace report with time consumed
Date: Wed, 30 Mar 2016 11:53:14 -0300 [thread overview]
Message-ID: <20160330145314.GE3420@kernel.org> (raw)
In-Reply-To: <1894563.GPSC8z33rH@agathebauer>
Em Tue, Mar 29, 2016 at 10:39:36PM +0200, Milian Wolff escreveu:
> Hey all,
>
> with "perf trace record --call-graph dwarf" I get a nice data file with
> potentially everything required to find slow syscalls in user space
> applications. But I'm missing a way to rewrite the data file to let "perf
> report" attribute samples with the time spent as cost, instead of the raw
> number of syscalls, i.e. samples.
Humm, perhaps use 'perf trace', maybe this is the push to add support for callgraphs there:
[root@jouet ~]# trace record sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.026 MB perf.data (68 samples) ]
[root@jouet ~]# ls -la perf.data
-rw-------. 1 root root 34446 Mar 30 11:49 perf.data
[root@jouet ~]# trace -s -i perf.data
Summary of events:
sleep (1139), 67 events, 98.5%, 0.000 msec
syscall calls total min avg max stddev
(msec) (msec) (msec) (msec) (%)
--------------- -------- --------- --------- --------- --------- ------
read 1 0.002 0.002 0.002 0.002 0.00%
open 3 0.017 0.005 0.006 0.006 3.14%
close 5 0.004 0.001 0.001 0.002 30.49%
fstat 3 0.003 0.001 0.001 0.002 22.16%
mmap 9 0.028 0.001 0.003 0.005 14.67%
mprotect 4 0.018 0.003 0.005 0.007 17.07%
munmap 1 0.008 0.008 0.008 0.008 0.00%
brk 4 0.005 0.000 0.001 0.003 43.48%
access 1 0.005 0.005 0.005 0.005 0.00%
nanosleep 1 1000.056 1000.056 1000.056 1000.056 0.00%
arch_prctl 1 0.001 0.001 0.001 0.001 0.00%
[root@jouet ~]# trace -i perf.data
0.021 ( 0.001 ms): sleep/1139 brk( ) = 0x5619db285000
0.036 ( 0.003 ms): sleep/1139 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7f3e5264b000
0.046 ( 0.005 ms): sleep/1139 access(filename: 0x52449e10, mode: R ) = -1 ENOENT No such file or directory
0.055 ( 0.005 ms): sleep/1139 open(filename: 0x52448761, flags: CLOEXEC ) = 4
0.058 ( 0.002 ms): sleep/1139 fstat(fd: 4, statbuf: 0x7ffebed25ef0 ) = 0
0.062 ( 0.004 ms): sleep/1139 mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 4 ) = 0x7f3e52630000
0.063 ( 0.001 ms): sleep/1139 close(fd: 4 ) = 0
0.078 ( 0.006 ms): sleep/1139 open(filename: 0x5264b640, flags: CLOEXEC ) = 4
0.081 ( 0.002 ms): sleep/1139 read(fd: 4, buf: 0x7ffebed26080, count: 832 ) = 832
0.083 ( 0.001 ms): sleep/1139 fstat(fd: 4, statbuf: 0x7ffebed25f30 ) = 0
0.089 ( 0.004 ms): sleep/1139 mmap(len: 3934784, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 4 ) = 0x7f3e5206b000
0.097 ( 0.007 ms): sleep/1139 mprotect(start: 0x7f3e52222000, len: 2097152 ) = 0
0.103 ( 0.005 ms): sleep/1139 mmap(addr: 0x7f3e52422000, len: 24576, prot: READ|WRITE, flags: PRIVATE|DENYWRITE|FIXED, fd: 4, off: 1798144) = 0x7f3e52422
0.109 ( 0.003 ms): sleep/1139 mmap(addr: 0x7f3e52428000, len: 14912, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS|FIXED, fd: -1) = 0x7f3e52428000
0.114 ( 0.001 ms): sleep/1139 close(fd: 4 ) = 0
0.126 ( 0.002 ms): sleep/1139 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7f3e5262f000
0.131 ( 0.002 ms): sleep/1139 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7f3e5262e000
0.134 ( 0.001 ms): sleep/1139 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7f3e5262d000
0.136 ( 0.001 ms): sleep/1139 arch_prctl(option: 4098, arg2: 139905646913280, arg3: 3, arg4: 34, arg5: 4294967295) = 0
0.201 ( 0.005 ms): sleep/1139 mprotect(start: 0x7f3e52422000, len: 16384, prot: READ ) = 0
0.224 ( 0.004 ms): sleep/1139 mprotect(start: 0x5619d955f000, len: 4096, prot: READ ) = 0
0.229 ( 0.003 ms): sleep/1139 mprotect(start: 0x7f3e5264c000, len: 4096, prot: READ ) = 0
0.239 ( 0.008 ms): sleep/1139 munmap(addr: 0x7f3e52630000, len: 106798 ) = 0
0.306 ( 0.001 ms): sleep/1139 brk( ) = 0x5619db285000
0.309 ( 0.003 ms): sleep/1139 brk(brk: 0x5619db2a6000 ) = 0x5619db2a6000
0.310 ( 0.000 ms): sleep/1139 brk( ) = 0x5619db2a6000
0.320 ( 0.006 ms): sleep/1139 open(filename: 0x521f6e20, flags: CLOEXEC ) = 4
0.325 ( 0.001 ms): sleep/1139 fstat(fd: 4, statbuf: 0x7f3e524279a0 ) = 0
0.330 ( 0.004 ms): sleep/1139 mmap(len: 111950656, prot: READ, flags: PRIVATE, fd: 4 ) = 0x7f3e4b5a7000
0.335 ( 0.001 ms): sleep/1139 close(fd: 4 ) = 0
1000.423 (1000.056 ms): sleep/1139 nanosleep(rqtp: 0x7ffebed266c0 ) = 0
1000.440 ( 0.002 ms): sleep/1139 close(fd: 1 ) = 0
1000.443 ( 0.001 ms): sleep/1139 close(fd: 2 ) = 0
1000.447 ( 0.000 ms): sleep/1139 exit_group(
[root@jouet ~]#
There is even:
[root@jouet ~]# trace --duration 1000 -i perf.data
1000.423 (1000.056 ms): sleep/1139 nanosleep(rqtp: 0x7ffebed266c0) = 0
[root@jouet ~]#
Having that with callgraph from userspace is what you're asking for, no?
'trace' here is just an alias for 'perf trace'.
- Arnaldo
> Is this functionality there already? Or do I have to write another "perf
> inject" command, similar to "perf inject --sched-stat"?
>
> Thanks
> --
> Milian Wolff | milian.wolff@kdab.com | Software Engineer
> KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
> Tel: +49-30-521325470
> KDAB - The Qt Experts
next prev parent reply other threads:[~2016-03-30 14:53 UTC|newest]
Thread overview: 16+ messages / expand[flat|nested] mbox.gz Atom feed top
2016-03-29 20:39 perf trace report with time consumed Milian Wolff
2016-03-30 14:53 ` Arnaldo Carvalho de Melo [this message]
2016-03-30 21:24 ` Milian Wolff
2016-03-30 21:58 ` Arnaldo Carvalho de Melo
2016-03-31 22:34 ` Milian Wolff
2016-04-01 13:01 ` Arnaldo Carvalho de Melo
2016-04-03 16:30 ` Jiri Olsa
2016-04-03 18:46 ` Milian Wolff
2016-04-04 6:14 ` Jiri Olsa
2016-04-04 21:17 ` Milian Wolff
2016-04-05 8:35 ` Jiri Olsa
2016-04-06 15:46 ` [PATCH] perf tools: Add dedicated unwind addr_space member into thread struct Jiri Olsa
2016-04-06 21:15 ` Milian Wolff
2016-04-08 12:58 ` Arnaldo Carvalho de Melo
2016-04-06 21:16 ` perf trace report with time consumed Milian Wolff
2016-04-08 13:01 ` Arnaldo Carvalho de Melo
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=20160330145314.GE3420@kernel.org \
--to=acme@kernel.org \
--cc=linux-perf-users@vger.kernel.org \
--cc=milian.wolff@kdab.com \
/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).