linux.git/tools/perf/Documentation, branch v4.8.7

perf probe: Support signedness casting

2016-08-09T13:52:22+00:00

The 'perf probe' tool detects a variable's type and use the detected
type to add a new probe. Then, kprobes prints its variable in
hexadecimal format if the variable is unsigned and prints in decimal if
it is signed.

We sometimes want to see unsigned variable in decimal format (i.e.
sector_t or size_t). In that case, we need to investigate the variable's
size manually to specify just signedness.

This patch add signedness casting support. By specifying "s" or "u" as a
type, perf-probe will investigate variable size as usual and use the
specified signedness.

E.g. without this:

  $ perf probe -a 'submit_bio bio->bi_iter.bi_sector'
  Added new event:
    probe:submit_bio     (on submit_bio with bi_sector=bio->bi_iter.bi_sector)
  You can now use it in all perf tools, such as:
          perf record -e probe:submit_bio -aR sleep 1
  $ cat trace_pipe|head
          dbench-9692  [003] d..1   971.096633: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x3a3d00
          dbench-9692  [003] d..1   971.096685: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x1a3d80
          dbench-9692  [003] d..1   971.096687: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x3a3d80
...
  // need to investigate the variable size
  $ perf probe -a 'submit_bio bio->bi_iter.bi_sector:s64'
  Added new event:
    probe:submit_bio     (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s64)
  You can now use it in all perf tools, such as:
        perf record -e probe:submit_bio -aR sleep 1

  With this:

  // just use "s" to cast its signedness
  $ perf probe -v -a 'submit_bio bio->bi_iter.bi_sector:s'
  Added new event:
    probe:submit_bio     (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s)
  You can now use it in all perf tools, such as:
          perf record -e probe:submit_bio -aR sleep 1
  $ cat trace_pipe|head
          dbench-9689  [001] d..1  1212.391237: submit_bio: (submit_bio+0x0/0x140) bi_sector=128
          dbench-9689  [001] d..1  1212.391252: submit_bio: (submit_bio+0x0/0x140) bi_sector=131072
          dbench-9697  [006] d..1  1212.398611: submit_bio: (submit_bio+0x0/0x140) bi_sector=30208

  This commit also update perf-probe.txt to describe "types". Most parts
  are based on existing documentation: Documentation/trace/kprobetrace.txt

Committer note:

Testing using 'perf trace':

  # perf probe -a 'submit_bio bio->bi_iter.bi_sector'
  Added new event:
    probe:submit_bio     (on submit_bio with bi_sector=bio->bi_iter.bi_sector)

  You can now use it in all perf tools, such as:

	perf record -e probe:submit_bio -aR sleep 1

  # trace --no-syscalls --ev probe:submit_bio
      0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=0xc133c0)
   3181.861 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffb8)
   3181.881 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffc0)
   3184.488 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffc8)

   4717.927 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x4dc7a88)
   4717.970 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x4dc7880)
  ^C[root@jouet ~]#

Now, using this new feature:

[root@jouet ~]# perf probe -a 'submit_bio bio->bi_iter.bi_sector:s'
Added new event:
  probe:submit_bio     (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s)

You can now use it in all perf tools, such as:

	perf record -e probe:submit_bio -aR sleep 1

  [root@jouet ~]# trace --no-syscalls --ev probe:submit_bio
     0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145704)
     0.017 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145712)
     0.019 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145720)
     2.567 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145728)
  5631.919 probe:submit_bio:(ffffffffac3aee00) bi_sector=0)
  5631.941 probe:submit_bio:(ffffffffac3aee00) bi_sector=8)
  5631.945 probe:submit_bio:(ffffffffac3aee00) bi_sector=16)
  5631.948 probe:submit_bio:(ffffffffac3aee00) bi_sector=24)
  ^C#

With callchains:

  # trace --no-syscalls --ev probe:submit_bio/max-stack=10/
     0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662544)
                                       submit_bio+0xa8200001 ([kernel.kallsyms])
                                       submit_bh+0xa8200013 ([kernel.kallsyms])
                                       jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
                                       kjournald2+0xa82000ca ([kernel.kallsyms])
                                       kthread+0xa82000d8 ([kernel.kallsyms])
                                       ret_from_fork+0xa820001f ([kernel.kallsyms])
     0.023 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662552)
                                       submit_bio+0xa8200001 ([kernel.kallsyms])
                                       submit_bh+0xa8200013 ([kernel.kallsyms])
                                       jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
                                       kjournald2+0xa82000ca ([kernel.kallsyms])
                                       kthread+0xa82000d8 ([kernel.kallsyms])
                                       ret_from_fork+0xa820001f ([kernel.kallsyms])
     0.027 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662560)
                                       submit_bio+0xa8200001 ([kernel.kallsyms])
                                       submit_bh+0xa8200013 ([kernel.kallsyms])
                                       jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
                                       kjournald2+0xa82000ca ([kernel.kallsyms])
                                       kthread+0xa82000d8 ([kernel.kallsyms])
                                       ret_from_fork+0xa820001f ([kernel.kallsyms])
     2.593 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662568)
                                       submit_bio+0xa8200001 ([kernel.kallsyms])
                                       submit_bh+0xa8200013 ([kernel.kallsyms])
                                       journal_submit_commit_record+0xa82001ac ([kernel.kallsyms])
                                       jbd2_journal_commit_transaction+0xa82012e8 ([kernel.kallsyms])
                                       kjournald2+0xa82000ca ([kernel.kallsyms])
                                       kthread+0xa82000d8 ([kernel.kallsyms])
                                       ret_from_fork+0xa820001f ([kernel.kallsyms])
  ^C#

Signed-off-by: Naohiro Aota 
Tested-by: Arnaldo Carvalho de Melo 
Cc: Alexander Shishkin 
Cc: Hemant Kumar 
Cc: Masami Hiramatsu 
Cc: Peter Zijlstra 
Cc: Wang Nan 
Link: http://lkml.kernel.org/r/1470710408-23515-1-git-send-email-naohiro.aota@hgst.com
Signed-off-by: Arnaldo Carvalho de Melo

perf script: Add 'bpf-output' field to usage message

2016-08-09T13:46:43+00:00

This adds the 'bpf-output' field to the perf script usage message, and docs.

Signed-off-by: Brendan Gregg 
Cc: Alexander Shishkin 
Cc: Alexei Starovoitov 
Cc: Peter Zijlstra 
Cc: Wang Nan 
Link: http://lkml.kernel.org/r/1470192469-11910-4-git-send-email-bgregg@netflix.com
Signed-off-by: Arnaldo Carvalho de Melo

perf record: Add --sample-cpu option

2016-08-02T19:33:29+00:00

Adding --sample-cpu option to be able to explicitly enable CPU sample
type. Currently it's only enable implicitly in case the target is cpu
related.

It will be useful for following c2c record tool.

Signed-off-by: Jiri Olsa 
Cc: David Ahern 
Cc: Namhyung Kim 
Cc: Peter Zijlstra 
Link: http://lkml.kernel.org/r/1470074555-24889-8-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo

perf record: Add --tail-synthesize option

2016-07-15T20:27:52+00:00

When working with overwritable ring buffer there's a inconvenience
problem: if perf dumps data after a long period after it starts,
non-sample events may lost, which makes following 'perf report' unable
to identify proc name and mmap layout. For example:

 # perf record -m 4 -e raw_syscalls:* -g --overwrite --switch-output \
        dd if=/dev/zero of=/dev/null

send SIGUSR2 after dd runs long enough. The resuling perf.data lost
correct comm and mmap events:

 # perf script -i perf.data.2016061522374354
 perf 24478 [004] 2581325.601789:  raw_syscalls:sys_exit: NR 0 = 512
 ^^^^
 Should be 'dd'
                   27b2e8 syscall_slow_exit_work+0xfe2000e3 (/lib/modules/4.6.0-rc3+/build/vmlinux)
                   203cc7 do_syscall_64+0xfe200117 (/lib/modules/4.6.0-rc3+/build/vmlinux)
                   b18d83 return_from_SYSCALL_64+0xfe200000 (/lib/modules/4.6.0-rc3+/build/vmlinux)
             7f47c417edf0 [unknown] ([unknown])
             ^^^^^^^^^^^^
             Fail to unwind

This patch provides a '--tail-synthesize' option, allows perf to collect
system status when finalizing output file. In resuling output file, the
non-sample events reflect system status when dumping data.

After this patch:
 # perf record -m 4 -e raw_syscalls:* -g --overwrite --switch-output --tail-synthesize \
        dd if=/dev/zero of=/dev/null

 # perf script -i perf.data.2016061600544998
 dd 27364 [004] 2583244.994464: raw_syscalls:sys_enter: NR 1 (1, ...
 ^^
 Correct comm
                   203a18 syscall_trace_enter_phase2+0xfe2001a8 ([kernel.kallsyms])
                   203aa5 syscall_trace_enter+0xfe200055 ([kernel.kallsyms])
                   203caa do_syscall_64+0xfe2000fa ([kernel.kallsyms])
                   b18d83 return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                    d8e50 __GI___libc_write+0xffff01d9639f4010 (/tmp/oxygen_root-w00229757/lib64/libc-2.18.so)
                    ^^^^^
                    Correct unwind

This option doesn't aim to solve this problem completely. If a process
terminates before SIGUSR2, we still lost its COMM and MMAP events. For
example, we can't unwind correctly from the final perf.data we get from
the previous example, because when perf collects the final output file
(when we press C-c), 'dd' has been terminated so its '/proc//mmap'
becomes empty.

However, this is a cheaper choice. To completely solve this problem we
need to continously output non-sample events. To satisify the
requirement of daemonization, we need to merge them periodically. It is
possible but requires much more code and cycles.

Automatically select --tail-synthesize when --overwrite is provided.

Signed-off-by: Wang Nan 
Cc: He Kuang 
Cc: Jiri Olsa 
Cc: Masami Hiramatsu 
Cc: Namhyung Kim 
Cc: Nilay Vaish 
Cc: Zefan Li 
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1468485287-33422-16-git-send-email-wangnan0@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo

perf tools: Enable overwrite settings

2016-07-15T20:27:51+00:00

This patch allows following config terms and option:

Globally setting events to overwrite;

  # perf record --overwrite ...

Set specific events to be overwrite or no-overwrite.

  # perf record --event cycles/overwrite/ ...
  # perf record --event cycles/no-overwrite/ ...

Add missing config terms and update the config term array size because
the longest string length has changed.

For overwritable events, it automatically selects attr.write_backward
since perf requires it to be backward for reading.

Test result:

  # perf record --overwrite -e syscalls:*enter_nanosleep* usleep 1
  [ perf record: Woken up 2 times to write data ]
  [ perf record: Captured and wrote 0.011 MB perf.data (1 samples) ]
  # perf evlist -v
  syscalls:sys_enter_nanosleep: type: 2, size: 112, config: 0x134, { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|CPU|PERIOD|RAW, disabled: 1, inherit: 1, mmap: 1, comm: 1, enable_on_exec: 1, task: 1, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1, write_backward: 1
  # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events

Signed-off-by: Wang Nan 
Tested-by: Arnaldo Carvalho de Melo 
Acked-by: Jiri Olsa 
Cc: Masami Hiramatsu 
Cc: Namhyung Kim 
Cc: Nilay Vaish 
Cc: Zefan Li 
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1468485287-33422-14-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang 
Signed-off-by: Arnaldo Carvalho de Melo

perf probe: Support a special SDT probe format

2016-07-14T02:09:09+00:00

Support a special SDT probe format which can omit the '%' prefix only if
the SDT group name starts with "sdt_". So, for example both of
"%sdt_libc:setjump" and "sdt_libc:setjump" are acceptable for perf probe
--add.

E.g. without this:

  # perf probe -a sdt_libc:setjmp
  Semantic error :There is non-digit char in line number.
  ...

With this:

  # perf probe -a sdt_libc:setjmp
  Added new event:
    sdt_libc:setjmp      (on %setjmp in /usr/lib64/libc-2.20.so)

  You can now use it in all perf tools, such as:

  	perf record -e sdt_libc:setjmp -aR sleep 1

Suggested-by: Brendan Gregg 
Signed-off-by: Masami Hiramatsu 
Tested-by: Arnaldo Carvalho de Melo 
Cc: Ananth N Mavinakayanahalli 
Cc: Brendan Gregg 
Cc: Hemant Kumar 
Cc: Namhyung Kim 
Cc: Peter Zijlstra 
Link: http://lkml.kernel.org/r/146831794674.17065.13359473252168740430.stgit@devbox
Signed-off-by: Arnaldo Carvalho de Melo

perf probe: Accept %sdt and %cached event name

2016-07-14T02:09:05+00:00

To improve usability, support %[PROVIDER:]SDTEVENT format to add new
probes on SDT and cached events.

e.g.
  ----
  # perf probe -x /lib/libc-2.17.so  %lll_lock_wait_private
  Added new event:
    sdt_libc:lll_lock_wait_private (on %lll_lock_wait_private in /usr/lib/libc-2.17.so)

  You can now use it in all perf tools, such as:

          perf record -e sdt_libc:lll_lock_wait_private -aR sleep 1

  # perf probe -l | more
    sdt_libc:lll_lock_wait_private (on __lll_lock_wait_private+21 in /usr/lib/libc-2.17.so)
  ----

Note that this is not only for SDT events, but also normal
events with event-name.

e.g. define "myevent" on cache (-n doesn't add the real probe)
  ----
  # perf probe -x ./perf --cache -n --add 'myevent=dso__load $params'
  ----
  Reuse the "myevent" from cache as below.
  ----
  # perf probe -x ./perf %myevent
  ----

Signed-off-by: Masami Hiramatsu 
Signed-off-by: Masami Hiramatsu 
Tested-by: Arnaldo Carvalho de Melo 
Cc: Ananth N Mavinakayanahalli 
Cc: Brendan Gregg 
Cc: Hemant Kumar 
Cc: Namhyung Kim 
Cc: Peter Zijlstra 
Link: http://lkml.kernel.org/r/146831788372.17065.3645054540325909346.stgit@devbox
Signed-off-by: Arnaldo Carvalho de Melo

perf report: Introduce --stdio-color to setup the color output mode selection

2016-07-12T03:00:39+00:00

'perf report --stdio' will colorize entries with most hits and possibly
some other aspects of its output, but those colors gets suppressed if we
redirect the output to a non-tty, allow keeping the colors by adding a
new option, --stdio-color, now this use case will also output escape
sequences for colors:

  $ perf annotate --stdio-color | more

Cc: Adrian Hunter 
Cc: David Ahern 
Cc: Jiri Olsa 
Cc: Namhyung Kim 
Cc: Peter Zijlstra 
Cc: Wang Nan 
Link: http://lkml.kernel.org/n/tip-3iuawqjldu4i8gziot7e3d5n@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo

perf annotate: Introduce --stdio-color to setup the color output mode selection

2016-07-12T03:00:39+00:00

'perf annotate --stdio' will colorize entries with most hits and
possibly some other aspects of its output, but those colors gets
suppressed if we redirect the output to a non-tty, allow keeping the
colors by adding a new option, --stdio-color, now this use case will
also output escape sequences for colors:

  $ perf annotate --stdio-color | more

Based-on-a-patch-by: Peter Zijlstra 
Cc: Adrian Hunter 
Cc: David Ahern 
Cc: Jiri Olsa 
Cc: Namhyung Kim 
Cc: Wang Nan 
Link: http://lkml.kernel.org/n/tip-sjrnixani5pg6qez640gaxhf@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo

perf tools: Update android build documentation

2016-07-04T23:27:27+00:00

Update the android build documentation according to recent android build
fixes. The instructions for step 1a and step 2 were updated to work with
NDK version 11(oldest supported version) and NDK version 12(current
version).

Signed-off-by: Chris Phlipot 
Cc: Peter Zijlstra 
Link: http://lkml.kernel.org/r/1467349955-1135-5-git-send-email-cphlipot0@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo