1. 18 Dec, 2018 4 commits
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_raw_syscalls: Copy 'access' arg as well · c48ee107
      Arnaldo Carvalho de Melo authored
      This will all come from userspace, but to test the changes to make 'perf
      trace' output similar to strace's, do this one more now manually.
      
      To update the precompiled augmented_raw_syscalls.o binary I just run:
      
        # perf record -e ~acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
        LLVM: dumping /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o
        [ perf record: Woken up 1 times to write data ]
        [ perf record: Captured and wrote 0.022 MB perf.data ]
        #
      
      Because to have augmented_raw_syscalls to be always used and a fast
      startup and remove the need to have the llvm toolchain installed, I'm
      using:
      
        # perf config | grep add_events
        trace.add_events=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o
        #
      
      So when doing changes to augmented_raw_syscals.c one needs to rebuild
      the .o file.
      
      This will be done automagically later, i.e. have a 'make' behaviour of
      recompiling when the .c gets changed.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Luis Cláudio Gonçalves <lclaudio@redhat.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Link: https://lkml.kernel.org/n/tip-lw3i2atyq8549fpqwmszn3qp@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      c48ee107
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_raw_syscalls: Do not include stdio.h · 4623ce40
      Arnaldo Carvalho de Melo authored
      We're not using that puts() thing, and thus we don't need to define the
      __bpf_stdout__ map, reducing the setup time.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Luis Cláudio Gonçalves <lclaudio@redhat.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Link: https://lkml.kernel.org/n/tip-3452xgatncpil7v22minkwbo@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      4623ce40
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Switch to using a struct for the syscalls map values · 27f2992e
      Arnaldo Carvalho de Melo authored
      We'll start adding more perf-syscall stuff, so lets do this prep step so
      that the next ones are just about adding more fields.
      
      Run it with the .c file once to cache the .o file:
      
        # trace --filter-pids 2834,2199 -e openat,augmented_raw_syscalls.c
        LLVM: dumping augmented_raw_syscalls.o
             0.000 ( 0.021 ms): tmux: server/4952 openat(dfd: CWD, filename: /proc/5691/cmdline                         ) = 11
           349.807 ( 0.040 ms): DNS Res~er #39/11082 openat(dfd: CWD, filename: /etc/hosts, flags: CLOEXEC                 ) = 44
          4988.759 ( 0.052 ms): gsd-color/2431 openat(dfd: CWD, filename: /etc/localtime                             ) = 18
          4988.976 ( 0.029 ms): gsd-color/2431 openat(dfd: CWD, filename: /etc/localtime                             ) = 18
        ^C[root@quaco bpf]#
      
      From now on, we can use just the newly built .o file, skipping the
      compilation step for a faster startup:
      
        # trace --filter-pids 2834,2199 -e openat,augmented_raw_syscalls.o
             0.000 ( 0.046 ms): DNS Res~er #39/11088 openat(dfd: CWD, filename: /etc/hosts, flags: CLOEXEC                 ) = 44
          1946.408 ( 0.190 ms): systemd/1 openat(dfd: CWD, filename: /proc/1071/cgroup, flags: CLOEXEC          ) = 20
          1946.792 ( 0.215 ms): systemd/1 openat(dfd: CWD, filename: /proc/954/cgroup, flags: CLOEXEC           ) = 20
        ^C#
      
      Now on to do the same in the builtin-trace.c side of things.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Link: https://lkml.kernel.org/n/tip-k8mwu04l8es29rje5loq9vg7@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      27f2992e
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Implement syscall filtering in augmented_syscalls · b27b38ed
      Arnaldo Carvalho de Melo authored
      Just another map, this time an BPF_MAP_TYPE_ARRAY, stating with
      one bool per syscall, stating if it should be filtered or not.
      
      So, with a pre-built augmented_raw_syscalls.o file, we use:
      
        # perf trace -e open*,augmented_raw_syscalls.o
           0.000 ( 0.016 ms): DNS Res~er #37/29652 openat(dfd: CWD, filename: /etc/hosts, flags: CLOEXEC                 ) = 138
         187.039 ( 0.048 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC                 ) = 11
         187.348 ( 0.041 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC       ) = 11
         188.793 ( 0.036 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC       ) = 11
         189.803 ( 0.029 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC       ) = 11
         190.774 ( 0.027 ms): gsd-housekeepi/2436 openat(dfd: CWD, filename: /proc/self/mountinfo, flags: CLOEXEC       ) = 11
         284.620 ( 0.149 ms): DataStorage/3076 openat(dfd: CWD, filename: /home/acme/.mozilla/firefox/ina67tev.default/SiteSecurityServiceState.txt, flags: CREAT|TRUNC|WRONLY, mode: IRUGO|IWUSR|IWGRP) = 167
        ^C#
      
      What is it that this gsd-housekeeping thingy needs to open
      /proc/self/mountinfo four times periodically? :-)
      
      This map will be extended to tell per-syscall parameters, i.e. how many
      bytes to copy per arg, using the function signature to get the types and
      then the size of those types, via BTF.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Link: https://lkml.kernel.org/n/tip-cy222g9ucvnym3raqvxp0hpg@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      b27b38ed
  2. 21 Nov, 2018 6 commits
    • Arnaldo Carvalho de Melo's avatar
      Revert "perf augmented_syscalls: Drop 'write', 'poll' for testing without self pid filter" · 4aa792de
      Arnaldo Carvalho de Melo authored
      Now that we have the "filtered_pids" logic in place, no need to do this
      rough filter to avoid the feedback loop from 'perf trace's own syscalls,
      revert it.
      
      This reverts commit 7ed71f124284359676b6496ae7db724fee9da753.
      
      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: https://lkml.kernel.org/n/tip-88vh02cnkam0vv5f9vp02o3h@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      4aa792de
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Remove example hardcoded set of filtered pids · e312747b
      Arnaldo Carvalho de Melo authored
      Now that 'perf trace' fills in that "filtered_pids" BPF map, remove the
      set of filtered pids used as an example to test that feature.
      
      That feature works like this:
      
      Starting a system wide 'strace' like 'perf trace' augmented session we
      noticed that lots of events take place for a pid, which ends up being
      the feedback loop of perf trace's syscalls being processed by the
      'gnome-terminal' process:
      
        # perf trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c
           0.391 ( 0.002 ms): gnome-terminal/2469 read(fd: 17</dev/ptmx>, buf: 0x564b79f750bc, count: 8176) = 453
           0.394 ( 0.001 ms): gnome-terminal/2469 read(fd: 17</dev/ptmx>, buf: 0x564b79f75280, count: 7724) = -1 EAGAIN Resource temporarily unavailable
           0.438 ( 0.001 ms): gnome-terminal/2469 read(fd: 4<anon_inode:[eventfd]>, buf: 0x7fffc696aeb0, count: 16) = 8
           0.519 ( 0.001 ms): gnome-terminal/2469 read(fd: 17</dev/ptmx>, buf: 0x564b79f75280, count: 7724) = 114
           0.522 ( 0.001 ms): gnome-terminal/2469 read(fd: 17</dev/ptmx>, buf: 0x564b79f752f1, count: 7611) = -1 EAGAIN Resource temporarily unavailable
        ^C
      
      So we can use --filter-pids to get rid of that one, and in this case what is
      being used to implement that functionality is that "filtered_pids" BPF map that
      the tools/perf/examples/bpf/augmented_raw_syscalls.c created and that 'perf trace'
      bpf loader noticed and created a "struct bpf_map" associated that then got populated
      by 'perf trace':
      
        # perf trace --filter-pids 2469 -e tools/perf/examples/bpf/augmented_raw_syscalls.c
           0.020 ( 0.002 ms): gnome-shell/1663 epoll_pwait(epfd: 12<anon_inode:[eventpoll]>, events: 0x7ffd8f3ef960, maxevents: 32, sigsetsize: 8) = 1
           0.025 ( 0.002 ms): gnome-shell/1663 read(fd: 24</dev/input/event4>, buf: 0x560c01bb8240, count: 8112) = 48
           0.029 ( 0.001 ms): gnome-shell/1663 read(fd: 24</dev/input/event4>, buf: 0x560c01bb8258, count: 8088) = -1 EAGAIN Resource temporarily unavailable
           0.032 ( 0.001 ms): gnome-shell/1663 read(fd: 24</dev/input/event4>, buf: 0x560c01bb8240, count: 8112) = -1 EAGAIN Resource temporarily unavailable
           0.040 ( 0.003 ms): gnome-shell/1663 recvmsg(fd: 46<socket:[35893]>, msg: 0x7ffd8f3ef950) = -1 EAGAIN Resource temporarily unavailable
          21.529 ( 0.002 ms): gnome-shell/1663 epoll_pwait(epfd: 5<anon_inode:[eventpoll]>, events: 0x7ffd8f3ef960, maxevents: 32, sigsetsize: 8) = 1
          21.533 ( 0.004 ms): gnome-shell/1663 recvmsg(fd: 82<socket:[42826]>, msg: 0x7ffd8f3ef7b0, flags: DONTWAIT|CMSG_CLOEXEC) = 236
          21.581 ( 0.006 ms): gnome-shell/1663 ioctl(fd: 8</dev/dri/card0>, cmd: DRM_I915_GEM_BUSY, arg: 0x7ffd8f3ef060) = 0
          21.605 ( 0.020 ms): gnome-shell/1663 ioctl(fd: 8</dev/dri/card0>, cmd: DRM_I915_GEM_CREATE, arg: 0x7ffd8f3eeea0) = 0
          21.626 ( 0.119 ms): gnome-shell/1663 ioctl(fd: 8</dev/dri/card0>, cmd: DRM_I915_GEM_SET_DOMAIN, arg: 0x7ffd8f3eee94) = 0
          21.746 ( 0.081 ms): gnome-shell/1663 ioctl(fd: 8</dev/dri/card0>, cmd: DRM_I915_GEM_PWRITE, arg: 0x7ffd8f3eeea0) = 0
        ^C
      
      Oops, yet another gnome process that is involved with the output that
      'perf trace' generates, lets filter that out too:
      
        # perf trace --filter-pids 2469,1663 -e tools/perf/examples/bpf/augmented_raw_syscalls.c
               ? (         ): wpa_supplicant/1366  ... [continued]: select()) = 0 Timeout
           0.006 ( 0.002 ms): wpa_supplicant/1366 clock_gettime(which_clock: BOOTTIME, tp: 0x7fffe5b1e430) = 0
           0.011 ( 0.001 ms): wpa_supplicant/1366 clock_gettime(which_clock: BOOTTIME, tp: 0x7fffe5b1e3e0) = 0
           0.014 ( 0.001 ms): wpa_supplicant/1366 clock_gettime(which_clock: BOOTTIME, tp: 0x7fffe5b1e430) = 0
               ? (         ): gmain/1791  ... [continued]: poll()) = 0 Timeout
           0.017 (         ): wpa_supplicant/1366 select(n: 6, inp: 0x55646fed3ad0, outp: 0x55646fed3b60, exp: 0x55646fed3bf0, tvp: 0x7fffe5b1e4a0) ...
         157.879 ( 0.019 ms): gmain/1791 inotify_add_watch(fd: 8<anon_inode:inotify>, pathname: , mask: 16789454) = -1 ENOENT No such file or directory
               ? (         ): cupsd/1001  ... [continued]: epoll_pwait()) = 0
               ? (         ): gsd-color/1908  ... [continued]: poll()) = 0 Timeout
         499.615 (         ): cupsd/1001 epoll_pwait(epfd: 4<anon_inode:[eventpoll]>, events: 0x557a21166500, maxevents: 4096, timeout: 1000, sigsetsize: 8) ...
         586.593 ( 0.004 ms): gsd-color/1908 recvmsg(fd: 3<socket:[38074]>, msg: 0x7ffdef34e800) = -1 EAGAIN Resource temporarily unavailable
               ? (         ): fwupd/2230  ... [continued]: poll()) = 0 Timeout
               ? (         ): rtkit-daemon/906  ... [continued]: poll()) = 0 Timeout
               ? (         ): rtkit-daemon/907  ... [continued]: poll()) = 1
         724.603 ( 0.007 ms): rtkit-daemon/907 read(fd: 6<anon_inode:[eventfd]>, buf: 0x7f05ff768d08, count: 8) = 8
               ? (         ): ssh/5461  ... [continued]: select()) = 1
         810.431 ( 0.002 ms): ssh/5461 clock_gettime(which_clock: BOOTTIME, tp: 0x7ffd7f39f870) = 0
         ^C
      
      Several syscall exit events for syscalls in flight when 'perf trace' started, etc. Saner :-)
      
      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: https://lkml.kernel.org/n/tip-c3tu5yg204p5mvr9kvwew07n@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      e312747b
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Use pid_filter · ed9a77ba
      Arnaldo Carvalho de Melo authored
      Just to test filtering a bunch of pids, now its time to go and get that
      hooked up in 'perf trace', right after we load the bpf program, if we
      find a "pids_filtered" map defined, we'll populate it with the filtered
      pids.
      
      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: https://lkml.kernel.org/n/tip-1i9s27wqqdhafk3fappow84x@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      ed9a77ba
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Drop 'write', 'poll' for testing without self pid filter · 77ecb640
      Arnaldo Carvalho de Melo authored
      When testing system wide tracing without filtering the syscalls called
      by 'perf trace' itself we get into a feedback loop, drop for now those
      two syscalls, that are the ones that 'perf trace' does in its loop for
      writing the syscalls it intercepts, to help with testing till we get
      that filtering in place.
      
      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: https://lkml.kernel.org/n/tip-rkbu536af66dbsfx51sr8yof@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      77ecb640
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Remove needless linux/socket.h include · 66067538
      Arnaldo Carvalho de Melo authored
      Leftover from when we started augmented_raw_syscalls.c from
      tools/perf/examples/bpf/augmented_syscalls.
      
      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>
      Fixes: e58a0322dbac ("perf examples bpf: Start augmenting raw_syscalls:sys_{start,exit}")
      Link: https://lkml.kernel.org/n/tip-pmts9ls2skh8n3zisb4txudd@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      66067538
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Filter on a hard coded pid · 55f127b4
      Arnaldo Carvalho de Melo authored
      Just to show where we'll hook pid based filters, and what we use to
      obtain the current pid, using a BPF getpid() equivalent.
      
      Now we need to remove that hardcoded PID with a BPF hash map, so that we
      start by filtering 'perf trace's own PID, implement the --filter-pid
      functionality, etc.
      
      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: https://lkml.kernel.org/n/tip-oshrcgcekiyhd0whwisxfvtv@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      55f127b4
  3. 05 Nov, 2018 1 commit
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Start collecting pathnames in the BPF program · 79ef68c7
      Arnaldo Carvalho de Melo authored
      This is the start of having the raw_syscalls:sys_enter BPF handler
      collecting pointer arguments, namely pathnames, and with two syscalls
      that have that pointer in different arguments, "open" as it as its first
      argument, "openat" as the second.
      
      With this in place the existing beautifiers in 'perf trace' works, those
      args are shown instead of just the pointer that comes with the syscalls
      tracepoints.
      
      This also serves to show and document pitfalls in the process of using
      just that place in the kernel (raw_syscalls:sys_enter) plus tables
      provided by userspace to collect syscall pointer arguments.
      
      One is the need to use a barrier, as suggested by Edward, to avoid clang
      optimizations that make the kernel BPF verifier to refuse loading our
      pointer contents collector.
      
      The end result should be a generic eBPF program that works in all
      architectures, with the differences amongst archs resolved by the
      userspace component, 'perf trace', that should get all its tables
      created automatically from the kernel components where they are defined,
      via string table constructors for things not expressed in BTF/DWARF
      (enums, structs, etc), and otherwise using those observability files
      (BTF).
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Alexei Starovoitov <ast@kernel.org>
      Cc: Daniel Borkmann <daniel@iogearbox.net>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Edward Cree <ecree@solarflare.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Martin KaFai Lau <kafai@fb.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Cc: Yonghong Song <yhs@fb.com>
      Link: https://lkml.kernel.org/n/tip-37dz54pmotgpnwg9tb6zuk9j@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      79ef68c7
  4. 01 Nov, 2018 1 commit
    • Arnaldo Carvalho de Melo's avatar
      perf examples bpf: Start augmenting raw_syscalls:sys_{start,exit} · febf8a37
      Arnaldo Carvalho de Melo authored
      The previous approach of attaching to each syscall showed how it is
      possible to augment tracepoints and use that augmentation, pointer
      payloads, in the existing beautifiers in 'perf trace', but for a more
      general solution we now will try to augment the main
      raw_syscalls:sys_{enter,exit} syscalls, and then pass instructions in
      maps so that it knows which syscalls and which pointer contents, and how
      many bytes for each of the arguments should be copied.
      
      Start with just the bare minimum to collect what is provided by those
      two tracepoints via the __augmented_syscalls__ map + bpf-output perf
      event, which results in perf trace showing them without connecting
      enter+exit:
      
        # perf trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
           0.000 sleep/11563 raw_syscalls:sys_exit:NR 59 = 0
           0.019 (         ): sleep/11563 brk() ...
           0.021 sleep/11563 raw_syscalls:sys_exit:NR 12 = 94682642325504
           0.033 (         ): sleep/11563 access(filename:, mode: R) ...
           0.037 sleep/11563 raw_syscalls:sys_exit:NR 21 = -2
           0.041 (         ): sleep/11563 openat(dfd: CWD, filename: , flags: CLOEXEC) ...
           0.044 sleep/11563 raw_syscalls:sys_exit:NR 257 = 3
           0.045 (         ): sleep/11563 fstat(fd: 3, statbuf: 0x7ffdbf7119b0) ...
           0.046 sleep/11563 raw_syscalls:sys_exit:NR 5 = 0
           0.047 (         ): sleep/11563 mmap(len: 103334, prot: READ, flags: PRIVATE, fd: 3) ...
           0.049 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196285493248
           0.050 (         ): sleep/11563 close(fd: 3) ...
           0.051 sleep/11563 raw_syscalls:sys_exit:NR 3 = 0
           0.059 (         ): sleep/11563 openat(dfd: CWD, filename: , flags: CLOEXEC) ...
           0.062 sleep/11563 raw_syscalls:sys_exit:NR 257 = 3
           0.063 (         ): sleep/11563 read(fd: 3, buf: 0x7ffdbf711b78, count: 832) ...
           0.065 sleep/11563 raw_syscalls:sys_exit:NR 0 = 832
           0.066 (         ): sleep/11563 fstat(fd: 3, statbuf: 0x7ffdbf711a10) ...
           0.067 sleep/11563 raw_syscalls:sys_exit:NR 5 = 0
           0.068 (         ): sleep/11563 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) ...
           0.070 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196285485056
           0.073 (         ): sleep/11563 mmap(len: 3889792, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3) ...
           0.076 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196279463936
           0.077 (         ): sleep/11563 mprotect(start: 0x7f81fd8a8000, len: 2093056) ...
           0.083 sleep/11563 raw_syscalls:sys_exit:NR 10 = 0
           0.084 (         ): sleep/11563 mmap(addr: 0x7f81fdaa7000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 1753088) ...
           0.088 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196283314176
           0.091 (         ): sleep/11563 mmap(addr: 0x7f81fdaad000, len: 14976, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) ...
           0.093 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196283338752
           0.097 (         ): sleep/11563 close(fd: 3) ...
           0.098 sleep/11563 raw_syscalls:sys_exit:NR 3 = 0
           0.107 (         ): sleep/11563 arch_prctl(option: 4098, arg2: 140196285490432) ...
           0.108 sleep/11563 raw_syscalls:sys_exit:NR 158 = 0
           0.143 (         ): sleep/11563 mprotect(start: 0x7f81fdaa7000, len: 16384, prot: READ) ...
           0.146 sleep/11563 raw_syscalls:sys_exit:NR 10 = 0
           0.157 (         ): sleep/11563 mprotect(start: 0x561d037e7000, len: 4096, prot: READ) ...
           0.160 sleep/11563 raw_syscalls:sys_exit:NR 10 = 0
           0.163 (         ): sleep/11563 mprotect(start: 0x7f81fdcd5000, len: 4096, prot: READ) ...
           0.165 sleep/11563 raw_syscalls:sys_exit:NR 10 = 0
           0.166 (         ): sleep/11563 munmap(addr: 0x7f81fdcbb000, len: 103334) ...
           0.174 sleep/11563 raw_syscalls:sys_exit:NR 11 = 0
           0.216 (         ): sleep/11563 brk() ...
           0.217 sleep/11563 raw_syscalls:sys_exit:NR 12 = 94682642325504
           0.217 (         ): sleep/11563 brk(brk: 0x561d05453000) ...
           0.219 sleep/11563 raw_syscalls:sys_exit:NR 12 = 94682642460672
           0.220 (         ): sleep/11563 brk() ...
           0.221 sleep/11563 raw_syscalls:sys_exit:NR 12 = 94682642460672
           0.224 (         ): sleep/11563 open(filename: , flags: CLOEXEC) ...
           0.228 sleep/11563 raw_syscalls:sys_exit:NR 2 = 3
           0.229 (         ): sleep/11563 fstat(fd: 3, statbuf: 0x7f81fdaacaa0) ...
           0.230 sleep/11563 raw_syscalls:sys_exit:NR 5 = 0
           0.231 (         ): sleep/11563 mmap(len: 113045344, prot: READ, flags: PRIVATE, fd: 3) ...
           0.234 sleep/11563 raw_syscalls:sys_exit:NR 9 = 140196166418432
           0.237 (         ): sleep/11563 close(fd: 3) ...
           0.238 sleep/11563 raw_syscalls:sys_exit:NR 3 = 0
           0.262 (         ): sleep/11563 nanosleep(rqtp: 0x7ffdbf7126f0) ...
        1000.399 sleep/11563 raw_syscalls:sys_exit:NR 35 = 0
        1000.440 (         ): sleep/11563 close(fd: 1) ...
        1000.447 sleep/11563 raw_syscalls:sys_exit:NR 3 = 0
        1000.454 (         ): sleep/11563 close(fd: 2) ...
        1000.468 (         ): sleep/11563 exit_group(                                                           )
        #
      
      In the next csets we'll connect those events to the existing enter/exit
      raw_syscalls handlers in 'perf trace', just like we did with the
      syscalls:sys_{enter,exit}_* tracepoints.
      
      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: https://lkml.kernel.org/n/tip-5nl8l4hx1tl9pqdx65nkp6pw@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      febf8a37
  5. 03 Sep, 2018 2 commits
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Avoid optimization to pass older BPF validators · 7538d163
      Arnaldo Carvalho de Melo authored
      See https://www.spinics.net/lists/netdev/msg480099.html for the whole
      discussio, but to make the augmented_syscalls.c BPF program to get built
      and loaded successfully in a greater range of kernels, add an extra
      check.
      
      Related patch:
      
        a60dd35d ("bpf: change bpf_perf_event_output arg5 type to ARG_CONST_SIZE_OR_ZERO")
      
      That is in the kernel since v4.15, I couldn't figure why this is hitting
      me with 4.17.17, but adding the workaround discussed there makes this
      work with this fedora kernel and with 4.18.recent.
      
      Before:
      
        # uname -a
        Linux seventh 4.17.17-100.fc27.x86_64 #1 SMP Mon Aug 20 15:53:11 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c cat /etc/passwd > /dev/null
        libbpf: load bpf program failed: Permission denied
        libbpf: -- BEGIN DUMP LOG ---
        libbpf:
        0: (bf) r6 = r1
        1: (b7) r1 = 0
        2: (7b) *(u64 *)(r10 -8) = r1
        3: (7b) *(u64 *)(r10 -16) = r1
        4: (7b) *(u64 *)(r10 -24) = r1
        5: (7b) *(u64 *)(r10 -32) = r1
        6: (7b) *(u64 *)(r10 -40) = r1
        7: (7b) *(u64 *)(r10 -48) = r1
        8: (7b) *(u64 *)(r10 -56) = r1
        9: (7b) *(u64 *)(r10 -64) = r1
        10: (7b) *(u64 *)(r10 -72) = r1
        11: (7b) *(u64 *)(r10 -80) = r1
        12: (7b) *(u64 *)(r10 -88) = r1
        13: (7b) *(u64 *)(r10 -96) = r1
        14: (7b) *(u64 *)(r10 -104) = r1
        15: (7b) *(u64 *)(r10 -112) = r1
        16: (7b) *(u64 *)(r10 -120) = r1
        17: (7b) *(u64 *)(r10 -128) = r1
        18: (7b) *(u64 *)(r10 -136) = r1
        19: (7b) *(u64 *)(r10 -144) = r1
        20: (7b) *(u64 *)(r10 -152) = r1
        21: (7b) *(u64 *)(r10 -160) = r1
        22: (7b) *(u64 *)(r10 -168) = r1
        23: (7b) *(u64 *)(r10 -176) = r1
        24: (7b) *(u64 *)(r10 -184) = r1
        25: (7b) *(u64 *)(r10 -192) = r1
        26: (7b) *(u64 *)(r10 -200) = r1
        27: (7b) *(u64 *)(r10 -208) = r1
        28: (7b) *(u64 *)(r10 -216) = r1
        29: (7b) *(u64 *)(r10 -224) = r1
        30: (7b) *(u64 *)(r10 -232) = r1
        31: (7b) *(u64 *)(r10 -240) = r1
        32: (7b) *(u64 *)(r10 -248) = r1
        33: (7b) *(u64 *)(r10 -256) = r1
        34: (7b) *(u64 *)(r10 -264) = r1
        35: (7b) *(u64 *)(r10 -272) = r1
        36: (7b) *(u64 *)(r10 -280) = r1
        37: (7b) *(u64 *)(r10 -288) = r1
        38: (7b) *(u64 *)(r10 -296) = r1
        39: (7b) *(u64 *)(r10 -304) = r1
        40: (7b) *(u64 *)(r10 -312) = r1
        41: (bf) r7 = r10
        42: (07) r7 += -312
        43: (bf) r1 = r7
        44: (b7) r2 = 48
        45: (bf) r3 = r6
        46: (85) call bpf_probe_read#4
        47: (79) r3 = *(u64 *)(r6 +24)
        48: (bf) r1 = r10
        49: (07) r1 += -256
        50: (b7) r8 = 256
        51: (b7) r2 = 256
        52: (85) call bpf_probe_read_str#45
        53: (bf) r1 = r0
        54: (67) r1 <<= 32
        55: (77) r1 >>= 32
        56: (bf) r5 = r0
        57: (07) r5 += 56
        58: (2d) if r8 > r1 goto pc+1
         R0=inv(id=0) R1=inv(id=0,umin_value=256,umax_value=4294967295,var_off=(0x0; 0xffffffff)) R5=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=fp-312,call_-1 R8=inv256 R10=fp0,call_-1 fp-264=0
        59: (b7) r5 = 312
        60: (63) *(u32 *)(r10 -264) = r0
        61: (67) r5 <<= 32
        62: (77) r5 >>= 32
        63: (bf) r1 = r6
        64: (18) r2 = 0xffff8b9120cc8500
        66: (18) r3 = 0xffffffff
        68: (bf) r4 = r7
        69: (85) call bpf_perf_event_output#25
        70: (b7) r0 = 0
        71: (95) exit
      
        from 58 to 60: R0=inv(id=0) R1=inv(id=0,umax_value=255,var_off=(0x0; 0xff)) R5=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=fp-312,call_-1 R8=inv256 R10=fp0,call_-1 fp-264=0
        60: (63) *(u32 *)(r10 -264) = r0
        61: (67) r5 <<= 32
        62: (77) r5 >>= 32
        63: (bf) r1 = r6
        64: (18) r2 = 0xffff8b9120cc8500
        66: (18) r3 = 0xffffffff
        68: (bf) r4 = r7
        69: (85) call bpf_perf_event_output#25
        R5 unbounded memory access, use 'var &= const' or 'if (var < const)'
      
        libbpf: -- END LOG --
        libbpf: failed to load program 'syscalls:sys_enter_openat'
        libbpf: failed to load object 'tools/perf/examples/bpf/augmented_syscalls.c'
        bpf: load objects failed: err=-4007: (Kernel verifier blocks program loading)
        event syntax error: 'tools/perf/examples/bpf/augmented_syscalls.c'
                             \___ Kernel verifier blocks program loading
      
      After:
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c cat /etc/passwd > /dev/null
           0.000 cat/29249 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
           0.008 cat/29249 syscalls:sys_exit_openat:0x3
           0.021 cat/29249 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC)
           0.025 cat/29249 syscalls:sys_exit_openat:0x3
           0.180 cat/29249 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC)
           0.185 cat/29249 syscalls:sys_exit_open:0x3
           0.242 cat/29249 openat(dfd: CWD, filename: /etc/passwd)
           0.245 cat/29249 syscalls:sys_exit_openat:0x3
        #
      
      It also works with a more recent kernel:
      
        # uname -a
        Linux jouet 4.18.0-00014-g4e67b2a5 #6 SMP Thu Aug 30 17:34:17 -03 2018 x86_64 x86_64 x86_64 GNU/Linux
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c cat /etc/passwd > /dev/null
           0.000 cat/26451 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
           0.020 cat/26451 syscalls:sys_exit_openat:0x3
           0.039 cat/26451 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC)
           0.044 cat/26451 syscalls:sys_exit_openat:0x3
           0.231 cat/26451 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC)
           0.238 cat/26451 syscalls:sys_exit_open:0x3
           0.278 cat/26451 openat(dfd: CWD, filename: /etc/passwd)
           0.282 cat/26451 syscalls:sys_exit_openat:0x3
        #
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Daniel Borkmann <daniel@iogearbox.net>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Gianluca Borello <g.borello@gmail.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Cc: Yonghong Song <yhs@fb.com>
      Link: https://lkml.kernel.org/n/tip-wkpsivs1a9afwldbul46btbv@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      7538d163
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Check probe_read_str() return separately · 21d7eb9a
      Arnaldo Carvalho de Melo authored
      Using a value returned from probe_read_str() to tell how many bytes to
      copy using perf_event_output() has issues in some older kernels, like
      4.17.17-100.fc27.x86_64, so separate the bounds checking done on how
      many bytes to copy to a separate variable, so that the next patch has
      only what is being done to make the test pass on older BPF validators.
      
      For reference, see the discussion in this thread:
      
        https://www.spinics.net/lists/netdev/msg480099.html
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Daniel Borkmann <daniel@iogearbox.net>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Wang Nan <wangnan0@huawei.com>
      Cc: Yonghong Song <yhs@fb.com>
      Link: https://lkml.kernel.org/n/tip-jtsapwibyxrnv1xjfsgzp0fj@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      21d7eb9a
  6. 30 Aug, 2018 14 commits
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Hook into syscalls:sys_exit_SYSCALL too · f5b076dc
      Arnaldo Carvalho de Melo authored
      Hook the pair enter/exit when using augmented_{filename,sockaddr,etc}_syscall(),
      this way we'll be able to see what entries are in the ELF sections generated
      from augmented_syscalls.c and filter them out from the main raw_syscalls:*
      tracepoints used by 'perf trace'.
      
      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: https://lkml.kernel.org/n/tip-cyav42qj5yylolw4attcw99z@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      f5b076dc
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Rename augmented_*_syscall__enter to just *_syscall · 4c8f0a72
      Arnaldo Carvalho de Melo authored
      As we'll also hook into the syscalls:sys_exit_SYSCALL for which there
      are enter hooks.
      
      This way we'll be able to iterate the ELF file for the eBPF program,
      find the syscalls that have hooks and filter them out from the general
      raw_syscalls:sys_{enter,exit} tracepoint for not-yet-augmented (the ones
      with pointer arguments not yet being attached to the usual syscalls
      tracepoint payload) and non augmentable syscalls (syscalls without
      pointer arguments).
      
      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: https://lkml.kernel.org/n/tip-cl1xyghwb1usp500354mv37h@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      4c8f0a72
    • Arnaldo Carvalho de Melo's avatar
      perf augmented_syscalls: Update the header comments · 5e2d8a5a
      Arnaldo Carvalho de Melo authored
      Reflecting the fact that it now augments more than syscalls:sys_enter_SYSCALL
      tracepoints that have filename strings as args. Also mention how the
      extra data is handled by the by now modified 'perf trace' beautifiers,
      that will use special "augmented" beautifiers when extra data is found
      after the expected syscall enter/exit tracepoints.
      
      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: https://lkml.kernel.org/n/tip-ybskanehmdilj5fs7080nz1g@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      5e2d8a5a
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Augment sendto's 'addr' arg · 6ebb6862
      Arnaldo Carvalho de Melo authored
      Its a 'struct sockaddr' pointer, augment it with the same beautifier as
      for 'connect' and 'bind', that all receive from userspace that pointer.
      
      Doing it in the other direction remains to be done, hooking at the
      syscalls:sys_exit_{accept4?,recvmsg} tracepoints somehow.
      
      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: https://lkml.kernel.org/n/tip-k2eu68lsphnm2fthc32gq76c@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      6ebb6862
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Augment bind's 'myaddr' sockaddr arg · 02ef2884
      Arnaldo Carvalho de Melo authored
      One more, to reuse the augmented_sockaddr_syscall_enter() macro
      introduced from the augmentation of connect's sockaddr arg, also to get
      a subset of the struct arg augmentations done using the manual method,
      before switching to something automatic, using tracefs's format file or,
      even better, BTF containing the syscall args structs.
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c
           0.000 sshd/11479 bind(fd: 3<socket:[170336]>, umyaddr: { .family: NETLINK }, addrlen: 12)
           1.752 sshd/11479 bind(fd: 3<socket:[170336]>, umyaddr: { .family: INET, port: 22, addr: 0.0.0.0 }, addrlen: 16)
           1.924 sshd/11479 bind(fd: 4<socket:[170338]>, umyaddr: { .family: INET6, port: 22, addr: :: }, addrlen: 28)
        ^C#
      
      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: https://lkml.kernel.org/n/tip-a2drqpahpmc7uwb3n3gj2plu@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      02ef2884
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Add augmented_sockaddr_syscall_enter() · 24a6c2cd
      Arnaldo Carvalho de Melo authored
      From the one for 'connect', so that we can use it with sendto and others
      that receive a 'struct sockaddr'.
      
      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: https://lkml.kernel.org/n/tip-8bdqv1q0ndcjl1nqns5r5je2@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      24a6c2cd
    • Arnaldo Carvalho de Melo's avatar
      perf trace augmented_syscalls: Augment connect's 'sockaddr' arg · d5a7e661
      Arnaldo Carvalho de Melo authored
      As the first example of augmenting something other than a 'filename',
      augment the 'struct sockaddr' argument for the 'connect' syscall:
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c ssh -6 fedorapeople.org
           0.000 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           0.042 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           1.329 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           1.362 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           1.458 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           1.478 ssh/29669 connect(fd: 3, uservaddr: { .family: LOCAL, path: /var/run/nscd/socket }, addrlen: 110)
           1.683 ssh/29669 connect(fd: 3<socket:[125942]>, uservaddr: { .family: INET, port: 53, addr: 192.168.43.1 }, addrlen: 16)
           4.710 ssh/29669 connect(fd: 3<socket:[125942]>, uservaddr: { .family: INET6, port: 22, addr: 2610:28:3090:3001:5054:ff:fea7:9474 }, addrlen: 28)
        root@fedorapeople.org: Permission denied (publickey).
        #
      
      This is still just augmenting the syscalls:sys_enter_connect part, later
      we'll wire this up to augment the enter+exit combo, like in the
      tradicional 'perf trace' and 'strace' outputs.
      
      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: https://lkml.kernel.org/n/tip-s7l541cbiqb22ifio6z7dpf6@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      d5a7e661
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Add a etcsnoop.c augmented syscalls eBPF utility · 9ab5aade
      Arnaldo Carvalho de Melo authored
      We need to put common stuff into a separate header in tools/perf/include/bpf/
      for these augmented syscalls, but I couldn't resist adding a etcsnoop.c tool,
      combining augmented syscalls + filtering, that in the future will be passed
      from 'perf trace''s command line, to use in building the eBPF program to do
      that specific filtering at the source, inside the kernel:
      
        Running system wide: (hope there isn't any embarassing stuff here...  ;-) )
      
        # perf trace -e tools/perf/examples/bpf/etcsnoop.c
             0.000 sed/21878 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
          1741.473 cat/21883 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
          1741.892 cat/21883 openat(dfd: CWD, filename: /etc/passwd)
          1748.948 sed/21886 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
          1777.136 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1777.738 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.158 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.528 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.595 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.901 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.939 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.966 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1778.992 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.019 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.045 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.071 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.095 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.121 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.148 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.175 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.202 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.229 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.254 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.279 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.309 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.336 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.363 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.388 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.414 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.442 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.470 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.500 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.529 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.557 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.586 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.617 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.648 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.679 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.706 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.739 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.769 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.798 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.823 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.844 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.862 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.880 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.911 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.942 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1779.972 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1780.004 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
          1780.035 gvfs-udisks2-v/2302 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
         13059.154 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13060.739 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13061.990 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13063.177 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13064.265 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13065.483 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13067.383 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13068.902 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13069.922 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13070.915 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13072.612 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13074.816 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13077.343 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13078.731 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13559.064 DNS Res~er #22/21054 open(filename: /etc/hosts, flags: CLOEXEC)
         22419.522 sed/21896 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         24473.313 git/21900 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         24491.988 less/21901 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         24493.793 git/21901 openat(dfd: CWD, filename: /etc/sysless)
         24565.772 sed/21924 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         25878.752 git/21928 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         26075.666 git/21928 open(filename: /etc/localtime, flags: CLOEXEC)
         26075.565 less/21929 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         26076.060 less/21929 openat(dfd: CWD, filename: /etc/sysless)
         26346.395 sed/21932 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         26483.583 sed/21938 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         26954.890 sed/21944 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         27016.165 gsd-color/1762 openat(dfd: CWD, filename: /etc/localtime)
         27016.414 gsd-color/1762 openat(dfd: CWD, filename: /etc/localtime)
         27712.313 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
         27712.616 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
         27829.035 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27829.368 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27829.584 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27829.800 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27830.107 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27830.521 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         27961.516 git/21948 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         27987.568 less/21949 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         27988.948 bash/21949 openat(dfd: CWD, filename: /etc/sysless)
         28043.536 sed/21972 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         28736.008 sed/21978 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         34882.664 git/21991 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         34882.664 sort/21990 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         34884.441 uniq/21992 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         35593.098 git/21997 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         35638.839 git/21997 openat(dfd: CWD, filename: /etc/gitattributes)
         35702.851 sed/22000 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         36076.039 sed/22006 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         37569.049 git/22014 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         37673.712 git/22014 open(filename: /etc/localtime, flags: CLOEXEC)
         37781.710 vim/22040 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         37783.667 git/22040 openat(dfd: CWD, filename: /etc/vimrc)
         37792.394 git/22040 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         37792.436 git/22040 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         37792.580 git/22040 open(filename: /etc/passwd, flags: CLOEXEC)
         43893.625 DNS Res~er #23/21365 open(filename: /etc/hosts, flags: CLOEXEC)
         48060.409 nm-dhcp-helper/22044 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48071.745 systemd/1 openat(dfd: CWD, filename: /etc/systemd/system/dbus-org.freedesktop.nm-dispatcher.service, flags: CLOEXEC|NOFOLLOW|NOCTTY)
         48082.780 nm-dispatcher/22049 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48111.418 systemd/22049 open(filename: /etc/NetworkManager/dispatcher.d, flags: CLOEXEC|DIRECTORY|NONBLOCK)
         48111.904 systemd/22049 open(filename: /etc/localtime, flags: CLOEXEC)
         48118.357 00-netreport/22052 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48119.668 systemd/22052 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48119.762 systemd/22052 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48119.887 systemd/22052 open(filename: /etc/passwd, flags: CLOEXEC)
         48120.025 systemd/22052 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/00-netreport)
         48124.144 hostname/22054 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48125.492 systemd/22052 openat(dfd: CWD, filename: /etc/init.d/functions)
         48127.253 systemd/22052 openat(dfd: CWD, filename: /etc/profile.d/lang.sh)
         48127.388 systemd/22052 openat(dfd: CWD, filename: /etc/locale.conf)
         48137.749 cat/22056 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48143.519 04-iscsi/22058 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48144.438 04-iscsi/22058 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48144.478 04-iscsi/22058 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48144.577 04-iscsi/22058 open(filename: /etc/passwd, flags: CLOEXEC)
         48144.819 04-iscsi/22058 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/04-iscsi)
         48145.620 10-ifcfg-rh-ro/22059 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48146.169 systemd/22059 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48146.207 systemd/22059 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48146.287 systemd/22059 open(filename: /etc/passwd, flags: CLOEXEC)
         48146.387 systemd/22059 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/10-ifcfg-rh-routes.sh)
         48147.215 11-dhclient/22060 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48147.787 11-dhclient/22060 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48147.813 11-dhclient/22060 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48147.929 11-dhclient/22060 open(filename: /etc/passwd, flags: CLOEXEC)
         48148.016 11-dhclient/22060 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/11-dhclient)
         48148.906 grep/22063 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48151.165 11-dhclient/22060 openat(dfd: CWD, filename: /etc/sysconfig/network)
         48151.560 11-dhclient/22060 open(filename: /etc/dhcp/dhclient.d/, flags: CLOEXEC|DIRECTORY|NONBLOCK)
         48151.704 11-dhclient/22060 openat(dfd: CWD, filename: /etc/dhcp/dhclient.d/chrony.sh)
         48153.593 20-chrony/22065 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48154.695 20-chrony/22065 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48154.756 20-chrony/22065 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48154.914 20-chrony/22065 open(filename: /etc/passwd, flags: CLOEXEC)
         48155.067 20-chrony/22065 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/20-chrony)
         48156.962 25-polipo/22066 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48157.824 systemd/22066 open(filename: /etc/nsswitch.conf, flags: CLOEXEC)
         48157.866 systemd/22066 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
         48157.981 systemd/22066 open(filename: /etc/passwd, flags: CLOEXEC)
         48158.090 systemd/22066 openat(dfd: CWD, filename: /etc/NetworkManager/dispatcher.d/25-polipo)
         48533.616 gsd-housekeepi/2412 openat(dfd: CWD, filename: /etc/fstab, flags: CLOEXEC)
         87122.021 gsd-color/1762 openat(dfd: CWD, filename: /etc/localtime)
         87122.146 gsd-color/1762 openat(dfd: CWD, filename: /etc/localtime)
         87825.582 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
         87825.844 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
         87829.524 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         87830.531 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         87831.288 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         87832.011 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         87832.672 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         87833.276 gnome-shell/2125 openat(dfd: CWD, filename: /etc/localtime)
         ^C#
      
      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: https://lkml.kernel.org/n/tip-0o770jvdcy04ee6vhv6v471m@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      9ab5aade
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Augment 'newstat' (aka 'stat') filename ptr · 16cc6359
      Arnaldo Carvalho de Melo authored
      This one will need some more work, that 'statbuf' pointer requires a
      beautifier in 'perf trace'.
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c
           0.000 weechat/3596 stat(filename: /etc/localtime, statbuf: 0x7ffd87d11f60)
           0.186 perf/29818 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_stat/format)
           0.279 perf/29818 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_newstat/for)
           0.670 perf/29818 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/form)
          60.805 DNS Res~er #20/21308 stat(filename: /etc/resolv.conf, statbuf: 0x7ffa733fe4a0)
          60.836 DNS Res~er #20/21308 open(filename: /etc/hosts, flags: CLOEXEC)
          60.931 perf/29818 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_open/format)
         607.070 DNS Res~er #21/29812 stat(filename: /etc/resolv.conf, statbuf: 0x7ffa5e1fe3f0)
         607.098 DNS Res~er #21/29812 open(filename: /etc/hosts, flags: CLOEXEC)
         999.336 weechat/3596 stat(filename: /etc/localtime, statbuf: 0x7ffd87d11f60)
      ^C#
      
      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: https://lkml.kernel.org/n/tip-4lhabe7m4uzo76lnqpyfmnvk@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      16cc6359
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Introduce augmented_filename_syscall_enter() declarator · f6618ce6
      Arnaldo Carvalho de Melo authored
      Helping with tons of boilerplate for syscalls that only want to augment
      a filename. Now supporting one such syscall is just a matter of
      declaring its arguments struct + using:
      
        augmented_filename_syscall_enter(openat);
      
      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: https://lkml.kernel.org/n/tip-ls7ojdseu8fxw7fvj77ejpao@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      f6618ce6
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Augment inotify_add_watch pathname syscall arg · 9779fc02
      Arnaldo Carvalho de Melo authored
      Again, just changing tools/perf/examples/bpf/augmented_syscalls.c, that
      is starting to have too much boilerplate, some macro will come to the
      rescue.
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c
           0.000 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /var/cache/app-info/yaml, mask: 16789454)
           0.023 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /var/lib/app-info/xmls, mask: 16789454)
           0.028 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /var/lib/app-info/yaml, mask: 16789454)
           0.032 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /usr/share/app-info/yaml, mask: 16789454)
           0.039 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /usr/local/share/app-info/xmls, mask: 16789454)
           0.045 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /usr/local/share/app-info/yaml, mask: 16789454)
           0.049 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /home/acme/.local/share/app-info/yaml, mask: 16789454)
           0.056 gmain/2590 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: , mask: 16789454)
           0.010 gmain/2245 inotify_add_watch(fd: 7<anon_inode:inotify>, pathname: /home/acme/~, mask: 16789454)
           0.087 perf/20116 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_inotify_add)
           0.436 perf/20116 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/form)
          56.042 gmain/2791 inotify_add_watch(fd: 4<anon_inode:inotify>, pathname: /var/lib/fwupd/remotes.d/lvfs-testing, mask: 16789454)
         113.986 gmain/1721 inotify_add_watch(fd: 3<anon_inode:inotify>, pathname: /var/lib/gdm/~, mask: 16789454)
        3777.265 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
        3777.550 gsd-color/2408 openat(dfd: CWD, filename: /etc/localtime)
      ^C[root@jouet perf]#
      
      Still not combining raw_syscalls:sys_enter + raw_syscalls:sys_exit, to
      get it strace-like, but that probably will come very naturally with some
      more wiring up...
      
      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: https://lkml.kernel.org/n/tip-ol83juin2cht9vzquynec5hz@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      9779fc02
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Augment the 'open' syscall 'filename' arg · daa1284a
      Arnaldo Carvalho de Melo authored
      As described in the previous cset, all we had to do was to touch the
      augmented_syscalls.c eBPF program, fire up 'perf trace' with that new
      eBPF script in system wide mode and wait for 'open' syscalls, in
      addition to 'openat' ones to see that it works:
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c
             0.000 StreamT~s #200/16150 openat(dfd: CWD, filename: /home/acme/.mozilla/firefox/fqxhj76d.default/prefs.js, flags: CREAT|EXCL|TRUNC|WRONLY, mode: IRUSR|IWUSR)
             0.065 StreamT~s #200/16150 openat(dfd: CWD, filename: /home/acme/.mozilla/firefox/fqxhj76d.default/prefs-1.js, flags: CREAT|EXCL|TRUNC|WRONLY, mode: IRUSR|IWUSR)
             0.435 StreamT~s #200/16150 openat(dfd: CWD, filename: /home/acme/.mozilla/firefox/fqxhj76d.default/prefs-1.js, flags: CREAT|TRUNC|WRONLY, mode: IRUSR|IWUSR)
             1.875 perf/16772 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/form)
          1227.260 gnome-shell/1463 openat(dfd: CWD, filename: /proc/self/stat)
          1227.397 gnome-shell/2125 openat(dfd: CWD, filename: /proc/self/stat)
          7227.619 gnome-shell/1463 openat(dfd: CWD, filename: /proc/self/stat)
          7227.661 gnome-shell/2125 openat(dfd: CWD, filename: /proc/self/stat)
         10018.079 gnome-shell/1463 openat(dfd: CWD, filename: /proc/self/stat)
         10018.514 perf/16772 openat(dfd: CWD, filename: /proc/1237/status)
         10018.568 perf/16772 openat(dfd: CWD, filename: /proc/1237/status)
         10022.409 gnome-shell/2125 openat(dfd: CWD, filename: /proc/self/stat)
         10090.044 NetworkManager/1237 openat(dfd: CWD, filename: /proc/2125/stat)
         10090.351 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         10090.407 perf/16772 openat(dfd: CWD, filename: /sys/kernel/debug/tracing/events/syscalls/sys_enter_open/format)
         10091.763 NetworkManager/1237 openat(dfd: CWD, filename: /proc/2125/stat)
         10091.812 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         10092.807 NetworkManager/1237 openat(dfd: CWD, filename: /proc/2125/stat)
         10092.851 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         10094.650 NetworkManager/1237 openat(dfd: CWD, filename: /proc/1463/stat)
         10094.926 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         10096.010 NetworkManager/1237 openat(dfd: CWD, filename: /proc/1463/stat)
         10096.057 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         10097.056 NetworkManager/1237 openat(dfd: CWD, filename: /proc/1463/stat)
         10097.099 NetworkManager/1237 open(filename: /etc/passwd, flags: CLOEXEC)
         13228.345 gnome-shell/1463 openat(dfd: CWD, filename: /proc/self/stat)
         13232.734 gnome-shell/2125 openat(dfd: CWD, filename: /proc/self/stat)
         15198.956 lighttpd/16748 open(filename: /proc/loadavg, mode: ISGID|IXOTH)
        ^C#
      
      It even catches 'perf' itself looking at the sys_enter_open and
      sys_enter_openat tracefs format dictionaries when it first finds them in
      the trace... :-)
      
      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: https://lkml.kernel.org/n/tip-upmogc57uatljr6el6u8537l@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      daa1284a
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Use the augmented filename, expanding syscall enter pointers · 75d1e306
      Arnaldo Carvalho de Melo authored
      This is the final touch in showing how a syscall argument beautifier can
      access the augmented args put in place by the
      tools/perf/examples/bpf/augmented_syscalls.c eBPF script, right after
      the regular raw syscall args, i.e. the up to 6 long integer values in
      the syscall interface.
      
      With this we are able to show the 'openat' syscall arg, now with up to
      64 bytes, but in time this will be configurable, just like with the
      'strace -s strsize' argument, from 'strace''s man page:
      
        -s strsize  Specify the maximum string size to print (the default is 32).
      
      This actually is the maximum string to _collect_ and store in the ring
      buffer, not just print.
      
      Before:
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c,openat cat /etc/passwd > /dev/null
           0.000 (         ): cat/9658 openat(dfd: CWD, filename: 0x6626eda8, flags: CLOEXEC)
           0.017 ( 0.007 ms): cat/9658 openat(dfd: CWD, filename: 0x6626eda8, flags: CLOEXEC) = 3
           0.049 (         ): cat/9658 openat(dfd: CWD, filename: 0x66476ce0, flags: CLOEXEC)
           0.051 ( 0.007 ms): cat/9658 openat(dfd: CWD, filename: 0x66476ce0, flags: CLOEXEC) = 3
           0.377 (         ): cat/9658 openat(dfd: CWD, filename: 0x1e8f806b)
           0.379 ( 0.005 ms): cat/9658 openat(dfd: CWD, filename: 0x1e8f806b) = 3
        #
      
      After:
      
        # perf trace -e tools/perf/examples/bpf/augmented_syscalls.c,openat cat /etc/passwd > /dev/null
           0.000 (         ): cat/11966 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC)
           0.006 ( 0.006 ms): cat/11966 openat(dfd: CWD, filename: 0x4bfdcda8, flags: CLOEXEC) = 3
           0.034 (         ): cat/11966 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC)
           0.036 ( 0.008 ms): cat/11966 openat(dfd: CWD, filename: 0x4c1e4ce0, flags: CLOEXEC) = 3
           0.375 (         ): cat/11966 openat(dfd: CWD, filename: /etc/passwd)
           0.377 ( 0.005 ms): cat/11966 openat(dfd: CWD, filename: 0xe87906b) = 3
        #
      
      This cset should show all the aspects of establishing a protocol between
      an eBPF syscall arg augmenter program, tools/perf/examples/bpf/augmented_syscalls.c and
      a 'perf trace' beautifier, the one associated with all 'char *' point
      syscall args with names that can heuristically be associated with
      filenames.
      
      Now to wire up 'open' to show a second syscall using this scheme, all we
      have to do now is to change tools/perf/examples/bpf/augmented_syscalls.c,
      as 'perf trace' will notice that the perf_sample.raw_size is more than
      what is expected for a particular syscall payload as defined by its
      tracefs format file and will then use the augmented payload in the
      'filename' syscall arg beautifier.
      
      The same protocol will be used for structs such as 'struct sockaddr *',
      'struct pollfd', etc, with additions for handling arrays.
      
      This will all be done under the hood when 'perf trace' realizes the
      system has the necessary components, and also can be done by providing
      a precompiled augmented_syscalls.c eBPF ELF object.
      
      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: https://lkml.kernel.org/n/tip-gj9kqb61wo7m3shtpzercbcr@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      75d1e306
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Make the augmented_syscalls filter out the tracepoint event · 6ccc18a9
      Arnaldo Carvalho de Melo authored
      When we attach a eBPF object to a tracepoint, if we return 1, then that
      tracepoint will be stored in the perf's ring buffer. In the
      augmented_syscalls.c case we want to just attach and _override_ the
      tracepoint payload with an augmented, extended one.
      
      In this example, tools/perf/examples/bpf/augmented_syscalls.c, we are
      attaching to the 'openat' syscall, and adding, after the
      syscalls:sys_enter_openat usual payload as defined by
      /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/format, a
      snapshot of its sole pointer arg:
      
        # grep 'field:.*\*' /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/format
      	field:const char * filename;	offset:24;	size:8;	signed:0;
        #
      
      For now this is not being considered, the next csets will make use of
      it, but as this is overriding the syscall tracepoint enter, we don't
      want that event appearing on the ring buffer, just our synthesized one.
      
      Before:
      
        # perf trace -e ~acme/git/perf/tools/perf/examples/bpf/augmented_syscalls.c,openat cat /etc/passwd > /dev/null
           0.000 (         ): __augmented_syscalls__:dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC
           0.006 (         ): syscalls:sys_enter_openat:dfd: CWD, filename: , flags: CLOEXEC
           0.007 ( 0.004 ms): cat/24044 openat(dfd: CWD, filename: 0x216dda8, flags: CLOEXEC                  ) = 3
           0.028 (         ): __augmented_syscalls__:dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC
           0.030 (         ): syscalls:sys_enter_openat:dfd: CWD, filename: , flags: CLOEXEC
           0.031 ( 0.006 ms): cat/24044 openat(dfd: CWD, filename: 0x2375ce0, flags: CLOEXEC                  ) = 3
           0.291 (         ): __augmented_syscalls__:dfd: CWD, filename: /etc/passwd
           0.293 (         ): syscalls:sys_enter_openat:dfd: CWD, filename:
           0.294 ( 0.004 ms): cat/24044 openat(dfd: CWD, filename: 0x637db06b                                 ) = 3
        #
      
      After:
      
        # perf trace -e ~acme/git/perf/tools/perf/examples/bpf/augmented_syscalls.c,openat cat /etc/passwd > /dev/null
           0.000 (         ): __augmented_syscalls__:dfd: CWD, filename: 0x9c6a1da8, flags: CLOEXEC
           0.005 ( 0.015 ms): cat/27341 openat(dfd: CWD, filename: 0x9c6a1da8, flags: CLOEXEC                 ) = 3
           0.040 (         ): __augmented_syscalls__:dfd: CWD, filename: 0x9c8a9ce0, flags: CLOEXEC
           0.041 ( 0.006 ms): cat/27341 openat(dfd: CWD, filename: 0x9c8a9ce0, flags: CLOEXEC                 ) = 3
           0.294 (         ): __augmented_syscalls__:dfd: CWD, filename: 0x482a706b
           0.296 ( 0.067 ms): cat/27341 openat(dfd: CWD, filename: 0x482a706b                                 ) = 3
        #
      
      Now lets replace that __augmented_syscalls__ name with the syscall name,
      using:
      
        # grep 'field:.*syscall_nr' /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat/format
      	field:int __syscall_nr;	offset:8;	size:4;	signed:1;
        #
      
      That the synthesized payload has exactly where the syscall enter
      tracepoint puts it.
      
      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: https://lkml.kernel.org/n/tip-og4r9k87mzp9hv7el046idmd@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      6ccc18a9
  7. 08 Aug, 2018 3 commits
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Handle "bpf-output" events associated with "__augmented_syscalls__" BPF map · e0b6d2ef
      Arnaldo Carvalho de Melo authored
      Add an example BPF script that writes syscalls:sys_enter_openat raw
      tracepoint payloads augmented with the first 64 bytes of the "filename"
      syscall pointer arg.
      
      Then catch it and print it just like with things written to the
      "__bpf_stdout__" map associated with a PERF_COUNT_SW_BPF_OUTPUT software
      event, by just letting the default tracepoint handler in 'perf trace',
      trace__event_handler(), to use bpf_output__fprintf(trace, sample), just
      like it does with all other PERF_COUNT_SW_BPF_OUTPUT events, i.e. just
      do a dump on the payload, so that we can check if what is being printed
      has at least the first 64 bytes of the "filename" arg:
      
      The augmented_syscalls.c eBPF script:
      
        # cat tools/perf/examples/bpf/augmented_syscalls.c
        // SPDX-License-Identifier: GPL-2.0
      
        #include <stdio.h>
      
        struct bpf_map SEC("maps") __augmented_syscalls__ = {
             .type = BPF_MAP_TYPE_PERF_EVENT_ARRAY,
             .key_size = sizeof(int),
             .value_size = sizeof(u32),
             .max_entries = __NR_CPUS__,
        };
      
        struct syscall_enter_openat_args {
      	unsigned long long common_tp_fields;
      	long		   syscall_nr;
      	long		   dfd;
      	char		   *filename_ptr;
      	long		   flags;
      	long		   mode;
        };
      
        struct augmented_enter_openat_args {
      	struct syscall_enter_openat_args args;
      	char				 filename[64];
        };
      
        int syscall_enter(openat)(struct syscall_enter_openat_args *args)
        {
      	struct augmented_enter_openat_args augmented_args;
      
      	probe_read(&augmented_args.args, sizeof(augmented_args.args), args);
      	probe_read_str(&augmented_args.filename, sizeof(augmented_args.filename), args->filename_ptr);
      	perf_event_output(args, &__augmented_syscalls__, BPF_F_CURRENT_CPU,
      			  &augmented_args, sizeof(augmented_args));
      	return 1;
        }
      
        license(GPL);
        #
      
      So it will just prepare a raw_syscalls:sys_enter payload for the
      "openat" syscall.
      
      This will eventually be done for all syscalls with pointer args,
      globally or just when the user asks, using some spec, which args of
      which syscalls it wants "expanded" this way, we'll probably start with
      just all the syscalls that have char * pointers with familiar names, the
      ones we already handle with the probe:vfs_getname kprobe if it is in
      place hooking the kernel getname_flags() function used to copy from user
      the paths.
      
      Running it we get:
      
        # perf trace -e perf/tools/perf/examples/bpf/augmented_syscalls.c,openat cat /etc/passwd > /dev/null
           0.000 (         ): __augmented_syscalls__:X?.C......................`\..................../etc/ld.so.cache..#......,....ao.k...............k......1.".........
           0.006 (         ): syscalls:sys_enter_openat:dfd: CWD, filename: 0x5c600da8, flags: CLOEXEC
           0.008 ( 0.005 ms): cat/31292 openat(dfd: CWD, filename: 0x5c600da8, flags: CLOEXEC                 ) = 3
           0.036 (         ): __augmented_syscalls__:X?.C.......................\..................../lib64/libc.so.6......... .\....#........?.......=.C..../.".........
           0.037 (         ): syscalls:sys_enter_openat:dfd: CWD, filename: 0x5c808ce0, flags: CLOEXEC
           0.039 ( 0.007 ms): cat/31292 openat(dfd: CWD, filename: 0x5c808ce0, flags: CLOEXEC                 ) = 3
           0.323 (         ): __augmented_syscalls__:X?.C.....................P....................../etc/passwd......>.C....@................>.C.....,....ao.>.C........
           0.325 (         ): syscalls:sys_enter_openat:dfd: CWD, filename: 0xe8be50d6
           0.327 ( 0.004 ms): cat/31292 openat(dfd: CWD, filename: 0xe8be50d6                                 ) = 3
        #
      
      We need to go on optimizing this to avoid seding trash or zeroes in the
      pointer content payload, using the return from bpf_probe_read_str(), but
      to keep things simple at this stage and make incremental progress, lets
      leave it at that for now.
      
      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: https://lkml.kernel.org/n/tip-g360n1zbj6bkbk6q0qo11c28@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      e0b6d2ef
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add bpf/stdio.h wrapper to bpf_perf_event_output function · 53a5d7b8
      Arnaldo Carvalho de Melo authored
      That, together with the map __bpf_output__ that is already handled by
      'perf trace' to print that event's contents as strings provides a
      debugging facility, to show it in use, print a simple string everytime
      the syscalls:sys_enter_openat() syscall tracepoint is hit:
      
        # cat tools/perf/examples/bpf/hello.c
        #include <stdio.h>
      
        int syscall_enter(openat)(void *args)
        {
      	  puts("Hello, world\n");
      	  return 0;
        }
      
        license(GPL);
        #
        # perf trace -e openat,tools/perf/examples/bpf/hello.c cat /etc/passwd > /dev/null
           0.016 (         ): __bpf_stdout__:Hello, world
           0.018 ( 0.010 ms): cat/9079 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
           0.057 (         ): __bpf_stdout__:Hello, world
           0.059 ( 0.011 ms): cat/9079 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC) = 3
           0.417 (         ): __bpf_stdout__:Hello, world
           0.419 ( 0.009 ms): cat/9079 openat(dfd: CWD, filename: /etc/passwd) = 3
        #
      
      This is part of an ongoing experimentation on making eBPF scripts as
      consumed by perf to be as concise as possible and using familiar
      concepts such as stdio.h functions, that end up just wrapping the
      existing BPF functions, trying to hide as much boilerplate as possible
      while using just conventions and C preprocessor tricks.
      
      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: https://lkml.kernel.org/n/tip-4tiaqlx5crf0fwpe7a6j84x7@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      53a5d7b8
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add 'syscall_enter' probe helper for syscall enter tracepoints · dda9ac96
      Arnaldo Carvalho de Melo authored
      Allowing one to hook into the syscalls:sys_enter_NAME tracepoints,
      an example is provided that hooks into the 'openat' syscall.
      
      Using it with the probe:vfs_getname probe into getname_flags to get the
      filename args as it is copied from userspace:
      
        # perf probe -l
        probe:vfs_getname    (on getname_flags:73@acme/git/linux/fs/namei.c with pathname)
        # perf trace -e probe:*getname,tools/perf/examples/bpf/sys_enter_openat.c cat /etc/passwd > /dev/null
           0.000 probe:vfs_getname:(ffffffffbd2a8983) pathname="/etc/ld.so.preload"
           0.022 syscalls:sys_enter_openat:dfd: CWD, filename: 0xafbe8da8, flags: CLOEXEC
           0.027 probe:vfs_getname:(ffffffffbd2a8983) pathname="/etc/ld.so.cache"
           0.054 syscalls:sys_enter_openat:dfd: CWD, filename: 0xafdf0ce0, flags: CLOEXEC
           0.057 probe:vfs_getname:(ffffffffbd2a8983) pathname="/lib64/libc.so.6"
           0.316 probe:vfs_getname:(ffffffffbd2a8983) pathname="/usr/lib/locale/locale-archive"
           0.375 syscalls:sys_enter_openat:dfd: CWD, filename: 0xe2b2b0b4
           0.379 probe:vfs_getname:(ffffffffbd2a8983) pathname="/etc/passwd"
        #
      
      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: https://lkml.kernel.org/n/tip-2po9jcqv1qgj0koxlg8kkg30@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      dda9ac96
  8. 15 May, 2018 5 commits
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add probe() helper to reduce kprobes boilerplate · d8fc764d
      Arnaldo Carvalho de Melo authored
      So that kprobe definitions become:
      
        int probe(function, variables)(void *ctx, int err, var1, var2, ...)
      
      The existing 5sec.c, got converted and goes from:
      
        SEC("func=hrtimer_nanosleep rqtp->tv_sec")
        int func(void *ctx, int err, long sec)
        {
        }
      
      To:
      
        int probe(hrtimer_nanosleep, rqtp->tv_sec)(void *ctx, int err, long sec)
        {
        }
      
      If we decide to add tv_nsec as well, then it becomes:
      
        $ cat tools/perf/examples/bpf/5sec.c
        #include <bpf.h>
      
        int probe(hrtimer_nanosleep, rqtp->tv_sec rqtp->tv_nsec)(void *ctx, int err, long sec, long nsec)
        {
      	  return sec == 5;
        }
      
        license(GPL);
        $
      
      And if we run it, system wide as before and run some 'sleep' with values
      for the tv_nsec field, we get:
      
        # perf trace --no-syscalls -e tools/perf/examples/bpf/5sec.c
           0.000 perf_bpf_probe:hrtimer_nanosleep:(ffffffff9811b5f0) tv_sec=5 tv_nsec=100000000
        9641.650 perf_bpf_probe:hrtimer_nanosleep:(ffffffff9811b5f0) tv_sec=5 tv_nsec=123450001
        ^C#
      
      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: https://lkml.kernel.org/n/tip-1v9r8f6ds5av0w9pcwpeknyl@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      d8fc764d
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add license(NAME) helper · 1f477305
      Arnaldo Carvalho de Melo authored
      To further reduce boilerplate.
      
      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: https://lkml.kernel.org/n/tip-vst6hj335s0ebxzqltes3nsc@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      1f477305
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add kprobe example to catch 5s naps · 7542b767
      Arnaldo Carvalho de Melo authored
      Description:
      
      . Disable strace like syscall tracing (--no-syscalls), or try tracing
        just some (-e *sleep).
      
      . Attach a filter function to a kernel function, returning when it should
        be considered, i.e. appear on the output:
      
        $ cat tools/perf/examples/bpf/5sec.c
        #include <bpf.h>
      
        SEC("func=hrtimer_nanosleep rqtp->tv_sec")
        int func(void *ctx, int err, long sec)
        {
      	  return sec == 5;
        }
      
        char _license[] SEC("license") = "GPL";
        int _version SEC("version") = LINUX_VERSION_CODE;
        $
      
      . Run it system wide, so that any sleep of >= 5 seconds and < than 6
        seconds gets caught.
      
      . Ask for callgraphs using DWARF info, so that userspace can be unwound
      
      . While this is running, run something like "sleep 5s".
      
        # perf trace --no-syscalls -e tools/perf/examples/bpf/5sec.c/call-graph=dwarf/
           0.000 perf_bpf_probe:func:(ffffffff9811b5f0) tv_sec=5
                                             hrtimer_nanosleep ([kernel.kallsyms])
                                             __x64_sys_nanosleep ([kernel.kallsyms])
                                             do_syscall_64 ([kernel.kallsyms])
                                             entry_SYSCALL_64 ([kernel.kallsyms])
                                             __GI___nanosleep (/usr/lib64/libc-2.26.so)
                                             rpl_nanosleep (/usr/bin/sleep)
                                             xnanosleep (/usr/bin/sleep)
                                             main (/usr/bin/sleep)
                                             __libc_start_main (/usr/lib64/libc-2.26.so)
                                             _start (/usr/bin/sleep)
        ^C#
      
      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: https://lkml.kernel.org/n/tip-2nmxth2l2h09f9gy85lyexcq@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      7542b767
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add bpf.h to be used in eBPF proggies · dd8e4ead
      Arnaldo Carvalho de Melo authored
      So, the first helper is the one shortening a variable/function section
      attribute, from, for instance:
      
        char _license[] __attribute__((section("license"), used)) = "GPL";
      
      to:
      
        char _license[] SEC("license") = "GPL";
      
      Convert empty.c to that and it becomes:
      
        # cat ~acme/lib/examples/perf/bpf/empty.c
        #include <bpf.h>
      
        char _license[] SEC("license") = "GPL";
        int _version SEC("version") = LINUX_VERSION_CODE;
        #
      
      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: https://lkml.kernel.org/n/tip-zmeg52dlvy51rdlhyumfl5yf@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      dd8e4ead
    • Arnaldo Carvalho de Melo's avatar
      perf bpf: Add 'examples' directories · 8f12a2ff
      Arnaldo Carvalho de Melo authored
      The first one is the bare minimum that bpf infrastructure accepts before
      it expects actual events to be set up:
      
        $ cat tools/perf/examples/bpf/empty.c
        char _license[] __attribute__((section("license"), used)) = "GPL";
        int _version __attribute__((section("version"), used)) = LINUX_VERSION_CODE;
        $
      
      If you remove that "version" line, then it will be refused with:
      
        # perf trace -e tools/perf/examples/bpf/empty.c
        event syntax error: 'tools/perf/examples/bpf/empty.c'
                             \___ Failed to load tools/perf/examples/bpf/empty.c from source: 'version' section incorrect or lost
      
        (add -v to see detail)
        Run 'perf list' for a list of valid events
      
         Usage: perf trace [<options>] [<command>]
            or: perf trace [<options>] -- <command> [<options>]
            or: perf trace record [<options>] [<command>]
            or: perf trace record [<options>] -- <command> [<options>]
      
            -e, --event <event>   event/syscall selector. use 'perf list' to list available events
        #
      
      The next ones will, step by step, show simple filters, then the needs
      for headers will be made clear, it will be put in place and tested with
      new examples, rinse, repeat.
      
      Back to using this first one to test the perf+bpf infrastructure:
      
      If we run it will fail, as no functions are present connecting with,
      say, a tracepoint or a function using the kprobes or uprobes
      infrastructure:
      
        # perf trace -e tools/perf/examples/bpf/empty.c
        WARNING: event parser found nothing
        invalid or unsupported event: 'tools/perf/examples/bpf/empty.c'
        Run 'perf list' for a list of valid events
      
         Usage: perf trace [<options>] [<command>]
            or: perf trace [<options>] -- <command> [<options>]
            or: perf trace record [<options>] [<command>]
            or: perf trace record [<options>] -- <command> [<options>]
      
            -e, --event <event>   event/syscall selector. use 'perf list' to list available events
        #
      
      But, if we set things up to dump the generated object file to a file,
      and do this after having run 'make install', still on the developer's
      $HOME directory:
      
        # cat ~/.perfconfig
        [llvm]
      
      	dump-obj = true
        #
        # perf trace -e ~acme/lib/examples/perf/bpf/empty.c
        LLVM: dumping /home/acme/lib/examples/perf/bpf/empty.o
        WARNING: event parser found nothing
        invalid or unsupported event: '/home/acme/lib/examples/perf/bpf/empty.c'
        <SNIP>
        #
      
      We can look at the dumped object file:
      
        # ls -la ~acme/lib/examples/perf/bpf/empty.o
        -rw-r--r--. 1 root root 576 May  4 12:10 /home/acme/lib/examples/perf/bpf/empty.o
        # file ~acme/lib/examples/perf/bpf/empty.o
        /home/acme/lib/examples/perf/bpf/empty.o: ELF 64-bit LSB relocatable, *unknown arch 0xf7* version 1 (SYSV), not stripped
        # readelf -sw ~acme/lib/examples/perf/bpf/empty.o
      
        Symbol table '.symtab' contains 3 entries:
           Num:    Value          Size Type    Bind   Vis      Ndx Name
             0: 0000000000000000     0 NOTYPE  LOCAL  DEFAULT  UND
             1: 0000000000000000     0 NOTYPE  GLOBAL DEFAULT    3 _license
             2: 0000000000000000     0 NOTYPE  GLOBAL DEFAULT    4 _version
        #
        # tools/bpf/bpftool/bpftool --pretty ~acme/lib/examples/perf/bpf/empty.o
        null
        #
      
      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: https://lkml.kernel.org/n/tip-y7dkhakejz3013o0w21n98xd@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      8f12a2ff