summaryrefslogtreecommitdiffstats
path: root/tools/perf/builtin-trace.c
Commit message (Collapse)AuthorAgeFilesLines
...
* perf trace: Add seccomp beautifier related defines for older systemsArnaldo Carvalho de Melo2016-04-141-0/+11
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | Were the detached tarball (make perf-tar-src-pkg) build was failing because those definitions aren't available in the system headers. On RHEL7, for instance: builtin-trace.c: In function ‘syscall_arg__scnprintf_seccomp_op’: builtin-trace.c:1069:7: error: ‘SECCOMP_SET_MODE_STRICT’ undeclared (first use in this function) P_SECCOMP_SET_MODE_OP(STRICT); ^ builtin-trace.c:1069:7: note: each undeclared identifier is reported only once for each function it appears in builtin-trace.c:1070:7: error: ‘SECCOMP_SET_MODE_FILTER’ undeclared (first use in this function) P_SECCOMP_SET_MODE_OP(FILTER); ^ builtin-trace.c: In function ‘syscall_arg__scnprintf_seccomp_flags’: builtin-trace.c:1091:14: error: ‘SECCOMP_FILTER_FLAG_TSYNC’ undeclared (first use in this function) P_FLAG(TSYNC); ^ Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-4f8dzzwd7g6l5dzz693u7kul@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Do not accept --no-syscalls together with -eArnaldo Carvalho de Melo2016-04-131-0/+7
| | | | | | | | | | | | | | | | Doesn't make sense and was causing a segfault, fix it. # trace -e clone --no-syscalls --event sched:*exec firefox The -e option can't be used with --no-syscalls. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-ccrahezikdk2uebptzr1eyyi@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf evsel: Move some methods from session.[ch] to evsel.[ch]Arnaldo Carvalho de Melo2016-04-131-3/+3
| | | | | | | | | | | | | | Those were converted to be evsel methods long ago, move the source to where it belongs. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-vja8rjmkw3gd5ungaeyb5s2j@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Support callchains for --event tooArnaldo Carvalho de Melo2016-04-131-15/+26
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | We already were able to ask for callchains for a specific event: # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1 This would enable tracing just the "nanosleep" syscall, with callchains at syscall exit and would ask the kernel for frame pointer callchains to be enabled for the "sched:sched_switch" tracepoint event, its just that we were not resolving the callchain and printing it in 'perf trace', do it: # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1 0.425 ( 0.013 ms): usleep/6718 nanosleep(rqtp: 0x7ffcc1d16e20) ... 0.425 ( ): sched:sched_switch:usleep:6718 [120] S ==> swapper/2:0 [120]) __schedule+0xfe200402 ([kernel.kallsyms]) schedule+0xfe200035 ([kernel.kallsyms]) do_nanosleep+0xfe20006f ([kernel.kallsyms]) hrtimer_nanosleep+0xfe2000dc ([kernel.kallsyms]) sys_nanosleep+0xfe20007a ([kernel.kallsyms]) do_syscall_64+0xfe200062 ([kernel.kallsyms]) return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms]) __nanosleep+0xffff008b8cbe2010 (/usr/lib64/libc-2.22.so) 0.486 ( 0.073 ms): usleep/6718 ... [continued]: nanosleep()) = 0 __nanosleep+0x10 (/usr/lib64/libc-2.22.so) usleep+0x34 (/usr/lib64/libc-2.22.so) main+0x1eb (/usr/bin/usleep) __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so) _start+0x29 (/usr/bin/usleep) # Pretty compact, huh? DWARF callchains for raw_syscalls:sys_exit + frame pointer callchains for a tracepoint, if your hardware supports LBR, go wild with /call-graph=lbr/, guess the next step is to lift this from 'perf script': -F, --fields <str> comma separated output fields prepend with 'type:'. Valid types: hw,sw,trace,raw. Fields: comm,tid,pid,time,cpu,event,trace,ip,sym,dso,addr,symoff,period,iregs,brstack,brstacksym,flags Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2e7yiv5hqdm8jywlmfivvx2v@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Print unresolved symbol names as addressesArnaldo Carvalho de Melo2016-04-121-2/+3
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | Instead of having "[unknown]" as the name used for unresolved symbols, use the address in the callchain, in hexadecimal form: 28.801 ( 0.007 ms): qemu-system-x8/10065 ppoll(ufds: 0x55c98b39e400, nfds: 72, tsp: 0x7fffe4e4fe60, sigsetsize: 8) = 0 Timeout ppoll+0x91 (/usr/lib64/libc-2.22.so) [0x337309] (/usr/bin/qemu-system-x86_64) [0x336ab4] (/usr/bin/qemu-system-x86_64) main+0x1724 (/usr/bin/qemu-system-x86_64) __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so) [0xc59a9] (/usr/bin/qemu-system-x86_64) 35.265 (14.805 ms): gnome-shell/2287 ... [continued]: poll()) = 1 [0xf6fdd] (/usr/lib64/libc-2.22.so) g_main_context_iterate.isra.29+0x17c (/usr/lib64/libglib-2.0.so.0.4600.2) g_main_loop_run+0xc2 (/usr/lib64/libglib-2.0.so.0.4600.2) meta_run+0x2c (/usr/lib64/libmutter.so.0.0.0) main+0x3f7 (/usr/bin/gnome-shell) __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so) [0x2909] (/usr/bin/gnome-shell) Suggested-by: Milian Wolff <milian.wolff@kdab.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-fja1ods5vqpg42mdz09xcz3r@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Make "--call-graph" affect just "raw_syscalls:sys_exit"Arnaldo Carvalho de Melo2016-04-121-1/+21
| | | | | | | | | | | | | | | We don't need the callchains at the syscall enter tracepoint, just when finishing it at syscall exit, so reduce the overhead by asking for callchains just at syscall exit. Suggested-by: Milian Wolff <milian.wolff@kdab.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-fja1ods5vqpg42mdz09xcz3r@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf evsel: Do not use globals in config()Arnaldo Carvalho de Melo2016-04-121-1/+1
| | | | | | | | | | | | | | | | | Instead receive a callchain_param pointer to configure callchain aspects, not doing so if NULL is passed. This will allow fine grained control over which evsels in an evlist gets callchains enabled. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2mupip6khc92mh5x4nw9to82@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Exclude the kernel part of the callchain leading to a syscallArnaldo Carvalho de Melo2016-04-121-0/+13
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | The kernel parts are not that useful: # trace -m 512 -e nanosleep --call dwarf usleep 1 0.065 ( 0.065 ms): usleep/18732 nanosleep(rqtp: 0x7ffc4ee4e200) = 0 syscall_slow_exit_work ([kernel.kallsyms]) do_syscall_64 ([kernel.kallsyms]) return_from_SYSCALL_64 ([kernel.kallsyms]) __nanosleep (/usr/lib64/libc-2.22.so) usleep (/usr/lib64/libc-2.22.so) main (/usr/bin/usleep) __libc_start_main (/usr/lib64/libc-2.22.so) _start (/usr/bin/usleep) # So lets just use perf_event_attr.exclude_callchain_kernel to avoid collecting it in the ring buffer: # trace -m 512 -e nanosleep --call dwarf usleep 1 0.063 ( 0.063 ms): usleep/19212 nanosleep(rqtp: 0x7ffc3df10fb0) = 0 __nanosleep (/usr/lib64/libc-2.22.so) usleep (/usr/lib64/libc-2.22.so) main (/usr/bin/usleep) __libc_start_main (/usr/lib64/libc-2.22.so) _start (/usr/bin/usleep) # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-qctu3gqhpim0dfbcp9d86c91@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf evsel: Introduce fprintf_callchain() method out of fprintf_sym()Arnaldo Carvalho de Melo2016-04-121-2/+2
| | | | | | | | | | | | | | | In 'perf trace' we're just interested in printing callchains, and we don't want to use the symbol_conf.use_callchain, so move the callchain part to a new method. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-kcn3romzivcpxb3u75s9nz33@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf evsel: Rename print_ip() to fprintf_sym()Arnaldo Carvalho de Melo2016-04-121-2/+2
| | | | | | | | | | | | | | | | | | As it receives a FILE, and its more than just the IP, which can even be requested not to be printed. For consistency with other similar methods in tools/perf/, name it as perf_evsel__fprintf_sym() and make it return the number of bytes printed, just like 'fprintf(3)' Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-84gawlqa3lhk63nf0t9vnqnn@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Add support for printing call chains on sys_exit events.Milian Wolff2016-04-121-0/+22
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | Now, one can print the call chain for every encountered sys_exit event, e.g.: $ perf trace -e nanosleep --call-graph dwarf path/to/ex_sleep 1005.757 (1000.090 ms): ex_sleep/13167 nanosleep(...) = 0 syscall_slow_exit_work ([kernel.kallsyms]) syscall_return_slowpath ([kernel.kallsyms]) int_ret_from_sys_call ([kernel.kallsyms]) __nanosleep (/usr/lib/libc-2.23.so) [unknown] (/usr/lib/libQt5Core.so.5.6.0) QThread::sleep (/usr/lib/libQt5Core.so.5.6.0) main (path/to/ex_sleep) __libc_start_main (/usr/lib/libc-2.23.so) _start (path/to/ex_sleep) Note that it is advised to increase the number of mmap pages to prevent event losses when using this new feature. Often, adding `-m 10M` to the `perf trace` invocation is enough. This feature is also available in strace when built with libunwind via `strace -k`. Performance wise, this solution is much better: $ time find path/to/linux &> /dev/null real 0m0.051s user 0m0.013s sys 0m0.037s $ time perf trace -m 800M --call-graph dwarf find path/to/linux &> /dev/null real 0m2.624s user 0m1.203s sys 0m1.333s $ time strace -k find path/to/linux &> /dev/null real 0m35.398s user 0m10.403s sys 0m23.173s Note that it is currently not possible to configure the print output. Adding such a feature, similar to what is available in `perf script` via its `--fields` knob can be added later on. Signed-off-by: Milian Wolff <milian.wolff@kdab.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> LPU-Reference: 1460115255-17648-1-git-send-email-milian.wolff@kdab.com [ Split from a larger patch, do not print the IP, left align, remove dup call symbol__init(), added man page entry ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf bpf: Clone bpf stdout events in multiple bpf scriptsWang Nan2016-04-121-0/+7
| | | | | | | | | | | | | | | | | | | | | | | | | | | This patch allows cloning bpf-output event configuration among multiple bpf scripts. If there exist a map named '__bpf_output__' and not configured using 'map:__bpf_output__.event=', this patch clones the configuration of another '__bpf_stdout__' map. For example, following command: # perf trace --ev bpf-output/no-inherit,name=evt/ \ --ev ./test_bpf_trace.c/map:__bpf_stdout__.event=evt/ \ --ev ./test_bpf_trace2.c usleep 100000 equals to: # perf trace --ev bpf-output/no-inherit,name=evt/ \ --ev ./test_bpf_trace.c/map:__bpf_stdout__.event=evt/ \ --ev ./test_bpf_trace2.c/map:__bpf_stdout__.event=evt/ \ usleep 100000 Signed-off-by: Wang Nan <wangnan0@huawei.com> Suggested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Zefan Li <lizefan@huawei.com> Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/1460128045-97310-4-git-send-email-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Move syscall table id <-> name routines to separate classArnaldo Carvalho de Melo2016-04-081-13/+11Star
| | | | | | | | | | | | | | | | | | | | We're using libaudit for doing name to id and id to syscall name translations, but that makes 'perf trace' to have to wait for newer libaudit versions supporting recently added syscalls, such as "userfaultfd" at the time of this changeset. We have all the information right there, in the kernel sources, so move this code to a separate place, wrapped behind functions that will progressively use the kernel source files to extract the syscall table for use in 'perf trace'. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-i38opd09ow25mmyrvfwnbvkj@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify mode_t argumentsArnaldo Carvalho de Melo2016-04-081-0/+3
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | When reading the syscall tracepoint /format file, look for arguments of type "mode_t" and attach a beautifier: [root@jouet ~]# cat ~/bin/tp_with_fields_of_type #!/bin/bash grep -w $1 /sys/kernel/tracing/events/syscalls/*/format | sed -r 's%.*sys_enter_(.*)/format.*%\1%g' | paste -d, -s # tp_with_fields_of_type umode_t chmod,creat,fchmodat,fchmod,mkdirat,mkdir,mknodat,mknod,mq_open,openat,open # Testing it: #define S_ISUID 0004000 #define S_ISGID 0002000 #define S_ISVTX 0001000 #define S_IRWXU 0000700 #define S_IRUSR 0000400 #define S_IWUSR 0000200 #define S_IXUSR 0000100 #define S_IRWXG 0000070 #define S_IRGRP 0000040 #define S_IWGRP 0000020 #define S_IXGRP 0000010 #define S_IRWXO 0000007 #define S_IROTH 0000004 #define S_IWOTH 0000002 #define S_IXOTH 0000001 # for mode in 4000 2000 1000 700 400 200 100 70 40 20 10 7 4 2 1 ; do \ echo -n $mode '->' ; trace --no-inherit -e chmod,fchmodat,fchmod chmod $mode x; \ done 4000 -> 0.338 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: ISUID) = 0 2000 -> 0.438 ( 0.015 ms): fchmodat(dfd: CWD, filename: x, mode: ISGID) = 0 1000 -> 0.677 ( 0.040 ms): fchmodat(dfd: CWD, filename: x, mode: ISVTX) = 0 700 -> 0.394 ( 0.013 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXU) = 0 400 -> 0.337 ( 0.010 ms): fchmodat(dfd: CWD, filename: x, mode: IRUSR) = 0 200 -> 0.259 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IWUSR) = 0 100 -> 0.249 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXUSR) = 0 70 -> 0.266 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXG) = 0 40 -> 0.329 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IRGRP) = 0 20 -> 0.250 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IWGRP) = 0 10 -> 0.259 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXGRP) = 0 7 -> 0.249 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXO) = 0 4 -> 0.278 ( 0.011 ms): fchmodat(dfd: CWD, filename: x, mode: IROTH) = 0 2 -> 0.276 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IWOTH) = 0 1 -> 0.250 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXOTH) = 0 # # trace --no-inherit -e chmod,fchmodat,fchmod chmod 7777 x 0.258 ( 0.011 ms): fchmodat(dfd: CWD, filename: x, mode: IALLUGO) = 0 # trace --no-inherit -e chmod,fchmodat,fchmod chmod 7770 x 0.258 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: ISUID|ISGID|ISVTX|IRWXU|IRWXG) = 0 # trace --no-inherit -e chmod,fchmodat,fchmod chmod 777 x 0.293 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXUGO # Now lets see if check by using the tracepoint for that specific syscall, instead of raw_syscalls:sys_enter as 'trace' does for its strace fu: # trace --no-inherit --ev syscalls:sys_enter_fchmodat -e fchmodat chmod 666 x 0.255 ( ): syscalls:sys_enter_fchmodat:dfd: 0xffffffffffffff9c, filename: 0x55db32a3f0f0, mode: 0x000001b6) 0.268 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: IRUGO|IWUGO ) = 0 # Perfect, 0x1bc == 0666. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-18e8zfgbkj83xo87yoom43kd@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify pid_t argumentsArnaldo Carvalho de Melo2016-04-071-53/+57
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | When reading the syscall tracepoint /format file, look for arguments of type "pid_t" and attach the PID beautifier, that will do a lookup on the threads it knows, i.e. the ones that came from PERF_RECORD_COMM events and add the COMM after the pid in such args: Excerpt of a system wide trace for syscalls with pid_t args: 55602.977 ( 0.006 ms): bash/12122 setpgid(pid: 24347 (bash), pgid: 24347 (bash)) = 0 55603.024 ( 0.004 ms): bash/24347 setpgid(pid: 24347 (bash), pgid: 24347 (bash)) = 0 55691.527 (88.397 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1720, options: UNTRACED|CONTINUED) ... 55692.479 ( 0.952 ms): git/24347 wait4(upid: 24368, stat_addr: 0x7ffe030d5724) ... 55694.549 ( 2.070 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4fc10) = 24369 (pre-commit) 55694.575 ( 0.002 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f650, options: NOHANG) = -1 ECHILD No child processes 55695.934 ( 0.010 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f2d0, options: NOHANG) = 24370 (git) 55695.937 ( 0.001 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f2d0, options: NOHANG) = -1 ECHILD No child processes 55717.963 ( 0.000 ms): pre-commit/24371 ... [continued]: wait4()) = 24372 55717.978 (21.468 ms): :24371/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) ... 55718.087 ( 0.109 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) = 24373 (tr) 55718.187 ( 0.096 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) = 24374 (wc) 55718.218 ( 0.002 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4eed0, options: NOHANG) = -1 ECHILD No child processes 55718.367 ( 0.005 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f1d0, options: NOHANG) = 24371 (pre-commit) 55718.369 ( 0.001 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f1d0, options: NOHANG) = -1 ECHILD No child processes 55741.021 (49.494 ms): git/24347 ... [continued]: wait4()) = 24368 (pre-commit) 74146.427 (18319.601 ms): git/24347 wait4(upid: 24375 (git), stat_addr: 0x7ffe030d6824) ... 74149.036 ( 0.891 ms): bash/24391 wait4(upid: -1, stat_addr: 0x7ffe0cee0560) = 24393 (sed) Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-75yl9hzjhb020iadc81gdj8t@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify set_tid_address, getpid, getppid return valuesArnaldo Carvalho de Melo2016-04-061-0/+3
| | | | | | | | | | | | | | | | | | Showing the COMM for that return, if available. # trace -e getpid,getppid,set_tid_address 490.007 ( 0.005 ms): sh/8250 getpid(...) = 8250 (sh) 490.014 ( 0.001 ms): sh/8250 getppid(...) = 7886 (make) 491.156 ( 0.004 ms): install/8251 set_tid_address(tidptr: 0x7f204a9d4ad0) = 8251 (install) ^C Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-psbpplqupatom9x4uohbxid5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Infrastructure to show COMM strings for syscalls returning PIDsArnaldo Carvalho de Melo2016-04-061-4/+15
| | | | | | | | | | | | | | | | | | | | | | | Starting with clone, waitid and wait4: # trace -e waitid,wait4 1.385 ( 1.385 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1720, options: UNTRACED|CONTINUED) = 1210 (ls) 1.426 ( 0.002 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1150, options: NOHANG|UNTRACED|CONTINUED) = 0 3.293 ( 0.604 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee0560 ) = 1214 (sed) 3.342 ( 0.002 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee01d0, options: NOHANG ) = -1 ECHILD No child processes 3.576 ( 0.016 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee0550, options: NOHANG|UNTRACED|CONTINUED) = 1211 (bash) ^C# trace -e clone 0.027 ( 0.000 ms): systemd/1 ... [continued]: clone()) = 1227 (systemd) 0.050 ( 0.000 ms): systemd/1227 ... [continued]: clone()) = 0 ^C[root@jouet ~]# Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-lyf5d3y5j15wikjb6pe6ukoi@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify wait4/waitid 'options' argumentArnaldo Carvalho de Melo2016-04-061-0/+5
| | | | | | | | | | | | | | | | | | | # trace -e waitid,wait4 0.557 ( 0.557 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f449f0) = 27336 1.250 ( 0.685 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f449f0) = 27337 1.312 ( 0.002 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f44690, options: NOHANG) = -1 ECHILD No child processes 1.550 ( 0.015 ms): bash/3856 wait4(upid: -1, stat_addr: 0x7ffd02f44990, options: NOHANG|UNTRACED|CONTINUED) = 27335 1.552 ( 0.001 ms): bash/3856 wait4(upid: -1, stat_addr: 0x7ffd02f44990, options: NOHANG|UNTRACED|CONTINUED) = 0 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-i5vlo5n5jv0amt8bkyicmdxh@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify sched_setscheduler 'policy' argumentArnaldo Carvalho de Melo2016-04-061-0/+4
| | | | | | | | | | | | | | | $ trace -e sched_setscheduler chrt -f 1 usleep 1 chrt: failed to set pid 0's policy: Operation not permitted 0.005 ( 0.005 ms): chrt/19189 sched_setscheduler(policy: FIFO, param: 0x7ffec5273d70) = -1 EPERM Operation not permitted $ Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-i5vlo5n5jv0amt8bkyicmdxh@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIMEArnaldo Carvalho de Melo2016-04-011-2/+11
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | This was causing bogus values to be shown at the timestamp column: Before: # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10 94631143.385 ( 0.001 ms): brk( ) = 0x555555757000 94631143.398 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7ffff7ff6000 94631143.406 ( 0.004 ms): access(filename: 0xf7df9e10, mode: R ) = -1 ENOENT No such file or directory 94631143.412 ( 0.004 ms): open(filename: 0xf7df8761, flags: CLOEXEC) = 3 94631143.415 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fffffffd6b0 ) = 0 94631143.419 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7ffff7fdb000 94631143.420 ( 0.001 ms): close(fd: 3 ) = 0 94631143.432 ( 0.004 ms): open(filename: 0xf7ff6640, flags: CLOEXEC) = 3 <SNIP> After: # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10 0.022 ( 0.001 ms): brk( ) = 0x55d7668a6000 0.037 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7f8fbeb97000 0.123 ( 0.083 ms): access(filename: 0xbe995e10, mode: R ) = -1 ENOENT No such file or directory 0.130 ( 0.004 ms): open(filename: 0xbe994761, flags: CLOEXEC) = 3 0.133 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fff6487a890 ) = 0 0.138 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8fbeb7c000 0.140 ( 0.001 ms): close(fd: 3 ) = 0 0.151 ( 0.004 ms): open(filename: 0xbeb97640, flags: CLOEXEC) = 3 <SNIP> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-p7m8llv81iv55ekxexdp5n57@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Introduce function to set the base timestampArnaldo Carvalho de Melo2016-04-011-5/+11
| | | | | | | | | | | | | | | | | | | That is used in both live runs, i.e.: # trace ls As when processing events recorded in a perf.data file: # trace -i perf.data Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-901l6yebnzeqg7z8mbaf49xb@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Pretty print getrandom() argsArnaldo Carvalho de Melo2016-03-311-0/+26
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | # trace -e getrandom 35622.560 ( 0.023 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35622.585 ( 0.006 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35622.594 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35627.395 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16 35630.940 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16 35718.613 ( 0.015 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35718.629 ( 0.005 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35718.637 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 35719.355 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16 35721.042 ( 0.030 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16 41090.830 ( 0.012 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41090.845 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41090.851 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41091.750 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16 41091.823 ( 0.006 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16 41122.078 ( 0.053 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41122.129 ( 0.009 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41122.139 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16 41124.492 ( 0.007 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16 41124.470 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16 41590.832 ( 0.014 ms): chrome/5957 getrandom(buf: 0x7fabac7b15b0, count: 16, flags: NONBLOCK ) = 16 41590.884 ( 0.004 ms): chrome/5957 getrandom(buf: 0x7fabac7b15c0, count: 16, flags: NONBLOCK ) = 16 Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-gca0n1p3aca3depey703ph2q@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Pretty print seccomp() argsArnaldo Carvalho de Melo2016-03-311-0/+47
| | | | | | | | | | | | | | | | | E.g: # trace -e seccomp 200.061 (0.009 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC ) = -1 EFAULT Bad address 200.910 (0.121 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC, uargs: 0x7fff57479fe0) = 0 Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-t369uckshlwp4evkks4bcoo7@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Do not process PERF_RECORD_LOST twiceArnaldo Carvalho de Melo2016-03-311-0/+1
| | | | | | | | | | | | | | | | | | 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 <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-wus2zlhw3qo24ye84ewu4aqw@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf tools: Add cpumode to struct perf_sampleArnaldo Carvalho de Melo2016-03-231-5/+4Star
| | | | | | | | | | | | | | | | | | To avoid parsing event->header.misc in many locations. This will also allow setting perf.sample.{ip,cpumode} in a single place, from tracepoint fields, as needed by 'perf kvm' with PPC guests, where the guest hardware counters is not available at the host. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Hemant Kumar <hemant@linux.vnet.ibm.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com> Cc: Ravi Bangoria <ravi.bangoria@linux.vnet.ibm.com> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-qp3yradhyt6q3wl895b1aat0@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Check and discard not only 'nr' but also '__syscall_nr'Taeung Song2016-02-291-2/+6
| | | | | | | | | | | | | | | | | | Format fields of a syscall have the first variable '__syscall_nr' or 'nr' that mean the syscall number. But it isn't relevant here so drop it. 'nr' among fields of syscall was renamed '__syscall_nr'. So add exception handling to drop '__syscall_nr' and modify the comment for this excpetion handling. Reported-by: Arnaldo Carvalho de Melo <acme@redhat.com> Signed-off-by: Taeung Song <treeze.taeung@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Steven Rostedt <rostedt@goodmis.org> Link: http://lkml.kernel.org/r/1456492465-5946-1-git-send-email-treeze.taeung@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Print content of bpf-output eventWang Nan2016-02-261-1/+34
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | With this patch the contend of BPF output event is printed by 'perf trace'. For example: # ./perf trace -a --ev bpf-output/no-inherit,name=evt/ \ --ev ./test_bpf_trace.c/map:channel.event=evt/ \ usleep 100000 ... 1.787 ( 0.004 ms): usleep/3832 nanosleep(rqtp: 0x7ffc78b18980 ) ... 1.787 ( ): evt:Raise a BPF event!..) 1.788 ( ): perf_bpf_probe:func_begin:(ffffffff810e97d0)) ... 101.866 (87.038 ms): gmain/1654 poll(ufds: 0x7f57a80008c0, nfds: 2, timeout_msecs: 1000 ) ... 101.866 ( ): evt:Raise a BPF event!..) 101.867 ( ): perf_bpf_probe:func_end:(ffffffff810e97d0 <- ffffffff81796173)) 101.869 (100.087 ms): usleep/3832 ... [continued]: nanosleep()) = 0 ... (There is an extra ')' at the end of several lines. However, it is another problem, unrelated to this commit.) Where test_bpf_trace.c is: /************************ BEGIN **************************/ #include <uapi/linux/bpf.h> struct bpf_map_def { unsigned int type; unsigned int key_size; unsigned int value_size; unsigned int max_entries; }; #define SEC(NAME) __attribute__((section(NAME), used)) static u64 (*ktime_get_ns)(void) = (void *)BPF_FUNC_ktime_get_ns; static int (*trace_printk)(const char *fmt, int fmt_size, ...) = (void *)BPF_FUNC_trace_printk; static int (*get_smp_processor_id)(void) = (void *)BPF_FUNC_get_smp_processor_id; static int (*perf_event_output)(void *, struct bpf_map_def *, int, void *, unsigned long) = (void *)BPF_FUNC_perf_event_output; struct bpf_map_def SEC("maps") channel = { .type = BPF_MAP_TYPE_PERF_EVENT_ARRAY, .key_size = sizeof(int), .value_size = sizeof(u32), .max_entries = __NR_CPUS__, }; static inline int __attribute__((always_inline)) func(void *ctx, int type) { char output_str[] = "Raise a BPF event!"; char err_str[] = "BAD %d\n"; int err; err = perf_event_output(ctx, &channel, get_smp_processor_id(), &output_str, sizeof(output_str)); if (err) trace_printk(err_str, sizeof(err_str), err); return 1; } SEC("func_begin=sys_nanosleep") int func_begin(void *ctx) {return func(ctx, 1);} SEC("func_end=sys_nanosleep%return") int func_end(void *ctx) { return func(ctx, 2);} char _license[] SEC("license") = "GPL"; int _version SEC("version") = LINUX_VERSION_CODE; /************************* END ***************************/ Signed-off-by: Wang Nan <wangnan0@huawei.com> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Li Zefan <lizefan@huawei.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/1456479154-136027-8-git-send-email-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Call bpf__apply_obj_config in 'perf trace'Wang Nan2016-02-261-0/+11
| | | | | | | | | | | | | | | | | | | | | | | Without this patch BPF map configuration is not applied. Command like this: # ./perf trace --ev bpf-output/no-inherit,name=evt/ \ --ev ./test_bpf_trace.c/map:channel.event=evt/ \ usleep 100000 Load BPF files without error, but since map:channel.event=evt is not applied, bpf-output event not work. This patch allows 'perf trace' load and run BPF scripts. Signed-off-by: Wang Nan <wangnan0@huawei.com> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Li Zefan <lizefan@huawei.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/1456479154-136027-7-git-send-email-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf subcmd: Create subcmd libraryJosh Poimboeuf2015-12-171-2/+2
| | | | | | | | | | | | | | | Move the subcommand-related files from perf to a new library named libsubcmd.a. Since we're moving files anyway, go ahead and rename 'exec_cmd.*' to 'exec-cmd.*' to be consistent with the naming of all the other files. Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/c0a838d4c878ab17fee50998811612b2281355c1.1450193761.git.jpoimboe@redhat.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Add cmd string table to decode sys_bpf first argArnaldo Carvalho de Melo2015-10-291-0/+7
| | | | | | | | | | | | | | # perf trace -e bpf perf record -e /tmp/foo.o -a 362.779 (0.130 ms): perf/3451 bpf(cmd: PROG_LOAD, uattr: 0x7ffe9a6825d0, size: 48) = 3 Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexei Starovoitov <ast@plumgrid.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2b0nknu53baz9e0wj4thcdd8@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf evsel: Propagate error info from tp_formatJiri Olsa2015-09-151-8/+11
| | | | | | | | | | | | | | | | | | | | | | | | | Propagate error info from tp_format via ERR_PTR to get it all the way down to the parse-event.c tracepoint adding routines. Following functions now return pointer with encoded error: - tp_format - trace_event__tp_format - perf_evsel__newtp_idx - perf_evsel__newtp This affects several other places in perf, that cannot use pointer check anymore, but must utilize the err.h interface, when getting error information from above functions list. Signed-off-by: Jiri Olsa <jolsa@kernel.org> Cc: David Ahern <dsahern@gmail.com> Cc: Matt Fleming <matt@codeblueprint.co.uk> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl> Cc: Raphael Beamonte <raphael.beamonte@gmail.com> Link: http://lkml.kernel.org/r/1441615087-13886-5-git-send-email-jolsa@kernel.org [ Add two missing ERR_PTR() and one IS_ERR() ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* tools lib api fs: Move debugfs__strerror_open into tracing_path.c objectJiri Olsa2015-09-041-2/+3
| | | | | | | | | | | | | | | | | | | Moving debugfs__strerror_open out of api/fs/debugfs.c, because it's not debugfs specific. It'll be changed to consider tracefs mount as well in following patches. Renaming it into tracing_path__strerror_open_tp to fit into the namespace. No functional change is intended. Signed-off-by: Jiri Olsa <jolsa@kernel.org> Reviewed-by: Matt Fleming <matt.fleming@intel.com> Cc: Raphael Beamonte <raphael.beamonte@gmail.com> Cc: David Ahern <dsahern@gmail.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl> Cc: Steven Rostedt <rostedt@goodmis.org> Link: http://lkml.kernel.org/r/1441180605-24737-6-git-send-email-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Add header with copyright and background infoArnaldo Carvalho de Melo2015-08-281-0/+19
| | | | | | | | | | | | Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-5yqtfs728r1j1u8zmg8ufxwm@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Move vfs_getname storage to per thread areaArnaldo Carvalho de Melo2015-08-141-11/+27
| | | | | | | | | | | | | | | | | | | We were storing the vfs_getname payload (i.e. ptr->string) into the trace wide storage area (struct trace), so that we could use the last payload when setting up the fd->pathname per thread tables, oops, not a good idea for multi cpu tracing sessions... Fix it by moving it to the per thread area (struct thread_trace). Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-3j05ttqyaem7kh7oubvr1keo@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Beautify keyctl's option argArnaldo Carvalho de Melo2015-08-121-0/+10
| | | | | | | | | | | | | | | | | | | | | | | 8.697 (0.103 ms): pool/2343 keyctl(option: GET_PERSISTENT, arg2: 1000, arg3: 4294967294, arg4: 140703061514067, arg5: 140703692383680) = 1023192809 8.763 (0.049 ms): pool/2343 keyctl(option: SEARCH, arg2: 1023192809, arg3: 140703745767772, arg4: 140703745767832, arg5: 4294967294) = 140224497 8.789 (0.016 ms): pool/2343 keyctl(option: SEARCH, arg2: 140224497, arg3: 140703745767814, arg4: 140703745767900) = 512300257 8.807 (0.011 ms): pool/2343 keyctl(option: READ, arg2: 512300257 ) = 13 8.822 (0.008 ms): pool/2343 keyctl(option: READ, arg2: 512300257, arg3: 140703061514000, arg4: 13 ) = 13 8.837 (0.007 ms): pool/2343 keyctl(option: READ, arg2: 140224497 ) = 4 8.852 (0.009 ms): pool/2343 keyctl(option: READ, arg2: 140224497, arg3: 140703061514000, arg4: 4 ) = 4 8.869 (0.010 ms): pool/2343 keyctl(option: SEARCH, arg2: 140224497, arg3: 140703745767772, arg4: 140703061514032) = -1 ENOKEY Required key not available 8.892 (0.017 ms): pool/2343 keyctl(option: DESCRIBE, arg2: 512300257 ) = 43 8.910 (0.012 ms): pool/2343 keyctl(option: DESCRIBE, arg2: 512300257, arg3: 140703061544384, arg4: 43) = 43 Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-013ab219irsxngyumrf5gp8s@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Use the FD beautifier for socket syscall fdsArnaldo Carvalho de Melo2015-08-121-6/+12
| | | | | | | | | | | | | | But we really should have something like 'strace -yy' here... Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-eyrt1ypfq68u4ljagyk2nj1i@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Add missing clockid entriesArnaldo Carvalho de Melo2015-08-121-1/+2
| | | | | | | | | | | | | | | | | | | | We were missing: CLOCK_BOOTTIME, CLOCK_REALTIME_ALARM, CLOCK_BOOTTIME_ALARM, CLOCK_SGI_CYCLE and CLOCK_TAI. Add them. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-d67rwqtwm9jyenwes98kr0cr@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Associate some more syscall args with the getname beautifierArnaldo Carvalho de Melo2015-08-121-5/+18
| | | | | | | | | | | | | | | | | | This time using 'trinity' to test these: fchmodat, futimesat, llistxattr, lremovexattr, lstat, mknodat, mq_unlink, stat and vmsplice. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-a1uqu249nwwh0ixrhm80k4a4@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Add total time column to summary.Milian Wolff2015-08-061-5/+5
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | It is cumbersome to manually calculate the total time spent in a given syscall by multiplying the average value with the number of calls. Instead, we now do this directly inside perf trace. Note that this is also done by 'strace', which even adds a column with relative numbers - something we could do in the future. Example: perf trace -s find /some/folder > /dev/null Summary of events: find (19976), 700123 events, 100.0%, 0.000 msec syscall calls total min avg max stddev (msec) (msec) (msec) (msec) (%) --------------- -------- --------- --------- --------- --------- ------ read 4 0.006 0.001 0.002 0.003 27.42% write 8046 9.617 0.001 0.001 0.035 0.56% open 34196 40.384 0.001 0.001 0.071 0.30% close 68375 57.104 0.001 0.001 0.076 0.25% stat 4 0.004 0.001 0.001 0.001 3.14% fstat 34189 27.518 0.001 0.001 0.060 0.34% mmap 13 0.029 0.001 0.002 0.003 10.74% mprotect 6 0.018 0.002 0.003 0.005 17.04% munmap 3 0.014 0.003 0.005 0.006 24.87% brk 87 0.490 0.001 0.006 0.016 6.50% ioctl 3 0.004 0.001 0.001 0.003 36.39% access 1 0.004 0.004 0.004 0.004 0.00% uname 1 0.001 0.001 0.001 0.001 0.00% getdents 68393 143.600 0.001 0.002 0.187 0.95% fchdir 68371 56.980 0.001 0.001 0.111 0.39% arch_prctl 1 0.001 0.001 0.001 0.001 0.00% openat 34184 41.737 0.001 0.001 0.102 0.41% newfstatat 34184 41.180 0.001 0.001 0.064 0.34% Signed-off-by: Milian Wolff <milian.wolff@kdab.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> LPU-Reference: 1438853069-5902-1-git-send-email-milian.wolff@kdab.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Write to stderr by defaultMilian Wolff2015-08-051-1/+1
| | | | | | | | | | | | | | | | Without this patch, it is cumbersome to read the trace output but ignoring the normal, potentially verbose, output of the debuggee. One common example is doing something like the following: perf trace -s find /tmp > /dev/null Without this patch, the trace summary will be lost. Now, it will still be printed at the end. This behavior is also applied by strace. Cc: Milian Wolff <milian.wolff@kdab.com> Cc: David Ahern <dsahern@gmail.com> Link: http://lkml.kernel.org/n/tip-tqnks6y2cnvm5f9g2dsfr7zl@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Use vfs_getname syscall arg beautifier in more syscallsArnaldo Carvalho de Melo2015-08-051-9/+65
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | Those were covered and tested in this cset: access, chdir, chmod, chown, chroot, creat, getxattr, inotify_add_watch, lchown, lgetxattr, listxattr, lsetxattr, mkdir, mkdirat, mknod, rmdir, faccessat, newfstatat, openat, readlink, readlinkat, removexattr, setxattr, statfs, swapon, swapoff, truncate, unlinkat, utime, utimes, utimensat. E.g.: # trace -e statfs,access,mkdir mkdir /tmp/bla 0.285 (0.020 ms): mkdir/2799 access(filename: /etc/ld.so.preload, mode: R ) = -1 ENOENT No such file or directory 1.070 (0.032 ms): mkdir/2799 statfs(pathname: /sys/fs/selinux, buf: 0x7ffeafbdc930) = 0 1.087 (0.013 ms): mkdir/2799 statfs(pathname: /sys/fs/selinux, buf: 0x7ffeafbdc820) = 0 1.189 (0.014 ms): mkdir/2799 access(filename: /etc/selinux/config ) = 0 1.905 (0.610 ms): mkdir/2799 mkdir(pathname: /tmp/bla, mode: 511 ) = 0 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-wbqtnlktquun3wtpjdz3okul@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> and an empty message aborts the commit.
* perf trace: Deref sys_enter pointer args with contents from probe:vfs_getnameArnaldo Carvalho de Melo2015-08-051-1/+75
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | To work like strace and dereference syscall pointer args we need to insert probes (or tracepoints) right after we copy those bytes from userspace. Since we're formatting the syscall args at raw_syscalls:sys_enter time, we need to have a formatter that just stores the position where, later, when we get the probe:vfs_getname, we can insert the pointer contents. Now, if a probe:vfs_getname with this format is in place: # perf probe -l probe:vfs_getname (on getname_flags:72@/home/git/linux/fs/namei.c with pathname) That was, in this case, put in place with: # perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event: probe:vfs_getname (on getname_flags:72 with pathname=filename:string) You can now use it in all perf tools, such as: perf record -e probe:vfs_getname -aR sleep 1 # Then 'perf trace' will notice that and do the pointer -> contents expansion: # trace -e open touch /tmp/bla 0.165 (0.010 ms): touch/17752 open(filename: /etc/ld.so.cache, flags: CLOEXEC) = 3 0.195 (0.011 ms): touch/17752 open(filename: /lib64/libc.so.6, flags: CLOEXEC) = 3 0.512 (0.012 ms): touch/17752 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3 0.582 (0.012 ms): touch/17752 open(filename: /tmp/bla, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: 438) = 3 # Roughly equivalent to strace's output: # strace -rT -e open touch /tmp/bla 0.000000 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000039> 0.000317 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000102> 0.001461 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 <0.000072> 0.000405 open("/tmp/bla", O_WRONLY|O_CREAT|O_NOCTTY|O_NONBLOCK, 0666) = 3 <0.000055> 0.000641 +++ exited with 0 +++ # Now we need to either look for at all syscalls that are marked as pointers and have some well known names ("filename", "pathname", etc) and set the arg formatter to the one used for the "open" syscall in this patch. This implementation works for syscalls with just a string being copied from userspace, for matching syscalls with more than one string being copied via the same probe/trace point (vfs_getname) we need to extend the vfs_getname probe spec to include the pointer too, but there are some problems with that in 'perf probe' or the kernel kprobes code, need to investigate before considering supporting multiple strings per syscall. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-xvuwx6nuj8cf389kf9s2ue2s@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Use a constant for the syscall formatting bufferArnaldo Carvalho de Melo2015-08-051-3/+5
| | | | | | | | | | | | | | | | | | | | | | We were using it as a magic number, 1024, fix that. Eventually we need to stop doing it per line, and do it per arg, traversing the args at output time, to avoid the memmove() calls that will be used in the next cset to replace pointers present at raw_syscalls:sys_enter time with its contents that appear at probe:vfs_getname time, before raw_syscalls:sys_exit time. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-4sz3wid39egay1pp8qmbur4u@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Remember if the vfs_getname tracepoint/kprobe is in placeArnaldo Carvalho de Melo2015-08-051-4/+6
| | | | | | | | | | | | | | | | | So that we can later decide if we will store where to expand the pathname once we are handling vfs_getname or if we should instead just go on and straight away print the pointer. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ytxk5s5jpc50wahffmlxgxuw@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Do not show syscall tracepoint filter in the --no-syscalls caseArnaldo Carvalho de Melo2015-08-051-2/+3
| | | | | | | | | | | | | | | | | | | We were accessing trace->syscalls.events members even when that struct wasn't initialized, i.e. --no-syscalls was specified on the command line, fix it to show that, still in debug mode, when we have an event qualifier list, i.e. when we actually are doing subset syscall tracing. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Fixes: 19867b6186f3 ("perf trace: Use event filters for the event qualifier list") Link: http://lkml.kernel.org/n/tip-7980ym6vujgh3yiai0cqzc88@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf python: Remove dependency on 'machine' methodsArnaldo Carvalho de Melo2015-07-291-1/+1
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | The python binding still doesn't provide symbol resolving facilities, but the recent addition of the trace_event__register_resolver() function made it add as a dependency the machine__resolve_kernel_addr() method, that in turn drags all the symbol resolving code. The problem: [root@zoo ~]# perf test -v python 17: Try 'import perf' in python, checking link problems : --- start --- test child forked, pid 6853 Traceback (most recent call last): File "<stdin>", line 1, in <module> ImportError: /tmp/build/perf/python/perf.so: undefined symbol: machine__resolve_kernel_addr test child finished with -1 ---- end ---- Try 'import perf' in python, checking link problems: FAILED! [root@zoo ~]# Fix it by requiring this function to receive the resolver as a parameter, just like pevent_register_function_resolver(), i.e. do not explicitely refer to an object file not included in tools/perf/util/python-ext-sources. [root@zoo ~]# perf test python 17: Try 'import perf' in python, checking link problems : Ok [root@zoo ~]# Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Fixes: c3168b0db93a ("perf symbols: Provide libtraceevent callback to resolve kernel symbols") Link: http://lkml.kernel.org/n/tip-vxlhh95v2em9zdbgj3jm7xi5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Provide libtracevent with a kernel symbol resolverArnaldo Carvalho de Melo2015-07-241-0/+3
| | | | | | | | | | | | | | | | | | | | | | | | So that beautifiers wanting to resolve kernel function addresses to names can do its work, now, for instance, the 'timer' tracepoints beautifiers works with 'perf trace', see the "function=tick..." part: # perf trace --event timer:hrtimer_start <SNIP> 0.000 timer:hrtimer_start:hrtimer=0xffff88026f3101c0 function=tick_sched_timer/0x0 expires=52098339000000 softexpires=52098339000000) 0.003 timer:hrtimer_start:hrtimer=0xffff88026f3101c0 function=tick_sched_timer/0x0 expires=52098339000000 softexpires=52098339000000) <SNIP> Reported-by: Thomas Gleixner <tglx@linutronix.de> Acked-by: David Ahern <dsahern@gmail.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Link: http://lkml.kernel.org/n/tip-n4i0hxpbl1tnleiqkok47fw2@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Support 'strace' syscall event groupsArnaldo Carvalho de Melo2015-07-201-1/+5
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | I.e.: $ cat ~/share/perf-core/strace/groups/file access chmod creat execve faccessat getcwd lstat mkdir open openat quotactl readlink rename rmdir stat statfs symlink unlink $ Then, on a quiet desktop, try running this and then moving your mouse to see the deluge of mouse related activity: # perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event: probe:vfs_getname (on getname_flags:72 with pathname=filename:string) You can now use it in all perf tools, such as: perf record -e probe:vfs_getname -aR sleep 1 # # trace --ev probe:vfs_getname --filter-pids 2232 -e file 0.042 (0.042 ms): mousetweaks/2235 open(filename: 0x14e3910, mode: 438 ) ... 0.042 ( ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/cursors/xterm") 0.100 (0.100 ms): mousetweaks/2235 ... [continued]: open()) = -1 ENOENT No such file or directory 0.142 (0.018 ms): mousetweaks/2235 open(filename: 0x14c3c10, mode: 438 ) ... 0.142 ( ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/index.theme") 0.192 (0.069 ms): mousetweaks/2235 ... [continued]: open()) = -1 ENOENT No such file or directory 0.230 (0.017 ms): mousetweaks/2235 open(filename: 0x14c3c10, mode: 438 ) ... 0.230 ( ): probe:vfs_getname:(ffffffff812230bc) pathname="/usr/share/icons/Adwaita/cursors/xterm") 0.253 (0.041 ms): mousetweaks/2235 ... [continued]: open()) = 14 0.459 (0.008 ms): mousetweaks/2235 open(filename: 0x14e3910, mode: 438 ) ... 0.459 ( ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/cursors/left_side") 0.468 (0.017 ms): mousetweaks/2235 ... [continued]: open()) = -1 ENOENT No such file or directory Need to combine that raw_syscalls:sys_enter(open) + probe:vfs_getname + raw_syscalls:sys_exit(open) sequence... Now, if you're bored, please write some more syscall groups, like the ones in 'strace' and send it our way :-) Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-a42xklu59lcbxp7bbnic74a8@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf strlist: Make dupstr be the default and part of an extensible config parmArnaldo Carvalho de Melo2015-07-201-1/+1
| | | | | | | | | | | | | | | | So that we can pass more info to strlist__new() without having to change its function signature, just adding entries to the strlist_config struct with sensible defaults for when those fields are not specified. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-5uaaler4931i0s9sedxjquhq@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
* perf trace: Use event filters for the event qualifier listArnaldo Carvalho de Melo2015-07-061-20/+32
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | We use raw_syscalls:sys_{enter,exit} events to show the syscalls, but were using a rather lazy/inneficient way to implement our 'strace -e' equivalent: filter out after reading the events in the ring buffer. Deflect more work to the kernel by appending a filter expression for that, that, together with the pid list, that is always present, if only to filter the tracer itself, reduces pressure on the ring buffer and otherwise use infrastructure already in place in the kernel to do early filtering. If we use it with -v we can see the filter passed to the kernel, for instance, for this contrieved case: # trace -v -e \!open,close,write,poll,recvfrom,select,recvmsg,writev,sendmsg,read,futex,epoll_wait,ioctl,eventfd --filter-pids 2189,2566,1398,2692,4475,4532 <SNIP> (common_pid != 2514 && common_pid != 1398 && common_pid != 2189 && common_pid != 2566 && common_pid != 2692 && common_pid != 4475 && common_pid != 4532) && (id != 3 && id != 232 && id != 284 && id != 202 && id != 16 && id != 2 && id != 7 && id != 0 && id != 45 && id != 47 && id != 23 && id != 46 && id != 1 && id != 20) 0.011 (0.011 ms): caribou/2295 eventfd2(flags: CLOEXEC|NONBLOCK) = 18 16.946 (0.019 ms): caribou/2295 eventfd2(flags: CLOEXEC|NONBLOCK) = 18 38.598 (0.167 ms): chronyd/794 socket(family: INET, type: DGRAM ) = 4 38.603 (0.002 ms): chronyd/794 fcntl(fd: 4<socket:[239307]>, cmd: GETFD) = 0 38.605 (0.001 ms): chronyd/794 fcntl(fd: 4<socket:[239307]>, cmd: SETFD, arg: 1) = 0 ^C # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Don Zickus <dzickus@redhat.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ti2tg18atproqpguc2moinp6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
generated by cgit v1.2.3-55-g7522 (git 2.39.0) at 2024-07-17 11:17:24 +0200