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

perf trace: Resolve prctl's 'option' arg strings to numbers

2020-02-11T19:41:50Z

# perf trace -e syscalls:sys_enter_prctl --filter="option==SET_NAME" 0.000 Socket Thread/3860 syscalls:sys_enter_prctl(option: SET_NAME, arg2: 0x7fc50b9733e8) 0.053 SSL Cert #78/3860 syscalls:sys_enter_prctl(option: SET_NAME, arg2: 0x7fc50b9733e8) ^C # If one uses '-v' with 'perf trace', we can see the filter it puts in place: New filter for syscalls:sys_enter_prctl: (option==0xf) && (common_pid != 3859 && common_pid != 2757) We still need to allow using plain '-e prctl' and have this turn into creating a 'syscalls:sys_enter_prctl' event so that the filter can be applied only to it as right now '-e prctl' ends up using the 'raw_syscalls:sys_enter/sys_exit'. The end goal is to have something like: # perf trace -e prctl/option==SET_NAME/ And have that use tracepoint filters or eBPF ones. Cc: Adrian Hunter Cc: Christian Brauner Cc: Jiri Olsa Cc: Mike Christie Cc: Namhyung Kim Signed-off-by: Arnaldo Carvalho de Melo

perf parse: Report initial event parsing error

2019-11-18T22:14:29Z

Record the first event parsing error and report. Implementing feedback from Jiri Olsa: https://lkml.org/lkml/2019/10/28/680 An example error is: $ tools/perf/perf stat -e c/c/ WARNING: multiple event parsing errors event syntax error: 'c/c/' \___ unknown term valid terms: event,filter_rem,filter_opc0,edge,filter_isoc,filter_tid,filter_loc,filter_nc,inv,umask,filter_opc1,tid_en,thresh,filter_all_op,filter_not_nm,filter_state,filter_nm,config,config1,config2,name,period,percore Initial error: event syntax error: 'c/c/' \___ Cannot find PMU `c'. Missing kernel support? Run 'perf list' for a list of valid events Usage: perf stat [] [] -e, --event event selector. use 'perf list' to list available events Signed-off-by: Ian Rogers Tested-by: Arnaldo Carvalho de Melo Cc: Adrian Hunter Cc: Alexander Shishkin Cc: Allison Randal Cc: Andi Kleen Cc: Anju T Sudhakar Cc: Christian Borntraeger Cc: Davidlohr Bueso Cc: Jin Yao Cc: Jiri Olsa Cc: Mark Rutland Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Ravi Bangoria Cc: Stephane Eranian Cc: Thomas Gleixner Cc: Thomas Richter Link: http://lore.kernel.org/lkml/20191116074652.9960-1-irogers@google.com Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Use STUL_STRARRAY_FLAGS with mmap

2019-10-19T18:35:02Z

The 'mmap' syscall has special needs so it doesn't use SCA_STRARRAY_FLAGS, see its implementation in syscall_arg__scnprintf_mmap_flags(), related to special handling of MAP_ANONYMOUS, so set ->parm to the strarray__mmap_flags and hook up with strarray__strtoul_flags manually, now we can filter by those or-ed string expressions: # perf trace -e syscalls:sys_enter_mmap sleep 1 0.000 syscalls:sys_enter_mmap(addr: NULL, len: 134346, prot: READ, flags: PRIVATE, fd: 3, off: 0) 0.026 syscalls:sys_enter_mmap(addr: NULL, len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) 0.036 syscalls:sys_enter_mmap(addr: NULL, len: 1857472, prot: READ, flags: PRIVATE|DENYWRITE, fd: 3, off: 0) 0.046 syscalls:sys_enter_mmap(addr: 0x7fae003d9000, len: 1363968, prot: READ|EXEC, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x22000) 0.052 syscalls:sys_enter_mmap(addr: 0x7fae00526000, len: 311296, prot: READ, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x16f000) 0.055 syscalls:sys_enter_mmap(addr: 0x7fae00573000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x1bb000) 0.062 syscalls:sys_enter_mmap(addr: 0x7fae00579000, len: 14272, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) 0.253 syscalls:sys_enter_mmap(addr: NULL, len: 217750512, prot: READ, flags: PRIVATE, fd: 3, off: 0) # # perf trace -e syscalls:sys_enter_mmap --filter="flags==PRIVATE|FIXED|DENYWRITE" sleep 1 0.000 syscalls:sys_enter_mmap(addr: 0x7f6ab3dcb000, len: 1363968, prot: READ|EXEC, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x22000) 0.010 syscalls:sys_enter_mmap(addr: 0x7f6ab3f18000, len: 311296, prot: READ, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x16f000) 0.014 syscalls:sys_enter_mmap(addr: 0x7f6ab3f65000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x1bb000) # perf trace -e syscalls:sys_enter_mmap --filter="flags==PRIVATE|ANONYMOUS" sleep 1 0.000 syscalls:sys_enter_mmap(addr: NULL, len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) # # perf trace -v -e syscalls:sys_enter_mmap --filter="flags==PRIVATE|ANONYMOUS" sleep 1 |& grep "New filter" New filter for syscalls:sys_enter_mmap: flags==0x22 # Cc: Adrian Hunter Cc: Andi Kleen Cc: Brendan Gregg Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-czw754b7m9rp9ibq2f6be2o1@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Wire up strarray__strtoul_flags()

2019-10-19T18:35:02Z

Now anything that uses STRARRAY_FLAGS, like the 'fsmount' syscall will support mapping or-ed strings back to a value that can be used in a filter. In some cases, where STRARRAY_FLAGS isn't used but instead the scnprintf is a special one because of specific needs, like for mmap, then one has to set the ->pars to the strarray. See the next cset. Cc: Adrian Hunter Cc: Andi Kleen Cc: Brendan Gregg Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-r2lpqo7dfsrhi4ll0npsb3u7@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

libbeauty: Introduce strarray__strtoul_flags()

2019-10-19T18:35:02Z

Counterpart of strarray__scnprintf_flags(), i.e. from a expression like: # perf trace -e syscalls:sys_enter_mmap --filter="flags==PRIVATE|FIXED|DENYWRITE" I.e. that "flags==PRIVATE|FIXED|DENYWRITE", turn that into # perf trace -e syscalls:sys_enter_mmap --filter=0x812 Cc: Adrian Hunter Cc: Andi Kleen Cc: Brendan Gregg Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-8xst3zrqqogax7fmfzwymvbl@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Use strtoul for the fcntl 'cmd' argument

2019-10-19T18:35:02Z

Since its values are in two ranges of values we ended up codifying it using a 'struct strarrays', so now hook it up with STUL_STRARRAYS so that we can do: # perf trace -e syscalls:*enter_fcntl --filter=cmd==SETLK||cmd==SETLKW 0.000 sssd_kcm/19021 syscalls:sys_enter_fcntl(fd: 13, cmd: SETLK, arg: 0x7ffcf0a4dee0) 1.523 sssd_kcm/19021 syscalls:sys_enter_fcntl(fd: 13, cmd: SETLK, arg: 0x7ffcf0a4de90) 1.629 sssd_kcm/19021 syscalls:sys_enter_fcntl(fd: 13, cmd: SETLK, arg: 0x7ffcf0a4de90) 2.711 sssd_kcm/19021 syscalls:sys_enter_fcntl(fd: 13, cmd: SETLK, arg: 0x7ffcf0a4de70) ^C# Cc: Adrian Hunter Cc: Andi Kleen Cc: Brendan Gregg Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-mob96wyzri4r3rvyigqfjv0a@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

libbeauty: Introduce syscall_arg__strtoul_strarrays()

2019-10-19T18:35:01Z

To allow going from string to integer for 'struct strarrays'. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-b1ia3xzcy72hv0u4m168fcd0@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Pass a syscall_arg to syscall_arg_fmt->strtoul()

2019-10-19T18:34:48Z

With just what we need for the STUL_STRARRAY, i.e. the 'struct strarray' pointer to be used, just like with syscall_arg_fmt->scnprintf() for the other direction (number -> string). With this all the strarrays that are associated with syscalls can be used with '-e syscalls:sys_enter_SYSCALLNAME --filter', and soon will be possible as well to use with the strace-like shorter form, with just the syscall names, i.e. something like: -e lseek/whence==END/ For now we have to use the longer form: # perf trace -e syscalls:sys_enter_lseek 0.000 pool/2242 syscalls:sys_enter_lseek(fd: 14, offset: 0, whence: CUR) 0.031 pool/2242 syscalls:sys_enter_lseek(fd: 15, offset: 0, whence: CUR) 0.046 pool/2242 syscalls:sys_enter_lseek(fd: 16, offset: 0, whence: CUR) 5003.528 pool/2242 syscalls:sys_enter_lseek(fd: 14, offset: 0, whence: CUR) 5003.575 pool/2242 syscalls:sys_enter_lseek(fd: 15, offset: 0, whence: CUR) 5003.593 pool/2242 syscalls:sys_enter_lseek(fd: 16, offset: 0, whence: CUR) 10002.017 pool/2242 syscalls:sys_enter_lseek(fd: 14, offset: 0, whence: CUR) 10002.051 pool/2242 syscalls:sys_enter_lseek(fd: 15, offset: 0, whence: CUR) 10002.068 pool/2242 syscalls:sys_enter_lseek(fd: 16, offset: 0, whence: CUR) ^C# perf trace -e syscalls:sys_enter_lseek --filter="whence!=CUR" 0.000 sshd/24476 syscalls:sys_enter_lseek(fd: 3, offset: 9032, whence: SET) 0.060 sshd/24476 syscalls:sys_enter_lseek(fd: 3, offset: 9032, whence: SET) 0.187 sshd/24476 syscalls:sys_enter_lseek(fd: 3, offset: 118632, whence: SET) 0.203 sshd/24476 syscalls:sys_enter_lseek(fd: 3, offset: 118632, whence: SET) 0.349 sshd/24476 syscalls:sys_enter_lseek(fd: 3, offset: 61936, whence: SET) ^C# And for those curious about what are those lseek(DSO, offset, SET), well, its the loader: # perf trace -e syscalls:sys_enter_lseek/max-stack=16/ --filter="whence!=CUR" 0.000 sshd/24495 syscalls:sys_enter_lseek(fd: 3, offset: 9032, whence: SET) __libc_lseek64 (/usr/lib64/ld-2.29.so) _dl_map_object (/usr/lib64/ld-2.29.so) 0.067 sshd/24495 syscalls:sys_enter_lseek(fd: 3, offset: 9032, whence: SET) __libc_lseek64 (/usr/lib64/ld-2.29.so) _dl_map_object_from_fd (/usr/lib64/ld-2.29.so) _dl_map_object (/usr/lib64/ld-2.29.so) 0.198 sshd/24495 syscalls:sys_enter_lseek(fd: 3, offset: 118632, whence: SET) __libc_lseek64 (/usr/lib64/ld-2.29.so) _dl_map_object (/usr/lib64/ld-2.29.so) 0.219 sshd/24495 syscalls:sys_enter_lseek(fd: 3, offset: 118632, whence: SET) __libc_lseek64 (/usr/lib64/ld-2.29.so) _dl_map_object_from_fd (/usr/lib64/ld-2.29.so) _dl_map_object (/usr/lib64/ld-2.29.so) ^C# :-) With this we can use strings in strarrays in filters, which allows us to reuse all these that are in place for syscalls: $ find tools/perf/trace/beauty/ -name "*.c" | xargs grep -w DEFINE_STRARRAY tools/perf/trace/beauty/fcntl.c: static DEFINE_STRARRAY(fcntl_setlease, "F_"); tools/perf/trace/beauty/mmap.c: static DEFINE_STRARRAY(mmap_flags, "MAP_"); tools/perf/trace/beauty/mmap.c: static DEFINE_STRARRAY(madvise_advices, "MADV_"); tools/perf/trace/beauty/sync_file_range.c: static DEFINE_STRARRAY(sync_file_range_flags, "SYNC_FILE_RANGE_"); tools/perf/trace/beauty/socket.c: static DEFINE_STRARRAY(socket_ipproto, "IPPROTO_"); tools/perf/trace/beauty/mount_flags.c: static DEFINE_STRARRAY(mount_flags, "MS_"); tools/perf/trace/beauty/pkey_alloc.c: static DEFINE_STRARRAY(pkey_alloc_access_rights, "PKEY_"); tools/perf/trace/beauty/sockaddr.c:DEFINE_STRARRAY(socket_families, "PF_"); tools/perf/trace/beauty/tracepoints/x86_irq_vectors.c:static DEFINE_STRARRAY(x86_irq_vectors, "_VECTOR"); tools/perf/trace/beauty/tracepoints/x86_msr.c:static DEFINE_STRARRAY(x86_MSRs, "MSR_"); tools/perf/trace/beauty/prctl.c: static DEFINE_STRARRAY(prctl_options, "PR_"); tools/perf/trace/beauty/prctl.c: static DEFINE_STRARRAY(prctl_set_mm_options, "PR_SET_MM_"); tools/perf/trace/beauty/fspick.c: static DEFINE_STRARRAY(fspick_flags, "FSPICK_"); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(ioctl_tty_cmd, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(drm_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(sndrv_pcm_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(sndrv_ctl_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(kvm_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(vhost_virtio_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(vhost_virtio_ioctl_read_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(perf_ioctl_cmds, ""); tools/perf/trace/beauty/ioctl.c: static DEFINE_STRARRAY(usbdevfs_ioctl_cmds, ""); tools/perf/trace/beauty/fsmount.c: static DEFINE_STRARRAY(fsmount_attr_flags, "MOUNT_ATTR_"); tools/perf/trace/beauty/renameat.c: static DEFINE_STRARRAY(rename_flags, "RENAME_"); tools/perf/trace/beauty/kcmp.c: static DEFINE_STRARRAY(kcmp_types, "KCMP_"); tools/perf/trace/beauty/move_mount.c: static DEFINE_STRARRAY(move_mount_flags, "MOVE_MOUNT_"); $ Well, some, as the mmap flags are like: $ tools/perf/trace/beauty/mmap_flags.sh static const char *mmap_flags[] = { [ilog2(0x40) + 1] = "32BIT", [ilog2(0x01) + 1] = "SHARED", [ilog2(0x02) + 1] = "PRIVATE", [ilog2(0x10) + 1] = "FIXED", [ilog2(0x20) + 1] = "ANONYMOUS", [ilog2(0x008000) + 1] = "POPULATE", [ilog2(0x010000) + 1] = "NONBLOCK", [ilog2(0x020000) + 1] = "STACK", [ilog2(0x040000) + 1] = "HUGETLB", [ilog2(0x080000) + 1] = "SYNC", [ilog2(0x100000) + 1] = "FIXED_NOREPLACE", [ilog2(0x0100) + 1] = "GROWSDOWN", [ilog2(0x0800) + 1] = "DENYWRITE", [ilog2(0x1000) + 1] = "EXECUTABLE", [ilog2(0x2000) + 1] = "LOCKED", [ilog2(0x4000) + 1] = "NORESERVE", }; $ So we'll need a strarray__strtoul_flags() that will break donw the flags into tokens separated by '|' before doing the lookup and then go on reconstructing the value from, say: # perf trace -e syscalls:sys_enter_mmap --filter="flags==PRIVATE|FIXED|DENYWRITE" into: # perf trace -e syscalls:sys_enter_mmap --filter="flags==0x2|0x10|0x0800" and finally into: # perf trace -e syscalls:sys_enter_mmap --filter="flags==0x812" That is what we see if we don't use the augmented view obtained from: # perf trace -e mmap 211792.885 procmail/15393 mmap(addr: 0x7fcd11645000, len: 8192, prot: READ, flags: PRIVATE|FIXED|DENYWRITE, fd: 8, off: 0xa000) = 0x7fcd11645000 But plain use tracefs: procmail-15559 [000] .... 54557.178262: sys_mmap(addr: 7f5c9bf7a000, len: 9b000, prot: 1, flags: 812, fd: 3, off: a9000) Cc: Adrian Hunter Cc: Andi Kleen Cc: Brendan Gregg Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-c6mgkjt8ujnc263eld5tb7q3@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf trace: Honour --max-events in processing syscalls:sys_enter_*

2019-10-18T15:19:02Z

We were doing this only at the sys_exit syscall tracepoint, as for strace-like we count the pair of sys_enter and sys_exit as one event, but when asking specifically for a the syscalls:sys_enter_NAME tracepoint we need to count each of those as an event. I.e. things like: # perf trace --max-events=4 -e syscalls:sys_enter_lseek 0.000 pool/2242 syscalls:sys_enter_lseek(fd: 14, offset: 0, whence: CUR) 0.034 pool/2242 syscalls:sys_enter_lseek(fd: 15, offset: 0, whence: CUR) 0.051 pool/2242 syscalls:sys_enter_lseek(fd: 16, offset: 0, whence: CUR) 2307.900 sshd/30800 syscalls:sys_enter_lseek(fd: 3, offset: 9032, whence: SET) # Were going on forever, since we only had sys_enter events. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-0ob1dky1a9ijlfrfhxyl40wr@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

libbeauty: Introduce syscall_arg__strtoul_strarray()

2019-10-18T15:07:46Z

To go from strarrays strings to its indexes. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Luis Cláudio Gonçalves Cc: Namhyung Kim Link: https://lkml.kernel.org/n/tip-wta0qvo207z27huib2c4ijxq@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo