kernel/tools/perf/builtin-trace.c, branch linux-4.1.y

perf trace: Add mmap alias for s390

2018-05-23T01:36:27Z

[ Upstream commit 54265664c15a68905d8d67d19205e9a767636434 ] The s390 architecture maps sys_mmap (nr 90) into sys_old_mmap. For this reason perf trace can't find the proper syscall event to get args format from and displays it wrongly as 'continued'. To fix that fill the "alias" field with "old_mmap" for trace's mmap record to get the correct translation. Before: 0.042 ( 0.011 ms): vest/43052 fstat(statbuf: 0x3ffff89fd90 ) = 0 0.042 ( 0.028 ms): vest/43052 ... [continued]: mmap()) = 0x3fffd6e2000 0.072 ( 0.025 ms): vest/43052 read(buf: 0x3fffd6e2000, count: 4096 ) = 6 After: 0.045 ( 0.011 ms): fstat(statbuf: 0x3ffff8a0930 ) = 0 0.057 ( 0.018 ms): mmap(arg: 0x3ffff8a0858 ) = 0x3fffd14a000 0.076 ( 0.025 ms): read(buf: 0x3fffd14a000, count: 4096 ) = 6 Signed-off-by: Jiri Olsa Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20170531113557.19175-1-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo Signed-off-by: Sasha Levin

perf trace: Do not process PERF_RECORD_LOST twice

2017-07-31T17:37:53Z

[ Upstream commit 3ed5ca2efff70e9f589087c2013789572901112d ] We catch this record to provide a visual indication that events are getting lost, then call the default method to allow extra logging shared with the other tools to take place. This extra logging was done twice because we were continuing to the "default" clause where machine__process_event() will end up calling machine__process_lost_event() again, fix it. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-wus2zlhw3qo24ye84ewu4aqw@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo Signed-off-by: Sasha Levin

perf trace: Disable events and drain events when forked workload ends

2015-04-23T20:08:08Z

We were not checking in the inner event processing loop if the forked workload had finished, which, on a busy system, may make it take a long time trying to drain events, entering a seemingly neverending loop, waiting for the system to get idle enough to make it drain the buffers. Fix it by disabling the events when 'done' is true, in the inner loop, to start draining what is in the buffers. Now: [root@ssdandy ~]# time trace --filter-pids 14003 -a sleep 1 | tail 996.748 ( 0.002 ms): sh/30296 rt_sigprocmask(how: SETMASK, nset: 0x7ffc83418160, sigsetsize: 8) = 0 996.751 ( 0.002 ms): sh/30296 rt_sigprocmask(how: BLOCK, nset: 0x7ffc834181f0, oset: 0x7ffc83418270, sigsetsize: 8) = 0 996.755 ( 0.002 ms): sh/30296 rt_sigaction(sig: INT, act: 0x7ffc83417f50, oact: 0x7ffc83417ff0, sigsetsize: 8) = 0 1004.543 ( 0.362 ms): tail/30198 ... [continued]: read()) = 4096 1004.548 ( 7.791 ms): sh/30296 wait4(upid: -1, stat_addr: 0x7ffc834181a0) ... 1004.975 ( 0.427 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096 1005.390 ( 0.410 ms): tail/30198 read(buf: 0x765410, count: 8192) = 4096 1005.743 ( 0.348 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096 1006.197 ( 0.449 ms): tail/30198 read(buf: 0x765410, count: 8192) = 4096 1006.492 ( 0.290 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096 real 0m1.219s user 0m0.704s sys 0m0.331s [root@ssdandy ~]# Reported-by: Michael Petlan Suggested-by: Jiri Olsa Acked-by: Jiri Olsa Cc: Adrian Hunter Cc: Borislav Petkov Cc: David Ahern Cc: Don Zickus Cc: Frederic Weisbecker Cc: Namhyung Kim Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-p6kpn1b26qcbe47pufpw0tex@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Enable events when doing system wide tracing and starting a workload

2015-04-23T20:07:59Z

commit f7aa222ff397 Author: Arnaldo Carvalho de Melo Date: Tue Feb 3 13:25:39 2015 -0300 perf trace: No need to enable evsels for workload started from perf The assumption was that whenever a workload is specified, the attr.enable_on_exec evsel flag would be set, but that is not happening when perf_record_opts.system_wide is set, for instance That resulted in both perf_evlist__enable() and attr.enable_on_exec being not called/set, which made the events to remain disabled while the workload runs, producing no output. Fix it, by calling perf_evlist__enable() in the 'trace' tool when forking and not targetting a workload started from trace v2: Test against !target__none(), as suggested by Namhyung Kim, that is what is used in perf_evsel__config() when deciding if the attr.enable_on_exec flag to be set. More work is needed to cover other cases such as opts->initial_delay. Acked-by: Jiri Olsa Cc: Adrian Hunter Cc: Borislav Petkov Cc: David Ahern Cc: Don Zickus Cc: Frederic Weisbecker Cc: Namhyung Kim Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-27z7169pvfxgj8upic636syv@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Support using -f to override perf.data file ownership

2015-04-02T16:18:51Z

Enable perf trace to use perf.data when it is not owned by current user or root. Example: # perf trace record ls # chown Yunlong.Song:Yunlong.Song perf.data # ls -al perf.data -rw------- 1 Yunlong.Song Yunlong.Song 4153101 Apr 2 15:28 perf.data # id uid=0(root) gid=0(root) groups=0(root),64(pkcs11) Before this patch: # perf trace -i perf.data File perf.data not owned by current user or root (use -f to override) # perf trace -i perf.data -f Error: unknown switch `f' usage: perf trace [] [] or: perf trace [] -- [] or: perf trace record [] [] or: perf trace record [] -- [] --event event selector. use 'perf list' to list available events --comm show the thread COMM next to its id --tool_stats show tool stats -e, --expr list of events to trace -o, --output output file name -i, --input Analyze events in file -p, --pid trace events on existing process id -t, --tid trace events on existing thread id --filter-pids ... As shown above, the -f option does not work at all. After this patch: # perf trace -i perf.data File perf.data not owned by current user or root (use -f to override) # perf trace -i perf.data -f 0.056 ( 0.002 ms): ls/47325 brk( ... 0.108 ( 0.018 ms): ls/47325 mmap(len: 4096, prot: READ|WRITE, ... 0.145 ( 0.013 ms): ls/47325 access(filename: 0x7f31259a0eb0, ... 0.172 ( 0.008 ms): ls/47325 open(filename: 0x7fffeb9a0d00, ... 0.180 ( 0.004 ms): ls/47325 stat(filename: 0x7fffeb9a0d00, ... 0.185 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00, ... 0.189 ( 0.003 ms): ls/47325 stat(filename: 0x7fffeb9a0d00, ... 0.195 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00, ... 0.199 ( 0.002 ms): ls/47325 stat(filename: 0x7fffeb9a0d00, ... 0.205 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00, ... 0.211 ( 0.004 ms): ls/47325 stat(filename: 0x7fffeb9a0d00, ... 0.220 ( 0.007 ms): ls/47325 open(filename: 0x7f312599e8ff, ... ... ... As shown above, the -f option really works now. Signed-off-by: Yunlong Song Tested-by: Arnaldo Carvalho de Melo Cc: Paul Mackerras Cc: Peter Zijlstra Cc: Wang Nan Link: http://lkml.kernel.org/r/1427982439-27388-10-git-send-email-yunlong.song@huawei.com Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Fix syscall enter formatting bug

2015-03-26T13:52:29Z

commit e596663ebb28a068f5cca57f83285b7b293a2c83 Author: Arnaldo Carvalho de Melo Date: Fri Feb 13 13:22:21 2015 -0300 perf trace: Handle multiple threads better wrt syscalls being intermixed Introduced a bug where it considered the number of bytes output directly to the output file when formatting the syscall entry buffer that is stored to be finally printed at syscall exit, ending up leaving garbage at the start of syscalls that appeared while another syscall was being processed, in another thread. Fix it. Example of garbage in the output before this patch: 4280.102 ( 0.000 ms): lsmd/763 ... [continued]: select()) = 0 Timeout 4280.107 (275.250 ms): tuned/852 select(tvp: 0x7f41f7ffde50 ) ... 4280.109 ( 0.002 ms): lsmd/763 Xl�� ) = -10 4639.197 ( 0.000 ms): systemd-journa/542 ... [continued]: epoll_wait()) = 1 4639.202 (359.088 ms): lsmd/763 select(n: 6, inp: 0x7ffff21daad0, tvp: 0x7ffff21daac0) ... 4639.207 ( 0.005 ms): systemd-journa/542 Hn�� ) = 106 4639.221 ( 0.002 ms): systemd-journa/542 uname(name: 0x7ffdbaed8e00) = 0 4639.271 ( 0.008 ms): systemd-journa/542 ftruncate(fd: 11, length: 50331648) = 0 Cc: Adrian Hunter Cc: Borislav Petkov Cc: David Ahern Cc: Don Zickus Cc: Frederic Weisbecker Cc: Jiri Olsa Cc: Namhyung Kim Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-9ckfe8mvsedgkg6y80gz1ul8@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Handle legacy syscalls tracepoints

2015-03-21T17:53:36Z

Currently the code skips the first field with the expectation that it is 'nr'. But older kernels do not have the 'nr' field: field:int nr; offset:8; size:4; signed:1; Change perf-trace to drop the field if it exists after parsing the format file. This fixes the off-by-one problem with older kernels (e.g., RHEL6). e.g, perf-trace shows this for write: 1.515 ( 0.006 ms): dd/4245 write(buf: 2, count: 140733837536224 ) = 26 where 2 is really the fd, the huge number is really the buf address, etc. With this patch you get the more appropriate: 1.813 ( 0.003 ms): dd/6330 write(fd: 2, buf: 0x7fff22fc81f0, count: 25) = 25 Based-on-a-patch-by: David Ahern Acked-by: David Ahern Cc: Adrian Hunter Cc: Borislav Petkov Cc: Don Zickus Cc: Frederic Weisbecker Cc: Jiri Olsa Cc: Namhyung Kim Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-gvpdave4u2yq2jnzbcdznpvf@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Fix summary_only option

2015-03-21T17:53:31Z

The intent of the -s/--summary-only option is to just show a summary of the system calls and statistics without any of the individual events. Commit e596663ebb2 broke that by showing the interrupted lines: perf trace -i perf.data -s ... 0.741 ( 0.000 ms): sleep/31316 fstat(fd: 4, statbuf: 0x7ffc75ceb830 ) ... 0.744 ( 0.000 ms): sleep/31316 mmap(len: 100244, prot: READ, flags: PRIVATE, fd: 4 ) ... 0.747 ( 0.000 ms): perf/31315 write(fd: 3, buf: 0x7d4bb0, count: 8 ) ... ... Fix by checking for the summary only option. Signed-off-by: David Ahern Link: http://lkml.kernel.org/r/1426789383-19023-1-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo

perf tools: Add the bash completion for listing subsubcommands of perf trace

2015-03-19T16:53:26Z

The bash completion does not support listing subsubcommands for 'perf trace ', so fix it. Example: Before this patch: $ perf trace $ As shown above, the subsubcommands of perf trace does not come out. After this patch: $ perf trace record As shown above, the subsubcommands of perf trace can come out now. Signed-off-by: Yunlong Song Tested-by: Arnaldo Carvalho de Melo Cc: Paul Mackerras Cc: Peter Zijlstra Cc: Wang Nan Link: http://lkml.kernel.org/r/1426685758-25488-13-git-send-email-yunlong.song@huawei.com Signed-off-by: Arnaldo Carvalho de Melo

perf ordered_events: Shorten function signatures

2015-03-11T13:17:09Z

By keeping pointers to machines, evlist and tool in ordered_events. Cc: Adrian Hunter Cc: Borislav Petkov Cc: David Ahern Cc: Don Zickus Cc: Frederic Weisbecker Cc: Jiri Olsa Cc: Namhyung Kim Cc: Stephane Eranian Link: http://lkml.kernel.org/n/tip-0c6huyaf59mqtm2ek9pmposl@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo