v2 -> v3:
- removed show-unresolved option
- setup different output defaults based on event type
- moved printing of comm, pid/tid, time and event name from print_event to
builtin-script and renamed print_event to print_trace_event
- removed unneeded cursor depth check
- updated to latest perf-core to get Arnaldo's recent makeovers
- created smaller, focused patches
v1 -> v2:
- fixed process_event handler in trace-event-perl
- removed unneeded call to callchain_register_param
- corrected walking of callchains in perf_session__print_symbols
- complete rewrite for handling non-tracepoint events
David Ahern (5):
perf script: change process_event prototype
perf script: move printing of 'common' data from print_event and
rename
perf script: support custom field selection for output
perf script: add support for dumping symbols
perf script: add support for H/W and S/W events
tools/perf/Documentation/perf-script.txt | 22 ++
tools/perf/builtin-script.c | 296 ++++++++++++++++++--
tools/perf/util/parse-events.c | 22 ++
tools/perf/util/parse-events.h | 1 +
.../perf/util/scripting-engines/trace-event-perl.c | 11 +-
.../util/scripting-engines/trace-event-python.c | 11 +-
tools/perf/util/session.c | 61 ++++
tools/perf/util/session.h | 4 +
tools/perf/util/trace-event-parse.c | 106 +-------
tools/perf/util/trace-event-scripting.c | 9 +-
tools/perf/util/trace-event.h | 10 +-
11 files changed, 416 insertions(+), 137 deletions(-)
--
1.7.4
Prepare for handling of samples for any event type.
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/builtin-script.c | 25 ++++++++++++-------
.../perf/util/scripting-engines/trace-event-perl.c | 11 ++++++--
.../util/scripting-engines/trace-event-python.c | 11 ++++++--
tools/perf/util/trace-event-scripting.c | 9 +++----
tools/perf/util/trace-event.h | 7 ++++-
5 files changed, 41 insertions(+), 22 deletions(-)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 5f40df6..b2bdd55 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -20,6 +20,20 @@ static u64 last_timestamp;
static u64 nr_unordered;
extern const struct option record_options[];
+static void process_event(union perf_event *event __unused,
+ struct perf_sample *sample,
+ struct perf_session *session __unused,
+ struct thread *thread)
+{
+ /*
+ * FIXME: better resolve from pid from the struct trace_entry
+ * field, although it should be the same than this perf
+ * event pid
+ */
+ print_event(sample->cpu, sample->raw_data, sample->raw_size,
+ sample->time, thread->comm);
+}
+
static int default_start_script(const char *script __unused,
int argc __unused,
const char **argv __unused)
@@ -40,7 +54,7 @@ static int default_generate_script(const char *outfile __unused)
static struct scripting_ops default_scripting_ops = {
.start_script = default_start_script,
.stop_script = default_stop_script,
- .process_event = print_event,
+ .process_event = process_event,
.generate_script = default_generate_script,
};
@@ -86,14 +100,7 @@ static int process_sample_event(union perf_event *event,
last_timestamp = sample->time;
return 0;
}
- /*
- * FIXME: better resolve from pid from the struct trace_entry
- * field, although it should be the same than this perf
- * event pid
- */
- scripting_ops->process_event(sample->cpu, sample->raw_data,
- sample->raw_size,
- sample->time, thread->comm);
+ scripting_ops->process_event(event, sample, session, thread);
}
session->hists.stats.total_period += sample->period;
diff --git a/tools/perf/util/scripting-engines/trace-event-perl.c b/tools/perf/util/scripting-engines/trace-event-perl.c
index 9368081..6214272 100644
--- a/tools/perf/util/scripting-engines/trace-event-perl.c
+++ b/tools/perf/util/scripting-engines/trace-event-perl.c
@@ -245,9 +245,10 @@ static inline struct event *find_cache_event(int type)
return event;
}
-static void perl_process_event(int cpu, void *data,
- int size __unused,
- unsigned long long nsecs, char *comm)
+static void perl_process_event(union perf_event *pevent __unused,
+ struct perf_sample *sample,
+ struct perf_session *session __unused,
+ struct thread *thread)
{
struct format_field *field;
static char handler[256];
@@ -256,6 +257,10 @@ static void perl_process_event(int cpu, void *data,
struct event *event;
int type;
int pid;
+ int cpu = sample->cpu;
+ void *data = sample->raw_data;
+ unsigned long long nsecs = sample->time;
+ char *comm = thread->comm;
dSP;
diff --git a/tools/perf/util/scripting-engines/trace-event-python.c b/tools/perf/util/scripting-engines/trace-event-python.c
index 2040b85..1b85d60 100644
--- a/tools/perf/util/scripting-engines/trace-event-python.c
+++ b/tools/perf/util/scripting-engines/trace-event-python.c
@@ -204,9 +204,10 @@ static inline struct event *find_cache_event(int type)
return event;
}
-static void python_process_event(int cpu, void *data,
- int size __unused,
- unsigned long long nsecs, char *comm)
+static void python_process_event(union perf_event *pevent __unused,
+ struct perf_sample *sample,
+ struct perf_session *session __unused,
+ struct thread *thread)
{
PyObject *handler, *retval, *context, *t, *obj, *dict = NULL;
static char handler_name[256];
@@ -217,6 +218,10 @@ static void python_process_event(int cpu, void *data,
unsigned n = 0;
int type;
int pid;
+ int cpu = sample->cpu;
+ void *data = sample->raw_data;
+ unsigned long long nsecs = sample->time;
+ char *comm = thread->comm;
t = PyTuple_New(MAX_FIELDS);
if (!t)
diff --git a/tools/perf/util/trace-event-scripting.c b/tools/perf/util/trace-event-scripting.c
index f7af2fc..66f4b78 100644
--- a/tools/perf/util/trace-event-scripting.c
+++ b/tools/perf/util/trace-event-scripting.c
@@ -36,11 +36,10 @@ static int stop_script_unsupported(void)
return 0;
}
-static void process_event_unsupported(int cpu __unused,
- void *data __unused,
- int size __unused,
- unsigned long long nsecs __unused,
- char *comm __unused)
+static void process_event_unsupported(union perf_event *event __unused,
+ struct perf_sample *sample __unused,
+ struct perf_session *session __unused,
+ struct thread *thread __unused)
{
}
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index b5f12ca..5f7b513 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -3,6 +3,7 @@
#include <stdbool.h>
#include "parse-events.h"
+#include "session.h"
#define __unused __attribute__((unused))
@@ -278,8 +279,10 @@ struct scripting_ops {
const char *name;
int (*start_script) (const char *script, int argc, const char **argv);
int (*stop_script) (void);
- void (*process_event) (int cpu, void *data, int size,
- unsigned long long nsecs, char *comm);
+ void (*process_event) (union perf_event *event,
+ struct perf_sample *sample,
+ struct perf_session *session,
+ struct thread *thread);
int (*generate_script) (const char *outfile);
};
--
1.7.4
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.
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/builtin-script.c | 38 ++++++++++--
tools/perf/util/trace-event-parse.c | 106 +++--------------------------------
tools/perf/util/trace-event.h | 3 +-
3 files changed, 40 insertions(+), 107 deletions(-)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index b2bdd55..0a79da2 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -20,18 +20,42 @@ static u64 last_timestamp;
static u64 nr_unordered;
extern const struct option record_options[];
+static void print_sample_start(struct perf_sample *sample,
+ struct thread *thread)
+{
+ int type;
+ struct event *event;
+ const char *evname = NULL;
+ unsigned long secs;
+ unsigned long usecs;
+ unsigned long long nsecs = sample->time;
+
+ if (latency_format)
+ printf("%8.8s-%-5d %3d", thread->comm, sample->tid, sample->cpu);
+ else
+ printf("%16s-%-5d [%03d]", thread->comm, sample->tid, sample->cpu);
+
+ secs = nsecs / NSECS_PER_SEC;
+ nsecs -= secs * NSECS_PER_SEC;
+ usecs = nsecs / NSECS_PER_USEC;
+ printf(" %5lu.%06lu: ", secs, usecs);
+
+ type = trace_parse_common_type(sample->raw_data);
+ event = trace_find_event(type);
+ if (event)
+ evname = event->name;
+
+ printf("%s: ", evname ? evname : "(unknown)");
+}
+
static void process_event(union perf_event *event __unused,
struct perf_sample *sample,
struct perf_session *session __unused,
struct thread *thread)
{
- /*
- * FIXME: better resolve from pid from the struct trace_entry
- * field, although it should be the same than this perf
- * event pid
- */
- print_event(sample->cpu, sample->raw_data, sample->raw_size,
- sample->time, thread->comm);
+ print_sample_start(sample, thread);
+ print_trace_event(sample->cpu, sample->raw_data, sample->raw_size);
+ printf("\n");
}
static int default_start_script(const char *script __unused,
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index d8e622d..3717f06 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2648,63 +2648,8 @@ static void print_lat_fmt(void *data, int size __unused)
printf("%d", lock_depth);
}
-/* taken from Linux, written by Frederic Weisbecker */
-static void print_graph_cpu(int cpu)
-{
- int i;
- int log10_this = log10_cpu(cpu);
- int log10_all = log10_cpu(cpus);
-
-
- /*
- * Start with a space character - to make it stand out
- * to the right a bit when trace output is pasted into
- * email:
- */
- printf(" ");
-
- /*
- * Tricky - we space the CPU field according to the max
- * number of online CPUs. On a 2-cpu system it would take
- * a maximum of 1 digit - on a 128 cpu system it would
- * take up to 3 digits:
- */
- for (i = 0; i < log10_all - log10_this; i++)
- printf(" ");
-
- printf("%d) ", cpu);
-}
-
-#define TRACE_GRAPH_PROCINFO_LENGTH 14
#define TRACE_GRAPH_INDENT 2
-static void print_graph_proc(int pid, const char *comm)
-{
- /* sign + log10(MAX_INT) + '\0' */
- char pid_str[11];
- int spaces = 0;
- int len;
- int i;
-
- sprintf(pid_str, "%d", pid);
-
- /* 1 stands for the "-" character */
- len = strlen(comm) + strlen(pid_str) + 1;
-
- if (len < TRACE_GRAPH_PROCINFO_LENGTH)
- spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
-
- /* First spaces to align center */
- for (i = 0; i < spaces / 2; i++)
- printf(" ");
-
- printf("%s-%s", comm, pid_str);
-
- /* Last spaces to align center */
- for (i = 0; i < spaces - (spaces / 2); i++)
- printf(" ");
-}
-
static struct record *
get_return_for_leaf(int cpu, int cur_pid, unsigned long long cur_func,
struct record *next)
@@ -2876,21 +2821,13 @@ static void print_graph_nested(struct event *event, void *data)
static void
pretty_print_func_ent(void *data, int size, struct event *event,
- int cpu, int pid, const char *comm,
- unsigned long secs, unsigned long usecs)
+ int cpu, int pid)
{
struct format_field *field;
struct record *rec;
void *copy_data;
unsigned long val;
- printf("%5lu.%06lu | ", secs, usecs);
-
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2923,22 +2860,13 @@ out_free:
}
static void
-pretty_print_func_ret(void *data, int size __unused, struct event *event,
- int cpu, int pid, const char *comm,
- unsigned long secs, unsigned long usecs)
+pretty_print_func_ret(void *data, int size __unused, struct event *event)
{
unsigned long long rettime, calltime;
unsigned long long duration, depth;
struct format_field *field;
int i;
- printf("%5lu.%06lu | ", secs, usecs);
-
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2976,31 +2904,21 @@ pretty_print_func_ret(void *data, int size __unused, struct event *event,
static void
pretty_print_func_graph(void *data, int size, struct event *event,
- int cpu, int pid, const char *comm,
- unsigned long secs, unsigned long usecs)
+ int cpu, int pid)
{
if (event->flags & EVENT_FL_ISFUNCENT)
- pretty_print_func_ent(data, size, event,
- cpu, pid, comm, secs, usecs);
+ pretty_print_func_ent(data, size, event, cpu, pid);
else if (event->flags & EVENT_FL_ISFUNCRET)
- pretty_print_func_ret(data, size, event,
- cpu, pid, comm, secs, usecs);
+ pretty_print_func_ret(data, size, event);
printf("\n");
}
-void print_event(int cpu, void *data, int size, unsigned long long nsecs,
- char *comm)
+void print_trace_event(int cpu, void *data, int size)
{
struct event *event;
- unsigned long secs;
- unsigned long usecs;
int type;
int pid;
- secs = nsecs / NSECS_PER_SEC;
- nsecs -= secs * NSECS_PER_SEC;
- usecs = nsecs / NSECS_PER_USEC;
-
type = trace_parse_common_type(data);
event = trace_find_event(type);
@@ -3012,17 +2930,10 @@ void print_event(int cpu, void *data, int size, unsigned long long nsecs,
pid = trace_parse_common_pid(data);
if (event->flags & (EVENT_FL_ISFUNCENT | EVENT_FL_ISFUNCRET))
- return pretty_print_func_graph(data, size, event, cpu,
- pid, comm, secs, usecs);
+ return pretty_print_func_graph(data, size, event, cpu, pid);
- if (latency_format) {
- printf("%8.8s-%-5d %3d",
- comm, pid, cpu);
+ if (latency_format)
print_lat_fmt(data, size);
- } else
- printf("%16s-%-5d [%03d]", comm, pid, cpu);
-
- printf(" %5lu.%06lu: %s: ", secs, usecs, event->name);
if (event->flags & EVENT_FL_FAILED) {
printf("EVENT '%s' FAILED TO PARSE\n",
@@ -3031,7 +2942,6 @@ void print_event(int cpu, void *data, int size, unsigned long long nsecs,
}
pretty_print(data, size, event);
- printf("\n");
}
static void print_fields(struct print_flag_sym *field)
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 5f7b513..b04da57 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -177,8 +177,7 @@ void print_printk(void);
int parse_ftrace_file(char *buf, unsigned long size);
int parse_event_file(char *buf, unsigned long size, char *sys);
-void print_event(int cpu, void *data, int size, unsigned long long nsecs,
- char *comm);
+void print_trace_event(int cpu, void *data, int size);
extern int file_bigendian;
extern int host_bigendian;
--
1.7.4
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:
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 5 +-
tools/perf/builtin-script.c | 154 +++++++++++++++++++++++-------
tools/perf/util/parse-events.c | 22 ++++
tools/perf/util/parse-events.h | 1 +
4 files changed, 145 insertions(+), 37 deletions(-)
diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index c64118a..66f040b 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -115,7 +115,10 @@ OPTIONS
-f::
--fields
Comma separated list of fields to print. Options are:
- comm, tid, pid, time, cpu, event, trace, sym
+ comm, tid, pid, time, cpu, event, trace, sym. Field
+ list must be prepended with the type, trace, sw or hw,
+ to indicate to which event type the field list applies.
+ e.g., -f sw:comm,tid,time,sym and -f trace:time,cpu,trace
-k::
--vmlinux=<file>::
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index e2d79cb..3b1e3e3 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -12,6 +12,8 @@
#include "util/trace-event.h"
#include "util/parse-options.h"
#include "util/util.h"
+#include "util/evlist.h"
+#include "util/evsel.h"
static char const *script_name;
static char const *generate_script_lang;
@@ -47,16 +49,61 @@ struct output_option {
};
/* default set to maintain compatibility with current format */
-static u64 output_fields = PERF_OUTPUT_COMM | PERF_OUTPUT_TID | \
- PERF_OUTPUT_CPU | PERF_OUTPUT_TIME | \
- PERF_OUTPUT_EVNAME | PERF_OUTPUT_TRACE;
+static u64 output_fields[PERF_TYPE_MAX] = {
+ [PERF_TYPE_HARDWARE] = PERF_OUTPUT_COMM | PERF_OUTPUT_TID | \
+ PERF_OUTPUT_CPU | PERF_OUTPUT_TIME | \
+ PERF_OUTPUT_EVNAME | PERF_OUTPUT_SYM,
+
+ [PERF_TYPE_SOFTWARE] = PERF_OUTPUT_COMM | PERF_OUTPUT_TID | \
+ PERF_OUTPUT_CPU | PERF_OUTPUT_TIME | \
+ PERF_OUTPUT_EVNAME | PERF_OUTPUT_SYM,
+
+ [PERF_TYPE_TRACEPOINT] = PERF_OUTPUT_COMM | PERF_OUTPUT_TID | \
+ PERF_OUTPUT_CPU | PERF_OUTPUT_TIME | \
+ PERF_OUTPUT_EVNAME | PERF_OUTPUT_TRACE,
+};
static bool output_set_by_user;
-#define PRINT_FIELD(x) (output_fields & PERF_OUTPUT_##x)
+#define PRINT_FIELD(x) (output_fields[attr->type] & PERF_OUTPUT_##x)
+
+static int perf_session__check_attr(struct perf_session *session,
+ struct perf_event_attr *attr)
+{
+ if (PRINT_FIELD(TRACE) &&
+ !perf_session__has_traces(session, "record -R"))
+ return -EINVAL;
+
+ if (PRINT_FIELD(SYM) &&
+ !(session->sample_type & PERF_SAMPLE_IP)) {
+ pr_err("Samples do not contain IP data.\n");
+ return -EINVAL;
+ }
+
+ if ((PRINT_FIELD(PID) || PRINT_FIELD(TID)) &&
+ !(session->sample_type & PERF_SAMPLE_TID)) {
+ pr_err("Samples do not contain TID/PID data.\n");
+ return -EINVAL;
+ }
+
+ if (PRINT_FIELD(TIME) &&
+ !(session->sample_type & PERF_SAMPLE_TIME)) {
+ pr_err("Samples do not contain timestamps.\n");
+ return -EINVAL;
+ }
+
+ if (PRINT_FIELD(CPU) &&
+ !(session->sample_type & PERF_SAMPLE_CPU)) {
+ pr_err("Samples do not contain cpu.\n");
+ return -EINVAL;
+ }
+
+ return 0;
+}
static void print_sample_start(struct perf_sample *sample,
- struct thread *thread)
+ struct thread *thread,
+ struct perf_event_attr *attr)
{
int type;
struct event *event;
@@ -95,23 +142,43 @@ static void print_sample_start(struct perf_sample *sample,
usecs = nsecs / NSECS_PER_USEC;
printf("%5lu.%06lu: ", secs, usecs);
}
-
+
if (PRINT_FIELD(EVNAME)) {
- type = trace_parse_common_type(sample->raw_data);
- event = trace_find_event(type);
- if (event)
- evname = event->name;
-
+ if (attr->type == PERF_TYPE_TRACEPOINT) {
+ type = trace_parse_common_type(sample->raw_data);
+ event = trace_find_event(type);
+ if (event)
+ evname = event->name;
+ } else
+ evname = __event_name(attr->type, attr->config);
+
printf("%s: ", evname ? evname : "(unknown)");
}
}
static void process_event(union perf_event *event __unused,
struct perf_sample *sample,
- struct perf_session *session __unused,
+ struct perf_session *session,
struct thread *thread)
{
- print_sample_start(sample, thread);
+ struct perf_event_attr *attr;
+ struct perf_evsel *evsel;
+
+ evsel = perf_evlist__id2evsel(session->evlist, sample->id);
+ if (evsel == NULL) {
+ pr_err("Invalid data. Contains samples with id not in "
+ "its header!\n");
+ return;
+ }
+ attr = &evsel->attr;
+
+ if (output_fields[attr->type] == 0)
+ return;
+
+ if (perf_session__check_attr(session, attr) < 0)
+ return;
+
+ print_sample_start(sample, thread, attr);
if (PRINT_FIELD(TRACE))
print_trace_event(sample->cpu, sample->raw_data,
@@ -183,19 +250,17 @@ static int process_sample_event(union perf_event *event,
return -1;
}
- if (session->sample_type & PERF_SAMPLE_RAW) {
- if (debug_mode) {
- if (sample->time < last_timestamp) {
- pr_err("Samples misordered, previous: %" PRIu64
- " this: %" PRIu64 "\n", last_timestamp,
- sample->time);
- nr_unordered++;
- }
- last_timestamp = sample->time;
- return 0;
+ if (debug_mode) {
+ if (sample->time < last_timestamp) {
+ pr_err("Samples misordered, previous: %" PRIu64
+ " this: %" PRIu64 "\n", last_timestamp,
+ sample->time);
+ nr_unordered++;
}
- scripting_ops->process_event(event, sample, session, thread);
+ last_timestamp = sample->time;
+ return 0;
}
+ scripting_ops->process_event(event, sample, session, thread);
session->hists.stats.total_period += sample->period;
return 0;
@@ -391,21 +456,40 @@ static int parse_output_fields(const struct option *opt __used,
int i, imax = sizeof(all_output_options) / sizeof(struct output_option);
int rc = 0;
char *str = strdup(arg);
+ int type = -1;
if (!str)
return -ENOMEM;
- tok = strtok(str, ",");
+ tok = strtok(str, ":");
if (!tok) {
- fprintf(stderr, "Invalid field string.");
+ fprintf(stderr,
+ "Invalid field string - not prepended with type.");
+ return -EINVAL;
+ }
+
+ /* first word should state which event type user
+ * is specifying the fields
+ */
+ if (!strcmp(tok, "hw"))
+ type = PERF_TYPE_HARDWARE;
+ else if (!strcmp(tok, "sw"))
+ type = PERF_TYPE_SOFTWARE;
+ else if (!strcmp(tok, "trace"))
+ type = PERF_TYPE_TRACEPOINT;
+ else {
+ fprintf(stderr, "Invalid event type in field string.");
return -EINVAL;
}
- output_fields = 0;
+ output_fields[type] = 0;
while (1) {
+ tok = strtok(NULL, ",");
+ if (!tok)
+ break;
for (i = 0; i < imax; ++i) {
if (strcmp(tok, all_output_options[i].str) == 0) {
- output_fields |= all_output_options[i].field;
+ output_fields[type] |= all_output_options[i].field;
break;
}
}
@@ -415,9 +499,11 @@ static int parse_output_fields(const struct option *opt __used,
break;
}
- tok = strtok(NULL, ",");
- if (!tok)
- break;
+ }
+
+ if (output_fields[type] == 0) {
+ pr_debug("No fields requested for %s type. "
+ "Events will not be displayed\n", event_type(type));
}
output_set_by_user = true;
@@ -747,7 +833,7 @@ static const struct option options[] = {
OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
"Look for files with symbols relative to this directory"),
OPT_CALLBACK('f', "fields", NULL, "str",
- "comma separated output fields. Options: comm,tid,pid,time,cpu,event,trace,sym",
+ "comma separated output fields prepend with 'type:'. Valid types: hw,sw,trace. Fields: comm,tid,pid,time,cpu,event,trace,sym",
parse_output_fields),
OPT_END()
@@ -931,10 +1017,6 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (session == NULL)
return -ENOMEM;
- if (strcmp(input_name, "-") &&
- !perf_session__has_traces(session, "record -R"))
- return -EINVAL;
-
if (generate_script_lang) {
struct stat perf_stat;
int input;
diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c
index 54a7e26..952b4ae 100644
--- a/tools/perf/util/parse-events.c
+++ b/tools/perf/util/parse-events.c
@@ -263,6 +263,28 @@ static char *event_cache_name(u8 cache_type, u8 cache_op, u8 cache_result)
return name;
}
+const char *event_type(int type)
+{
+ switch (type) {
+ case PERF_TYPE_HARDWARE:
+ return "hardware";
+
+ case PERF_TYPE_SOFTWARE:
+ return "software";
+
+ case PERF_TYPE_TRACEPOINT:
+ return "tracepoint";
+
+ case PERF_TYPE_HW_CACHE:
+ return "hardware-cache";
+
+ default:
+ break;
+ }
+
+ return "unknown";
+}
+
const char *event_name(struct perf_evsel *evsel)
{
u64 config = evsel->attr.config;
diff --git a/tools/perf/util/parse-events.h b/tools/perf/util/parse-events.h
index 212f88e..746d3fc 100644
--- a/tools/perf/util/parse-events.h
+++ b/tools/perf/util/parse-events.h
@@ -20,6 +20,7 @@ struct tracepoint_path {
extern struct tracepoint_path *tracepoint_id_to_path(u64 config);
extern bool have_tracepoints(struct list_head *evlist);
+const char *event_type(int type);
const char *event_name(struct perf_evsel *event);
extern const char *__event_name(int type, u64 config);
--
1.7.4
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)
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 16 +++++++-
tools/perf/builtin-script.c | 28 +++++++++++++-
tools/perf/util/session.c | 61 ++++++++++++++++++++++++++++++
tools/perf/util/session.h | 4 ++
4 files changed, 107 insertions(+), 2 deletions(-)
diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index b73cf58..c64118a 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -115,7 +115,21 @@ OPTIONS
-f::
--fields
Comma separated list of fields to print. Options are:
- comm, tid, pid, time, cpu, event, trace
+ comm, tid, pid, time, cpu, event, trace, sym
+
+-k::
+--vmlinux=<file>::
+ vmlinux pathname
+
+--kallsyms=<file>::
+ kallsyms pathname
+
+--symfs=<directory>::
+ Look for files with symbols relative to this directory.
+
+-G::
+--hide-call-graph::
+ When printing symbols do not display call chain.
SEE ALSO
--------
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index e541059..e2d79cb 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -19,6 +19,7 @@ static bool debug_mode;
static u64 last_timestamp;
static u64 nr_unordered;
extern const struct option record_options[];
+static bool no_callchain;
enum perf_output_field {
PERF_OUTPUT_COMM = 1U << 0,
@@ -28,6 +29,7 @@ enum perf_output_field {
PERF_OUTPUT_CPU = 1U << 4,
PERF_OUTPUT_EVNAME = 1U << 5,
PERF_OUTPUT_TRACE = 1U << 6,
+ PERF_OUTPUT_SYM = 1U << 7,
};
struct output_option {
@@ -41,6 +43,7 @@ struct output_option {
{.str = "cpu", .field = PERF_OUTPUT_CPU},
{.str = "event", .field = PERF_OUTPUT_EVNAME},
{.str = "trace", .field = PERF_OUTPUT_TRACE},
+ {.str = "sym", .field = PERF_OUTPUT_SYM},
};
/* default set to maintain compatibility with current format */
@@ -65,6 +68,8 @@ static void print_sample_start(struct perf_sample *sample,
if (PRINT_FIELD(COMM)) {
if (latency_format)
printf("%8.8s ", thread->comm);
+ else if (PRINT_FIELD(SYM) && !no_callchain)
+ printf("%s ", thread->comm);
else
printf("%16s ", thread->comm);
}
@@ -112,6 +117,14 @@ static void process_event(union perf_event *event __unused,
print_trace_event(sample->cpu, sample->raw_data,
sample->raw_size);
+ if (PRINT_FIELD(SYM)) {
+ if (no_callchain)
+ printf(" ");
+ else
+ printf("\n");
+ perf_session__print_symbols(event, sample, session);
+ }
+
printf("\n");
}
@@ -190,7 +203,10 @@ static int process_sample_event(union perf_event *event,
static struct perf_event_ops event_ops = {
.sample = process_sample_event,
+ .mmap = perf_event__process_mmap,
.comm = perf_event__process_comm,
+ .exit = perf_event__process_task,
+ .fork = perf_event__process_task,
.attr = perf_event__process_attr,
.event_type = perf_event__process_event_type,
.tracing_data = perf_event__process_tracing_data,
@@ -722,8 +738,16 @@ static const struct option options[] = {
"input file name"),
OPT_BOOLEAN('d', "debug-mode", &debug_mode,
"do various checks like samples ordering and lost events"),
+ OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name,
+ "file", "vmlinux pathname"),
+ OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name,
+ "file", "kallsyms pathname"),
+ OPT_BOOLEAN('G', "hide-call-graph", &no_callchain,
+ "When printing symbols do not display call chain"),
+ OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
+ "Look for files with symbols relative to this directory"),
OPT_CALLBACK('f', "fields", NULL, "str",
- "comma separated output fields. Options: comm,tid,pid,time,cpu,event,trace",
+ "comma separated output fields. Options: comm,tid,pid,time,cpu,event,trace,sym",
parse_output_fields),
OPT_END()
@@ -868,6 +892,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
exit(-1);
}
+ symbol_conf.use_callchain = no_callchain ? false : true;
+
if (rec_script_path)
script_path = rec_script_path;
if (rep_script_path)
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 0d41419..274ab16 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1198,3 +1198,64 @@ size_t perf_session__fprintf_nr_events(struct perf_session *session, FILE *fp)
return ret;
}
+
+void perf_session__print_symbols(union perf_event *event,
+ struct perf_sample *sample,
+ struct perf_session *session)
+{
+ struct addr_location al;
+ const char *symname, *dsoname;
+ struct callchain_cursor *cursor = &session->callchain_cursor;
+ struct callchain_cursor_node *node;
+
+ if (perf_event__preprocess_sample(event, session, &al, sample,
+ NULL) < 0) {
+ error("problem processing %d event, skipping it.\n",
+ event->header.type);
+ return;
+ }
+
+ if (symbol_conf.use_callchain && sample->callchain) {
+
+ if (perf_session__resolve_callchain(session, al.thread,
+ sample->callchain, NULL) != 0) {
+ if (verbose)
+ error("Failed to resolve callchain. Skipping\n");
+ return;
+ }
+ callchain_cursor_commit(cursor);
+
+ while (1) {
+ node = callchain_cursor_current(cursor);
+ if (!node)
+ break;
+
+ if (node->sym && node->sym->name)
+ symname = node->sym->name;
+ else
+ symname = "";
+
+ if (node->map && node->map->dso && node->map->dso->name)
+ dsoname = node->map->dso->name;
+ else
+ dsoname = "";
+
+ printf("\t%16" PRIx64 " %s (%s)\n", node->ip, symname, dsoname);
+
+ callchain_cursor_advance(cursor);
+ }
+
+ } else {
+ if (al.sym && al.sym->name)
+ symname = al.sym->name;
+ else
+ symname = "";
+
+ if (al.map && al.map->dso && al.map->dso->name)
+ dsoname = al.map->dso->name;
+ else
+ dsoname = "";
+
+ printf("%16" PRIx64 " %s (%s)", al.addr, symname, dsoname);
+ }
+}
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index 05dd7bc..64369d3 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -161,4 +161,8 @@ static inline int perf_session__parse_sample(struct perf_session *session,
session->sample_id_all, sample);
}
+void perf_session__print_symbols(union perf_event *event,
+ struct perf_sample *sample,
+ struct perf_session *session);
+
#endif /* __PERF_SESSION_H */
--
1.7.4
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 ...
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 5 +
tools/perf/builtin-script.c | 147 ++++++++++++++++++++++++++----
2 files changed, 133 insertions(+), 19 deletions(-)
diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index 29ad942..b73cf58 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -112,6 +112,11 @@ OPTIONS
--debug-mode::
Do various checks like samples ordering and lost events.
+-f::
+--fields
+ Comma separated list of fields to print. Options are:
+ comm, tid, pid, time, cpu, event, trace
+
SEE ALSO
--------
linkperf:perf-record[1], linkperf:perf-script-perl[1],
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 0a79da2..e541059 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -20,6 +20,38 @@ static u64 last_timestamp;
static u64 nr_unordered;
extern const struct option record_options[];
+enum perf_output_field {
+ PERF_OUTPUT_COMM = 1U << 0,
+ PERF_OUTPUT_TID = 1U << 1,
+ PERF_OUTPUT_PID = 1U << 2,
+ PERF_OUTPUT_TIME = 1U << 3,
+ PERF_OUTPUT_CPU = 1U << 4,
+ PERF_OUTPUT_EVNAME = 1U << 5,
+ PERF_OUTPUT_TRACE = 1U << 6,
+};
+
+struct output_option {
+ const char *str;
+ enum perf_output_field field;
+} all_output_options [] = {
+ {.str = "comm", .field = PERF_OUTPUT_COMM},
+ {.str = "tid", .field = PERF_OUTPUT_TID},
+ {.str = "pid", .field = PERF_OUTPUT_PID},
+ {.str = "time", .field = PERF_OUTPUT_TIME},
+ {.str = "cpu", .field = PERF_OUTPUT_CPU},
+ {.str = "event", .field = PERF_OUTPUT_EVNAME},
+ {.str = "trace", .field = PERF_OUTPUT_TRACE},
+};
+
+/* default set to maintain compatibility with current format */
+static u64 output_fields = PERF_OUTPUT_COMM | PERF_OUTPUT_TID | \
+ PERF_OUTPUT_CPU | PERF_OUTPUT_TIME | \
+ PERF_OUTPUT_EVNAME | PERF_OUTPUT_TRACE;
+
+static bool output_set_by_user;
+
+#define PRINT_FIELD(x) (output_fields & PERF_OUTPUT_##x)
+
static void print_sample_start(struct perf_sample *sample,
struct thread *thread)
{
@@ -28,24 +60,45 @@ static void print_sample_start(struct perf_sample *sample,
const char *evname = NULL;
unsigned long secs;
unsigned long usecs;
- unsigned long long nsecs = sample->time;
-
- if (latency_format)
- printf("%8.8s-%-5d %3d", thread->comm, sample->tid, sample->cpu);
- else
- printf("%16s-%-5d [%03d]", thread->comm, sample->tid, sample->cpu);
-
- secs = nsecs / NSECS_PER_SEC;
- nsecs -= secs * NSECS_PER_SEC;
- usecs = nsecs / NSECS_PER_USEC;
- printf(" %5lu.%06lu: ", secs, usecs);
+ unsigned long long nsecs;
- type = trace_parse_common_type(sample->raw_data);
- event = trace_find_event(type);
- if (event)
- evname = event->name;
-
- printf("%s: ", evname ? evname : "(unknown)");
+ if (PRINT_FIELD(COMM)) {
+ if (latency_format)
+ printf("%8.8s ", thread->comm);
+ else
+ printf("%16s ", thread->comm);
+ }
+
+ if (PRINT_FIELD(PID) && PRINT_FIELD(TID))
+ printf("%5d/%-5d ", sample->pid, sample->tid);
+ else if (PRINT_FIELD(PID))
+ printf("%5d ", sample->pid);
+ else if (PRINT_FIELD(TID))
+ printf("%5d ", sample->tid);
+
+ if (PRINT_FIELD(CPU)) {
+ if (latency_format)
+ printf("%3d ", sample->cpu);
+ else
+ printf("[%03d] ", sample->cpu);
+ }
+
+ if (PRINT_FIELD(TIME)) {
+ nsecs = sample->time;
+ secs = nsecs / NSECS_PER_SEC;
+ nsecs -= secs * NSECS_PER_SEC;
+ usecs = nsecs / NSECS_PER_USEC;
+ printf("%5lu.%06lu: ", secs, usecs);
+ }
+
+ if (PRINT_FIELD(EVNAME)) {
+ type = trace_parse_common_type(sample->raw_data);
+ event = trace_find_event(type);
+ if (event)
+ evname = event->name;
+
+ printf("%s: ", evname ? evname : "(unknown)");
+ }
}
static void process_event(union perf_event *event __unused,
@@ -54,7 +107,11 @@ static void process_event(union perf_event *event __unused,
struct thread *thread)
{
print_sample_start(sample, thread);
- print_trace_event(sample->cpu, sample->raw_data, sample->raw_size);
+
+ if (PRINT_FIELD(TRACE))
+ print_trace_event(sample->cpu, sample->raw_data,
+ sample->raw_size);
+
printf("\n");
}
@@ -311,6 +368,48 @@ static int parse_scriptname(const struct option *opt __used,
return 0;
}
+static int parse_output_fields(const struct option *opt __used,
+ const char *arg, int unset __used)
+{
+ char *tok;
+ int i, imax = sizeof(all_output_options) / sizeof(struct output_option);
+ int rc = 0;
+ char *str = strdup(arg);
+
+ if (!str)
+ return -ENOMEM;
+
+ tok = strtok(str, ",");
+ if (!tok) {
+ fprintf(stderr, "Invalid field string.");
+ return -EINVAL;
+ }
+
+ output_fields = 0;
+ while (1) {
+ for (i = 0; i < imax; ++i) {
+ if (strcmp(tok, all_output_options[i].str) == 0) {
+ output_fields |= all_output_options[i].field;
+ break;
+ }
+ }
+ if (i == imax) {
+ fprintf(stderr, "Invalid field requested.");
+ rc = -EINVAL;
+ break;
+ }
+
+ tok = strtok(NULL, ",");
+ if (!tok)
+ break;
+ }
+
+ output_set_by_user = true;
+
+ free(str);
+ return rc;
+}
+
/* Helper function for filesystems that return a dent->d_type DT_UNKNOWN */
static int is_directory(const char *base_path, const struct dirent *dent)
{
@@ -623,6 +722,9 @@ static const struct option options[] = {
"input file name"),
OPT_BOOLEAN('d', "debug-mode", &debug_mode,
"do various checks like samples ordering and lost events"),
+ OPT_CALLBACK('f', "fields", NULL, "str",
+ "comma separated output fields. Options: comm,tid,pid,time,cpu,event,trace",
+ parse_output_fields),
OPT_END()
};
@@ -809,8 +911,15 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (generate_script_lang) {
struct stat perf_stat;
+ int input;
+
+ if (output_set_by_user) {
+ fprintf(stderr,
+ "custom fields not supported for generated scripts");
+ return -1;
+ }
- int input = open(input_name, O_RDONLY);
+ input = open(input_name, O_RDONLY);
if (input < 0) {
perror("failed to open file");
exit(-1);
--
1.7.4