1. 31 Oct, 2012 9 commits
    • David Sharp's avatar
      tracing: Trivial cleanup · 01e3e710
      David Sharp authored
      Remove ftrace_format_syscall() declaration; it is neither defined nor
      used. Also update a comment and formatting.
      
      Link: http://lkml.kernel.org/r/1339112785-21806-1-git-send-email-vnagarnaik@google.comSigned-off-by: default avatarDavid Sharp <dhsharp@google.com>
      Signed-off-by: default avatarVaibhav Nagarnaik <vnagarnaik@google.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      01e3e710
    • Steven Rostedt's avatar
      tracing: Cache comms only after an event occurred · 7ffbd48d
      Steven Rostedt authored
      Whenever an event is registered, the comm of tasks are saved at
      every task switch instead of saving them at every event. But if
      an event isn't executed much, the comm cache will be filled up
      by tasks that did not record the event and you lose out on the comms
      that did.
      
      Here's an example, if you enable the following events:
      
      echo 1 > /debug/tracing/events/kvm/kvm_cr/enable
      echo 1 > /debug/tracing/events/net/net_dev_xmit/enable
      
      Note, there's no kvm running on this machine so the first event will
      never be triggered, but because it is enabled, the storing of comms
      will continue. If we now disable the network event:
      
      echo 0 > /debug/tracing/events/net/net_dev_xmit/enable
      
      and look at the trace:
      
      cat /debug/tracing/trace
                  sshd-2672  [001] ..s2   375.731616: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s1   375.731617: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s2   375.859356: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s1   375.859357: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s2   375.947351: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s1   375.947352: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s2   376.035383: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s1   376.035383: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                  sshd-2672  [001] ..s2   377.563806: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=226 rc=0
                  sshd-2672  [001] ..s1   377.563807: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=226 rc=0
                  sshd-2672  [001] ..s2   377.563834: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6be0 len=114 rc=0
                  sshd-2672  [001] ..s1   377.563842: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6be0 len=114 rc=0
      
      We see that process 2672 which triggered the events has the comm "sshd".
      But if we run hackbench for a bit and look again:
      
      cat /debug/tracing/trace
                 <...>-2672  [001] ..s2   375.731616: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s1   375.731617: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s2   375.859356: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s1   375.859357: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s2   375.947351: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s1   375.947352: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s2   376.035383: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s1   376.035383: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=242 rc=0
                 <...>-2672  [001] ..s2   377.563806: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6de0 len=226 rc=0
                 <...>-2672  [001] ..s1   377.563807: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6de0 len=226 rc=0
                 <...>-2672  [001] ..s2   377.563834: net_dev_xmit: dev=eth0 skbaddr=ffff88005cbb6be0 len=114 rc=0
                 <...>-2672  [001] ..s1   377.563842: net_dev_xmit: dev=br0 skbaddr=ffff88005cbb6be0 len=114 rc=0
      
      The stored "sshd" comm has been flushed out and we get a useless "<...>".
      
      But by only storing comms after a trace event occurred, we can run
      hackbench all day and still get the same output.
      
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      7ffbd48d
    • Steven Rostedt's avatar
      tracing: Have tracing_sched_wakeup_trace() use standard unlock_commit · 2b70e590
      Steven Rostedt authored
      The functon tracing_sched_wakeup_trace() does an open coded unlock
      commit and save stack. This is what the trace_nowake_buffer_unlock_commit()
      is for.
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      2b70e590
    • Steven Rostedt's avatar
      tracing: Enable comm recording if trace_printk() is used · 81698831
      Steven Rostedt authored
      If comm recording is not enabled when trace_printk() is used then
      you just get this type of output:
      
      [ adding trace_printk("hello! %d", irq); in do_IRQ ]
      
                 <...>-2843  [001] d.h.    80.812300: do_IRQ: hello! 14
                 <...>-2734  [002] d.h2    80.824664: do_IRQ: hello! 14
                 <...>-2713  [003] d.h.    80.829971: do_IRQ: hello! 14
                 <...>-2814  [000] d.h.    80.833026: do_IRQ: hello! 14
      
      By enabling the comm recorder when trace_printk is enabled:
      
             hackbench-6715  [001] d.h.   193.233776: do_IRQ: hello! 21
                  sshd-2659  [001] d.h.   193.665862: do_IRQ: hello! 21
                <idle>-0     [001] d.h1   193.665996: do_IRQ: hello! 21
      Suggested-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      81698831
    • Steven Rostedt's avatar
      tracing: Expand ring buffer when trace_printk() is used · b382ede6
      Steven Rostedt authored
      Since tracing is not used by 99% of Linux users, even though tracing
      may be configured in, it does not make sense to allocate 1.4 Megs
      per CPU for the ring buffers if they are not used. Thus, on boot up
      the ring buffers are set to a minimal size until something needs the
      and they are expanded.
      
      This works well for events and tracers (function, etc), but for the
      asynchronous use of trace_printk() which can write to the ring buffer
      at any time, does not expand the buffers.
      
      On boot up a check is made to see if any trace_printk() is used to
      see if the trace_printk() temp buffer pages should be allocated. This
      same code can be used to expand the buffers as well.
      Suggested-by: default avatarPeter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      b382ede6
    • Slava Pestov's avatar
      ring-buffer: Add a 'dropped events' counter · 884bfe89
      Slava Pestov authored
      The existing 'overrun' counter is incremented when the ring
      buffer wraps around, with overflow on (the default). We wanted
      a way to count requests lost from the buffer filling up with
      overflow off, too. I decided to add a new counter instead
      of retro-fitting the existing one because it seems like a
      different statistic to count conceptually, and also because
      of how the code was structured.
      
      Link: http://lkml.kernel.org/r/1310765038-26399-1-git-send-email-slavapestov@google.comSigned-off-by: default avatarSlava Pestov <slavapestov@google.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      884bfe89
    • Hiraku Toyooka's avatar
      tracing: Change tracer's integer flags to bool · f43c738b
      Hiraku Toyooka authored
      print_max and use_max_tr in struct tracer are "int" variables and
      used like flags. This is wasteful, so change the type to "bool".
      
      Link: http://lkml.kernel.org/r/20121002082710.9807.86393.stgit@falsitaSigned-off-by: default avatarHiraku Toyooka <hiraku.toyooka.gu@hitachi.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      f43c738b
    • Steven Rostedt's avatar
      tracing: Allow tracers to start at core initcall · 6f415672
      Steven Rostedt authored
      There's times during debugging that it is helpful to see traces of early
      boot functions. But the tracers are initialized at device_initcall()
      which is quite late during the boot process. Setting the kernel command
      line parameter ftrace=function will not show anything until the function
      tracer is initialized. This prevents being able to trace functions before
      device_initcall().
      
      There's no reason that the tracers need to be initialized so late in the
      boot process. Move them up to core_initcall() as they still need to come
      after early_initcall() which initializes the tracing buffers.
      
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      6f415672
    • Daniel Walter's avatar
      tracing: Replace strict_strto* with kstrto* · bcd83ea6
      Daniel Walter authored
       * remove old string conversions with kstrto*
      
      Link: http://lkml.kernel.org/r/20120926200838.GC1244@0x90.atSigned-off-by: default avatarDaniel Walter <sahne@0x90.at>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      bcd83ea6
  2. 30 Oct, 2012 2 commits
    • Peter Huewe's avatar
      perf/x86: Fix sparse warnings · 95d18aa2
      Peter Huewe authored
      FYI, there are new sparse warnings:
      
       arch/x86/kernel/cpu/perf_event.c:1356:18: sparse: symbol 'events_attr' was not declared. Should it be static?
      
      This patch makes it static and also adds the static keyword to
      fix arch/x86/kernel/cpu/perf_event.c:1344:9: warning: symbol
      'events_sysfs_show' was not declared.
      Signed-off-by: default avatarPeter Huewe <peterhuewe@gmx.de>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Cc: Yuanhan Liu <yuanhan.liu@linux.intel.com>
      Cc: fengguang.wu@intel.com
      Cc: Jiri Olsa <jolsa@redhat.com>
      Link: http://lkml.kernel.org/n/tip-lerdpXlnruh0yvWs2owwuizl@git.kernel.orgSigned-off-by: default avatarIngo Molnar <mingo@kernel.org>
      95d18aa2
    • Ingo Molnar's avatar
      Merge tag 'perf-core-for-mingo' of... · 8748dd9b
      Ingo Molnar authored
      Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core
      
      Pull perf/core improvements, fixes and code move from Arnaldo Carvalho de Melo:
      
       * Initialize 'page_size' variable in the python binding, this was sent
         for perf/urgent by mistake, then when merging Ingo removed it, fixing
         the problem for perf/urgent, but when perf/urgent was merged with
         perf/core, where that initialization is needed, made the python
         binding mmap call to fail, fix it by initializing page_size again.
      
       * Add a browser for 'perf script' and make it available from the report
         and annotate browsers. It does filtering to find the scripts that
         handle events found in the perf.data file used. From Feng Tang
      
       * Move some functions from symbol.c to more appropriate files, creating
         dso.[ch] in the process, no code changes. From Jiri Olsa
      
       * Fix mmap error output message for when perf_mmap fails and returns
         !-EPERM, where the default for mmap_pages, INT_MAX, was causing a
         !power of 2 error message, fix from Jiri Olsa.
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      Signed-off-by: default avatarIngo Molnar <mingo@kernel.org>
      8748dd9b
  3. 29 Oct, 2012 13 commits
  4. 28 Oct, 2012 1 commit
  5. 26 Oct, 2012 11 commits
  6. 25 Oct, 2012 4 commits
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Use sched:sched_stat_runtime to provide a thread summary · 1302d88e
      Arnaldo Carvalho de Melo authored
      [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox`
      <SNIP>
       17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout
       17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096         ) = -1 EAGAIN Resource temporarily unavailable
       17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout
       17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096         ) = -1 EAGAIN Resource temporarily unavailable
      ^C
       _____________________________________________________________________
       __)    Summary of events    (__
      
                    [ task - pid ]     [ events ] [ ratio ]  [ runtime ]
       _____________________________________________________________________
      
                   firefox - 17643 :      18013   [ 72.2% ]    359.110 ms
                   firefox - 17663 :         41   [  0.2% ]     21.439 ms
                   firefox - 17664 :       6840   [ 27.4% ]    133.642 ms
                   firefox - 17667 :         46   [  0.2% ]      0.682 ms
      [root@sandy ~]#
      
      This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2
      branch.
      
      Another example, setting a huge duration filter to get just a system
      wide summary:
      
      [root@sandy ~]# perf trace --duration 10000.0 --sched
      ^C
       _____________________________________________________________________
       __)    Summary of events    (__
      
                    [ task - pid ]     [ events ] [ ratio ]  [ runtime ]
       _____________________________________________________________________
      
                 scsi_eh_1 - 258   :         15   [  0.0% ]      0.133 ms
              kworker/0:1H - 322   :         13   [  0.0% ]      0.032 ms
               jbd2/dm-0-8 - 384   :          4   [  0.0% ]      0.115 ms
               flush-253:0 - 470   :          1   [  0.0% ]      0.027 ms
                   firefox - 950   :       4783   [  0.1% ]     24.863 ms
                   firefox - 992   :       1883   [  0.1% ]      6.808 ms
                   firefox - 995   :         35   [  0.0% ]      0.111 ms
               ksoftirqd/6 - 4362  :          2   [  0.0% ]      0.005 ms
               ksoftirqd/7 - 4365  :          1   [  0.0% ]      0.007 ms
                      Xorg - 4671  :        148   [  0.0% ]      0.912 ms
           gnome-settings- - 4846  :         14   [  0.0% ]      0.086 ms
           seahorse-daemon - 4847  :         14   [  0.0% ]      0.092 ms
               gnome-panel - 4875  :         46   [  0.0% ]      0.159 ms
           gnome-power-man - 4918  :         16   [  0.0% ]      0.065 ms
           gvfs-afc-volume - 4992  :         77   [  0.0% ]      0.136 ms
           gnome-screensav - 5114  :         24   [  0.0% ]      0.128 ms
                     xchat - 8082  :        466   [  0.0% ]      2.019 ms
                  synergyc - 8369  :        941   [  0.0% ]      3.291 ms
                  synergyc - 8371  :         85   [  0.0% ]      1.817 ms
               jbd2/dm-4-8 - 9352  :          4   [  0.0% ]      0.109 ms
                   rpcbind - 9786  :          3   [  0.0% ]      0.017 ms
              rtkit-daemon - 12802 :         10   [  0.0% ]      0.038 ms
              rtkit-daemon - 12803 :          8   [  0.0% ]      0.000 ms
             udisks-daemon - 13020 :         27   [  0.0% ]      0.240 ms
               kworker/7:0 - 14651 :        669   [  0.0% ]      2.616 ms
               kworker/5:1 - 16220 :          2   [  0.0% ]      0.069 ms
               kworker/4:0 - 19776 :         13   [  0.0% ]      0.176 ms
                   openvpn - 20131 :        133   [  0.0% ]      0.762 ms
           plugin-containe - 20508 :      60658   [  1.7% ]    131.153 ms
              npviewer.bin - 20520 :      72208   [  2.0% ]    138.945 ms
              npviewer.bin - 20542 :         35   [  0.0% ]      0.074 ms
              npviewer.bin - 20543 :         30   [  0.0% ]      0.074 ms
              npviewer.bin - 20547 :         35   [  0.0% ]      0.092 ms
              npviewer.bin - 20552 :         35   [  0.0% ]      0.093 ms
                      sshd - 20645 :         32   [  0.0% ]      0.071 ms
              npviewer.bin - 21053 :         35   [  0.0% ]      0.074 ms
              npviewer.bin - 21054 :         35   [  0.0% ]      0.097 ms
               kworker/0:2 - 21169 :        149   [  0.0% ]      1.143 ms
               kworker/3:0 - 22171 :        113   [  0.0% ]     96.892 ms
               flush-253:4 - 22410 :          1   [  0.0% ]      0.028 ms
               kworker/6:0 - 24581 :         25   [  0.0% ]      0.275 ms
               kworker/1:0 - 25572 :          4   [  0.0% ]      0.103 ms
               kworker/2:1 - 26299 :        138   [  0.0% ]      1.440 ms
               kworker/0:0 - 26325 :          1   [  0.0% ]      0.003 ms
                      perf - 26330 :    3506967   [ 96.1% ]   6648.310 ms
      [root@sandy ~]#
      
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@gmail.com>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      1302d88e
    • Arnaldo Carvalho de Melo's avatar
      perf trace: Count number of events for each thread and globally · efd5745e
      Arnaldo Carvalho de Melo authored
      The nr_events in trace__run was local, but we will need it in other
      trace methods, move it to struct trace.
      
      We'll also need the number of events per thread, so introduce a
      nr_events method for that in struct thread_trace.
      
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@gmail.com>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-ksutaz0mtejnf7e6az3ca1td@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      efd5745e
    • Arnaldo Carvalho de Melo's avatar
      perf tools: Don't stop synthesizing threads when one vanishes · ba361c92
      Arnaldo Carvalho de Melo authored
      The perf_event__synthesize_threads routine synthesizes all the existing
      threads in the system, because we don't have any kernel facilities to
      ask for PERF_RECORD_{FORK,MMAP,COMM} for existing threads.
      
      It was returning an error as soon as one thread couldn't be synthesized,
      which is a bit extreme when, for instance, a forkish workload is
      running, like a kernel compile.
      
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@gmail.com>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-i7oas1eodpoer2bx38fwyasv@git.kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      ba361c92
    • Ingo Molnar's avatar
      Merge tag 'perf-core-for-mingo' of... · 6ca2a9c6
      Ingo Molnar authored
      Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core
      
      Pull perf/core improvements and fixes from Arnaldo Carvalho de Melo:
      
       * Align the 'Ok'/'FAILED!' test results in 'perf test.
      
       * Support interrupted syscalls in 'trace'
      
       * Add an event duration column and filter in 'trace'.
      
       * There are references to the man pages in some tools, so try to build
         Documentation when installing, warning the user if that is not possible,
         from Borislav Petkov.
      
       * Give user better message if precise is not supported, from David Ahern.
      
       * Try to find cross-built objdump path by using the session environment
         information in the perf.data file header, from Irina Tirdea, original
         patch and idea by Namhyung Kim.
      
       * Diplays more output on features check for make V=1, so that one can figure
         out what is happening by looking at gcc output, etc. From Jiri Olsa.
      
       * Account the nr_entries in rblist properly, fix by Suzuki K. Poulose.
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      6ca2a9c6