1. 23 2月, 2015 5 次提交
    • A
      perf trace: Introduce --filter-pids · f078c385
      Arnaldo Carvalho de Melo 提交于
      When tracing in X we get event loops due to the tracing activity, i.e.
      updates to a gnome-terminal that generate syscalls for X.org, etc.
      
      To get a more useful view of what is happening, syscall wise, system
      wide, we need to filter those, like in:
      
       # ps ax|egrep '981|2296|1519' | grep -v egrep
         981 tty1 Ss+ 5:40 /usr/bin/Xorg :0 -background none ...
        1519 ?    Sl  2:22 /usr/bin/gnome-shell
        2296 ?    Sl  4:16 /usr/libexec/gnome-terminal-server
       #
      
       # trace -e write --filter-pids 981,2296,1519
          0.385 ( 0.021 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 136) = 136
          0.922 ( 0.014 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 140) = 140
       5006.525 ( 0.029 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 136) = 136
       5007.235 ( 0.023 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 140) = 140
       5177.646 ( 0.018 ms): rtkit-daemon/782 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7f7eea70be88, count: 8) = 8
       8314.497 ( 0.004 ms): gsd-locate-poi/2084 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7fffe96af7b0, count: 8) = 8
       8314.518 ( 0.002 ms): gsd-locate-poi/2084 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7fffe96af0e0, count: 8) = 8
       ^C#
      
      When this option is used the tracer pid is also filtered.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-f5qmiyy7c0uxdm21ncatpeek@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      f078c385
    • A
      perf evlist: Introduce set_filter_pids method · be199ada
      Arnaldo Carvalho de Melo 提交于
      We need to filter multiple pids in trace, i.e. trace itself,
      gnome-terminal, X.org, etc.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-frtpkg7qapqwf7asa35wf8am@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      be199ada
    • A
      perf trace: Filter out the trace pid when no threads are specified · 241b057c
      Arnaldo Carvalho de Melo 提交于
      To avoid tracing the tracer.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-shmwd1khzpaobr3i0j1ygapg@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      241b057c
    • A
      perf evlist: Introduce set_filter_pid method · cfd70a26
      Arnaldo Carvalho de Melo 提交于
      To filter out events for a certain pid, for instance, when tracing
      system wide, so that the tracer itself doesn't creates an event loop.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-byoia9dzu4gmkdv87etnd9zf@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      cfd70a26
    • A
      perf trace: Only insert blank duration bracket when tracing syscalls · 0808921a
      Arnaldo Carvalho de Melo 提交于
      When printing just events, i.e. '--no-sys --ev some:events' it makes no
      sense to waste screen space.
      
      Before:
      
       # trace --no-sys --ev probe:*
       84481.704 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/services")
       84481.892 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/services")
       84482.230 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/resolv.conf")
       84482.481 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/hosts")
       85097.725 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/root"
       #
      
      After:
      
       # trace --no-sys --ev probe:*
       0.000 probe:vfs_getname:(ffffffff811ed023) pathname="/root")
       1.711 probe:vfs_getname:(ffffffff811ed023) pathname="/etc/localtime")
       2.103 probe:vfs_getname:(ffffffff811ed023) pathname="/etc/localtime")
      ^C#
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-jhryxgnam8zecq0q0wsy6pyb@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      0808921a
  2. 19 2月, 2015 22 次提交
  3. 14 2月, 2015 3 次提交
    • A
      perf trace: Support --events foo:bar --no-syscalls · 726f3234
      Arnaldo Carvalho de Melo 提交于
      I.e. support tracing just tracepoints, without strace like
      raw_syscalls:*.
      
      [acme@ssdandy linux]$ trace --no-sys --ev sched:*exec,sched:*switch,sched:*exit usleep 1
        0.048 (     ): sched:sched_process_exec:filename=/usr/bin/usleep pid=27298 old_pid=27298)
        0.369 (     ): sched:sched_switch:usleep:27298 [120] S ==> swapper/5:0 [120])
        0.452 (     ): sched:sched_process_exit:comm=usleep pid=27298 prio=120)
      [acme@ssdandy linux]$
      
      TODO: remove that (...) thing when --no-syscalls is specified.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-vn0hsixsbhm31b2rpj97r96k@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      726f3234
    • A
      perf trace: Allow mixing with other events · 14a052df
      Arnaldo Carvalho de Melo 提交于
      Basically adopting 'perf record' --event command line argument syntax:
      
       # trace -e \!mprotect,mmap,munmap,open,close,read,fstat,access,arch_prctl --event sched:*switch,sched:*exec,sched:*exit usleep 1
        0.048 (        ): sched:sched_process_exec:filename=/bin/usleep pid=24732 old_pid=24732)
        0.078 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
        0.430 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
        0.434 (0.003 ms): usleep/24732 brk(brk: 0x7b0000             ) = 0x7b0000
        0.438 (0.001 ms): usleep/24732 brk(                          ) = 0x7b0000
        0.460 (0.004 ms): usleep/24732 nanosleep(rqtp: 0x7ffff3696a40) ...
        0.460 (        ): sched:sched_switch:prev_comm=usleep prev_pid=24732 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_prio=120)
        0.515 (0.058 ms): usleep/24732  ... [continued]: nanosleep()) = 0
        0.520 (0.000 ms): usleep/24732 exit_group(
        0.550 (        ): sched:sched_process_exit:comm=usleep pid=24732 prio=120)
       #
      
      Next steps, probably in this order:
      
      1) Use ordered_events code, the logic in trace needs the events to be
         time ordered when needed, i.e. when multiple CPUs are involved.
      
      2) Callchains!
      
      3) Automatically account for interruptions when saying how long things
         took.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-gpst8mph575yb4wgf91qibyb@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      14a052df
    • A
      perf trace: Handle multiple threads better wrt syscalls being intermixed · e596663e
      Arnaldo Carvalho de Melo 提交于
       $ trace time taskset -c 0 usleep 1
         0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...
         0.865 ( 0.008 ms): time/16723 execve(arg0: 140733595272004, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = -2
         2.395 ( 1.523 ms): taskset/16723 execve(arg0: 140733595272013, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = 0
         2.411 ( 0.002 ms): taskset/16723 brk(                                                                  ) = 0x1915000
         3.300 ( 0.058 ms): usleep/16723 nanosleep(rqtp: 0x7ffff4ada190                                        ) = 0
       <SNIP>
         3.305 ( 0.000 ms): usleep/16723 exit_group(
         3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723
         3.366 ( 0.001 ms): time/16722 rt_sigaction(sig: INT, act: 0x7fff17f44160, oact: 0x7fff17f44200, sigsetsize: 8) = 0
      
      We we're not seeing this line:
      
        0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...
      
      just the one when it finishes:
      
        3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723
      
      Still some issues left till we move to ordered_samples when multiple
      CPUs/threads are involved...
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-zq9x30a1ky3djqewqn2v3ja3@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      e596663e
  4. 13 2月, 2015 10 次提交