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

Commit-ID:  fd5cead23f54697310bd565aa2a23ae5128080a0
Gitweb:     http://git.kernel.org/tip/fd5cead23f54697310bd565aa2a23ae5128080a0
Author:     Arnaldo Carvalho de Melo <[email protected]>
AuthorDate: Tue, 14 Mar 2017 16:19:30 -0300
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Fri, 31 Mar 2017 14:42:31 -0300

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.

---
 tools/perf/Build                                  |  1 +
 tools/perf/arch/x86/entry/syscalls/syscall_64.tbl |  1 +
 tools/perf/builtin-trace.c                        | 14 ++---
 tools/perf/trace/beauty/Build                     |  1 +
 tools/perf/trace/beauty/beauty.h                  | 24 ++++++++
 tools/perf/trace/beauty/statx.c                   | 72 +++++++++++++++++++++++
 6 files changed, 104 insertions(+), 9 deletions(-)

index 9b79f8d..bd8eeb6 100644
@@ -50,5 +50,6 @@ libperf-y += util/
 libperf-y += arch/
 libperf-y += ui/
 libperf-y += scripts/
+libperf-y += trace/beauty/
 
 gtk-y += ui/gtk/

index e93ef0b..5aef183 100644
@@ -338,6 +338,7 @@
 329	common	pkey_mprotect		sys_pkey_mprotect
 330	common	pkey_alloc		sys_pkey_alloc
 331	common	pkey_free		sys_pkey_free
+332	common	statx			sys_statx
 
 #
 # x32-specific system call numbers start at 512 to avoid cache impact

index 7379792..fce278d 100644
@@ -31,6 +31,7 @@
 #include "util/intlist.h"
 #include "util/thread_map.h"
 #include "util/stat.h"
+#include "trace/beauty/beauty.h"
 #include "trace-event.h"
 #include "util/parse-events.h"
 #include "util/bpf-loader.h"

@@ -267,15 +268,6 @@ out_delete:
 	({ struct syscall_tp *fields = evsel->priv; \
 	   fields->name.pointer(&fields->name, sample); })
 
-struct syscall_arg {
-	unsigned long val;
-	struct thread *thread;
-	struct trace  *trace;
-	void	      *parm;
-	u8	      idx;
-	u8	      mask;
-};
-
 struct strarray {
 	int	    offset;
 	int	    nr_entries;

@@ -771,6 +763,10 @@ static struct syscall_fmt {
 	  .arg_parm	 = { [0] = &strarray__socket_families, /* family */ }, },
 	{ .name	    = "stat",	    .errmsg = true, .alias = "newstat", },
 	{ .name	    = "statfs",	    .errmsg = true, },
+	{ .name	    = "statx",	    .errmsg = true,
+	  .arg_scnprintf = { [0] = SCA_FDAT, /* flags */
+			     [2] = SCA_STATX_FLAGS, /* flags */
+			     [3] = SCA_STATX_MASK, /* mask */ }, },
 	{ .name	    = "swapoff",    .errmsg = true,
 	  .arg_scnprintf = { [0] = SCA_FILENAME, /* specialfile */ }, },
 	{ .name	    = "swapon",	    .errmsg = true,

new file mode 100644
index 0000000..be95ac6
@@ -0,0 +1 @@
+libperf-y += statx.o

new file mode 100644
index 0000000..cf50be3
@@ -0,0 +1,24 @@
+#ifndef _PERF_TRACE_BEAUTY_H
+#define _PERF_TRACE_BEAUTY_H
+
+#include <linux/types.h>
+
+struct trace;
+struct thread;
+
+struct syscall_arg {
+	unsigned long val;
+	struct thread *thread;
+	struct trace  *trace;
+	void	      *parm;
+	u8	      idx;
+	u8	      mask;
+};
+
+size_t syscall_arg__scnprintf_statx_flags(char *bf, size_t size, struct syscall_arg *arg);
+#define SCA_STATX_FLAGS syscall_arg__scnprintf_statx_flags
+
+size_t syscall_arg__scnprintf_statx_mask(char *bf, size_t size, struct syscall_arg *arg);
+#define SCA_STATX_MASK syscall_arg__scnprintf_statx_mask
+
+#endif /* _PERF_TRACE_BEAUTY_H */