Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

perf trace: Beautify statx syscall 'flag' and 'mask' arguments

To test it, build samples/statx/test_statx, which I did as:

$ make headers_install
$ cc -I ~/git/linux/usr/include samples/statx/test-statx.c -o /tmp/statx

And then use perf trace on it:

# perf trace -e statx /tmp/statx /etc/passwd
statx(/etc/passwd) = 0
results=7ff
Size: 3496 Blocks: 8 IO Block: 4096 regular file
Device: fd:00 Inode: 280156 Links: 1
Access: (0644/-rw-r--r--) Uid: 0 Gid: 0
Access: 2017-03-29 16:01:01.650073438-0300
Modify: 2017-03-10 16:25:14.156479354-0300
Change: 2017-03-10 16:25:14.171479328-0300
0.000 ( 0.007 ms): statx/30648 statx(dfd: CWD, filename: 0x7ef503f4, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff7ef4eb10) = 0
#

Using the test-stat.c options to change the mask:

# perf trace -e statx /tmp/statx -O /etc/passwd > /dev/null
0.000 ( 0.008 ms): statx/30745 statx(dfd: CWD, filename: 0x3a0753f4, flags: SYMLINK_NOFOLLOW, mask: BTIME, buffer: 0x7ffd3a0735c0) = 0
#
# perf trace -e statx /tmp/statx -A /etc/passwd > /dev/null
0.000 ( 0.010 ms): statx/30757 statx(dfd: CWD, filename: 0xa94e63f4, flags: SYMLINK_NOFOLLOW|NO_AUTOMOUNT, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffea94e49d0) = 0
#
# trace --no-inherit -e statx /tmp/statx -F /etc/passwd > /dev/null
0.000 ( 0.011 ms): statx(dfd: CWD, filename: 0x3b02d3f3, flags: SYMLINK_NOFOLLOW|STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffd3b02c850) = 0
#
# trace --no-inherit -e statx /tmp/statx -F -L /etc/passwd > /dev/null
0.000 ( 0.008 ms): statx(dfd: CWD, filename: 0x15cff3f3, flags: STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff15cfdda0) = 0
#
# trace --no-inherit -e statx /tmp/statx -D -O /etc/passwd > /dev/null
0.000 ( 0.009 ms): statx(dfd: CWD, filename: 0xfa37f3f3, flags: SYMLINK_NOFOLLOW|STATX_DONT_SYNC, mask: BTIME, buffer: 0x7ffffa37da20) = 0
#

Adding a probe to get the filename collected as well:

# perf probe 'vfs_getname=getname_flags:72 pathname=result->name:string'
Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=result->name:string)

You can now use it in all perf tools, such as:

perf record -e probe:vfs_getname -aR sleep 1

# trace --no-inherit -e statx /tmp/statx -D -O /etc/passwd > /dev/null
0.169 ( 0.007 ms): statx(dfd: CWD, filename: /etc/passwd, flags: SYMLINK_NOFOLLOW|STATX_DONT_SYNC, mask: BTIME, buffer: 0x7ffda9bf50f0) = 0
#

Same technique could be used to collect and beautify the result put in
the 'buffer' argument.

Finally do a system wide 'perf trace' session looking for any use of statx,
then run the test proggie with various flags:

# trace -e statx
16612.967 ( 0.028 ms): statx/4562 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffef195d660) = 0
33064.447 ( 0.011 ms): statx/4569 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW|STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffc5484c790) = 0
36050.891 ( 0.023 ms): statx/4576 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: BTIME, buffer: 0x7ffeb18b66e0) = 0
38039.889 ( 0.023 ms): statx/4584 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff1db0ea90) = 0
^C#

This one also starts moving the beautifiers from files directly included
in builtin-trace.c to separate objects + a beauty.h header with
prototypes, so that we can add test cases in tools/perf/tests/ to fire
syscalls with various arguments and then get them intercepted as
syscalls:sys_enter_foo or raw_syscalls:sys_enter + sys_exit to then
format and check that the formatted output is the one we expect.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Al Viro <viro@zeniv.linux.org.uk>
Cc: David Ahern <dsahern@gmail.com>
Cc: David Howells <dhowells@redhat.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-xvzw8eynffvez5czyzidhrno@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

+104 -9
+1
tools/perf/Build
··· 50 50 libperf-y += arch/ 51 51 libperf-y += ui/ 52 52 libperf-y += scripts/ 53 + libperf-y += trace/beauty/ 53 54 54 55 gtk-y += ui/gtk/
+1
tools/perf/arch/x86/entry/syscalls/syscall_64.tbl
··· 338 338 329 common pkey_mprotect sys_pkey_mprotect 339 339 330 common pkey_alloc sys_pkey_alloc 340 340 331 common pkey_free sys_pkey_free 341 + 332 common statx sys_statx 341 342 342 343 # 343 344 # x32-specific system call numbers start at 512 to avoid cache impact
+5 -9
tools/perf/builtin-trace.c
··· 31 31 #include "util/intlist.h" 32 32 #include "util/thread_map.h" 33 33 #include "util/stat.h" 34 + #include "trace/beauty/beauty.h" 34 35 #include "trace-event.h" 35 36 #include "util/parse-events.h" 36 37 #include "util/bpf-loader.h" ··· 267 266 #define perf_evsel__sc_tp_ptr(evsel, name, sample) \ 268 267 ({ struct syscall_tp *fields = evsel->priv; \ 269 268 fields->name.pointer(&fields->name, sample); }) 270 - 271 - struct syscall_arg { 272 - unsigned long val; 273 - struct thread *thread; 274 - struct trace *trace; 275 - void *parm; 276 - u8 idx; 277 - u8 mask; 278 - }; 279 269 280 270 struct strarray { 281 271 int offset; ··· 763 771 .arg_parm = { [0] = &strarray__socket_families, /* family */ }, }, 764 772 { .name = "stat", .errmsg = true, .alias = "newstat", }, 765 773 { .name = "statfs", .errmsg = true, }, 774 + { .name = "statx", .errmsg = true, 775 + .arg_scnprintf = { [0] = SCA_FDAT, /* flags */ 776 + [2] = SCA_STATX_FLAGS, /* flags */ 777 + [3] = SCA_STATX_MASK, /* mask */ }, }, 766 778 { .name = "swapoff", .errmsg = true, 767 779 .arg_scnprintf = { [0] = SCA_FILENAME, /* specialfile */ }, }, 768 780 { .name = "swapon", .errmsg = true,
+1
tools/perf/trace/beauty/Build
··· 1 + libperf-y += statx.o
+24
tools/perf/trace/beauty/beauty.h
··· 1 + #ifndef _PERF_TRACE_BEAUTY_H 2 + #define _PERF_TRACE_BEAUTY_H 3 + 4 + #include <linux/types.h> 5 + 6 + struct trace; 7 + struct thread; 8 + 9 + struct syscall_arg { 10 + unsigned long val; 11 + struct thread *thread; 12 + struct trace *trace; 13 + void *parm; 14 + u8 idx; 15 + u8 mask; 16 + }; 17 + 18 + size_t syscall_arg__scnprintf_statx_flags(char *bf, size_t size, struct syscall_arg *arg); 19 + #define SCA_STATX_FLAGS syscall_arg__scnprintf_statx_flags 20 + 21 + size_t syscall_arg__scnprintf_statx_mask(char *bf, size_t size, struct syscall_arg *arg); 22 + #define SCA_STATX_MASK syscall_arg__scnprintf_statx_mask 23 + 24 + #endif /* _PERF_TRACE_BEAUTY_H */
+72
tools/perf/trace/beauty/statx.c
··· 1 + /* 2 + * trace/beauty/statx.c 3 + * 4 + * Copyright (C) 2017, Red Hat Inc, Arnaldo Carvalho de Melo <acme@redhat.com> 5 + * 6 + * Released under the GPL v2. (and only v2, not any later version) 7 + */ 8 + 9 + #include "trace/beauty/beauty.h" 10 + #include <linux/kernel.h> 11 + #include <sys/types.h> 12 + #include <uapi/linux/fcntl.h> 13 + #include <uapi/linux/stat.h> 14 + 15 + size_t syscall_arg__scnprintf_statx_flags(char *bf, size_t size, struct syscall_arg *arg) 16 + { 17 + int printed = 0, flags = arg->val; 18 + 19 + if (flags == 0) 20 + return scnprintf(bf, size, "SYNC_AS_STAT"); 21 + #define P_FLAG(n) \ 22 + if (flags & AT_##n) { \ 23 + printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \ 24 + flags &= ~AT_##n; \ 25 + } 26 + 27 + P_FLAG(SYMLINK_NOFOLLOW); 28 + P_FLAG(REMOVEDIR); 29 + P_FLAG(SYMLINK_FOLLOW); 30 + P_FLAG(NO_AUTOMOUNT); 31 + P_FLAG(EMPTY_PATH); 32 + P_FLAG(STATX_FORCE_SYNC); 33 + P_FLAG(STATX_DONT_SYNC); 34 + 35 + #undef P_FLAG 36 + 37 + if (flags) 38 + printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags); 39 + 40 + return printed; 41 + } 42 + 43 + size_t syscall_arg__scnprintf_statx_mask(char *bf, size_t size, struct syscall_arg *arg) 44 + { 45 + int printed = 0, flags = arg->val; 46 + 47 + #define P_FLAG(n) \ 48 + if (flags & STATX_##n) { \ 49 + printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \ 50 + flags &= ~STATX_##n; \ 51 + } 52 + 53 + P_FLAG(TYPE); 54 + P_FLAG(MODE); 55 + P_FLAG(NLINK); 56 + P_FLAG(UID); 57 + P_FLAG(GID); 58 + P_FLAG(ATIME); 59 + P_FLAG(MTIME); 60 + P_FLAG(CTIME); 61 + P_FLAG(INO); 62 + P_FLAG(SIZE); 63 + P_FLAG(BLOCKS); 64 + P_FLAG(BTIME); 65 + 66 + #undef P_FLAG 67 + 68 + if (flags) 69 + printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags); 70 + 71 + return printed; 72 + }