aboutsummaryrefslogtreecommitdiff
path: root/tools/perf/builtin-trace.c
AgeCommit message (Collapse)AuthorFilesLines
2018-12-28perf trace: Move the files table resizing to outside set_pathname()Arnaldo Carvalho de Melo1-6/+16
So that we can have that table expanded when setting other attributes. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-28perf trace: Rename thread_thread->paths to thread_trace->filesArnaldo Carvalho de Melo1-19/+23
So that we can add more per file attributes besides the pathname, such as which ioctl beautifier to use, for cases such as the sound and usbdeffs ioctls, that both use the 'U' command, so we have to differentiate at the major number for the device file. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-21perf trace: Do not hardcode the size of the tracepoint common_ fieldsArnaldo Carvalho de Melo1-21/+52
We shouldn't hardcode the size of the tracepoint common_ fields, use the offset of the 'id'/'__syscallnr' field in the sys_enter event instead. This caused the augmented syscalls code to fail on a particular build of a PREEMPT_RT_FULL kernel where these extra 'common_migrate_disable' and 'common_padding' fields were before the syscall id one: # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/format name: sys_enter ID: 22 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:unsigned short common_migrate_disable; offset:8; size:2; signed:0; field:unsigned short common_padding; offset:10; size:2; signed:0; field:long id; offset:16; size:8; signed:1; field:unsigned long args[6]; offset:24; size:48; signed:0; print fmt: "NR %ld (%lx, %lx, %lx, %lx, %lx, %lx)", REC->id, REC->args[0], REC->args[1], REC->args[2], REC->args[3], REC->args[4], REC->args[5] # All those 'common_' prefixed fields are zeroed when they hit a BPF tracepoint hook, we better just discard those, i.e. somehow pass an offset to the BPF program from the start of the ctx and make adjustments in the 'perf trace' handlers to adjust the offset of the syscall arg offsets obtained from tracefs. Till then, fix it the quick way and add this to the augmented_raw_syscalls.c to bet it to work in such kernels: diff --git a/tools/perf/examples/bpf/augmented_raw_syscalls.c b/tools/perf/examples/bpf/augmented_raw_syscalls.c index 53c233370fae..1f746f931e13 100644 --- a/tools/perf/examples/bpf/augmented_raw_syscalls.c +++ b/tools/perf/examples/bpf/augmented_raw_syscalls.c @@ -38,12 +38,14 @@ struct bpf_map SEC("maps") syscalls = { struct syscall_enter_args { unsigned long long common_tp_fields; + long rt_common_tp_fields; long syscall_nr; unsigned long args[6]; }; struct syscall_exit_args { unsigned long long common_tp_fields; + long rt_common_tp_fields; long syscall_nr; long ret; }; Just to check that this was the case. Fix it properly later, for now remove the hardcoding of the offset in the 'perf trace' side and document the situation with this patch. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-21perf trace: Check if the raw_syscalls:sys_{enter,exit} are setup before ↵Arnaldo Carvalho de Melo1-1/+3
setting tp filter While updating 'perf trace' on an machine with an old precompiled augmented_raw_syscalls.o that didn't setup the syscall map the new 'perf trace' codebase notices the augmented_raw_syscalls.o eBPF event, decides to use it instead of the old raw_syscalls:sys_{enter,exit} method, but then because we don't have the syscall map tries to set the tracepoint filter on the sys_{enter,exit} evsels, that are NULL, segfaulting. Make the code more robust by checking it those tracepoints have their respective evsels in place before trying to set the tp filter. With this we still get everything to work, just not setting up the syscall filters, which is better than a segfault. Now to update the precompiled augmented_raw_syscalls.o and continue development :-) Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf beauty mmap: Print mmap's 'offset' arg in hexadecimalArnaldo Carvalho de Melo1-1/+2
Also to make it match 'strace' output, for regression testing. Both now produce this option, when 'perf trace' uses a .perfconfig asking for the strace like output: mmap(0x7faf66e6a000, 1363968, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7faf66e6a000 Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace beauty: Beautify arch_prctl()'s argumentsArnaldo Carvalho de Melo1-1/+4
This actually so far, AFAIK is available only in x86, so the code was put in place with x86 prefixes, in arches where it is not available it will just not be called, so no further mechanisms are needed at this time. Later, when other arches wire this up, we'll just look at the uname (live sessions) or perf_env data in the perf.data header to auto-wire the right beautifier. With this the output is the same as produced by 'strace' when used with the following ~/.perfconfig: # cat ~/.perfconfig [llvm] dump-obj = true [trace] add_events = /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o show_zeros = yes show_duration = no no_inherit = yes show_timestamp = no show_arg_names = no args_alignment = -40 show_prefix = yes # And, on fedora 29, since the string tables are generated from the kernel sources, we don't know about 0x3001, just like strace: --- /tmp/strace 2018-12-17 11:22:08.707586721 -0300 +++ /tmp/trace 2018-12-18 11:11:32.037512729 -0300 @@ -1,49 +1,49 @@ -arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc8a92dc80) = -1 EINVAL (Invalid argument) +arch_prctl(0x3001 /* ARCH_??? */, 0x7ffe4eb93ae0) = -1 EINVAL (Invalid argument) -arch_prctl(ARCH_SET_FS, 0x7faf6700f540) = 0 +arch_prctl(ARCH_SET_FS, 0x7fb507364540) = 0 And that seems to be related to the CET/Shadow Stack feature, that userland in Fedora 29 (glibc 2.28) are querying the kernel about, that 0x3001 seems to be ARCH_CET_STATUS, I'll check the situation and test with a fedora 29 kernel to see if the other codes are used. A diff that ignores the different pointers for different runs needs to be put in place in the upcoming regression tests comparing 'perf trace's output to strace's. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: When showing string prefixes show prefix + ??? for unknown entriesArnaldo Carvalho de Melo1-3/+11
To match 'strace' output, like in: arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc8a92dc80) = -1 EINVAL (Invalid argument) Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Move strarrays to beauty.h for further reuseArnaldo Carvalho de Melo1-16/+10
We'll use it in the upcoming arch_prctl() 'code' arg beautifier. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Show NULL when syscall pointer args are 0Arnaldo Carvalho de Melo1-16/+12
Matching strace's output format. The 'format' file for the syscall tracepoints have an indication if the arg is a pointer, with some exceptions like 'mmap' that has its first arg as an 'unsigned long', so use a heuristic using the argument name, i.e. if it contains the 'addr' substring, format it with the pointer formatter. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Enclose the errno strings with ()Arnaldo Carvalho de Melo1-2/+2
To match strace, now both emit the same line for calls like: access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Add alignment spaces after the closing parensArnaldo Carvalho de Melo1-11/+26
To use strace's style, helping in comparing the output of 'perf trace' with the one from 'strace', to help in upcoming regression tests. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow asking for not suppressing common string prefixesArnaldo Carvalho de Melo1-10/+20
So far we've been suppressing common stuff such as "MAP_" in the mmap flags, showing "SHARED" instead of "MAP_SHARED", allow for those prefixes (and a few suffixes) to be shown: # trace -e *map,open*,*seek sleep 1 openat("/etc/ld.so.cache", CLOEXEC) = 3 mmap(0, 109093, READ, PRIVATE, 3, 0) = 0x7ff61c695000 openat("/lib64/libc.so.6", CLOEXEC) = 3 lseek(3, 792, SET) = 792 mmap(0, 8192, READ|WRITE, PRIVATE|ANONYMOUS) = 0x7ff61c693000 lseek(3, 792, SET) = 792 lseek(3, 864, SET) = 864 mmap(0, 1857568, READ, PRIVATE|DENYWRITE, 3, 0) = 0x7ff61c4cd000 mmap(0x7ff61c4ef000, 1363968, EXEC|READ, PRIVATE|FIXED|DENYWRITE, 3, 139264) = 0x7ff61c4ef000 mmap(0x7ff61c63c000, 311296, READ, PRIVATE|FIXED|DENYWRITE, 3, 1503232) = 0x7ff61c63c000 mmap(0x7ff61c689000, 24576, READ|WRITE, PRIVATE|FIXED|DENYWRITE, 3, 1814528) = 0x7ff61c689000 mmap(0x7ff61c68f000, 14368, READ|WRITE, PRIVATE|FIXED|ANONYMOUS) = 0x7ff61c68f000 munmap(0x7ff61c695000, 109093) = 0 openat("/usr/lib/locale/locale-archive", CLOEXEC) = 3 mmap(0, 217749968, READ, PRIVATE, 3, 0) = 0x7ff60f523000 # # vim ~/.perfconfig # # perf config llvm.dump-obj=true trace.add_events=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o trace.show_zeros=yes trace.show_duration=no trace.no_inherit=yes trace.show_timestamp=no trace.show_arg_names=no trace.args_alignment=0 trace.string_quote=" trace.show_prefix=yes # # # trace -e *map,open*,*seek sleep 1 openat(AT_FDCWD, "/etc/ld.so.cache", O_CLOEXEC) = 3 mmap(0, 109093, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7ebbe59000 openat(AT_FDCWD, "/lib64/libc.so.6", O_CLOEXEC) = 3 lseek(3, 792, SEEK_SET) = 792 mmap(0, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS) = 0x7f7ebbe57000 lseek(3, 792, SEEK_SET) = 792 lseek(3, 864, SEEK_SET) = 864 mmap(0, 1857568, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f7ebbc91000 mmap(0x7f7ebbcb3000, 1363968, PROT_EXEC|PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 139264) = 0x7f7ebbcb3000 mmap(0x7f7ebbe00000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 1503232) = 0x7f7ebbe00000 mmap(0x7f7ebbe4d000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 1814528) = 0x7f7ebbe4d000 mmap(0x7f7ebbe53000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS) = 0x7f7ebbe53000 munmap(0x7f7ebbe59000, 109093) = 0 openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_CLOEXEC) = 3 mmap(0, 217749968, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7eaece7000 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Add a prefix member to the strarray classArnaldo Carvalho de Melo1-10/+11
So that the user, in an upcoming patch, can select printing it to get the full string as used in the source code, not one with a common prefix chopped off so as to make the output more compact. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Enclose strings with double quotesArnaldo Carvalho de Melo1-1/+1
To match 'strace' output, helping with upcoming regression tests comparing both outputs. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Make the alignment of the syscall args be configurableArnaldo Carvalho de Melo1-3/+9
Since the start 'perf trace' aligns the parens enclosing the list of syscall args to align the syscall results, allow this to be configurable, keeping the default of 70. Using: # perf config llvm.dump-obj=true trace.add_events=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o trace.show_zeros=yes trace.show_duration=no trace.no_inherit=yes trace.show_timestamp=no trace.show_arg_names=no trace.args_alignment=0 # trace -e open*,close,*sleep sleep 1 openat(CWD, /etc/ld.so.cache, CLOEXEC) = 3 close(3) = 0 openat(CWD, /lib64/libc.so.6, CLOEXEC) = 3 close(3) = 0 openat(CWD, /usr/lib/locale/locale-archive, CLOEXEC) = 3 close(3) = 0 nanosleep(0x7ffc00de66f0, 0) = 0 close(1) = 0 close(2) = 0 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow suppressing the syscall argument namesArnaldo Carvalho de Melo1-4/+18
To show just the values: Default: # trace -e open*,close,*sleep sleep 1 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3 close(fd: 3 ) = 0 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3 close(fd: 3 ) = 0 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3 close(fd: 3 ) = 0 nanosleep(rqtp: 0x7ffc0c4ea0d0, rmtp: 0 ) = 0 close(fd: 1 ) = 0 close(fd: 2 ) = 0 # Remove it: # perf config trace.show_arg_names=no # trace -e open*,close,*sleep sleep 1 openat(CWD, /etc/ld.so.cache, CLOEXEC ) = 3 close(3 ) = 0 openat(CWD, /lib64/libc.so.6, CLOEXEC ) = 3 close(3 ) = 0 openat(CWD, /usr/lib/locale/locale-archive, CLOEXEC ) = 3 close(3 ) = 0 nanosleep(0x7ffced3a8c40, 0 ) = 0 close(1 ) = 0 close(2 ) = 0 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow configuring if the syscall start timestamp should be printedArnaldo Carvalho de Melo1-1/+8
# trace -e open*,close,*sleep sleep 1 0.000 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3 0.016 close(fd: 3 ) = 0 0.024 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3 0.074 close(fd: 3 ) = 0 0.235 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3 0.251 close(fd: 3 ) = 0 0.285 nanosleep(rqtp: 0x7ffd68e6d620, rmtp: 0 ) = 0 1000.386 close(fd: 1 ) = 0 1000.395 close(fd: 2 ) = 0 # # perf config trace.show_timestamp=no # trace -e open*,close,*sleep sleep 1 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3 close(fd: 3 ) = 0 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3 close(fd: 3 ) = 0 openat(dfd: CWD, filename: , flags: CLOEXEC ) = 3 close(fd: 3 ) = 0 nanosleep(rqtp: 0x7fffa79c38e0, rmtp: 0 ) = 0 close(fd: 1 ) = 0 close(fd: 2 ) = 0 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow configuring default for perf_event_attr.inheritArnaldo Carvalho de Melo1-0/+2
I.f. if children should inherit the parent perf_event configuration, i.e. if we should trace children as well or just the parent. The default is to follow children, to disable this and have a behaviour similar to strace, set this config option or use the --no_inherit 'perf trace' option. E.g.: Default: # perf config trace.no_inherit # trace -e clone,*sleep time sleep 1 0.000 time/21107 clone(clone_flags: CHILD_CLEARTID|CHILD_SETTID|0x11, newsp: 0, child_tidptr: 0x7f7b8f9ae810) = 21108 (time) ? time/21108 ... [continued]: clone() 0.691 sleep/21108 nanosleep(rqtp: 0x7ffed01d0540, rmtp: 0 ) = 0 0.00user 0.00system 0:01.00elapsed 0%CPU (0avgtext+0avgdata 1988maxresident)k 0inputs+0outputs (0major+76minor)pagefaults 0swaps # Disable it: # trace -e clone,*sleep time sleep 1 0.000 clone(clone_flags: CHILD_CLEARTID|CHILD_SETTID|0x11, newsp: 0, child_tidptr: 0x7ff41e100810) = 21414 (time) 0.00user 0.00system 0:01.00elapsed 0%CPU (0avgtext+0avgdata 1964maxresident)k 0inputs+0outputs (0major+76minor)pagefaults 0swaps # Notice that since there is just one thread, the "comm/TID" column is suppressed. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow configuring if the syscall duration should be printedArnaldo Carvalho de Melo1-2/+7
# perf config trace.show_duration=no # perf config -l | grep trace trace.default_events=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o trace.show_zeros=true trace.show_duration=no # trace -e *sleep sleep 1 0.000 sleep/8729 nanosleep(rqtp: 0x7ffcb0b4c940, rmtp: 0) = 0 # perf config trace.show_duration=yes # trace -e *sleep sleep 1 0.000 (1000.212 ms): sleep/8735 nanosleep(rqtp: 0x7ffca15fa770, rmtp: 0) = 0 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow configuring if zeroed syscall args should be printedArnaldo Carvalho de Melo1-1/+5
The default so far, since we show argument names followed by its values, was to make the output more compact by suppressing most zeroed args. Make this configurable so that users can choose what best suit their needs. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow specifying a set of events to add in perfconfigArnaldo Carvalho de Melo1-0/+20
To add augmented_raw_syscalls to the events speficied by the user, or be the only one if no events were specified by the user, one can add this to perfconfig: # cat ~/.perfconfig [trace] add_events = /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o # I.e. pre-compile the augmented_raw_syscalls.c BPF program and make it always load, this way: # perf trace -e open* cat /etc/passwd > /dev/null 0.000 ( 0.013 ms): cat/31557 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC) = 3 0.035 ( 0.007 ms): cat/31557 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC) = 3 0.353 ( 0.009 ms): cat/31557 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3 0.424 ( 0.006 ms): cat/31557 openat(dfd: CWD, filename: /etc/passwd) = 3 # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Switch to using a struct for the aumented_raw_syscalls syscalls ↵Arnaldo Carvalho de Melo1-2/+11
map values We'll start adding more perf-syscall stuff, so lets do this prep step so that the next ones are just about adding more fields. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Implement syscall filtering in augmented_syscallsArnaldo Carvalho de Melo1-0/+66
Just another map, this time an BPF_MAP_TYPE_ARRAY, stating with one bool per syscall, stating if it should be filtered or not. So, with a pre-built augmented_raw_syscalls.o file, we use: # perf trace -e open*,augmented_raw_syscalls.o 0.000 ( 0.016 ms): DNS Res~er #37/29652 openat(dfd: CWD, filename: /etc/hosts, flags: CLOEXEC ) = 138 187.039 ( 0.048 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC ) = 11 187.348 ( 0.041 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC ) = 11 188.793 ( 0.036 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC ) = 11 189.803 ( 0.029 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC ) = 11 190.774 ( 0.027 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC ) = 11 284.620 ( 0.149 ms): DataStorage/3076 openat(dfd: CWD, filename: /home/acme/.mozilla/firefox/ina67tev.default/SiteSecurityServiceState.txt, flags: CREAT|TRUNC|WRONLY, mode: IRUGO|IWUSR|IWGRP) = 167 ^C# What is it that this gsd-housekeeping thingy needs to open /proc/self/mountinfo four times periodically? :-) This map will be extended to tell per-syscall parameters, i.e. how many bytes to copy per arg, using the function signature to get the types and then the size of those types, via BTF. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Avoid using raw_syscalls in duplicity with eBPF augmentationArnaldo Carvalho de Melo1-6/+10
So when we do something like: # perf trace -e open*,augmented_raw_syscalls.o We need to set trace->trace_syscalls because there is logic that use that when mixing strace-like output with other events, such as scheduler tracepoints, but with that set we ended up having multiple raw_syscalls:sys_{enter,exit} setup, which garbled the output, so check if trace->augmented_raw_syscalls is set and avoid the two extra tracepoints. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Rename set_ev_qualifier_filter to clarify its a tracepoint filterArnaldo Carvalho de Melo1-1/+6
Rename it to trace__set_ev_qualifier_tp_filter(), as this just sets up tracepoint filters on the raw_syscalls:sys_{enter,exit} tracepoints, and since we're going to do the same for the augmented_raw_syscalls codepath, when used, rename it to clarify. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace beauty: renameat's newdirfd may also be AT_FDCWDArnaldo Carvalho de Melo1-1/+2
Noticed while working on renameat2. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Beautify renameat2's flags argumentArnaldo Carvalho de Melo1-1/+2
# strace -e renameat2 -f perf trace -e rename* mv c /tmp strace: Process 10824 attached [pid 10824] renameat2(AT_FDCWD, "c", AT_FDCWD, "/tmp", RENAME_NOREPLACE) = -1 EXDEV (Invalid cross-device link) [pid 10824] renameat2(AT_FDCWD, "c", AT_FDCWD, "/tmp/c", RENAME_NOREPLACE) = -1 EEXIST (File exists) 1.857 ( 0.008 ms): mv/10824 renameat2(olddfd: CWD, oldname: 0x7ffc72ff3d81, newdfd: CWD, newname: 0x7ffc72ff3d83, flags: NOREPLACE) = -1 EXDEV Invalid cross-device link 2.002 ( 0.006 ms): mv/10824 renameat2(olddfd: CWD, oldname: 0x7ffc72ff3d81, newdfd: CWD, newname: 0x55ad609efcc0, flags: NOREPLACE) = -1 EEXIST File exists mv: 'c' and '/tmp/c' are the same file [pid 10824] +++ exited with 1 +++ --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=10824, si_uid=0, si_status=1, si_utime=0, si_stime=0} --- +++ exited with 0 +++ # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace beauty: Beautify renameat2's fd arg wrt AT_FDCWDArnaldo Carvalho de Melo1-0/+3
Just like is done with the 'renameat' syscall. # strace -e renameat2 -f perf trace -e rename* mv c /tmp [pid 12334] renameat2(AT_FDCWD, "c", AT_FDCWD, "/tmp", RENAME_NOREPLACE) = -1 EXDEV (Invalid cross-device link) [pid 12334] renameat2(AT_FDCWD, "c", AT_FDCWD, "/tmp/c", RENAME_NOREPLACE) = -1 EEXIST (File exists) 1.947 ( 0.007 ms): mv/12334 renameat2(olddfd: CWD, oldname: 0x7ffce8b7fd81, newdfd: CWD, newname: 0x7ffce8b7fd83, flags: 1) = -1 EXDEV Invalid cross-device link 2.073 ( 0.009 ms): mv/12334 renameat2(olddfd: CWD, oldname: 0x7ffce8b7fd81, newdfd: CWD, newname: 0x55ce7f0a1cc0, flags: 1mv: ) = -1 EEXIST File exists'c' and '/tmp/c' are the same file # Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Allow selecting use the use of the ordered_events codeArnaldo Carvalho de Melo1-6/+19
I was trigger happy on this one, as using ordered_events as implemented by Jiri for use with the --block code under discussion on lkml incurs in delaying processing to form batches that then get ordered and then printed. With 'perf trace' we want to process the events as they go, without that delay, and doing it that way works well for the common case which is to trace a thread or a workload started by 'perf trace'. So revert back to not using ordered_events but add an option to select that mode so that users can experiment with their particular use case to see if works better, i.e. if the added delay is not a problem and the ordering helps. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-18perf trace: Rename delivery functions to ease making ordered_events selectableArnaldo Carvalho de Melo1-7/+7
Just hide a bit more how events gets delivered, hiding ordered_events details from the main loop. Cc: Adrian Hunter <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17perf trace: Add ordered processingJiri Olsa1-1/+51
Sort events to provide the precise outcome of ordered events, just like is done with 'perf report' and 'perf top'. Signed-off-by: Jiri Olsa <[email protected]> Tested-by: Arnaldo Carvalho de Melo <[email protected]> Cc: Alexander Shishkin <[email protected]> Cc: Dmitry Levin <[email protected]> Cc: Eugene Syromiatnikov <[email protected]> Cc: Frederic Weisbecker <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Peter Zijlstra <[email protected]> Cc: Steven Rostedt (VMware) <[email protected]> Cc: Thomas Gleixner <[email protected]> Link: http://lkml.kernel.org/r/[email protected] [ split from a larger patch, added trace__ prefixes to new 'struct trace' methods ] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17perf trace: Move event delivery to a new deliver_event() functionJiri Olsa1-9/+16
Mov event delivery code to a new trace__deliver_event() function, so it's easier to add ordered delivery coming in the following patches. Signed-off-by: Jiri Olsa <[email protected]> Cc: Alexander Shishkin <[email protected]> Cc: Dmitry Levin <[email protected]> Cc: Eugene Syromiatnikov <[email protected]> Cc: Frederic Weisbecker <[email protected]> Cc: Luis Cláudio Gonçalves <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Peter Zijlstra <[email protected]> Cc: Steven Rostedt (VMware) <[email protected]> Cc: Thomas Gleixner <[email protected]> Link: http://lkml.kernel.org/r/[email protected] [ Add trace__ prefix to the deliver_event method ] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17perf trace: We need to consider "nr" if "__syscall_nr" is not thereArnaldo Carvalho de Melo1-1/+2
To cope with older kernels that don't have this patch backported: 026842d148b9 ("tracing/syscalls: Rename "/format" tracepoint field name "nr" to "__syscall_nr:") This makes 'perf trace' work again in RHEL7 kernels. Cc: Taeung Song <[email protected]> Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17perf tools: Allow specifying proc-map-timeout in config fileMark Drayton1-3/+2
The default timeout of 500ms for parsing /proc/<pid>/maps files is too short for profiling many of our services. This can be overridden by passing --proc-map-timeout to the relevant command but it'd be nice to globally increase our default value. This patch permits setting a different default with the core.proc-map-timeout config file parameter. Signed-off-by: Mark Drayton <[email protected]> Acked-by: Song Liu <[email protected]> Acked-by: Namhyung Kim <[email protected]> Cc: Alexander Shishkin <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Peter Zijlstra <[email protected]> Link: http://lkml.kernel.org/r/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17perf tools: Fix diverse comment typosIngo Molnar1-1/+1
Go over the tools/ files that are maintained in Arnaldo's tree and fix common typos: half of them were in comments, the other half in JSON files. No change in functionality intended. Committer notes: This was split from a larger patch as there are code that is, additionally, maintained outside the kernel tree, so to ease cherry-picking and/or backporting, split this into multiple patches. Just typos in comments, no need to backport, reducing the possibility of possible backporting artifacts. Signed-off-by: Ingo Molnar <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Peter Zijlstra <[email protected]> Link: http://lkml.kernel.org/r/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-12-17tools lib traceevent, perf tools: Rename 'struct tep_event_format' to ↵Tzvetomir Stoyanov1-1/+1
'struct tep_event' In order to make libtraceevent into a proper library, variables, data structures and functions require a unique prefix to prevent name space conflicts. This renames 'struct tep_event_format' to 'struct tep_event', which describes more closely the purpose of the struct. Signed-off-by: Tzvetomir Stoyanov <[email protected]> Cc: Adrian Hunter <[email protected]> Cc: Andrew Morton <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Link: http://lkml.kernel.org/r/[email protected] Signed-off-by: Steven Rostedt (VMware) <[email protected]> [ Fixup conflict with 6e33c250a88f ("tools lib traceevent: Fix compile warnings in tools/lib/traceevent/event-parse.c") ] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-21perf trace: Fill in BPF "filtered_pids" map when presentArnaldo Carvalho de Melo1-13/+48
This makes the augmented_syscalls support the --filter-pids and auto-filtered feedback loop pids just like when working without BPF, i.e. with just raw_syscalls:sys_{enter,exit} and tracepoint filters. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-21perf trace: See if there is a map named "filtered_pids"Arnaldo Carvalho de Melo1-1/+24
Lookup for the first map named "filtered_pids" and, if augmenting syscalls, i.e. if a BPF event is present and the "__augmented_syscalls__" is present, then fill in that map with the pids to filter, be it feedback loop ones (perf trace's pid, its father if it is "sshd", more auto-filtered in the future) or the ones explicitely stated in the tool command line via --filter-pids. The code to actually fill in the map comes next. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-21perf trace: Add "_from_option" suffix to trace__set_filter()Arnaldo Carvalho de Melo1-3/+3
As we'll need that name for a new function to set filters for both tracepoints and BPF maps for filtering pids. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-21perf evlist: Rename perf_evlist__set_filter* to perf_evlist__set_tp_filter*Arnaldo Carvalho de Melo1-2/+2
To better reflect that this is a tracepoint filter, as opposed, for instance to map based BPF filters. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-03perf trace: Fix setting of augmented payload when using eBPF + raw_syscallsArnaldo Carvalho de Melo1-7/+30
For now with BPF raw_augmented we hook into raw_syscalls:sys_enter and there we get all 6 syscall args plus the tracepoint common fields (sizeof(long)) and the syscall_nr (another long). So we check if that is the case and if so don't look after the sc->args_size, but always after the full raw_syscalls:sys_enter payload, which is fixed. We'll revisit this later to pass s->args_size to the BPF augmenter (now tools/perf/examples/bpf/augmented_raw_syscalls.c, so that it copies only what we need for each syscall, like what happens when we use syscalls:sys_enter_NAME, so that we reduce the kernel/userspace traffic to just what is needed for each syscall. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-11-01perf trace: When augmenting raw_syscalls plug raw_syscalls:sys_exit tooArnaldo Carvalho de Melo1-1/+2
With just this commit we get to support all syscalls via hooking raw_syscalls:sys_{enter,exit} to the trace__sys_{enter,exit} routines to combine, strace-like, those tracepoints. # trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1 ? ( ): sleep/31680 ... [continued]: execve()) = 0 0.043 ( 0.004 ms): sleep/31680 brk() = 0x55652a851000 0.070 ( 0.009 ms): sleep/31680 access(filename:, mode: R) = -1 ENOENT No such file or directory 0.087 ( 0.006 ms): sleep/31680 openat(dfd: CWD, filename: , flags: CLOEXEC) = 3 0.096 ( 0.003 ms): sleep/31680 fstat(fd: 3, statbuf: 0x7ffc5269e190) = 0 0.101 ( 0.005 ms): sleep/31680 mmap(len: 103334, prot: READ, flags: PRIVATE, fd: 3) = 0x7f709c239000 0.109 ( 0.002 ms): sleep/31680 close(fd: 3) = 0 0.126 ( 0.006 ms): sleep/31680 openat(dfd: CWD, filename: , flags: CLOEXEC) = 3 0.135 ( 0.003 ms): sleep/31680 read(fd: 3, buf: 0x7ffc5269e358, count: 832) = 832 0.141 ( 0.002 ms): sleep/31680 fstat(fd: 3, statbuf: 0x7ffc5269e1f0) = 0 0.146 ( 0.005 ms): sleep/31680 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) = 0x7f709c237000 0.159 ( 0.007 ms): sleep/31680 mmap(len: 3889792, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3) = 0x7f709bc79000 0.168 ( 0.009 ms): sleep/31680 mprotect(start: 0x7f709be26000, len: 2093056) = 0 0.179 ( 0.010 ms): sleep/31680 mmap(addr: 0x7f709c025000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 1753088) = 0x7f709c025000 0.196 ( 0.005 ms): sleep/31680 mmap(addr: 0x7f709c02b000, len: 14976, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7f709c02b000 0.210 ( 0.002 ms): sleep/31680 close(fd: 3) = 0 0.230 ( 0.002 ms): sleep/31680 arch_prctl(option: 4098, arg2: 140121632638208) = 0 0.306 ( 0.009 ms): sleep/31680 mprotect(start: 0x7f709c025000, len: 16384, prot: READ) = 0 0.338 ( 0.005 ms): sleep/31680 mprotect(start: 0x556529607000, len: 4096, prot: READ) = 0 0.348 ( 0.005 ms): sleep/31680 mprotect(start: 0x7f709c253000, len: 4096, prot: READ) = 0 0.356 ( 0.019 ms): sleep/31680 munmap(addr: 0x7f709c239000, len: 103334) = 0 0.463 ( 0.002 ms): sleep/31680 brk() = 0x55652a851000 0.468 ( 0.004 ms): sleep/31680 brk(brk: 0x55652a872000) = 0x55652a872000 0.474 ( 0.002 ms): sleep/31680 brk() = 0x55652a872000 0.484 ( 0.008 ms): sleep/31680 open(filename: , flags: CLOEXEC) = 3 0.497 ( 0.002 ms): sleep/31680 fstat(fd: 3, statbuf: 0x7f709c02aaa0) = 0 0.501 ( 0.006 ms): sleep/31680 mmap(len: 113045344, prot: READ, flags: PRIVATE, fd: 3) = 0x7f70950aa000 0.514 ( 0.002 ms): sleep/31680 close(fd: 3) = 0 0.554 (1000.140 ms): sleep/31680 nanosleep(rqtp: 0x7ffc5269eed0) = 0 1000.734 ( 0.007 ms): sleep/31680 close(fd: 1) = 0 1000.748 ( 0.004 ms): sleep/31680 close(fd: 2) = 0 1000.769 ( ): sleep/31680 exit_group() # Now to allow selecting which syscalls should be traced, using a map. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-30perf trace: Beautify mount's first pathname argArnaldo Carvalho de Melo1-1/+2
The pathname beautifiers so far support just one augmented pathname per syscall, so do it just for mount's first arg, later this will get fixed. With: # perf probe -l probe:vfs_getname (on getname_flags:73@acme/git/linux/fs/namei.c with pathname) # Later this will get added to augmented_syscalls.c (eBPF): In one xterm: # perf trace -e mount,umount 2687.331 ( 3.544 ms): mount/8892 mount(dev_name: /mnt, dir_name: 0x561f9ac184a0, type: 0x561f9ac1b170, flags: BIND) = 0 3912.126 ( 8.807 ms): umount/8895 umount2(name: /mnt) = 0 ^C# In the other: $ sudo mount --bind /proc /mnt $ sudo umount /mnt Cc: Adrian Hunter <[email protected]> Cc: Benjamin Peterson <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-30perf trace: Beautify the umount's 'name' argumentArnaldo Carvalho de Melo1-1/+2
By using the SCA_FILENAME beautifier, that works when either the probe:vfs_getname probe is in place or with the eBPF program tools/perf/examples/bpf/augmented_syscalls.c: # perf probe -l probe:vfs_getname (on getname_flags:73@acme/git/linux/fs/namei.c with pathname) # perf trace -e umount 9630.332 ( 9.521 ms): umount/8082 umount2(name: /mnt) = 0 # The augmented syscalls one will be done in the next patch. Cc: Adrian Hunter <[email protected]> Cc: Benjamin Peterson <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-30perf trace: Consider syscall aliases tooArnaldo Carvalho de Melo1-1/+21
When trying to trace the 'umount' syscall on x86_64 I noticed that it was failing: # trace -e umount umount /mnt event syntax error: 'umount' \___ parser error Run 'perf list' for a list of valid events Usage: perf trace [<options>] [<command>] or: perf trace [<options>] -- <command> [<options>] or: perf trace record [<options>] [<command>] or: perf trace record [<options>] -- <command> [<options>] -e, --event <event> event/syscall selector. use 'perf list' to list available events # This is because in the x86-64 we have it just as 'umount2': $ grep umount arch/x86/entry/syscalls/syscall_64.tbl 166 common umount2 __x64_sys_umount $ So if the syscall name fails, try fallbacking to looking at the aliases we have in the syscall_fmts table to then re-lookup, now: # trace -e umount umount -f /mnt umount: /mnt: not mounted. 1.759 ( 0.004 ms): umount/18365 umount2(name: 0x55fbfcbc4480, flags: 1) = -1 EINVAL Invalid argument # Time to beautify the flags arg :-) Cc: Adrian Hunter <[email protected]> Cc: Benjamin Peterson <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-30perf trace beauty: Beautify mount/umount's 'flags' argumentArnaldo Carvalho de Melo1-0/+3
# trace -e mount mount -o ro -t debugfs nodev /mnt 0.000 ( 1.040 ms): mount/27235 mount(dev_name: 0x5601cc8c64e0, dir_name: 0x5601cc8c6500, type: 0x5601cc8c6480, flags: RDONLY) = 0 # trace -e mount mount -o remount,relatime -t debugfs nodev /mnt 0.000 ( 2.946 ms): mount/27262 mount(dev_name: 0x55f4a73d64e0, dir_name: 0x55f4a73d6500, type: 0x55f4a73d6480, flags: REMOUNT|RELATIME) = 0 # trace -e mount mount -o remount,strictatime -t debugfs nodev /mnt 0.000 ( 2.934 ms): mount/27265 mount(dev_name: 0x5617f71d94e0, dir_name: 0x5617f71d9500, type: 0x5617f71d9480, flags: REMOUNT|STRICTATIME) = 0 # trace -e mount mount -o remount,suid,silent -t debugfs nodev /mnt 0.000 ( 0.049 ms): mount/27273 mount(dev_name: 0x55ad65df24e0, dir_name: 0x55ad65df2500, type: 0x55ad65df2480, flags: REMOUNT|SILENT) = 0 # trace -e mount mount -o remount,rw,sync,lazytime -t debugfs nodev /mnt 0.000 ( 2.684 ms): mount/27281 mount(dev_name: 0x561216055530, dir_name: 0x561216055550, type: 0x561216055510, flags: SYNCHRONOUS|REMOUNT|LAZYTIME) = 0 # trace -e mount mount -o remount,dirsync -t debugfs nodev /mnt 0.000 ( 3.512 ms): mount/27314 mount(dev_name: 0x55c4e7188480, dir_name: 0x55c4e7188530, type: 0x55c4e71884a0, flags: REMOUNT|DIRSYNC, data: 0x55c4e71884e0) = 0 # Cc: Adrian Hunter <[email protected]> Cc: Benjamin Peterson <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-30perf trace beauty: Allow syscalls to mask an argument before considering itArnaldo Carvalho de Melo1-0/+19
Take mount's 'flags' arg, to cope with this semantic, as defined in do_mount in fs/namespace.c: /* * Pre-0.97 versions of mount() didn't have a flags word. When the * flags word was introduced its top half was required to have the * magic value 0xC0ED, and this remained so until 2.4.0-test9. * Therefore, if this magic number is present, it carries no * information and must be discarded. */ We need to mask this arg, and then see if it is zero, when we simply don't print the arg name and value. The next patch will use this for mount's 'flag' arg. Cc: Adrian Hunter <[email protected]> Cc: Benjamin Peterson <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-22perf trace: Introduce per-event maximum number of events propertyArnaldo Carvalho de Melo1-2/+17
Call it 'nr', as in this context it should be expressive enough, i.e.: # perf trace -e sched:*waking/nr=8,call-graph=fp/ 0.000 :0/0 sched:sched_waking:comm=rcu_sched pid=10 prio=120 target_cpu=001 try_to_wake_up ([kernel.kallsyms]) sched_clock ([kernel.kallsyms]) 3.933 :0/0 sched:sched_waking:comm=rcu_sched pid=10 prio=120 target_cpu=001 try_to_wake_up ([kernel.kallsyms]) sched_clock ([kernel.kallsyms]) 3.970 IPDL Backgroun/3622 sched:sched_waking:comm=Gecko_IOThread pid=3569 prio=120 target_cpu=003 try_to_wake_up ([kernel.kallsyms]) __libc_write (/usr/lib64/libpthread-2.26.so) 20.069 IPDL Backgroun/3622 sched:sched_waking:comm=Gecko_IOThread pid=3569 prio=120 target_cpu=003 try_to_wake_up ([kernel.kallsyms]) __libc_write (/usr/lib64/libpthread-2.26.so) 37.170 IPDL Backgroun/3622 sched:sched_waking:comm=Gecko_IOThread pid=3569 prio=120 target_cpu=003 try_to_wake_up ([kernel.kallsyms]) __libc_write (/usr/lib64/libpthread-2.26.so) 53.267 IPDL Backgroun/3622 sched:sched_waking:comm=Gecko_IOThread pid=3569 prio=120 target_cpu=003 try_to_wake_up ([kernel.kallsyms]) __libc_write (/usr/lib64/libpthread-2.26.so) 70.365 IPDL Backgroun/3622 sched:sched_waking:comm=Gecko_IOThread pid=3569 prio=120 target_cpu=003 try_to_wake_up ([kernel.kallsyms]) __libc_write (/usr/lib64/libpthread-2.26.so) 75.781 Web Content/3649 sched:sched_waking:comm=JS Helper pid=3670 prio=120 target_cpu=000 try_to_wake_up ([kernel.kallsyms]) try_to_wake_up ([kernel.kallsyms]) wake_up_q ([kernel.kallsyms]) futex_wake ([kernel.kallsyms]) do_futex ([kernel.kallsyms]) __x64_sys_futex ([kernel.kallsyms]) do_syscall_64 ([kernel.kallsyms]) entry_SYSCALL_64_after_hwframe ([kernel.kallsyms]) pthread_cond_signal@@GLIBC_2.3.2 (/usr/lib64/libpthread-2.26.so) # # perf trace -e sched:*switch/nr=2/,block:*_plug/nr=4/,block:*_unplug/nr=1/,net:*dev_queue/nr=3,max-stack=16/ 0.000 :0/0 sched:sched_switch:swapper/0:0 [120] S ==> trace:3367 [120] 0.046 :0/0 sched:sched_switch:swapper/1:0 [120] S ==> kworker/u16:58:2722 [120] 570.670 irq/50-iwlwifi/680 net:net_dev_queue:dev=wlp3s0 skbaddr=0xffff93498051ef00 len=66 __dev_queue_xmit ([kernel.kallsyms]) 1106.141 jbd2/dm-0-8/476 block:block_plug:[jbd2/dm-0-8] 1106.175 jbd2/dm-0-8/476 block:block_unplug:[jbd2/dm-0-8] 1 1618.088 kworker/u16:30/2694 block:block_plug:[kworker/u16:30] 1810.000 :0/0 net:net_dev_queue:dev=vnet0 skbaddr=0xffff93498051ef00 len=52 __dev_queue_xmit ([kernel.kallsyms]) 3857.974 :0/0 net:net_dev_queue:dev=vnet0 skbaddr=0xffff93498051f900 len=52 __dev_queue_xmit ([kernel.kallsyms]) 4790.277 jbd2/dm-2-8/748 block:block_plug:[jbd2/dm-2-8] 4790.448 jbd2/dm-2-8/748 block:block_plug:[jbd2/dm-2-8] # The global --max-events has precendence: # trace --max-events 3 -e sched:*switch/nr=2/,block:*_plug/nr=4/,block:*_unplug/nr=1/,net:*dev_queue/nr=3,max-stack=16/ 0.000 :0/0 sched:sched_switch:swapper/0:0 [120] S ==> qemu-system-x86:2252 [120] 0.029 qemu-system-x8/2252 sched:sched_switch:qemu-system-x86:2252 [120] D ==> swapper/0:0 [120] 58.047 DNS Res~er #14/31661 net:net_dev_queue:dev=wlp3s0 skbaddr=0xffff9346966af100 len=84 __dev_queue_xmit ([kernel.kallsyms]) __libc_send (/usr/lib64/libpthread-2.26.so) # Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-22perf trace: Drop thread refcount in trace__event_handler()Arnaldo Carvalho de Melo1-1/+1
We must pair: thread = machine__findnew_thread(); with thread__put(thread). Fix it. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Fixes: c4191e55b874 ("perf trace: Show comm and tid for tracepoint events") Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
2018-10-22perf trace: Drop addr_location refcountsArnaldo Carvalho de Melo1-3/+5
When we use machine__resolve() we grab a reference to addr_location.thread (and in the future to other elements there) via machine__findnew_thread(), so we must pair that with addr_location__put(), else we'll never drop that thread when it exits and no other remaining data structures have pointers to it. Fix it. Cc: Adrian Hunter <[email protected]> Cc: David Ahern <[email protected]> Cc: Jiri Olsa <[email protected]> Cc: Namhyung Kim <[email protected]> Cc: Wang Nan <[email protected]> Link: https://lkml.kernel.org/n/[email protected] Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
Powered by cgit, Gruvboxed by Blaster4385.