BMC/Intel-BMC/linux.git/tools/perf/builtin-trace.c, branch dev-5.0

perf trace: Fixup etcsnoop example

2019-04-05T20:34:47+00:00

[ Upstream commit 1d59cb1bbd4cbe5a8f8032242cdacea5658129cf ] Where we don't have "raw_syscalls:sys_enter", so we need to look for a "*syscalls:sys_enter*" to initialize the offsets for the __augmented_syscalls__ evsel, which is the case with etcsnoop, that was segfaulting, fixed: # trace -e /home/acme/git/perf/tools/perf/examples/bpf/etcsnoop.c 0.000 ( ): gnome-shell/2105 openat(dfd: CWD, filename: "/etc/localtime") ... 631.834 ( ): cat/6521 openat(dfd: CWD, filename: "/etc/ld.so.cache", flags: RDONLY|CLOEXEC) ... 632.637 ( ): bash/6521 openat(dfd: CWD, filename: "/etc/passwd") ... ^C# Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Fixes: b9b6a2ea2baf ("perf trace: Do not hardcode the size of the tracepoint common_ fields") Link: https://lkml.kernel.org/n/tip-0tjwcit8qitsmh4nyvf2b0jo@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo Signed-off-by: Sasha Levin

perf trace: Check if the 'fd' is negative when mapping it to pathname

2019-04-05T20:34:37+00:00

[ Upstream commit 051074867434cc520c08f188479d4757dcfdaef8 ] We were crashing when processing a negative fd: Program received signal SIGSEGV, Segmentation fault. 0x0000000000609bbf in syscall_arg__scnprintf_ioctl_cmd (bf=0x1172eca "", size=2038, arg=0x7fffffff8360) at trace/beauty/ioctl.c:182 182 if (file->dev_maj == USB_DEVICE_MAJOR) Missing separate debuginfos, use: dnf debuginfo-install bzip2-libs-1.0.6-28.fc29.x86_64 elfutils-libelf-0.174-5.fc29.x86_64 elfutils-libs-0.174-5.fc29.x86_64 glib2-2.58.3-1.fc29.x86_64 libbabeltrace-1.5.6-1.fc29.x86_64 libunwind-1.2.1-6.fc29.x86_64 libuuid-2.32.1-1.fc29.x86_64 libxcrypt-4.4.3-2.fc29.x86_64 numactl-libs-2.0.12-1.fc29.x86_64 openssl-libs-1.1.1a-1.fc29.x86_64 pcre-8.42-6.fc29.x86_64 perl-libs-5.28.1-427.fc29.x86_64 popt-1.16-15.fc29.x86_64 python2-libs-2.7.15-11.fc29.x86_64 slang-2.3.2-4.fc29.x86_64 xz-libs-5.2.4-3.fc29.x86_64 (gdb) bt #0 0x0000000000609bbf in syscall_arg__scnprintf_ioctl_cmd (bf=0x1172eca "", size=2038, arg=0x7fffffff8360) at trace/beauty/ioctl.c:182 #1 0x000000000048e295 in syscall__scnprintf_val (sc=0x123b500, bf=0x1172eca "", size=2038, arg=0x7fffffff8360, val=21519) at builtin-trace.c:1594 #2 0x000000000048e60d in syscall__scnprintf_args (sc=0x123b500, bf=0x1172ec6 "-1, ", size=2042, args=0x7ffff6a7c034 "\377\377\377\377", augmented_args=0x7ffff6a7c064, augmented_args_size=4, trace=0x7fffffffa8d0, thread=0x1175cd0) at builtin-trace.c:1661 #3 0x000000000048f04e in trace__sys_enter (trace=0x7fffffffa8d0, evsel=0xb260b0, event=0x7ffff6a7bfe8, sample=0x7fffffff84f0) at builtin-trace.c:1880 #4 0x00000000004915a4 in trace__handle_event (trace=0x7fffffffa8d0, event=0x7ffff6a7bfe8, sample=0x7fffffff84f0) at builtin-trace.c:2590 #5 0x0000000000491eed in __trace__deliver_event (trace=0x7fffffffa8d0, event=0x7ffff6a7bfe8) at builtin-trace.c:2818 #6 0x0000000000492030 in trace__deliver_event (trace=0x7fffffffa8d0, event=0x7ffff6a7bfe8) at builtin-trace.c:2845 #7 0x0000000000492896 in trace__run (trace=0x7fffffffa8d0, argc=0, argv=0x7fffffffdb58) at builtin-trace.c:3040 #8 0x000000000049603a in cmd_trace (argc=0, argv=0x7fffffffdb58) at builtin-trace.c:3952 #9 0x00000000004d5103 in main (argc=1, argv=0x7fffffffdb58) at perf.c:474 (gdb) p fd $1 = -1 (gdb) p file $7 = (struct file *) 0xfffffffffffffff0 (gdb) p ((struct thread_trace *)arg->thread)->files.table + fd $8 = (struct file *) 0xfffffffffffffff0 (gdb) Check for that and return NULL instead. This problem was introduced recently, the other codepaths leading to thread_trace__files_entry() check for negative fds, like thread__fd_path(), but we need to do it at thread_trace__files_entry() as more users are now calling it directly. Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Fixes: 2d473389f87a ("perf trace beauty: Export function to get the files for a thread") Link: https://lkml.kernel.org/n/tip-oq7bvaaf07gsd4yqty3107u2@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo Signed-off-by: Sasha Levin

perf trace: Support multiple "vfs_getname" probes

2019-02-04T18:50:38+00:00

With a suitably defined "probe:vfs_getname" probe, 'perf trace' can "beautify" its output, so syscalls like open() or openat() can print the "filename" argument instead of just its hex address, like: $ perf trace -e open -- touch /dev/null [...] 0.590 ( 0.014 ms): touch/18063 open(filename: /dev/null, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3 [...] The output without such beautifier looks like: 0.529 ( 0.011 ms): touch/18075 open(filename: 0xc78cf288, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3 However, when the vfs_getname probe expands to multiple probes and it is not the first one that is hit, the beautifier fails, as following: 0.326 ( 0.010 ms): touch/18072 open(filename: , flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3 Fix it by hooking into all the expanded probes (inlines), now, for instance: [root@quaco ~]# perf probe -l probe:vfs_getname (on getname_flags:73@fs/namei.c with pathname) probe:vfs_getname_1 (on getname_flags:73@fs/namei.c with pathname) [root@quaco ~]# perf trace -e open* sleep 1 0.010 ( 0.005 ms): sleep/5588 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC) = 3 0.029 ( 0.006 ms): sleep/5588 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDONLY|CLOEXEC) = 3 0.194 ( 0.008 ms): sleep/5588 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: RDONLY|CLOEXEC) = 3 [root@quaco ~]# Works, further verified with: [root@quaco ~]# perf test vfs 65: Use vfs_getname probe to get syscall args filenames : Ok 66: Add vfs_getname probe to get syscall args filenames : Ok 67: Check open filename arg using perf trace + vfs_getname: Ok [root@quaco ~]# Reported-by: Michael Petlan Tested-by: Michael Petlan Cc: Adrian Hunter Cc: Jiri Olsa Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-mv8kolk17xla1smvmp3qabv1@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Fix alignment for [continued] lines

2019-01-08T16:28:12+00:00

We were not taking into account the "... [continued]" printed characters, fix it. Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-qt20y0acmf8k0bzisce8kw95@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Fix ')' placement in "interrupted" syscall lines

2019-01-08T16:28:12+00:00

When we get the sys_enter for a syscall we check if the last one is still waiting for its matching sys_exit, if so we print this: 468.753 ( ): firefox/32382 poll(ufds: 0x7f3988d3dd00, nfds: 7, timeout_msecs: 4294967295) ... 449.575 ( 0.004 ms): Softwar~cThrea/32434 futex(uaddr: 0x7f39a18a9b70, op: WAKE|PRIVATE_FLAG, val: 1) = 0 At some point we'll get that poll sys_exit event and will print a "[continued]" line. While making the sizing of the alignment after the syscall arg list and its result configurable, so that we can mimic strace, which uses a smaller alingment by default, a bug was introduced where the closing parens appeared before the syscall name and its arg list, fix it. Fixes: 4b8a240ed5e0 ("perf trace: Add alignment spaces after the closing parens") Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-oi45i54s59h1w1kmgpzrfuum@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace beauty: Export function to get the files for a thread

2018-12-28T19:33:05+00:00

So that beautifiers can access things like dev_maj. Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-wm5o51f206c5pi063dsaeraq@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Store the major number for a file when storing its pathname

2018-12-28T19:33:04+00:00

We keep a table for the fds to map them back to pathnames when showing 'fd' based APIs such as write(), store as well the major number for the device the path is in, to use in things like choosing the right ioctl 'cmd' beautifier. Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-qjkds7bnk7v7fk2xhqsb0a4v@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Move the files table resizing to outside set_pathname()

2018-12-28T19:33:03+00:00

So that we can have that table expanded when setting other attributes. Cc: Adrian Hunter Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-hzvpe3qwafe6sqcq3bhtbxds@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Rename thread_thread->paths to thread_trace->files

2018-12-28T19:33:03+00:00

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 Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-1895cmhrdz2dkl5prf2cj2yj@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Do not hardcode the size of the tracepoint common_ fields

2018-12-21T12:42:46+00:00

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 Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-2pqavrktqkliu5b9nzouio21@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo