v3 -> v4:
- moved code removal to separate patch
- added check that callchain exists before trying to use it
- cleaned up whitespace errors so acme does not have to
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 (6):
perf script: change process_event prototype
perf: remove print_graph_cpu and print_graph_proc from
trace-event-parse
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 | 300 ++++++++++++++++++--
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 | 110 +-------
tools/perf/util/trace-event-scripting.c | 9 +-
tools/perf/util/trace-event.h | 10 +-
11 files changed, 423 insertions(+), 138 deletions(-)
--
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 | 157 +++++++++++++++++++++++-------
tools/perf/util/parse-events.c | 22 ++++
tools/perf/util/parse-events.h | 1 +
4 files changed, 148 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 b45b09c..3de2f13 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,65 @@ 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)) {
+ if (!(session->sample_type & PERF_SAMPLE_IP)) {
+ pr_err("Samples do not contain IP data.\n");
+ return -EINVAL;
+ }
+ if (!no_callchain &&
+ !(session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ symbol_conf.use_callchain = false;
+ }
+
+ 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;
@@ -96,11 +147,14 @@ static void print_sample_start(struct perf_sample *sample,
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 (PRINT_FIELD(EVNAME)) {
+ 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)");
}
@@ -108,10 +162,27 @@ static void print_sample_start(struct perf_sample *sample,
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 +254,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 +460,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;
}
}
@@ -414,10 +502,11 @@ static int parse_output_fields(const struct option *opt __used,
rc = -EINVAL;
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 +836,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()
@@ -929,15 +1018,11 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (session == NULL)
return -ENOMEM;
- if (!no_callchain && (session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ if (!no_callchain)
symbol_conf.use_callchain = true;
else
symbol_conf.use_callchain = false;
- 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
Next patch moves printing of 'common' data into perf-script which
removes the need for these functions.
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/util/trace-event-parse.c | 65 +---------------------------------
1 files changed, 2 insertions(+), 63 deletions(-)
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index d8e622d..dd5f058 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,7 +2821,7 @@ 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,
+ int cpu, int pid, const char *comm __unused,
unsigned long secs, unsigned long usecs)
{
struct format_field *field;
@@ -2886,9 +2831,6 @@ pretty_print_func_ent(void *data, int size, struct event *event,
printf("%5lu.%06lu | ", secs, usecs);
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
printf(" | ");
if (latency_format) {
@@ -2924,7 +2866,7 @@ out_free:
static void
pretty_print_func_ret(void *data, int size __unused, struct event *event,
- int cpu, int pid, const char *comm,
+ int cpu __unused, int pid __unused, const char *comm __unused,
unsigned long secs, unsigned long usecs)
{
unsigned long long rettime, calltime;
@@ -2934,9 +2876,6 @@ pretty_print_func_ret(void *data, int size __unused, struct event *event,
printf("%5lu.%06lu | ", secs, usecs);
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
printf(" | ");
if (latency_format) {
--
1.7.4
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)
Signed-off-by: David Ahern <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 16 +++++++-
tools/perf/builtin-script.c | 31 +++++++++++++++-
tools/perf/util/session.c | 61 ++++++++++++++++++++++++++++++
tools/perf/util/session.h | 4 ++
4 files changed, 110 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 c046e6e..b45b09c 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) && symbol_conf.use_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 (!symbol_conf.use_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()
@@ -905,6 +929,11 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (session == NULL)
return -ENOMEM;
+ if (!no_callchain && (session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ symbol_conf.use_callchain = true;
+ else
+ symbol_conf.use_callchain = false;
+
if (strcmp(input_name, "-") &&
!perf_session__has_traces(session, "record -R"))
return -EINVAL;
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 | 141 ++++++++++++++++++++++++++----
2 files changed, 130 insertions(+), 16 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..c046e6e 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;
+ unsigned long long nsecs;
+
+ if (PRINT_FIELD(COMM)) {
+ if (latency_format)
+ printf("%8.8s ", thread->comm);
+ else
+ printf("%16s ", thread->comm);
+ }
- 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);
+ 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);
+ }
- secs = nsecs / NSECS_PER_SEC;
- nsecs -= secs * NSECS_PER_SEC;
- usecs = nsecs / NSECS_PER_USEC;
- printf(" %5lu.%06lu: ", secs, usecs);
+ 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);
+ }
- type = trace_parse_common_type(sample->raw_data);
- event = trace_find_event(type);
- if (event)
- evname = event->name;
+ 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)");
+ 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
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 | 49 +++++++---------------------------
tools/perf/util/trace-event.h | 3 +-
3 files changed, 42 insertions(+), 48 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 dd5f058..0a7ed5b 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2643,9 +2643,9 @@ static void print_lat_fmt(void *data, int size __unused)
printf(".");
if (lock_depth < 0)
- printf(".");
+ printf(". ");
else
- printf("%d", lock_depth);
+ printf("%d ", lock_depth);
}
#define TRACE_GRAPH_INDENT 2
@@ -2821,18 +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 __unused,
- 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);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2865,19 +2860,13 @@ out_free:
}
static void
-pretty_print_func_ret(void *data, int size __unused, struct event *event,
- int cpu __unused, int pid __unused, const char *comm __unused,
- 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);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2915,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);
@@ -2951,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",
@@ -2970,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
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
On Wed, Mar 09, 2011 at 10:23:25PM -0700, David Ahern wrote:
> 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 | 49 +++++++---------------------------
I was hoping after the next merge window to start making a common library
for parsing events. This way things like powertop and timechart or
anything that uses the perf interface does not need to write its own
parsing of events, or expect the event formats to be hardcoded.
The trace-event-parse.c was taking from trace-cmd's parse-events.c code
and hopefully the two can merge again. The parse-events.c code in
trace-cmd has gone through several iterations that has made it much more
robust and flexible. I purposely kept it as a separate libarary not
dependent on trace-cmd so that it could be used by other utilities like
perf.
> tools/perf/util/trace-event.h | 3 +-
> 3 files changed, 42 insertions(+), 48 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 dd5f058..0a7ed5b 100644
> --- a/tools/perf/util/trace-event-parse.c
> +++ b/tools/perf/util/trace-event-parse.c
> @@ -2643,9 +2643,9 @@ static void print_lat_fmt(void *data, int size __unused)
> printf(".");
>
> if (lock_depth < 0)
> - printf(".");
> + printf(". ");
> else
> - printf("%d", lock_depth);
> + printf("%d ", lock_depth);
For example, I'm removing the field lock_depth, as that was added by
Frederic as a temporary field to help with the removal of the BKL.
Currently this code is unused by perf, but if it is in the future, it
must be able to handle not having this field. In fact, I'm thinking of
modifying other "common" fields to help improve tracing performance.
If we could have a common library for all tools that need to parse
events, then this code can be updated in a single place. Which also
brings another point. Do we want to move the events out of debugfs. And
if we do, I would love to change the way the event format is. I consider
the format in debugfs as it stands a true ABI, but the content that the
format shows is not.
-- Steve
Em Thu, Mar 10, 2011 at 10:20:53AM -0500, Steven Rostedt escreveu:
> On Wed, Mar 09, 2011 at 10:23:25PM -0700, David Ahern wrote:
> > 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 | 49 +++++++---------------------------
> I was hoping after the next merge window to start making a common library
> for parsing events. This way things like powertop and timechart or
> anything that uses the perf interface does not need to write its own
> parsing of events, or expect the event formats to be hardcoded.
>
> The trace-event-parse.c was taking from trace-cmd's parse-events.c code
> and hopefully the two can merge again. The parse-events.c code in
> trace-cmd has gone through several iterations that has made it much more
> robust and flexible. I purposely kept it as a separate libarary not
> dependent on trace-cmd so that it could be used by other utilities like
> perf.
David is kinda new to this perf/ftrace/trace-cmd/etc soap opera, and he
has been patient to go thru the motions with Peter, Thomas, Fr?d?ric and
me, going from doing what he wants in 'perf report' to 'perf script',
etc.
We're almost to the point where his feature is implemented in a
way Fr?d?ric, the one most actively reviewing his work, is satisfied,
right Fr?d?ric?
I think the merge with the libraries you mention is something that is
not a precondition to merging David's work.
And his work is at least moving things in the trace parts of tools/,
that was so far dormant.
- Arnaldo
On Thu, 2011-03-10 at 12:51 -0300, Arnaldo Carvalho de Melo wrote:
> Em Thu, Mar 10, 2011 at 10:20:53AM -0500, Steven Rostedt escreveu:
> > On Wed, Mar 09, 2011 at 10:23:25PM -0700, David Ahern wrote:
> > > 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 | 49 +++++++---------------------------
>
> > I was hoping after the next merge window to start making a common library
> > for parsing events. This way things like powertop and timechart or
> > anything that uses the perf interface does not need to write its own
> > parsing of events, or expect the event formats to be hardcoded.
> >
> > The trace-event-parse.c was taking from trace-cmd's parse-events.c code
> > and hopefully the two can merge again. The parse-events.c code in
> > trace-cmd has gone through several iterations that has made it much more
> > robust and flexible. I purposely kept it as a separate libarary not
> > dependent on trace-cmd so that it could be used by other utilities like
> > perf.
>
> David is kinda new to this perf/ftrace/trace-cmd/etc soap opera, and he
Lucky him ;)
> has been patient to go thru the motions with Peter, Thomas, Fr?d?ric and
> me, going from doing what he wants in 'perf report' to 'perf script',
> etc.
>
> We're almost to the point where his feature is implemented in a
> way Fr?d?ric, the one most actively reviewing his work, is satisfied,
> right Fr?d?ric?
You must have one of those keyboards where it is easy to make that ?
>
> I think the merge with the libraries you mention is something that is
> not a precondition to merging David's work.
>
> And his work is at least moving things in the trace parts of tools/,
> that was so far dormant.
Note, I'm not saying that his work should be put on hold. I actually
want to start it up again. Maybe I worded this response wrong. It was
more about bringing David up to speed on what I want to do next than
saying not to do this work.
Thanks,
-- Steve
Em Thu, Mar 10, 2011 at 11:05:35AM -0500, Steven Rostedt escreveu:
> On Thu, 2011-03-10 at 12:51 -0300, Arnaldo Carvalho de Melo wrote:
> > David is kinda new to this perf/ftrace/trace-cmd/etc soap opera, and he
> Lucky him ;)
:-)
> > has been patient to go thru the motions with Peter, Thomas, Fr?d?ric and
> > me, going from doing what he wants in 'perf report' to 'perf script',
> > etc.
> >
> > We're almost to the point where his feature is implemented in a
> > way Fr?d?ric, the one most actively reviewing his work, is satisfied,
> > right Fr?d?ric?
>
> You must have one of those keyboards where it is easy to make that ?
gnome makes this all mostly easy, and my native language, as Fr?d?ric's,
have those pesky characters :)
> > I think the merge with the libraries you mention is something that is
> > not a precondition to merging David's work.
> >
> > And his work is at least moving things in the trace parts of tools/,
> > that was so far dormant.
>
> Note, I'm not saying that his work should be put on hold. I actually
> want to start it up again. Maybe I worded this response wrong. It was
> more about bringing David up to speed on what I want to do next than
> saying not to do this work.
Right, I just wanted to make sure he doesn't spill his coffee with what
could seem like yet another requirement to work on infrastructure to get
his legitimate feature implementation merged :-)
- Arnaldo
On 03/10/11 09:20, Arnaldo Carvalho de Melo wrote:
>>> I think the merge with the libraries you mention is something that is
>>> not a precondition to merging David's work.
>>>
>>> And his work is at least moving things in the trace parts of tools/,
>>> that was so far dormant.
>>
>> Note, I'm not saying that his work should be put on hold. I actually
>> want to start it up again. Maybe I worded this response wrong. It was
>> more about bringing David up to speed on what I want to do next than
>> saying not to do this work.
>
> Right, I just wanted to make sure he doesn't spill his coffee with what
> could seem like yet another requirement to work on infrastructure to get
> his legitimate feature implementation merged :-)
I appreciate the clarification. Luckily, no coffee in hand.
I need to get the time-of-day strings done next, and someone else is
pushing the reverse callchain display (another local change I wanted to
get upstream). I could take a look at other requests - like common code
- as time allows.
David
>
> - Arnaldo
On Thu, 2011-03-10 at 09:45 -0700, David Ahern wrote:
>
> On 03/10/11 09:20, Arnaldo Carvalho de Melo wrote:
> >>> I think the merge with the libraries you mention is something that is
> >>> not a precondition to merging David's work.
> >>>
> >>> And his work is at least moving things in the trace parts of tools/,
> >>> that was so far dormant.
> >>
> >> Note, I'm not saying that his work should be put on hold. I actually
> >> want to start it up again. Maybe I worded this response wrong. It was
> >> more about bringing David up to speed on what I want to do next than
> >> saying not to do this work.
> >
> > Right, I just wanted to make sure he doesn't spill his coffee with what
> > could seem like yet another requirement to work on infrastructure to get
> > his legitimate feature implementation merged :-)
>
> I appreciate the clarification. Luckily, no coffee in hand.
>
> I need to get the time-of-day strings done next, and someone else is
> pushing the reverse callchain display (another local change I wanted to
> get upstream). I could take a look at other requests - like common code
> - as time allows.
Right, we could start looking at making the common code on top of your
changes. I don't want to hinder progress for asking for too much.
Thanks,
-- Steve
On Thu, Mar 10, 2011 at 12:51:09PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Thu, Mar 10, 2011 at 10:20:53AM -0500, Steven Rostedt escreveu:
> > On Wed, Mar 09, 2011 at 10:23:25PM -0700, David Ahern wrote:
> > > 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 | 49 +++++++---------------------------
>
> > I was hoping after the next merge window to start making a common library
> > for parsing events. This way things like powertop and timechart or
> > anything that uses the perf interface does not need to write its own
> > parsing of events, or expect the event formats to be hardcoded.
> >
> > The trace-event-parse.c was taking from trace-cmd's parse-events.c code
> > and hopefully the two can merge again. The parse-events.c code in
> > trace-cmd has gone through several iterations that has made it much more
> > robust and flexible. I purposely kept it as a separate libarary not
> > dependent on trace-cmd so that it could be used by other utilities like
> > perf.
>
> David is kinda new to this perf/ftrace/trace-cmd/etc soap opera, and he
> has been patient to go thru the motions with Peter, Thomas, Fr?d?ric and
> me, going from doing what he wants in 'perf report' to 'perf script',
> etc.
>
> We're almost to the point where his feature is implemented in a
> way Fr?d?ric, the one most actively reviewing his work, is satisfied,
> right Fr?d?ric?
Yeah, nice work! Thanks David!
Acked-by: Frederic Weisbecker <[email protected]>
Commit-ID: be6d842a65babc54e2b204b382df2529e304be48
Gitweb: http://git.kernel.org/tip/be6d842a65babc54e2b204b382df2529e304be48
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:23 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:05:50 -0300
perf script: Change process_event prototype
Prepare for handling of samples for any event type.
Acked-by: Frederic Weisbecker <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[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);
};
Commit-ID: 2ee7a49f935b19f7daf0a110800488acd2479cba
Gitweb: http://git.kernel.org/tip/2ee7a49f935b19f7daf0a110800488acd2479cba
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:24 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:05:51 -0300
perf tracing: Remove print_graph_cpu and print_graph_proc from trace-event-parse
Next patch moves printing of 'common' data into perf-script which
removes the need for these functions.
Acked-by: Frederic Weisbecker <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/trace-event-parse.c | 65 +---------------------------------
1 files changed, 2 insertions(+), 63 deletions(-)
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index d8e622d..dd5f058 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,7 +2821,7 @@ 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,
+ int cpu, int pid, const char *comm __unused,
unsigned long secs, unsigned long usecs)
{
struct format_field *field;
@@ -2886,9 +2831,6 @@ pretty_print_func_ent(void *data, int size, struct event *event,
printf("%5lu.%06lu | ", secs, usecs);
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
printf(" | ");
if (latency_format) {
@@ -2924,7 +2866,7 @@ out_free:
static void
pretty_print_func_ret(void *data, int size __unused, struct event *event,
- int cpu, int pid, const char *comm,
+ int cpu __unused, int pid __unused, const char *comm __unused,
unsigned long secs, unsigned long usecs)
{
unsigned long long rettime, calltime;
@@ -2934,9 +2876,6 @@ pretty_print_func_ret(void *data, int size __unused, struct event *event,
printf("%5lu.%06lu | ", secs, usecs);
- print_graph_cpu(cpu);
- print_graph_proc(pid, comm);
-
printf(" | ");
if (latency_format) {
Commit-ID: 745f43e3433a7939bd9c351c8106e0c1db2044c6
Gitweb: http://git.kernel.org/tip/745f43e3433a7939bd9c351c8106e0c1db2044c6
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:26 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:06:16 -0300
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 <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 5 +
tools/perf/builtin-script.c | 141 ++++++++++++++++++++++++++----
2 files changed, 130 insertions(+), 16 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..c046e6e 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;
+ unsigned long long nsecs;
+
+ if (PRINT_FIELD(COMM)) {
+ if (latency_format)
+ printf("%8.8s ", thread->comm);
+ else
+ printf("%16s ", thread->comm);
+ }
- 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);
+ 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);
+ }
- secs = nsecs / NSECS_PER_SEC;
- nsecs -= secs * NSECS_PER_SEC;
- usecs = nsecs / NSECS_PER_USEC;
- printf(" %5lu.%06lu: ", secs, usecs);
+ 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);
+ }
- type = trace_parse_common_type(sample->raw_data);
- event = trace_find_event(type);
- if (event)
- evname = event->name;
+ 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)");
+ 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);
Commit-ID: c70c94b47405d2c94df19c16273daf1f5fb9193d
Gitweb: http://git.kernel.org/tip/c70c94b47405d2c94df19c16273daf1f5fb9193d
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:25 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:05:55 -0300
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 <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/builtin-script.c | 38 ++++++++++++++++++++++-----
tools/perf/util/trace-event-parse.c | 49 +++++++---------------------------
tools/perf/util/trace-event.h | 3 +-
3 files changed, 42 insertions(+), 48 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 dd5f058..0a7ed5b 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2643,9 +2643,9 @@ static void print_lat_fmt(void *data, int size __unused)
printf(".");
if (lock_depth < 0)
- printf(".");
+ printf(". ");
else
- printf("%d", lock_depth);
+ printf("%d ", lock_depth);
}
#define TRACE_GRAPH_INDENT 2
@@ -2821,18 +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 __unused,
- 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);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2865,19 +2860,13 @@ out_free:
}
static void
-pretty_print_func_ret(void *data, int size __unused, struct event *event,
- int cpu __unused, int pid __unused, const char *comm __unused,
- 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);
-
- printf(" | ");
-
if (latency_format) {
print_lat_fmt(data, size);
printf(" | ");
@@ -2915,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);
@@ -2951,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",
@@ -2970,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;
Commit-ID: c0230b2bfbd16e42d937c34aed99e5d6493eb5e4
Gitweb: http://git.kernel.org/tip/c0230b2bfbd16e42d937c34aed99e5d6493eb5e4
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:27 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:06:50 -0300
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 <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 16 +++++++-
tools/perf/builtin-script.c | 31 +++++++++++++++-
tools/perf/util/session.c | 61 ++++++++++++++++++++++++++++++
tools/perf/util/session.h | 4 ++
4 files changed, 110 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 c046e6e..b45b09c 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) && symbol_conf.use_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 (!symbol_conf.use_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()
@@ -905,6 +929,11 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (session == NULL)
return -ENOMEM;
+ if (!no_callchain && (session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ symbol_conf.use_callchain = true;
+ else
+ symbol_conf.use_callchain = false;
+
if (strcmp(input_name, "-") &&
!perf_session__has_traces(session, "record -R"))
return -EINVAL;
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index f26639f..c68cf40 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1134,3 +1134,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 b5b148b..0b3c9af 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -159,4 +159,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 */
Commit-ID: 1424dc96807909438282663079adc7f27c10b4a5
Gitweb: http://git.kernel.org/tip/1424dc96807909438282663079adc7f27c10b4a5
Author: David Ahern <[email protected]>
AuthorDate: Wed, 9 Mar 2011 22:23:28 -0700
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 14 Mar 2011 17:07:20 -0300
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 <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: David Ahern <[email protected]>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/Documentation/perf-script.txt | 5 +-
tools/perf/builtin-script.c | 155 +++++++++++++++++++++++-------
tools/perf/util/parse-events.c | 22 ++++
tools/perf/util/parse-events.h | 1 +
4 files changed, 147 insertions(+), 36 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 b45b09c..9f5fc54 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,65 @@ 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)) {
+ if (!(session->sample_type & PERF_SAMPLE_IP)) {
+ pr_err("Samples do not contain IP data.\n");
+ return -EINVAL;
+ }
+ if (!no_callchain &&
+ !(session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ symbol_conf.use_callchain = false;
+ }
+
+ 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;
@@ -97,10 +148,13 @@ static void print_sample_start(struct perf_sample *sample,
}
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)");
}
@@ -108,10 +162,27 @@ static void print_sample_start(struct perf_sample *sample,
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 +254,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 +460,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;
}
}
@@ -414,10 +502,11 @@ static int parse_output_fields(const struct option *opt __used,
rc = -EINVAL;
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 +836,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()
@@ -929,15 +1018,11 @@ int cmd_script(int argc, const char **argv, const char *prefix __used)
if (session == NULL)
return -ENOMEM;
- if (!no_callchain && (session->sample_type & PERF_SAMPLE_CALLCHAIN))
+ if (!no_callchain)
symbol_conf.use_callchain = true;
else
symbol_conf.use_callchain = false;
- 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);