Commit Graph

16 Commits

Author SHA1 Message Date
David Ahern
1424dc9680 perf script: Add support for H/W and S/W events
Custom fields set for each type by prepending field argument with type.
For file with multiple event types (e.g., trace and S/W) display of an
event type suppressed by setting output fields to "".

e.g.,
perf record -ga -e sched:sched_switch -e cpu-clock -c 10000000 -R -- sleep 1
perf script

openssl 11496 [000]  9711.807107: cpu-clock-msecs:
        ffffffff810c22dc arch_local_irq_restore ([kernel.kallsyms])
        ffffffff810c518c __alloc_pages_nodemask ([kernel.kallsyms])
        ffffffff810297b2 pte_alloc_one ([kernel.kallsyms])
        ffffffff810d8b98 __pte_alloc ([kernel.kallsyms])
        ffffffff810daf07 handle_mm_fault ([kernel.kallsyms])
        ffffffff8138763a do_page_fault ([kernel.kallsyms])
        ffffffff81384a65 page_fault ([kernel.kallsyms])
            7f6130507d70 asn1_check_tlen (/lib64/libcrypto.so.1.0.0c)
                       0  ()

         openssl 11496 [000]  9711.808042: sched_switch: prev_comm=openssl ...
     kworker/0:0     4 [000]  9711.808067: sched_switch: prev_comm=kworker/...
         swapper     0 [001]  9711.808090: sched_switch: prev_comm=kworker/...
            sshd 11451 [001]  9711.808185: sched_switch: prev_comm=sshd pre...
swapper     0 [001]  9711.816155: cpu-clock-msecs:
        ffffffff81023609 native_safe_halt ([kernel.kallsyms])
        ffffffff8100132a cpu_idle ([kernel.kallsyms])
        ffffffff8137cf9b start_secondary ([kernel.kallsyms])

openssl 11496 [000]  9711.817104: cpu-clock-msecs:
            7f61304ad723 AES_cbc_encrypt (/lib64/libcrypto.so.1.0.0c)
            7fff3402f950  ()
        12f0debc9a785634  ()

swapper     0 [001]  9711.826155: cpu-clock-msecs:
        ffffffff81023609 native_safe_halt ([kernel.kallsyms])
        ffffffff8100132a cpu_idle ([kernel.kallsyms])
        ffffffff8137cf9b start_secondary ([kernel.kallsyms])

To suppress trace events within the file and use default output for S/W events:
perf script -f trace:

or to suppress S/W events and do default display for trace events:
perf script -f sw:

Custom field selections:
perf script -f sw:comm,tid,time -f trace:time,trace

         openssl 11496  9711.797162:
         swapper     0  9711.807071:
         openssl 11496  9711.807107:
 9711.808042: prev_comm=openssl prev_pid=11496 prev_prio=120 prev_state=R ...
 9711.808067: prev_comm=kworker/0:0 prev_pid=4 prev_prio=120 prev_state=S ...
 9711.808090: prev_comm=kworker/0:0 prev_pid=0 prev_prio=120 prev_state=R ...
 9711.808185: prev_comm=sshd prev_pid=11451 prev_prio=120 prev_state=S ==>...
         swapper     0  9711.816155:
         openssl 11496  9711.817104:
         swapper     0  9711.826155:

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1299734608-5223-7-git-send-email-daahern@cisco.com>
Signed-off-by: David Ahern <daahern@cisco.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-14 17:07:20 -03:00
David Ahern
c0230b2bfb perf script: Add support for dumping symbols
Add option to dump symbols found in events.

e.g., perf script -f comm,pid,tid,time,trace,sym

swapper     0/0       537.037184: prev_comm=swapper prev_pid=0 prev_prio=120...
        ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms])
        ffffffff81382ac5 schedule ([kernel.kallsyms])
        ffffffff8100134a cpu_idle ([kernel.kallsyms])
        ffffffff81370b39 rest_init ([kernel.kallsyms])
        ffffffff81696c23 start_kernel ([kernel.kallsyms].init.text)
        ffffffff816962af x86_64_start_reservations ([kernel.kallsyms].init.text)
        ffffffff816963b9 x86_64_start_kernel ([kernel.kallsyms].init.text)

sshd  1675/1675    537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120...
        ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms])
        ffffffff81382ac5 schedule ([kernel.kallsyms])
        ffffffff813837aa schedule_hrtimeout_range_clock ([kernel.kallsyms])
        ffffffff81383886 schedule_hrtimeout_range ([kernel.kallsyms])
        ffffffff8110c4f9 poll_schedule_timeout ([kernel.kallsyms])
        ffffffff8110cd20 do_select ([kernel.kallsyms])
        ffffffff8110ced8 core_sys_select ([kernel.kallsyms])
        ffffffff8110d00d sys_select ([kernel.kallsyms])
        ffffffff81002bc2 system_call ([kernel.kallsyms])
            7f1647e56e93 __GI_select (/lib64/libc-2.12.90.so)

netstat  1692/1692    537.038664: prev_comm=netstat prev_pid=1692 prev_prio=...
        ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms])
        ffffffff81382ac5 schedule ([kernel.kallsyms])
        ffffffff81002c3a sysret_careful ([kernel.kallsyms])
            7f7a6cd1b210 __GI___libc_read (/lib64/libc-2.12.90.so)

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1299734608-5223-6-git-send-email-daahern@cisco.com>
Signed-off-by: David Ahern <daahern@cisco.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-14 17:06:50 -03:00
David Ahern
745f43e343 perf script: Support custom field selection for output
Allow a user to select which fields to print to stdout for event data.
Options include comm (command name), tid (thread id), pid (process id),
time (perf timestamp), cpu, event (for event name), and trace (for
trace data).

Default is set to maintain compatibility with current output; this
feature does alter output format slightly -- no '-' between command
and pid/tid.

Thanks to Frederic Weisbecker for detailed suggestions on this approach.

Examples (output compressed)

1. trace, default format

perf record -ga -e sched:sched_switch
perf script

swapper    0 [000] 537.037184: sched_switch: prev_comm=swapper prev_pid=0...
   sshd 1675 [000] 537.037309: sched_switch: prev_comm=sshd prev_pid=1675...
netstat 1692 [001] 537.038664: sched_switch: prev_comm=netstat prev_pid=1692...

2. trace, custom format

perf record -ga -e sched:sched_switch
perf script -f comm,pid,time,trace     <--- omitting cpu and event name

swapper    0 537.037184: prev_comm=swapper prev_pid=0 prev_prio=120 ...
   sshd 1675 537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120 ...
netstat 1692 537.038664: prev_comm=netstat prev_pid=1692 prev_prio=120 ...

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1299734608-5223-5-git-send-email-daahern@cisco.com>
Signed-off-by: David Ahern <daahern@cisco.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-14 17:06:16 -03:00
David Ahern
c70c94b474 perf script: Move printing of 'common' data from print_event and rename
This change does impact output: latency data is trace specific and is
now printed after the common data - comm, tid, cpu, time and event name.

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1299734608-5223-4-git-send-email-daahern@cisco.com>
Signed-off-by: David Ahern <daahern@cisco.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-14 17:05:55 -03:00
David Ahern
be6d842a65 perf script: Change process_event prototype
Prepare for handling of samples for any event type.

Acked-by: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1299734608-5223-2-git-send-email-daahern@cisco.com>
Signed-off-by: David Ahern <daahern@cisco.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-14 17:05:50 -03:00
Arnaldo Carvalho de Melo
8115d60c32 perf tools: Kill event_t typedef, use 'union perf_event' instead
And move the event_t methods to the perf_event__ too.

No code changes, just namespace consistency.

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-01-29 16:25:37 -02:00
Arnaldo Carvalho de Melo
8d50e5b417 perf tools: Rename 'struct sample_data' to 'struct perf_sample'
Making the namespace more uniform.

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-01-29 16:25:20 -02:00
Arnaldo Carvalho de Melo
9486aa3877 perf tools: Fix 64 bit integer format strings
Using %L[uxd] has issues in some architectures, like on ppc64.  Fix it
by making our 64 bit integers typedefs of stdint.h types and using
PRI[ux]64 like, for instance, git does.

Reported by Denis Kirjanov that provided a patch for one case, I went
and changed all cases.

Reported-by: Denis Kirjanov <dkirjanov@kernel.org>
Tested-by: Denis Kirjanov <dkirjanov@kernel.org>
LKML-Reference: <20110120093246.GA8031@hera.kernel.org>
Cc: Denis Kirjanov <dkirjanov@kernel.org>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Pingtian Han <phan@redhat.com>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-01-22 23:41:57 -02:00
Arnaldo Carvalho de Melo
eccdfe2d24 perf script: Make some lists static
Not accessed outside builtin-script, so make them static.

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-01-05 14:53:59 -02:00
Arnaldo Carvalho de Melo
6d8afb5630 perf script: Use the default lost event handler
That already does what was being done here. The warning is now unconditionally
given by __perf_session__process_pipe_events, just like for non pipe processing.

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-01-05 14:53:43 -02:00
Arnaldo Carvalho de Melo
ce0ac9e185 perf script: Fix event ordering settings to work with older kernels
If we don't use .ordering_requires_timestamps we'll end up trying to order
events with no timestamps when running on older kernels.

Problem introduced in eac23d1c.

After the last three fixes, perf scripting is back working, tested with
new perf userspace on old and new (with sample_id_all) kernels.

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ian Munsie <imunsie@au1.ibm.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Tom Zanussi <tzanussi@gmail.com>
Cc: Torok Edwin <edwintorok@gmail.com>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2010-12-25 18:33:12 -02:00
Ian Munsie
21ef97f05a perf session: Fallback to unordered processing if no sample_id_all
If we are running the new perf on an old kernel without support for
sample_id_all, we should fall back to the old unordered processing of
events. If we didn't than we would *always* process events without
timestamps out of order, whether or not we hit a reordering race. In
other words, instead of there being a chance of not attributing samples
correctly, we would guarantee that samples would not be attributed.

While processing all events without timestamps before events with
timestamps may seem like an intuitive solution, it falls down as
PERF_RECORD_EXIT events would also be processed before any samples.
Even with a workaround for that case, samples before/after an exec would
not be attributed correctly.

This patch allows commands to indicate whether they need to fall back to
unordered processing, so that commands that do not care about timestamps
on every event will not be affected. If we do fallback, this will print
out a warning if report -D was invoked.

This patch adds the test in perf_session__new so that we only need to
test once per session. Commands that do not use an event_ops (such as
record and top) can simply pass NULL in it's place.

Acked-by: Thomas Gleixner <tglx@linutronix.de>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
LKML-Reference: <1291951882-sup-6069@au1.ibm.com>
Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2010-12-21 20:17:51 -02:00
Stephane Eranian
965bb6beaf perf script: Fix compiler warning in builtin_script.c:is_top_script()
Fix annoying compiler warning in the is_top_script() function.

The issue was that a const char * was cast into a char * to call
ends_with(). We fix the users of ends_with() instead. Some are passing a
char *, but it is okay to cast the return value of ends_with() to char *
(because we understand what ends_with() does).

Cc: David S. Miller <davem@davemloft.net>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Robert Richter <robert.richter@amd.com>
Cc: Stephane Eranian <eranian@gmail.com>
LKML-Reference: <4cf92096.17edd80a.1540.5d60@mx.google.com>
Signed-off-by: Stephane Eranian <eranian@google.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2010-12-06 12:44:27 -02:00
Arnaldo Carvalho de Melo
640c03ce83 perf session: Parse sample earlier
At perf_session__process_event, so that we reduce the number of lines in eache
tool sample processing routine that now receives a sample_data pointer already
parsed.

This will also be useful in the next patch, where we'll allow sample the
identity fields in MMAP, FORK, EXIT, etc, when it will be possible to see (cpu,
timestamp) just after before every event.

Also validate callchains in perf_session__process_event, i.e. as early as
possible, and keep a counter of the number of events discarded due to invalid
callchains, warning the user about it if it happens.

There is an assumption that was kept that all events have the same sample_type,
that will be dealt with in the future, when this preexisting limitation will be
removed.

Tested-by: Thomas Gleixner <tglx@linutronix.de>
Reviewed-by: Thomas Gleixner <tglx@linutronix.de>
Acked-by: Ian Munsie <imunsie@au1.ibm.com>
Acked-by: Thomas Gleixner <tglx@linutronix.de>
Cc: Frédéric Weisbecker <fweisbec@gmail.com>
Cc: Ian Munsie <imunsie@au1.ibm.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Stephane Eranian <eranian@google.com>
LKML-Reference: <1291318772-30880-4-git-send-email-acme@infradead.org>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2010-12-04 23:05:19 -02:00
Ingo Molnar
b3d006c0e7 Merge branch 'perf/rename' into perf/core
Merge reason: This is an older commit under testing that was not pushed yet - merge it.

Also fix up the merge in command-list.txt.

Signed-off-by: Ingo Molnar <mingo@elte.hu>
Acked-by: Tom Zanussi <tzanussi@gmail.com>
2010-12-01 09:22:19 +01:00
Ingo Molnar
133dc4c39c perf: Rename 'perf trace' to 'perf script'
Free the perf trace name space and rename the trace to 'script' which is a
better match for the scripting engine.

Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
2010-11-16 19:37:44 +01:00