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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.