1. 29 8月, 2017 1 次提交
    • A
      perf trace beauty: Beautify pkey_{alloc,free,mprotect} arguments · 83bc9c37
      Arnaldo Carvalho de Melo 提交于
      Reuse 'mprotect' beautifiers for 'pkey_mprotect'.
      
      System wide tracing pkey_alloc, pkey_free and pkey_mprotect calls, with
      backtraces:
      
        # perf trace -e pkey_alloc,pkey_mprotect,pkey_free --max-stack=5
           0.000 ( 0.011 ms): pkey/7818 pkey_alloc(init_val: DISABLE_ACCESS|DISABLE_WRITE) = -1 EINVAL Invalid argument
                                             syscall (/usr/lib64/libc-2.25.so)
                                             pkey_alloc (/home/acme/c/pkey)
           0.022 ( 0.003 ms): pkey/7818 pkey_mprotect(start: 0x7f28c3890000, len: 4096, prot: READ|WRITE, pkey: -1) = 0
                                             syscall (/usr/lib64/libc-2.25.so)
                                             pkey_mprotect (/home/acme/c/pkey)
           0.030 ( 0.002 ms): pkey/7818 pkey_free(pkey: -1                               ) = -1 EINVAL Invalid argument
                                             syscall (/usr/lib64/libc-2.25.so)
                                             pkey_free (/home/acme/c/pkey)
      
      The tools/include/uapi/asm-generic/mman-common.h file is used to find
      the access rights defines for the pkey_alloc syscall second argument.
      
      Since we have the detector of changes for the tools/include header files
      versus its kernel origin (include/uapi/asm-generic/mman-common.h), we'll
      get whatever new flag appears for that argument automatically.
      
      This method should be used in other cases where it is easy to generate
      those flags tables because the header has properly namespaced defines
      like PKEY_DISABLE_ACCESS and PKEY_DISABLE_WRITE.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Arnd Bergmann <arnd@arndb.de>
      Cc: Dave Hansen <dave.hansen@linux.intel.com>
      Cc: David Ahern <dsahern@gmail.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-3xq5312qlks7wtfzv2sk3nct@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      83bc9c37
  2. 01 8月, 2017 1 次提交
    • A
      perf trace beauty ioctl: Improve 'cmd' beautifier · 1cc47f2d
      Arnaldo Carvalho de Melo 提交于
      By using the _IOC_(DIR,NR,TYPE,SIZE) macros to lookup a 'type' keyed
      table that then gets indexed by 'nr', falling back to a notation similar
      to the one used by 'strace', only more compact, i.e.:
      
         474.356 ( 0.007 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xae, 0x1c), arg: 0x7ffc934f7880) = 0
         474.369 ( 0.053 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xb0, 0x18), arg: 0x7ffc934f77d0) = 0
         505.055 ( 0.014 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xaf, 0x4), arg: 0x7ffc934f741c) = 0
      
      This also moves it out of builtin-trace.c and into trace/beauty/ioctl.c
      to better compartimentalize all these formatters.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: David Ahern <dsahern@gmail.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-s3enursdxsvnhdomh6qlte4g@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      1cc47f2d
  3. 20 7月, 2017 1 次提交
    • A
      perf trace beauty clone: Beautify syscall arguments · 33396a3a
      Arnaldo Carvalho de Melo 提交于
      Now, syswide tracing, selected entries:
      
        # trace -e clone
        24417.203 ( 0.158 ms): bash/11323 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11325 (bash)
                ? (     ?   ): bash/11325  ... [continued]: clone()) = 0
        24419.355 ( 0.093 ms): bash/10586 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11326 (bash)
                ? (     ?   ): bash/11326  ... [continued]: clone()) = 0
        24419.744 ( 0.102 ms): bash/11326 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11327 (bash)
                ? (     ?   ): bash/11327  ... [continued]: clone()) = 0
        24420.138 ( 0.105 ms): bash/11327 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11328 (bash)
                ? (     ?   ): bash/11328  ... [continued]: clone()) = 0
        35747.722 ( 0.044 ms): gpg-agent/18087 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ff0755f6ff0, parent_tidptr: 0x7ff0755f79d0, child_tidptr: 0x7ff0755f79d0, tls: 0x7ff0755f7700) = 11329 (gpg-agent)
                ? (     ?   ): gpg-agent/11329  ... [continued]: clone()) = 0
        35748.359 ( 0.022 ms): gpg-agent/18087 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ff075df7ff0, parent_tidptr: 0x7ff075df89d0, child_tidptr: 0x7ff075df89d0, tls: 0x7ff075df8700) = 11330 (gpg-agent)
                ? (     ?   ): gpg-agent/11330  ... [continued]: clone()) = 0
        35781.422 ( 0.452 ms): NetworkManager/1112 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7f2f1fffedb0, parent_tidptr: 0x7f2f1ffff9d0, child_tidptr: 0x7f2f1ffff9d0, tls: 0x7f2f1ffff700) = 11331 (NetworkManager)
                ? (     ?   ): NetworkManager/11331  ... [continued]: clone()) = 0
      
      Need to improve the formatting of the second return, to the child, this
      cset only focused on the argument formatting.
      
      If we trace just one pid:
      
        # trace -e clone -p 19863
           0.349 ( 0.025 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb84eaac70, parent_tidptr: 0x7ffb84eab9d0, child_tidptr: 0x7ffb84eab9d0, tls: 0x7ffb84eab700) = 11637 (Chrome_IOThread)
           0.392 ( 0.013 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb664b8c70, parent_tidptr: 0x7ffb664b99d0, child_tidptr: 0x7ffb664b99d0, tls: 0x7ffb664b9700) = 11638 (Chrome_IOThread)
           0.573 ( 0.015 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb6046cc70, parent_tidptr: 0x7ffb6046d9d0, child_tidptr: 0x7ffb6046d9d0, tls: 0x7ffb6046d700) = 11639 (Chrome_IOThread)
           0.617 ( 0.014 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb730dcc70, parent_tidptr: 0x7ffb730dd9d0, child_tidptr: 0x7ffb730dd9d0, tls: 0x7ffb730dd700) = 11640 (Chrome_IOThread)
           4.350 ( 0.065 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb720d9c70, parent_tidptr: 0x7ffb720da9d0, child_tidptr: 0x7ffb720da9d0, tls: 0x7ffb720da700) = 11642 (Chrome_IOThread)
           5.642 ( 0.079 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb718d8c70, parent_tidptr: 0x7ffb718d99d0, child_tidptr: 0x7ffb718d99d0, tls: 0x7ffb718d9700) = 11643 (Chrome_IOThread)
      ^C#
      
      We'll also have to fix the argument ordering in different arches,
      probably having multiple syscall_fmt entries with each possible order
      and then use perf_evsel__env_arch() (if dealing with a perf.data file)
      or the current system info, for live sessions.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: David Ahern <dsahern@gmail.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-am068uyubgj83snepolwhbfe@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      33396a3a
  4. 19 7月, 2017 1 次提交
  5. 01 4月, 2017 1 次提交
    • A
      perf trace: Beautify statx syscall 'flag' and 'mask' arguments · fd5cead2
      Arnaldo Carvalho de Melo 提交于
      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.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      fd5cead2