* [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2)
@ 2015-12-15 15:35 Namhyung Kim
2015-12-15 15:35 ` [PATCH 01/10] perf hist: Pass struct sample to __hists__add_entry() Namhyung Kim
` (10 more replies)
0 siblings, 11 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Hello,
This is an attempt to improve perf to deal with tracepoint events
better. The perf tools can handle tracepoint events but perf report
on them is less useful since they're always sampled in a fixed
location and not provide event specific info. We can use perf script
but I always wishes there's more convenient way to see the result.
* changes in v2)
- add 'trace' sort key and make it default (Jiri)
- add '--raw-trace' option and '/raw' field modifier (Jiri)
- support event name shortcuts (David)
I suggest dynamic sort keys created for each event.field on demand.
Consider following example:
# Overhead Command Shared Object Symbol
# ........ ............... ................ ..............
#
47.22% swapper [kernel.vmlinux] [k] __schedule
21.67% transmission-gt [kernel.vmlinux] [k] __schedule
8.23% netctl-auto [kernel.vmlinux] [k] __schedule
5.53% kworker/0:1H [kernel.vmlinux] [k] __schedule
1.98% Xephyr [kernel.vmlinux] [k] __schedule
1.33% irq/33-iwlwifi [kernel.vmlinux] [k] __schedule
1.17% wpa_cli [kernel.vmlinux] [k] __schedule
1.13% rcu_preempt [kernel.vmlinux] [k] __schedule
0.85% ksoftirqd/0 [kernel.vmlinux] [k] __schedule
0.77% Timer [kernel.vmlinux] [k] __schedule
...
Currently perf report only shows this but important info is on the
event fields, that is:
# sudo cat /sys/kernel/debug/tracing/events/sched/sched_switch/format
name: sched_switch
ID: 268
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:char prev_comm[16]; offset:8; size:16; signed:1;
field:pid_t prev_pid; offset:24; size:4; signed:1;
field:int prev_prio; offset:28; size:4; signed:1;
field:long prev_state; offset:32; size:8; signed:1;
field:char next_comm[16]; offset:40; size:16; signed:1;
field:pid_t next_pid; offset:56; size:4; signed:1;
field:int next_prio; offset:60; size:4; signed:1;
print fmt: "prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==>
next_comm=%s next_pid=%d next_prio=%d",
REC->prev_comm, REC->prev_pid, REC->prev_prio,
REC->prev_state & (2048-1) ? __print_flags(REC->prev_state & (2048-1),
"|", { 1, "S"} , { 2, "D" }, { 4, "T" }, { 8, "t" }, { 16, "Z" }, { 32, "X" },
{ 64, "x" }, { 128, "K"}, { 256, "W" }, { 512, "P" }, { 1024, "N" }) : "R",
REC->prev_state & 2048 ? "+" : "", REC->next_comm, REC->next_pid, REC->next_prio
With dynamic sort keys, you can use <event.field> as a sort key. Those
dynamic keys are checked and created on demand. For instance, below is
to sort by next_pid field on the same data file.
$ perf report -s comm,sched:sched_switch.next_pid --stdio
...
# Overhead Command next_pid
# ........ ............... ..........
#
21.23% transmission-gt 0
20.86% swapper 17773
6.62% netctl-auto 0
5.25% swapper 109
5.21% kworker/0:1H 0
1.98% Xephyr 0
1.98% swapper 6524
1.98% swapper 27478
1.37% swapper 27476
1.17% swapper 233
...
Multiple dynamic sort keys are also supported and the event name can
be simplified (or even om in a couple of ways (see patch 10/10):
$ perf report -s comm,switch.next_pid,next_comm --stdio
...
# Overhead Command next_pid next_comm
# ........ ............... .......... ................
#
20.86% swapper 17773 transmission-gt
9.64% transmission-gt 0 swapper/0
9.16% transmission-gt 0 swapper/2
5.25% swapper 109 kworker/0:1H
5.21% kworker/0:1H 0 swapper/0
2.14% netctl-auto 0 swapper/2
1.98% netctl-auto 0 swapper/0
1.98% swapper 6524 Xephyr
1.98% swapper 27478 netctl-auto
1.78% transmission-gt 0 swapper/3
1.53% Xephyr 0 swapper/0
1.29% netctl-auto 0 swapper/1
1.29% swapper 27476 netctl-auto
1.21% netctl-auto 0 swapper/3
1.17% swapper 233 irq/33-iwlwifi
...
Note that pid 0 exists for each cpu so have comm of 'swapper/N'.
Also now it add a new 'trace' sort key to print whole trace output.
(The 'trace' sort key is the default key for tracepoint events now).
Below is the output using sched_switch plugin.
$ perf report -s trace --stdio
...
# Overhead Trace output
# ........ ...................................................
#
9.48% swapper/0:0 [120] R ==> transmission-gt:17773 [120]
9.48% transmission-gt:17773 [120] S ==> swapper/0:0 [120]
9.04% swapper/2:0 [120] R ==> transmission-gt:17773 [120]
8.92% transmission-gt:17773 [120] S ==> swapper/2:0 [120]
5.25% swapper/0:0 [120] R ==> kworker/0:1H:109 [100]
5.21% kworker/0:1H:109 [100] S ==> swapper/0:0 [120]
1.78% swapper/3:0 [120] R ==> transmission-gt:17773 [120]
1.78% transmission-gt:17773 [120] S ==> swapper/3:0 [120]
1.53% Xephyr:6524 [120] S ==> swapper/0:0 [120]
1.53% swapper/0:0 [120] R ==> Xephyr:6524 [120]
1.17% swapper/2:0 [120] R ==> irq/33-iwlwifi:233 [49]
1.13% irq/33-iwlwifi:233 [49] S ==> swapper/2:0 [120]
...
The --raw-trace option is to control display of raw field info
$ perf report -s trace --stdio --raw-trace
...
# Overhead Trace output
# ........ ...........................................................................................................
#
9.48% prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=0 next_comm=transmission-gt next_pid=17773 next_pr
9.48% prev_comm=transmission-gt prev_pid=17773 prev_prio=120 prev_state=1 next_comm=swapper/0 next_pid=0 next_pr
9.04% prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=0 next_comm=transmission-gt next_pid=17773 next_pr
8.92% prev_comm=transmission-gt prev_pid=17773 prev_prio=120 prev_state=1 next_comm=swapper/2 next_pid=0 next_pr
5.25% prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=0 next_comm=kworker/0:1H next_pid=109 next_prio=10
5.21% prev_comm=kworker/0:1H prev_pid=109 prev_prio=100 prev_state=1 next_comm=swapper/0 next_pid=0 next_prio=12
1.78% prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=0 next_comm=transmission-gt next_pid=17773 next_pr
1.78% prev_comm=transmission-gt prev_pid=17773 prev_prio=120 prev_state=1 next_comm=swapper/3 next_pid=0 next_pr
1.53% prev_comm=Xephyr prev_pid=6524 prev_prio=120 prev_state=1 next_comm=swapper/0 next_pid=0 next_prio=120
1.53% prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=0 next_comm=Xephyr next_pid=6524 next_prio=120
1.17% prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=0 next_comm=irq/33-iwlwifi next_pid=233 next_prio=
1.13% prev_comm=irq/33-iwlwifi prev_pid=233 prev_prio=49 prev_state=1 next_comm=swapper/2 next_pid=0 next_prio=1
...
This is available on 'perf/dynamic-sort-v2' branch in my tree
git://git.kernel.org/pub/scm/linux/kernel/git/namhyung/linux-perf.git
Any comments are welcome, thanks!
Namhyung
Namhyung Kim (10):
perf hist: Pass struct sample to __hists__add_entry()
perf hist: Save raw_data/size for tracepoint events
tools lib traceevent: Factor out and export print_event_field[s]
perf tools: Pass evlist to setup_sorting()
perf tools: Add dynamic sort key for tracepoint events
perf tools: Try to show pretty printed output for dynamic sort keys
perf tools: Add 'trace' sort key
perf tools: Add --raw-trace option
perf tools: Make 'trace' sort key default for tracepoint events
perf tools: Support shortcuts for events in dynamic sort keys
tools/lib/traceevent/event-parse.c | 125 ++++----
tools/lib/traceevent/event-parse.h | 4 +
tools/perf/Documentation/perf-report.txt | 3 +
tools/perf/Documentation/perf-top.txt | 3 +
tools/perf/builtin-annotate.c | 9 +-
tools/perf/builtin-diff.c | 13 +-
tools/perf/builtin-report.c | 4 +-
tools/perf/builtin-top.c | 16 +-
tools/perf/tests/hists_cumulate.c | 8 +-
tools/perf/tests/hists_filter.c | 2 +-
tools/perf/tests/hists_link.c | 8 +-
tools/perf/tests/hists_output.c | 10 +-
tools/perf/util/hist.c | 34 ++-
tools/perf/util/hist.h | 5 +-
tools/perf/util/sort.c | 483 ++++++++++++++++++++++++++++++-
tools/perf/util/sort.h | 10 +-
tools/perf/util/symbol.h | 3 +-
17 files changed, 619 insertions(+), 121 deletions(-)
--
2.6.4
^ permalink raw reply [flat|nested] 26+ messages in thread
* [PATCH 01/10] perf hist: Pass struct sample to __hists__add_entry()
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 02/10] perf hist: Save raw_data/size for tracepoint events Namhyung Kim
` (9 subsequent siblings)
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
This is a preparation to add more info into the hist_entry. Also it
already passes too many argument, so passing sample directly will reduce
the overhead of the function call.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-annotate.c | 7 +++++--
tools/perf/builtin-diff.c | 11 +++++------
tools/perf/tests/hists_link.c | 6 +++---
tools/perf/util/hist.c | 31 +++++++++++++++++--------------
tools/perf/util/hist.h | 4 ++--
5 files changed, 32 insertions(+), 27 deletions(-)
diff --git a/tools/perf/builtin-annotate.c b/tools/perf/builtin-annotate.c
index 1f00dc7cecba..e193340853ba 100644
--- a/tools/perf/builtin-annotate.c
+++ b/tools/perf/builtin-annotate.c
@@ -47,7 +47,7 @@ struct perf_annotate {
};
static int perf_evsel__add_sample(struct perf_evsel *evsel,
- struct perf_sample *sample __maybe_unused,
+ struct perf_sample *sample,
struct addr_location *al,
struct perf_annotate *ann)
{
@@ -72,7 +72,10 @@ static int perf_evsel__add_sample(struct perf_evsel *evsel,
return 0;
}
- he = __hists__add_entry(hists, al, NULL, NULL, NULL, 1, 1, 0, true);
+ sample->period = 1;
+ sample->weight = 1;
+
+ he = __hists__add_entry(hists, al, NULL, NULL, NULL, sample, true);
if (he == NULL)
return -ENOMEM;
diff --git a/tools/perf/builtin-diff.c b/tools/perf/builtin-diff.c
index 0b180a885ba3..69f5b1feff39 100644
--- a/tools/perf/builtin-diff.c
+++ b/tools/perf/builtin-diff.c
@@ -311,11 +311,11 @@ static int formula_fprintf(struct hist_entry *he, struct hist_entry *pair,
}
static int hists__add_entry(struct hists *hists,
- struct addr_location *al, u64 period,
- u64 weight, u64 transaction)
+ struct addr_location *al,
+ struct perf_sample *sample)
{
- if (__hists__add_entry(hists, al, NULL, NULL, NULL, period, weight,
- transaction, true) != NULL)
+ if (__hists__add_entry(hists, al, NULL, NULL, NULL,
+ sample, true) != NULL)
return 0;
return -ENOMEM;
}
@@ -336,8 +336,7 @@ static int diff__process_sample_event(struct perf_tool *tool __maybe_unused,
return -1;
}
- if (hists__add_entry(hists, &al, sample->period,
- sample->weight, sample->transaction)) {
+ if (hists__add_entry(hists, &al, sample)) {
pr_warning("problem incrementing symbol period, skipping event\n");
goto out_put;
}
diff --git a/tools/perf/tests/hists_link.c b/tools/perf/tests/hists_link.c
index 6243e2b2a245..9eac98daecb8 100644
--- a/tools/perf/tests/hists_link.c
+++ b/tools/perf/tests/hists_link.c
@@ -64,7 +64,7 @@ static int add_hist_entries(struct perf_evlist *evlist, struct machine *machine)
struct perf_evsel *evsel;
struct addr_location al;
struct hist_entry *he;
- struct perf_sample sample = { .period = 1, };
+ struct perf_sample sample = { .period = 1, .weight = 1, };
size_t i = 0, k;
/*
@@ -90,7 +90,7 @@ static int add_hist_entries(struct perf_evlist *evlist, struct machine *machine)
goto out;
he = __hists__add_entry(hists, &al, NULL,
- NULL, NULL, 1, 1, 0, true);
+ NULL, NULL, &sample, true);
if (he == NULL) {
addr_location__put(&al);
goto out;
@@ -116,7 +116,7 @@ static int add_hist_entries(struct perf_evlist *evlist, struct machine *machine)
goto out;
he = __hists__add_entry(hists, &al, NULL,
- NULL, NULL, 1, 1, 0, true);
+ NULL, NULL, &sample, true);
if (he == NULL) {
addr_location__put(&al);
goto out;
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 56e97f5af598..039bb91d0a92 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -461,7 +461,7 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
struct symbol *sym_parent,
struct branch_info *bi,
struct mem_info *mi,
- u64 period, u64 weight, u64 transaction,
+ struct perf_sample *sample,
bool sample_self)
{
struct hist_entry entry = {
@@ -478,15 +478,15 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
.level = al->level,
.stat = {
.nr_events = 1,
- .period = period,
- .weight = weight,
+ .period = sample->period,
+ .weight = sample->weight,
},
.parent = sym_parent,
.filtered = symbol__parent_filter(sym_parent) | al->filtered,
.hists = hists,
.branch_info = bi,
.mem_info = mi,
- .transaction = transaction,
+ .transaction = sample->transaction,
};
return hists__findnew_entry(hists, &entry, al, sample_self);
@@ -526,12 +526,13 @@ iter_add_single_mem_entry(struct hist_entry_iter *iter, struct addr_location *al
u64 cost;
struct mem_info *mi = iter->priv;
struct hists *hists = evsel__hists(iter->evsel);
+ struct perf_sample *sample = iter->sample;
struct hist_entry *he;
if (mi == NULL)
return -EINVAL;
- cost = iter->sample->weight;
+ cost = sample->weight;
if (!cost)
cost = 1;
@@ -542,8 +543,10 @@ iter_add_single_mem_entry(struct hist_entry_iter *iter, struct addr_location *al
* and this is indirectly achieved by passing period=weight here
* and the he_stat__add_period() function.
*/
+ sample->period = cost;
+
he = __hists__add_entry(hists, al, iter->parent, NULL, mi,
- cost, cost, 0, true);
+ sample, true);
if (!he)
return -ENOMEM;
@@ -630,6 +633,7 @@ iter_add_next_branch_entry(struct hist_entry_iter *iter, struct addr_location *a
struct branch_info *bi;
struct perf_evsel *evsel = iter->evsel;
struct hists *hists = evsel__hists(evsel);
+ struct perf_sample *sample = iter->sample;
struct hist_entry *he = NULL;
int i = iter->curr;
int err = 0;
@@ -643,9 +647,11 @@ iter_add_next_branch_entry(struct hist_entry_iter *iter, struct addr_location *a
* The report shows the percentage of total branches captured
* and not events sampled. Thus we use a pseudo period of 1.
*/
+ sample->period = 1;
+ sample->weight = bi->flags.cycles ? bi->flags.cycles : 1;
+
he = __hists__add_entry(hists, al, iter->parent, &bi[i], NULL,
- 1, bi->flags.cycles ? bi->flags.cycles : 1,
- 0, true);
+ sample, true);
if (he == NULL)
return -ENOMEM;
@@ -682,8 +688,7 @@ iter_add_single_normal_entry(struct hist_entry_iter *iter, struct addr_location
struct hist_entry *he;
he = __hists__add_entry(evsel__hists(evsel), al, iter->parent, NULL, NULL,
- sample->period, sample->weight,
- sample->transaction, true);
+ sample, true);
if (he == NULL)
return -ENOMEM;
@@ -744,8 +749,7 @@ iter_add_single_cumulative_entry(struct hist_entry_iter *iter,
int err = 0;
he = __hists__add_entry(hists, al, iter->parent, NULL, NULL,
- sample->period, sample->weight,
- sample->transaction, true);
+ sample, true);
if (he == NULL)
return -ENOMEM;
@@ -818,8 +822,7 @@ iter_add_next_cumulative_entry(struct hist_entry_iter *iter,
}
he = __hists__add_entry(evsel__hists(evsel), al, iter->parent, NULL, NULL,
- sample->period, sample->weight,
- sample->transaction, false);
+ sample, false);
if (he == NULL)
return -ENOMEM;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index a48a2078d288..36439bfad059 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -114,8 +114,8 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
struct addr_location *al,
struct symbol *parent,
struct branch_info *bi,
- struct mem_info *mi, u64 period,
- u64 weight, u64 transaction,
+ struct mem_info *mi,
+ struct perf_sample *sample,
bool sample_self);
int hist_entry_iter__add(struct hist_entry_iter *iter, struct addr_location *al,
int max_stack_depth, void *arg);
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 02/10] perf hist: Save raw_data/size for tracepoint events
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
2015-12-15 15:35 ` [PATCH 01/10] perf hist: Pass struct sample to __hists__add_entry() Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-17 8:14 ` [PATCH v2.1] " Namhyung Kim
2015-12-15 15:35 ` [PATCH 03/10] tools lib traceevent: Factor out and export print_event_field[s] Namhyung Kim
` (8 subsequent siblings)
10 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The raw_data and raw_size fields are to provide tracepoint specific
information. They will be used by dynamic sort keys later.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/hist.c | 2 ++
tools/perf/util/sort.h | 2 ++
2 files changed, 4 insertions(+)
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 039bb91d0a92..99a6f1c17806 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -487,6 +487,8 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
.branch_info = bi,
.mem_info = mi,
.transaction = sample->transaction,
+ .raw_data = sample->raw_data,
+ .raw_size = sample->raw_size,
};
return hists__findnew_entry(hists, &entry, al, sample_self);
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index 31228851e397..1c08cd8a5e3b 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -122,6 +122,8 @@ struct hist_entry {
struct branch_info *branch_info;
struct hists *hists;
struct mem_info *mem_info;
+ void *raw_data;
+ u32 raw_size;
struct callchain_root callchain[0]; /* must be last member */
};
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 03/10] tools lib traceevent: Factor out and export print_event_field[s]
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
2015-12-15 15:35 ` [PATCH 01/10] perf hist: Pass struct sample to __hists__add_entry() Namhyung Kim
2015-12-15 15:35 ` [PATCH 02/10] perf hist: Save raw_data/size for tracepoint events Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 04/10] perf tools: Pass evlist to setup_sorting() Namhyung Kim
` (7 subsequent siblings)
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The print_event_field() and print_event_field() are to print basic
information of a given field or event without the print format. They'll
be used by dynamic sort keys later.
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/lib/traceevent/event-parse.c | 125 ++++++++++++++++++++-----------------
tools/lib/traceevent/event-parse.h | 4 ++
2 files changed, 70 insertions(+), 59 deletions(-)
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index 68276f35e323..1b43f2b9aebe 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -4735,73 +4735,80 @@ static int is_printable_array(char *p, unsigned int len)
return 1;
}
-static void print_event_fields(struct trace_seq *s, void *data,
- int size __maybe_unused,
- struct event_format *event)
+void print_event_field(struct trace_seq *s, void *data,
+ struct format_field *field)
{
- struct format_field *field;
unsigned long long val;
unsigned int offset, len, i;
-
- field = event->format.fields;
- while (field) {
- trace_seq_printf(s, " %s=", field->name);
- if (field->flags & FIELD_IS_ARRAY) {
- offset = field->offset;
- len = field->size;
- if (field->flags & FIELD_IS_DYNAMIC) {
- val = pevent_read_number(event->pevent, data + offset, len);
- offset = val;
- len = offset >> 16;
- offset &= 0xffff;
- }
- if (field->flags & FIELD_IS_STRING &&
- is_printable_array(data + offset, len)) {
- trace_seq_printf(s, "%s", (char *)data + offset);
- } else {
- trace_seq_puts(s, "ARRAY[");
- for (i = 0; i < len; i++) {
- if (i)
- trace_seq_puts(s, ", ");
- trace_seq_printf(s, "%02x",
- *((unsigned char *)data + offset + i));
- }
- trace_seq_putc(s, ']');
- field->flags &= ~FIELD_IS_STRING;
- }
+ struct pevent *pevent = field->event->pevent;
+
+ if (field->flags & FIELD_IS_ARRAY) {
+ offset = field->offset;
+ len = field->size;
+ if (field->flags & FIELD_IS_DYNAMIC) {
+ val = pevent_read_number(pevent, data + offset, len);
+ offset = val;
+ len = offset >> 16;
+ offset &= 0xffff;
+ }
+ if (field->flags & FIELD_IS_STRING &&
+ is_printable_array(data + offset, len)) {
+ trace_seq_printf(s, "%s", (char *)data + offset);
} else {
- val = pevent_read_number(event->pevent, data + field->offset,
- field->size);
- if (field->flags & FIELD_IS_POINTER) {
- trace_seq_printf(s, "0x%llx", val);
- } else if (field->flags & FIELD_IS_SIGNED) {
- switch (field->size) {
- case 4:
- /*
- * If field is long then print it in hex.
- * A long usually stores pointers.
- */
- if (field->flags & FIELD_IS_LONG)
- trace_seq_printf(s, "0x%x", (int)val);
- else
- trace_seq_printf(s, "%d", (int)val);
- break;
- case 2:
- trace_seq_printf(s, "%2d", (short)val);
- break;
- case 1:
- trace_seq_printf(s, "%1d", (char)val);
- break;
- default:
- trace_seq_printf(s, "%lld", val);
- }
- } else {
+ trace_seq_puts(s, "ARRAY[");
+ for (i = 0; i < len; i++) {
+ if (i)
+ trace_seq_puts(s, ", ");
+ trace_seq_printf(s, "%02x",
+ *((unsigned char *)data + offset + i));
+ }
+ trace_seq_putc(s, ']');
+ field->flags &= ~FIELD_IS_STRING;
+ }
+ } else {
+ val = pevent_read_number(pevent, data + field->offset,
+ field->size);
+ if (field->flags & FIELD_IS_POINTER) {
+ trace_seq_printf(s, "0x%llx", val);
+ } else if (field->flags & FIELD_IS_SIGNED) {
+ switch (field->size) {
+ case 4:
+ /*
+ * If field is long then print it in hex.
+ * A long usually stores pointers.
+ */
if (field->flags & FIELD_IS_LONG)
- trace_seq_printf(s, "0x%llx", val);
+ trace_seq_printf(s, "0x%x", (int)val);
else
- trace_seq_printf(s, "%llu", val);
+ trace_seq_printf(s, "%d", (int)val);
+ break;
+ case 2:
+ trace_seq_printf(s, "%2d", (short)val);
+ break;
+ case 1:
+ trace_seq_printf(s, "%1d", (char)val);
+ break;
+ default:
+ trace_seq_printf(s, "%lld", val);
}
+ } else {
+ if (field->flags & FIELD_IS_LONG)
+ trace_seq_printf(s, "0x%llx", val);
+ else
+ trace_seq_printf(s, "%llu", val);
}
+ }
+}
+
+void print_event_fields(struct trace_seq *s, void *data,
+ int size __maybe_unused, struct event_format *event)
+{
+ struct format_field *field;
+
+ field = event->format.fields;
+ while (field) {
+ trace_seq_printf(s, " %s=", field->name);
+ print_event_field(s, data, field);
field = field->next;
}
}
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 6fc83c7edbe9..600c73277a6f 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -705,6 +705,10 @@ struct cmdline *pevent_data_pid_from_comm(struct pevent *pevent, const char *com
struct cmdline *next);
int pevent_cmdline_pid(struct pevent *pevent, struct cmdline *cmdline);
+void print_event_field(struct trace_seq *s, void *data,
+ struct format_field *field);
+void print_event_fields(struct trace_seq *s, void *data,
+ int size __maybe_unused, struct event_format *event);
void pevent_event_info(struct trace_seq *s, struct event_format *event,
struct pevent_record *record);
int pevent_strerror(struct pevent *pevent, enum pevent_errno errnum,
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 04/10] perf tools: Pass evlist to setup_sorting()
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (2 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 03/10] tools lib traceevent: Factor out and export print_event_field[s] Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
` (6 subsequent siblings)
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
This is a preparation to support dynamic sort keys for tracepoint
events. Dynamic sort keys can be created for specific fields in trace
events so it needs the event information.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-annotate.c | 2 +-
tools/perf/builtin-diff.c | 2 +-
tools/perf/builtin-report.c | 2 +-
tools/perf/builtin-top.c | 14 +++++++-------
tools/perf/tests/hists_cumulate.c | 8 ++++----
tools/perf/tests/hists_filter.c | 2 +-
tools/perf/tests/hists_link.c | 2 +-
tools/perf/tests/hists_output.c | 10 +++++-----
tools/perf/util/sort.c | 15 +++++++++------
tools/perf/util/sort.h | 5 +++--
10 files changed, 33 insertions(+), 29 deletions(-)
diff --git a/tools/perf/builtin-annotate.c b/tools/perf/builtin-annotate.c
index e193340853ba..8ed582a44b39 100644
--- a/tools/perf/builtin-annotate.c
+++ b/tools/perf/builtin-annotate.c
@@ -370,7 +370,7 @@ int cmd_annotate(int argc, const char **argv, const char *prefix __maybe_unused)
if (ret < 0)
goto out_delete;
- if (setup_sorting() < 0)
+ if (setup_sorting(NULL) < 0)
usage_with_options(annotate_usage, options);
if (annotate.use_stdio)
diff --git a/tools/perf/builtin-diff.c b/tools/perf/builtin-diff.c
index 69f5b1feff39..87063835d741 100644
--- a/tools/perf/builtin-diff.c
+++ b/tools/perf/builtin-diff.c
@@ -1279,7 +1279,7 @@ int cmd_diff(int argc, const char **argv, const char *prefix __maybe_unused)
sort__mode = SORT_MODE__DIFF;
- if (setup_sorting() < 0)
+ if (setup_sorting(NULL) < 0)
usage_with_options(diff_usage, options);
setup_pager();
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 5a454669d075..3b8eb77d586d 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -897,7 +897,7 @@ repeat:
symbol_conf.cumulate_callchain = false;
}
- if (setup_sorting() < 0) {
+ if (setup_sorting(session->evlist) < 0) {
if (sort_order)
parse_options_usage(report_usage, options, "s", 1);
if (field_order)
diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index 92fe963e43c4..feb9f5e1ef3d 100644
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -1231,11 +1231,17 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
if (argc)
usage_with_options(top_usage, options);
+ if (!top.evlist->nr_entries &&
+ perf_evlist__add_default(top.evlist) < 0) {
+ pr_err("Not enough memory for event selector list\n");
+ goto out_delete_evlist;
+ }
+
sort__mode = SORT_MODE__TOP;
/* display thread wants entries to be collapsed in a different tree */
sort__need_collapse = 1;
- if (setup_sorting() < 0) {
+ if (setup_sorting(top.evlist) < 0) {
if (sort_order)
parse_options_usage(top_usage, options, "s", 1);
if (field_order)
@@ -1277,12 +1283,6 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
goto out_delete_evlist;
}
- if (!top.evlist->nr_entries &&
- perf_evlist__add_default(top.evlist) < 0) {
- ui__error("Not enough memory for event selector list\n");
- goto out_delete_evlist;
- }
-
symbol_conf.nr_events = top.evlist->nr_entries;
if (top.delay_secs < 1)
diff --git a/tools/perf/tests/hists_cumulate.c b/tools/perf/tests/hists_cumulate.c
index 8292948bc5f9..e36089212061 100644
--- a/tools/perf/tests/hists_cumulate.c
+++ b/tools/perf/tests/hists_cumulate.c
@@ -281,7 +281,7 @@ static int test1(struct perf_evsel *evsel, struct machine *machine)
symbol_conf.cumulate_callchain = false;
perf_evsel__reset_sample_bit(evsel, CALLCHAIN);
- setup_sorting();
+ setup_sorting(NULL);
callchain_register_param(&callchain_param);
err = add_hist_entries(hists, machine);
@@ -428,7 +428,7 @@ static int test2(struct perf_evsel *evsel, struct machine *machine)
symbol_conf.cumulate_callchain = false;
perf_evsel__set_sample_bit(evsel, CALLCHAIN);
- setup_sorting();
+ setup_sorting(NULL);
callchain_register_param(&callchain_param);
err = add_hist_entries(hists, machine);
@@ -486,7 +486,7 @@ static int test3(struct perf_evsel *evsel, struct machine *machine)
symbol_conf.cumulate_callchain = true;
perf_evsel__reset_sample_bit(evsel, CALLCHAIN);
- setup_sorting();
+ setup_sorting(NULL);
callchain_register_param(&callchain_param);
err = add_hist_entries(hists, machine);
@@ -670,7 +670,7 @@ static int test4(struct perf_evsel *evsel, struct machine *machine)
symbol_conf.cumulate_callchain = true;
perf_evsel__set_sample_bit(evsel, CALLCHAIN);
- setup_sorting();
+ setup_sorting(NULL);
callchain_register_param(&callchain_param);
err = add_hist_entries(hists, machine);
diff --git a/tools/perf/tests/hists_filter.c b/tools/perf/tests/hists_filter.c
index ccb5b4921f25..2a784befd9ce 100644
--- a/tools/perf/tests/hists_filter.c
+++ b/tools/perf/tests/hists_filter.c
@@ -122,7 +122,7 @@ int test__hists_filter(int subtest __maybe_unused)
goto out;
/* default sort order (comm,dso,sym) will be used */
- if (setup_sorting() < 0)
+ if (setup_sorting(NULL) < 0)
goto out;
machines__init(&machines);
diff --git a/tools/perf/tests/hists_link.c b/tools/perf/tests/hists_link.c
index 9eac98daecb8..c764d69ac6ef 100644
--- a/tools/perf/tests/hists_link.c
+++ b/tools/perf/tests/hists_link.c
@@ -294,7 +294,7 @@ int test__hists_link(int subtest __maybe_unused)
goto out;
/* default sort order (comm,dso,sym) will be used */
- if (setup_sorting() < 0)
+ if (setup_sorting(NULL) < 0)
goto out;
machines__init(&machines);
diff --git a/tools/perf/tests/hists_output.c b/tools/perf/tests/hists_output.c
index 248beec1d917..ebe6cd485b5d 100644
--- a/tools/perf/tests/hists_output.c
+++ b/tools/perf/tests/hists_output.c
@@ -134,7 +134,7 @@ static int test1(struct perf_evsel *evsel, struct machine *machine)
field_order = NULL;
sort_order = NULL; /* equivalent to sort_order = "comm,dso,sym" */
- setup_sorting();
+ setup_sorting(NULL);
/*
* expected output:
@@ -236,7 +236,7 @@ static int test2(struct perf_evsel *evsel, struct machine *machine)
field_order = "overhead,cpu";
sort_order = "pid";
- setup_sorting();
+ setup_sorting(NULL);
/*
* expected output:
@@ -292,7 +292,7 @@ static int test3(struct perf_evsel *evsel, struct machine *machine)
field_order = "comm,overhead,dso";
sort_order = NULL;
- setup_sorting();
+ setup_sorting(NULL);
/*
* expected output:
@@ -366,7 +366,7 @@ static int test4(struct perf_evsel *evsel, struct machine *machine)
field_order = "dso,sym,comm,overhead,dso";
sort_order = "sym";
- setup_sorting();
+ setup_sorting(NULL);
/*
* expected output:
@@ -468,7 +468,7 @@ static int test5(struct perf_evsel *evsel, struct machine *machine)
field_order = "cpu,pid,comm,dso,sym";
sort_order = "dso,pid";
- setup_sorting();
+ setup_sorting(NULL);
/*
* expected output:
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 2d8ccd4d9e1b..0c038a27fe5c 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -4,6 +4,8 @@
#include "comm.h"
#include "symbol.h"
#include "evsel.h"
+#include "evlist.h"
+#include <traceevent/event-parse.h>
regex_t parent_regex;
const char default_parent_pattern[] = "^sys_|^do_page_fault";
@@ -1583,7 +1585,8 @@ int hpp_dimension__add_output(unsigned col)
return __hpp_dimension__add_output(&hpp_sort_dimensions[col]);
}
-int sort_dimension__add(const char *tok)
+static int sort_dimension__add(const char *tok,
+ struct perf_evlist *evlist __maybe_unused)
{
unsigned int i;
@@ -1712,7 +1715,7 @@ static int setup_sort_order(void)
return 0;
}
-static int __setup_sorting(void)
+static int __setup_sorting(struct perf_evlist *evlist)
{
char *tmp, *tok, *str;
const char *sort_keys;
@@ -1743,7 +1746,7 @@ static int __setup_sorting(void)
for (tok = strtok_r(str, ", ", &tmp);
tok; tok = strtok_r(NULL, ", ", &tmp)) {
- ret = sort_dimension__add(tok);
+ ret = sort_dimension__add(tok, evlist);
if (ret == -EINVAL) {
error("Invalid --sort key: `%s'", tok);
break;
@@ -1954,16 +1957,16 @@ out:
return ret;
}
-int setup_sorting(void)
+int setup_sorting(struct perf_evlist *evlist)
{
int err;
- err = __setup_sorting();
+ err = __setup_sorting(evlist);
if (err < 0)
return err;
if (parent_pattern != default_parent_pattern) {
- err = sort_dimension__add("parent");
+ err = sort_dimension__add("parent", evlist);
if (err < 0)
return err;
}
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index 1c08cd8a5e3b..dd1c2973a836 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -226,10 +226,11 @@ struct sort_entry {
extern struct sort_entry sort_thread;
extern struct list_head hist_entry__sort_list;
-int setup_sorting(void);
+struct perf_evlist;
+struct pevent;
+int setup_sorting(struct perf_evlist *evlist);
int setup_output_field(void);
void reset_output_field(void);
-extern int sort_dimension__add(const char *);
void sort__setup_elide(FILE *fp);
void perf_hpp__set_elide(int idx, bool elide);
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (3 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 04/10] perf tools: Pass evlist to setup_sorting() Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-20 13:51 ` Jiri Olsa
2015-12-15 15:35 ` [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys Namhyung Kim
` (5 subsequent siblings)
10 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The existing sort keys are less useful for tracepoint events in that
they are always sampled at a same location.
For example, report on sched:sched_switch event looks like following
# Overhead Command Shared Object Symbol
# ........ ............... ................ ..............
#
47.22% swapper [kernel.vmlinux] [k] __schedule
21.67% transmission-gt [kernel.vmlinux] [k] __schedule
8.23% netctl-auto [kernel.vmlinux] [k] __schedule
5.53% kworker/0:1H [kernel.vmlinux] [k] __schedule
1.98% Xephyr [kernel.vmlinux] [k] __schedule
1.33% irq/33-iwlwifi [kernel.vmlinux] [k] __schedule
1.17% wpa_cli [kernel.vmlinux] [k] __schedule
1.13% rcu_preempt [kernel.vmlinux] [k] __schedule
0.85% ksoftirqd/0 [kernel.vmlinux] [k] __schedule
0.77% Timer [kernel.vmlinux] [k] __schedule
In fact, tracepoints have meaningful information in their fields but
there's no way to use in the perf report currently. The dynamic sort
keys are to overcome this problem.
The sched:sched_switch events have following fields:
# sudo cat /sys/kernel/debug/tracing/events/sched/sched_switch/format
name: sched_switch
ID: 268
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:char prev_comm[16]; offset:8; size:16; signed:1;
field:pid_t prev_pid; offset:24; size:4; signed:1;
field:int prev_prio; offset:28; size:4; signed:1;
field:long prev_state; offset:32; size:8; signed:1;
field:char next_comm[16]; offset:40; size:16; signed:1;
field:pid_t next_pid; offset:56; size:4; signed:1;
field:int next_prio; offset:60; size:4; signed:1;
print fmt: "prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==>
next_comm=%s next_pid=%d next_prio=%d",
REC->prev_comm, REC->prev_pid, REC->prev_prio,
REC->prev_state & (2048-1) ? __print_flags(REC->prev_state & (2048-1),
"|", { 1, "S"} , { 2, "D" }, { 4, "T" }, { 8, "t" }, { 16, "Z" }, { 32, "X" },
{ 64, "x" }, { 128, "K"}, { 256, "W" }, { 512, "P" }, { 1024, "N" }) : "R",
REC->prev_state & 2048 ? "+" : "", REC->next_comm, REC->next_pid, REC->next_prio
With dynamic sort keys, you can use <event.field> as a sort key. Those
dynamic keys are checked and created on demand. For instance, below is
to sort by next_pid field on the same data file.
$ perf report -s comm,sched:sched_switch.next_pid --stdio
...
# Overhead Command next_pid
# ........ ............... ..........
#
21.23% transmission-gt 0
20.86% swapper 17773
6.62% netctl-auto 0
5.25% swapper 109
5.21% kworker/0:1H 0
1.98% Xephyr 0
1.98% swapper 6524
1.98% swapper 27478
1.37% swapper 27476
1.17% swapper 233
Multiple dynamic sort keys are also supported:
$ perf report -s comm,sched:sched_switch.next_pid,sched:sched_switch.next_comm --stdio
...
# Overhead Command next_pid next_comm
# ........ ............... .......... ................
#
20.86% swapper 17773 transmission-gt
9.64% transmission-gt 0 swapper/0
9.16% transmission-gt 0 swapper/2
5.25% swapper 109 kworker/0:1H
5.21% kworker/0:1H 0 swapper/0
2.14% netctl-auto 0 swapper/2
1.98% netctl-auto 0 swapper/0
1.98% swapper 6524 Xephyr
1.98% swapper 27478 netctl-auto
1.78% transmission-gt 0 swapper/3
1.53% Xephyr 0 swapper/0
1.29% netctl-auto 0 swapper/1
1.29% swapper 27476 netctl-auto
1.21% netctl-auto 0 swapper/3
1.17% swapper 233 irq/33-iwlwifi
Note that pid 0 exists for each cpu so have comm of 'swapper/N'.
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/sort.c | 223 +++++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 223 insertions(+)
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 0c038a27fe5c..f2bac1c149a9 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1531,6 +1531,226 @@ static int __sort_dimension__add_hpp_output(struct sort_dimension *sd)
return 0;
}
+struct hpp_dynamic_entry {
+ struct perf_hpp_fmt hpp;
+ struct perf_evsel *evsel;
+ struct format_field *field;
+ unsigned dynamic_len;
+};
+
+static int hde_width(struct hpp_dynamic_entry *hde)
+{
+ if (!hde->hpp.len) {
+ int len = hde->dynamic_len;
+ int namelen = strlen(hde->field->name);
+ int fieldlen = hde->field->size;
+
+ if (namelen > len)
+ len = namelen;
+
+ if (!(hde->field->flags & FIELD_IS_STRING)) {
+ /* length for print hex numbers */
+ fieldlen = hde->field->size * 2 + 2;
+ }
+ if (fieldlen > len)
+ len = fieldlen;
+
+ hde->hpp.len = len;
+ }
+ return hde->hpp.len;
+}
+
+static int __sort__hde_header(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
+ struct perf_evsel *evsel __maybe_unused)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, hde->field->name);
+}
+
+static int __sort__hde_width(struct perf_hpp_fmt *fmt,
+ struct perf_hpp *hpp __maybe_unused,
+ struct perf_evsel *evsel __maybe_unused)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ return len;
+}
+
+static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
+ struct hist_entry *he)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+ struct trace_seq seq;
+ int ret;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ if (hists_to_evsel(he->hists) != hde->evsel)
+ return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
+
+ trace_seq_init(&seq);
+ print_event_field(&seq, he->raw_data, hde->field);
+ ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, seq.buffer);
+ trace_seq_destroy(&seq);
+ return ret;
+}
+
+static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
+ struct hist_entry *a, struct hist_entry *b)
+{
+ struct hpp_dynamic_entry *hde;
+ struct format_field *field;
+ unsigned offset, size;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (hists_to_evsel(a->hists) != hde->evsel)
+ return 0;
+
+ field = hde->field;
+ if (field->flags & FIELD_IS_DYNAMIC) {
+ unsigned long long dyn;
+
+ pevent_read_number_field(field, a->raw_data, &dyn);
+ offset = dyn & 0xffff;
+ size = (dyn >> 16) & 0xffff;
+
+ /* record max width for output */
+ if (size > hde->dynamic_len)
+ hde->dynamic_len = size;
+ } else {
+ offset = field->offset;
+ size = field->size;
+ }
+
+ return memcmp(a->raw_data + offset, b->raw_data + offset, size);
+}
+
+static struct hpp_dynamic_entry *
+__alloc_dynamic_entry(struct perf_evsel *evsel, struct format_field *field)
+{
+ struct hpp_dynamic_entry *hde;
+
+ hde = malloc(sizeof(*hde));
+ if (hde == NULL) {
+ pr_debug("Memory allocation failed\n");
+ return NULL;
+ }
+
+ hde->evsel = evsel;
+ hde->field = field;
+ hde->dynamic_len = 0;
+
+ hde->hpp.name = field->name;
+ hde->hpp.header = __sort__hde_header;
+ hde->hpp.width = __sort__hde_width;
+ hde->hpp.entry = __sort__hde_entry;
+ hde->hpp.color = NULL;
+
+ hde->hpp.cmp = __sort__hde_cmp;
+ hde->hpp.collapse = __sort__hde_cmp;
+ hde->hpp.sort = __sort__hde_cmp;
+
+ INIT_LIST_HEAD(&hde->hpp.list);
+ INIT_LIST_HEAD(&hde->hpp.sort_list);
+ hde->hpp.elide = false;
+ hde->hpp.len = 0;
+ hde->hpp.user_len = 0;
+
+ return hde;
+}
+
+static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
+{
+ char *str, *event_name, *field_name;
+ struct perf_evsel *evsel, *pos;
+ struct event_format *format;
+ struct format_field *field;
+ struct hpp_dynamic_entry *hde;
+ int ret = 0;
+
+ if (evlist == NULL)
+ return -ENOENT;
+
+ str = strdup(tok);
+ if (str == NULL)
+ return -ENOMEM;
+
+ event_name = str;
+ field_name = strchr(str, '.');
+ if (field_name == NULL) {
+ ret = -EINVAL;
+ goto out;
+ }
+ *field_name++ = '\0';
+
+ evsel = NULL;
+ evlist__for_each(evlist, pos) {
+ if (!strcmp(pos->name, event_name)) {
+ evsel = pos;
+ break;
+ }
+ }
+
+ if (evsel == NULL) {
+ pr_debug("Cannot find event: %s\n", event_name);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ if (evsel->attr.type != PERF_TYPE_TRACEPOINT) {
+ pr_debug("%s is not a tracepoint event\n", event_name);
+ ret = -EINVAL;
+ goto out;
+ }
+
+ format = pevent_find_event(evsel->tp_format->pevent,
+ evsel->attr.config);
+ if (format == NULL) {
+ pr_debug("Cannot find event format for %s (id: %u)\n",
+ event_name, (unsigned) evsel->attr.config);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ field = pevent_find_any_field(format, field_name);
+ if (field == NULL) {
+ pr_debug("Cannot find event field for %s.%s\n",
+ event_name, field_name);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ hde = __alloc_dynamic_entry(evsel, field);
+ if (hde == NULL) {
+ ret = -ENOMEM;
+ goto out;
+ }
+
+ perf_hpp__register_sort_field(&hde->hpp);
+
+out:
+ free(str);
+ return ret;
+}
+
static int __sort_dimension__add(struct sort_dimension *sd)
{
if (sd->taken)
@@ -1667,6 +1887,9 @@ static int sort_dimension__add(const char *tok,
return 0;
}
+ if (!add_dynamic_entry(evlist, tok))
+ return 0;
+
return -ESRCH;
}
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (4 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-20 14:12 ` Jiri Olsa
2015-12-15 15:35 ` [PATCH 07/10] perf tools: Add 'trace' sort key Namhyung Kim
` (4 subsequent siblings)
10 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Each tracepoint event has format string for print to improve
readability. Try to parse the output and match the field name. If it
finds one, use that for the result. If not, fallbacks to the original
output.
For example, sort on kmem:kmalloc.gfp_flags looks like below:
(Note: libtraceevent plugins are not installed on my system. They might
affect the output below)
Before:
# Overhead Command gfp_flags
# ........ ....... ..........
#
99.89% perf 32848
0.06% sleep 208
0.03% perf 32976
0.01% perf 208
After:
# Overhead Command gfp_flags
# ........ ....... ...................
#
99.89% perf GFP_NOFS|GFP_ZERO
0.06% sleep GFP_KERNEL
0.03% perf GFP_KERNEL|GFP_ZERO
0.01% perf GFP_KERNEL
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/sort.c | 75 ++++++++++++++++++++++++++++++++++++++++++++++++--
tools/perf/util/sort.h | 1 +
2 files changed, 74 insertions(+), 2 deletions(-)
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index f2bac1c149a9..746b1c405db2 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1560,6 +1560,47 @@ static int hde_width(struct hpp_dynamic_entry *hde)
return hde->hpp.len;
}
+static void update_dynamic_len(struct hpp_dynamic_entry *hde,
+ struct hist_entry *he)
+{
+ char *str, *pos;
+ struct trace_seq seq;
+ struct format_field *field = hde->field;
+ struct pevent_record rec = {
+ .cpu = he->cpu,
+ .data = he->raw_data,
+ .size = he->raw_size,
+ };
+ size_t namelen;
+
+ if (he->dynlen_updated)
+ return;
+
+ /* parse pretty print result and update max length */
+ trace_seq_init(&seq);
+ pevent_event_info(&seq, field->event, &rec);
+
+ namelen = strlen(field->name);
+ str = strtok_r(seq.buffer, " ", &pos);
+ while (str) {
+ if (!strncmp(str, field->name, namelen)) {
+ size_t len;
+
+ str += namelen + 1;
+ len = strlen(str);
+
+ if (len > hde->dynamic_len)
+ hde->dynamic_len = len;
+ break;
+ }
+
+ str = strtok_r(NULL, " ", &pos);
+ }
+ trace_seq_destroy(&seq);
+
+ he->dynlen_updated = true;
+}
+
static int __sort__hde_header(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
struct perf_evsel *evsel __maybe_unused)
{
@@ -1595,6 +1636,14 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
struct hpp_dynamic_entry *hde;
size_t len = fmt->user_len;
struct trace_seq seq;
+ char *str, *pos;
+ struct format_field *field;
+ struct pevent_record rec = {
+ .cpu = he->cpu,
+ .data = he->raw_data,
+ .size = he->raw_size,
+ };
+ size_t namelen;
int ret;
hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
@@ -1605,9 +1654,28 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
if (hists_to_evsel(he->hists) != hde->evsel)
return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
+ field = hde->field;
trace_seq_init(&seq);
- print_event_field(&seq, he->raw_data, hde->field);
- ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, seq.buffer);
+ pevent_event_info(&seq, field->event, &rec);
+
+ namelen = strlen(field->name);
+ str = strtok_r(seq.buffer, " ", &pos);
+ while (str) {
+ if (!strncmp(str, field->name, namelen)) {
+ str += namelen + 1;
+ break;
+ }
+
+ str = strtok_r(NULL, " ", &pos);
+ }
+
+ if (str == NULL) {
+ trace_seq_reset(&seq);
+ print_event_field(&seq, he->raw_data, hde->field);
+ str = seq.buffer;
+ }
+
+ ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, str);
trace_seq_destroy(&seq);
return ret;
}
@@ -1638,6 +1706,9 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
} else {
offset = field->offset;
size = field->size;
+
+ update_dynamic_len(hde, a);
+ update_dynamic_len(hde, b);
}
return memcmp(a->raw_data + offset, b->raw_data + offset, size);
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index dd1c2973a836..aefcc2f8f173 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -97,6 +97,7 @@ struct hist_entry {
/* We are added by hists__add_dummy_entry. */
bool dummy;
+ bool dynlen_updated;
char level;
u8 filtered;
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 07/10] perf tools: Add 'trace' sort key
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (5 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 08/10] perf tools: Add --raw-trace option Namhyung Kim
` (3 subsequent siblings)
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The 'trace' sort key is to show tracepoint event output using either
print fmt or plugin. For example sched_switch event (using plugin) will
show output like below:
$ perf report -s trace --stdio
...
# Overhead Trace output
# ........ ...................................................
#
9.48% swapper/0:0 [120] R ==> transmission-gt:17773 [120]
9.48% transmission-gt:17773 [120] S ==> swapper/0:0 [120]
9.04% swapper/2:0 [120] R ==> transmission-gt:17773 [120]
8.92% transmission-gt:17773 [120] S ==> swapper/2:0 [120]
5.25% swapper/0:0 [120] R ==> kworker/0:1H:109 [100]
5.21% kworker/0:1H:109 [100] S ==> swapper/0:0 [120]
1.78% swapper/3:0 [120] R ==> transmission-gt:17773 [120]
1.78% transmission-gt:17773 [120] S ==> swapper/3:0 [120]
1.53% Xephyr:6524 [120] S ==> swapper/0:0 [120]
1.53% swapper/0:0 [120] R ==> Xephyr:6524 [120]
1.17% swapper/2:0 [120] R ==> irq/33-iwlwifi:233 [49]
1.13% irq/33-iwlwifi:233 [49] S ==> swapper/2:0 [120]
Note that the 'trace' sort key works only for tracepoint events. If
it's used to other type of events, just "N/A" will be printed.
Suggested-by: Jiri Olsa <jolsa@redhat.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/hist.c | 1 +
tools/perf/util/hist.h | 1 +
tools/perf/util/sort.c | 61 ++++++++++++++++++++++++++++++++++++++++++++++++++
tools/perf/util/sort.h | 2 ++
4 files changed, 65 insertions(+)
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 99a6f1c17806..e471e0fa6a18 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -976,6 +976,7 @@ void hist_entry__delete(struct hist_entry *he)
if (he->srcfile && he->srcfile[0])
free(he->srcfile);
free_callchain(he->callchain);
+ free(he->trace_output);
free(he);
}
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index 36439bfad059..15b22c563d30 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -52,6 +52,7 @@ enum hist_column {
HISTC_MEM_IADDR_SYMBOL,
HISTC_TRANSACTION,
HISTC_CYCLES,
+ HISTC_TRACE,
HISTC_NR_COLS, /* Last entry */
};
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 746b1c405db2..caa8d3c1f6f9 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -445,6 +445,66 @@ struct sort_entry sort_socket = {
.se_width_idx = HISTC_SOCKET,
};
+/* --sort trace */
+
+static char *get_trace_output(struct hist_entry *he)
+{
+ struct trace_seq seq;
+ struct perf_evsel *evsel;
+ struct pevent_record rec = {
+ .cpu = he->cpu,
+ .data = he->raw_data,
+ .size = he->raw_size,
+ };
+
+ evsel = hists_to_evsel(he->hists);
+
+ trace_seq_init(&seq);
+ pevent_event_info(&seq, evsel->tp_format, &rec);
+ return seq.buffer;
+}
+
+static int64_t
+sort__trace_cmp(struct hist_entry *left, struct hist_entry *right)
+{
+ struct perf_evsel *evsel;
+
+ evsel = hists_to_evsel(left->hists);
+ if (evsel->attr.type != PERF_TYPE_TRACEPOINT)
+ return 0;
+
+ if (left->trace_output == NULL)
+ left->trace_output = get_trace_output(left);
+ if (right->trace_output == NULL)
+ right->trace_output = get_trace_output(right);
+
+ hists__new_col_len(left->hists, HISTC_TRACE, strlen(left->trace_output));
+ hists__new_col_len(right->hists, HISTC_TRACE, strlen(right->trace_output));
+
+ return strcmp(right->trace_output, left->trace_output);
+}
+
+static int hist_entry__trace_snprintf(struct hist_entry *he, char *bf,
+ size_t size, unsigned int width)
+{
+ struct perf_evsel *evsel;
+
+ evsel = hists_to_evsel(he->hists);
+ if (evsel->attr.type != PERF_TYPE_TRACEPOINT)
+ return scnprintf(bf, size, "%-*.*s", width, width, "N/A");
+
+ if (he->trace_output == NULL)
+ he->trace_output = get_trace_output(he);
+ return repsep_snprintf(bf, size, "%-*.*s", width, width, he->trace_output);
+}
+
+struct sort_entry sort_trace = {
+ .se_header = "Trace output",
+ .se_cmp = sort__trace_cmp,
+ .se_snprintf = hist_entry__trace_snprintf,
+ .se_width_idx = HISTC_TRACE,
+};
+
/* sort keys for branch stacks */
static int64_t
@@ -1314,6 +1374,7 @@ static struct sort_dimension common_sort_dimensions[] = {
DIM(SORT_LOCAL_WEIGHT, "local_weight", sort_local_weight),
DIM(SORT_GLOBAL_WEIGHT, "weight", sort_global_weight),
DIM(SORT_TRANSACTION, "transaction", sort_transaction),
+ DIM(SORT_TRACE, "trace", sort_trace),
};
#undef DIM
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index aefcc2f8f173..a2c4bd059b81 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -125,6 +125,7 @@ struct hist_entry {
struct mem_info *mem_info;
void *raw_data;
u32 raw_size;
+ void *trace_output;
struct callchain_root callchain[0]; /* must be last member */
};
@@ -183,6 +184,7 @@ enum sort_type {
SORT_LOCAL_WEIGHT,
SORT_GLOBAL_WEIGHT,
SORT_TRANSACTION,
+ SORT_TRACE,
/* branch stack specific sort keys */
__SORT_BRANCH_STACK,
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 08/10] perf tools: Add --raw-trace option
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (6 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 07/10] perf tools: Add 'trace' sort key Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-20 14:58 ` Jiri Olsa
2015-12-15 15:35 ` [PATCH 09/10] perf tools: Make 'trace' sort key default for tracepoint events Namhyung Kim
` (2 subsequent siblings)
10 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The --raw-trace option is to prevent pretty printing by event's
print_fmt or plugin. Besides that, each dynamic sort key now receives
'raw' suffix separated by '/' to apply the raw trace to a specific
field.
$ perf report -s comm,kmem:kmalloc.gfp_flags
...
# Overhead Command gfp_flags
# ........ ....... ...................
#
99.89% perf GFP_NOFS|GFP_ZERO
0.06% sleep GFP_KERNEL
0.03% perf GFP_KERNEL|GFP_ZERO
0.01% perf GFP_KERNEL
Now
$ perf report -s comm,kmem:kmalloc.gfp_flags --raw-trace
or
$ perf report -s comm,kmem:kmalloc.gfp_flags/raw
...
# Overhead Command gfp_flags
# ........ ....... ..........
#
99.89% perf 32848
0.06% sleep 208
0.03% perf 32976
0.01% perf 208
Suggested-by: Jiri Olsa <jolsa@redhat.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/Documentation/perf-report.txt | 3 +++
tools/perf/Documentation/perf-top.txt | 3 +++
tools/perf/builtin-report.c | 2 ++
tools/perf/builtin-top.c | 2 ++
tools/perf/util/sort.c | 30 +++++++++++++++++++++++++++---
tools/perf/util/symbol.h | 3 ++-
6 files changed, 39 insertions(+), 4 deletions(-)
diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt
index dab99ed2b339..ae7cd91727f6 100644
--- a/tools/perf/Documentation/perf-report.txt
+++ b/tools/perf/Documentation/perf-report.txt
@@ -371,6 +371,9 @@ include::itrace.txt[]
--socket-filter::
Only report the samples on the processor socket that match with this filter
+--raw-trace::
+ When displaying traceevent output, do not use print fmt or plugins.
+
include::callchain-overhead-calculation.txt[]
SEE ALSO
diff --git a/tools/perf/Documentation/perf-top.txt b/tools/perf/Documentation/perf-top.txt
index 556cec09bf50..b0e60e17db38 100644
--- a/tools/perf/Documentation/perf-top.txt
+++ b/tools/perf/Documentation/perf-top.txt
@@ -230,6 +230,9 @@ Default is to monitor all CPUS.
The various filters must be specified as a comma separated list: --branch-filter any_ret,u,k
Note that this feature may not be available on all processors.
+--raw-trace::
+ When displaying traceevent output, do not use print fmt or plugins.
+
INTERACTIVE PROMPTING KEYS
--------------------------
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 3b8eb77d586d..6138bd9d7402 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -788,6 +788,8 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
"Show callgraph from reference event"),
OPT_INTEGER(0, "socket-filter", &report.socket_filter,
"only show processor socket that match with this filter"),
+ OPT_BOOLEAN(0, "raw-trace", &symbol_conf.raw_trace,
+ "Show raw trace event output (do not use print fmt or plugins)"),
OPT_END()
};
struct perf_data_file file = {
diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index feb9f5e1ef3d..2fc73c93fc62 100644
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -1210,6 +1210,8 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
OPT_CALLBACK('j', "branch-filter", &opts->branch_stack,
"branch filter mask", "branch stack filter modes",
parse_branch_stack),
+ OPT_BOOLEAN(0, "raw-trace", &symbol_conf.raw_trace,
+ "Show raw trace event output (do not use print fmt or plugins)"),
OPT_END()
};
const char * const top_usage[] = {
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index caa8d3c1f6f9..da65b07258bb 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -460,7 +460,11 @@ static char *get_trace_output(struct hist_entry *he)
evsel = hists_to_evsel(he->hists);
trace_seq_init(&seq);
- pevent_event_info(&seq, evsel->tp_format, &rec);
+ if (symbol_conf.raw_trace)
+ print_event_fields(&seq, he->raw_data, he->raw_size,
+ evsel->tp_format);
+ else
+ pevent_event_info(&seq, evsel->tp_format, &rec);
return seq.buffer;
}
@@ -1597,6 +1601,7 @@ struct hpp_dynamic_entry {
struct perf_evsel *evsel;
struct format_field *field;
unsigned dynamic_len;
+ bool raw_trace;
};
static int hde_width(struct hpp_dynamic_entry *hde)
@@ -1634,7 +1639,7 @@ static void update_dynamic_len(struct hpp_dynamic_entry *hde,
};
size_t namelen;
- if (he->dynlen_updated)
+ if (he->dynlen_updated || hde->raw_trace)
return;
/* parse pretty print result and update max length */
@@ -1717,6 +1722,10 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
field = hde->field;
trace_seq_init(&seq);
+
+ if (hde->raw_trace)
+ goto raw_field;
+
pevent_event_info(&seq, field->event, &rec);
namelen = strlen(field->name);
@@ -1731,6 +1740,7 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
}
if (str == NULL) {
+raw_field:
trace_seq_reset(&seq);
print_event_field(&seq, he->raw_data, hde->field);
str = seq.buffer;
@@ -1811,11 +1821,12 @@ __alloc_dynamic_entry(struct perf_evsel *evsel, struct format_field *field)
static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
{
- char *str, *event_name, *field_name;
+ char *str, *event_name, *field_name, *raw_opt;
struct perf_evsel *evsel, *pos;
struct event_format *format;
struct format_field *field;
struct hpp_dynamic_entry *hde;
+ bool raw_trace = symbol_conf.raw_trace;
int ret = 0;
if (evlist == NULL)
@@ -1833,6 +1844,18 @@ static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
}
*field_name++ = '\0';
+ raw_opt = strchr(field_name, '/');
+ if (raw_opt) {
+ *raw_opt++ = '\0';
+
+ if (strcmp(raw_opt, "raw")) {
+ pr_err("Unsupported field option %s\n", raw_opt);
+ ret = -EINVAL;
+ goto out;
+ }
+ raw_trace = true;
+ }
+
evsel = NULL;
evlist__for_each(evlist, pos) {
if (!strcmp(pos->name, event_name)) {
@@ -1875,6 +1898,7 @@ static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
ret = -ENOMEM;
goto out;
}
+ hde->raw_trace = raw_trace;
perf_hpp__register_sort_field(&hde->hpp);
diff --git a/tools/perf/util/symbol.h b/tools/perf/util/symbol.h
index 857f707ac12b..ccd1caa40e11 100644
--- a/tools/perf/util/symbol.h
+++ b/tools/perf/util/symbol.h
@@ -109,7 +109,8 @@ struct symbol_conf {
branch_callstack,
has_filter,
show_ref_callgraph,
- hide_unresolved;
+ hide_unresolved,
+ raw_trace;
const char *vmlinux_name,
*kallsyms_name,
*source_prefix,
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 09/10] perf tools: Make 'trace' sort key default for tracepoint events
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (7 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 08/10] perf tools: Add --raw-trace option Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 10/10] perf tools: Support shortcuts for events in dynamic sort keys Namhyung Kim
2015-12-17 0:17 ` [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Arnaldo Carvalho de Melo
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
When an evlist contains tracepoint events only, use 'trace' sort key as
default. This will make users more convenient to see trace result.
Suggested-by: Jiri Olsa <jolsa@redhat.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/sort.c | 22 +++++++++++++++++-----
1 file changed, 17 insertions(+), 5 deletions(-)
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index da65b07258bb..e661d3dd3ef3 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -2049,7 +2049,7 @@ static int sort_dimension__add(const char *tok,
return -ESRCH;
}
-static const char *get_default_sort_order(void)
+static const char *get_default_sort_order(struct perf_evlist *evlist)
{
const char *default_sort_orders[] = {
default_sort_order,
@@ -2058,13 +2058,25 @@ static const char *get_default_sort_order(void)
default_top_sort_order,
default_diff_sort_order,
};
+ bool use_trace = true;
+ struct perf_evsel *evsel;
BUG_ON(sort__mode >= ARRAY_SIZE(default_sort_orders));
+ evlist__for_each(evlist, evsel) {
+ if (evsel->attr.type != PERF_TYPE_TRACEPOINT) {
+ use_trace = false;
+ break;
+ }
+ }
+
+ if (use_trace)
+ return "trace";
+
return default_sort_orders[sort__mode];
}
-static int setup_sort_order(void)
+static int setup_sort_order(struct perf_evlist *evlist)
{
char *new_sort_order;
@@ -2085,7 +2097,7 @@ static int setup_sort_order(void)
* because it's checked over the rest of the code.
*/
if (asprintf(&new_sort_order, "%s,%s",
- get_default_sort_order(), sort_order + 1) < 0) {
+ get_default_sort_order(evlist), sort_order + 1) < 0) {
error("Not enough memory to set up --sort");
return -ENOMEM;
}
@@ -2100,7 +2112,7 @@ static int __setup_sorting(struct perf_evlist *evlist)
const char *sort_keys;
int ret = 0;
- ret = setup_sort_order();
+ ret = setup_sort_order(evlist);
if (ret)
return ret;
@@ -2114,7 +2126,7 @@ static int __setup_sorting(struct perf_evlist *evlist)
return 0;
}
- sort_keys = get_default_sort_order();
+ sort_keys = get_default_sort_order(evlist);
}
str = strdup(sort_keys);
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* [PATCH 10/10] perf tools: Support shortcuts for events in dynamic sort keys
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (8 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 09/10] perf tools: Make 'trace' sort key default for tracepoint events Namhyung Kim
@ 2015-12-15 15:35 ` Namhyung Kim
2015-12-17 0:17 ` [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Arnaldo Carvalho de Melo
10 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-15 15:35 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The dynamic sort key requires event name but specifying full event name
is rather inconvenient. This patch adds more ways to identify the event
in a more compact way.
1. If session has just one event, event name can be omitted.
2. Events can be accessed by index preceded by a percent sign.
3. A part of the name can be used, if it's not ambiguous. The partial
name should not contain ':' in it.
4. Full system + event name is still used, it should contain ':'.
So in the below example all does same thing:
$ perf record -e sched:sched_switch -a sleep 1
$ perf report -s next_pid,next_comm
$ perf report -s %1.next_pid,%1.next_comm
$ perf report -s switch.next_pid,switch.next_comm
$ perf report -s sched:sched_switch.next_pid,sched:sched_switch_.next_comm
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/sort.c | 107 ++++++++++++++++++++++++++++++++++++++++---------
1 file changed, 87 insertions(+), 20 deletions(-)
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index e661d3dd3ef3..0725bf0eb3b6 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1819,10 +1819,90 @@ __alloc_dynamic_entry(struct perf_evsel *evsel, struct format_field *field)
return hde;
}
+static int parse_field_name(char *str, char **event, char **field, char **opt)
+{
+ char *event_name, *field_name, *opt_name;
+
+ event_name = str;
+ field_name = strchr(str, '.');
+
+ if (field_name) {
+ *field_name++ = '\0';
+ } else {
+ event_name = NULL;
+ field_name = str;
+ }
+
+ opt_name = strchr(field_name, '/');
+ if (opt_name)
+ *opt_name++ = '\0';
+
+ *event = event_name;
+ *field = field_name;
+ *opt = opt_name;
+
+ return 0;
+}
+
+/* find match evsel using a given event name. The event name can be:
+ * 1. NULL - only valid for single event session
+ * 2. '%' + event index (e.g. '%1' for first event)
+ * 3. full event name (e.g. sched:sched_switch)
+ * 4. partial event name (should not contain ':')
+ */
+static struct perf_evsel *find_evsel(struct perf_evlist *evlist, char *event_name)
+{
+ struct perf_evsel *evsel = NULL;
+ struct perf_evsel *pos;
+ bool full_name;
+
+ /* case 1 */
+ if (event_name == NULL) {
+ if (evlist->nr_entries != 1) {
+ pr_debug("event name should be given\n");
+ return NULL;
+ }
+
+ return perf_evlist__first(evlist);
+ }
+
+ /* case 2 */
+ if (event_name[0] == '%') {
+ int nr = strtol(event_name+1, NULL, 0);
+
+ if (nr > evlist->nr_entries)
+ return NULL;
+
+ evsel = perf_evlist__first(evlist);
+ while (--nr > 0)
+ evsel = perf_evsel__next(evsel);
+
+ return evsel;
+ }
+
+ full_name = !!strchr(event_name, ':');
+ evlist__for_each(evlist, pos) {
+ /* case 3 */
+ if (full_name && !strcmp(pos->name, event_name))
+ return pos;
+ /* case 4 */
+ if (!full_name && strstr(pos->name, event_name)) {
+ if (evsel) {
+ pr_debug("'%s' event is ambiguous: it can be %s or %s\n",
+ event_name, evsel->name, pos->name);
+ return NULL;
+ }
+ evsel = pos;
+ }
+ }
+
+ return evsel;
+}
+
static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
{
- char *str, *event_name, *field_name, *raw_opt;
- struct perf_evsel *evsel, *pos;
+ char *str, *event_name, *field_name, *opt_name;
+ struct perf_evsel *evsel;
struct event_format *format;
struct format_field *field;
struct hpp_dynamic_entry *hde;
@@ -1836,34 +1916,21 @@ static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
if (str == NULL)
return -ENOMEM;
- event_name = str;
- field_name = strchr(str, '.');
- if (field_name == NULL) {
+ if (parse_field_name(str, &event_name, &field_name, &opt_name) < 0) {
ret = -EINVAL;
goto out;
}
- *field_name++ = '\0';
- raw_opt = strchr(field_name, '/');
- if (raw_opt) {
- *raw_opt++ = '\0';
-
- if (strcmp(raw_opt, "raw")) {
- pr_err("Unsupported field option %s\n", raw_opt);
+ if (opt_name) {
+ if (strcmp(opt_name, "raw")) {
+ pr_debug("unsupported field option %s\n", opt_name);
ret = -EINVAL;
goto out;
}
raw_trace = true;
}
- evsel = NULL;
- evlist__for_each(evlist, pos) {
- if (!strcmp(pos->name, event_name)) {
- evsel = pos;
- break;
- }
- }
-
+ evsel = find_evsel(evlist, event_name);
if (evsel == NULL) {
pr_debug("Cannot find event: %s\n", event_name);
ret = -ENOENT;
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
* Re: [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2)
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
` (9 preceding siblings ...)
2015-12-15 15:35 ` [PATCH 10/10] perf tools: Support shortcuts for events in dynamic sort keys Namhyung Kim
@ 2015-12-17 0:17 ` Arnaldo Carvalho de Melo
2015-12-17 7:56 ` Namhyung Kim
10 siblings, 1 reply; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-12-17 0:17 UTC (permalink / raw)
To: Namhyung Kim
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Em Wed, Dec 16, 2015 at 12:35:33AM +0900, Namhyung Kim escreveu:
> Hello,
>
> This is an attempt to improve perf to deal with tracepoint events
> better. The perf tools can handle tracepoint events but perf report
> on them is less useful since they're always sampled in a fixed
> location and not provide event specific info. We can use perf script
> but I always wishes there's more convenient way to see the result.
>
> * changes in v2)
> - add 'trace' sort key and make it default (Jiri)
> - add '--raw-trace' option and '/raw' field modifier (Jiri)
> - support event name shortcuts (David)
Can you take a look if you can reproduce this? Without callchains it works in
all tests I did.
[root@zoo ~]# perf record -g -e kmem:kmalloc -a
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 1.193 MB perf.data (250 samples) ]
[root@zoo ~]# perf report
perf: Segmentation fault
-------- backtrace --------
perf[0x539f1b]
/lib64/libc.so.6(+0x34960)[0x7fc8e3752960]
perf(pevent_read_number+0x78)[0x542e40]
perf(pevent_read_number_field+0x70)[0x542ed3]
/root/.traceevent/plugins/plugin_kmem.so(+0x603)[0x7fc8e1a6c603]
perf(pevent_event_info+0x96)[0x547597]
perf[0x4dce26]
perf[0x4e0e89]
perf(hist_entry_iter__add+0xee)[0x4e125e]
perf[0x4304be]
perf[0x4c2db3]
perf[0x4c3301]
perf[0x4c6089]
perf(perf_session__process_events+0x3f1)[0x4c4b91]
perf(cmd_report+0x120b)[0x4319cb]
perf[0x47c871]
perf(main+0x63f)[0x42242f]
/lib64/libc.so.6(__libc_start_main+0xf0)[0x7fc8e373dfe0]
perf[0x422549]
[0x0]
[root@zoo ~]# ls -la ~/.traceevent/
total 12
drwxr-xr-x. 3 acme acme 4096 May 4 2015 .
drwx------. 61 acme acme 4096 Dec 16 21:12 ..
drwxr-xr-x. 2 acme acme 4096 Nov 23 11:15 plugins
[root@zoo ~]# ls -la ~/.traceevent
lrwxrwxrwx. 1 root root 23 May 4 2015 /root/.traceevent -> /home/acme/.traceevent/
[root@zoo ~]# perf record -e sched:sched_switch -a
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 1.704 MB perf.data (4967 samples) ]
[root@zoo ~]# perf report
[root@zoo ~]# perf record -g -e sched:sched_switch -a
^C[ perf record: Woken up 2 times to write data ]
[ perf record: Captured and wrote 2.062 MB perf.data (4743 samples) ]
[root@zoo ~]# perf report
perf: Segmentation fault
-------- backtrace --------
perf[0x539f1b]
/lib64/libc.so.6(+0x34960)[0x7fecb3223960]
perf(pevent_read_number+0x60)[0x542e28]
perf(pevent_read_number_field+0x70)[0x542ed3]
perf(get_field_val+0x6b)[0x548cd5]
perf(pevent_get_field_val+0x6b)[0x548e77]
/root/.traceevent/plugins/plugin_sched_switch.so(+0x95b)[0x7fecb194195b]
perf(pevent_event_info+0x96)[0x547597]
perf[0x4dce26]
perf[0x4e0e89]
perf(hist_entry_iter__add+0xee)[0x4e125e]
perf[0x4304be]
perf[0x4c2db3]
perf[0x4c3301]
perf[0x4c5fdb]
perf[0x4c3535]
perf(perf_session__process_events+0x3a0)[0x4c4b40]
perf(cmd_report+0x120b)[0x4319cb]
perf[0x47c871]
perf(main+0x63f)[0x42242f]
/lib64/libc.so.6(__libc_start_main+0xf0)[0x7fecb320efe0]
perf[0x422549]
[0x0]
[root@zoo ~]#
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2)
2015-12-17 0:17 ` [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Arnaldo Carvalho de Melo
@ 2015-12-17 7:56 ` Namhyung Kim
2015-12-17 12:21 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-17 7:56 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Hi Arnaldo,
On Wed, Dec 16, 2015 at 09:17:59PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Wed, Dec 16, 2015 at 12:35:33AM +0900, Namhyung Kim escreveu:
> > Hello,
> >
> > This is an attempt to improve perf to deal with tracepoint events
> > better. The perf tools can handle tracepoint events but perf report
> > on them is less useful since they're always sampled in a fixed
> > location and not provide event specific info. We can use perf script
> > but I always wishes there's more convenient way to see the result.
> >
> > * changes in v2)
> > - add 'trace' sort key and make it default (Jiri)
> > - add '--raw-trace' option and '/raw' field modifier (Jiri)
> > - support event name shortcuts (David)
>
> Can you take a look if you can reproduce this? Without callchains it works in
> all tests I did.
Argh, it was because I forgot to set raw_data/size field for
--children case. I'll send the fix soon.
Maybe we can disable --children for tracepoint sessions (or if it
doesn't have symbol sort key)?
Thanks,
Namhyung
>
> [root@zoo ~]# perf record -g -e kmem:kmalloc -a
> ^C[ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 1.193 MB perf.data (250 samples) ]
>
> [root@zoo ~]# perf report
> perf: Segmentation fault
> -------- backtrace --------
> perf[0x539f1b]
> /lib64/libc.so.6(+0x34960)[0x7fc8e3752960]
> perf(pevent_read_number+0x78)[0x542e40]
> perf(pevent_read_number_field+0x70)[0x542ed3]
> /root/.traceevent/plugins/plugin_kmem.so(+0x603)[0x7fc8e1a6c603]
> perf(pevent_event_info+0x96)[0x547597]
> perf[0x4dce26]
> perf[0x4e0e89]
> perf(hist_entry_iter__add+0xee)[0x4e125e]
> perf[0x4304be]
> perf[0x4c2db3]
> perf[0x4c3301]
> perf[0x4c6089]
> perf(perf_session__process_events+0x3f1)[0x4c4b91]
> perf(cmd_report+0x120b)[0x4319cb]
> perf[0x47c871]
> perf(main+0x63f)[0x42242f]
> /lib64/libc.so.6(__libc_start_main+0xf0)[0x7fc8e373dfe0]
> perf[0x422549]
> [0x0]
> [root@zoo ~]# ls -la ~/.traceevent/
> total 12
> drwxr-xr-x. 3 acme acme 4096 May 4 2015 .
> drwx------. 61 acme acme 4096 Dec 16 21:12 ..
> drwxr-xr-x. 2 acme acme 4096 Nov 23 11:15 plugins
> [root@zoo ~]# ls -la ~/.traceevent
> lrwxrwxrwx. 1 root root 23 May 4 2015 /root/.traceevent -> /home/acme/.traceevent/
> [root@zoo ~]# perf record -e sched:sched_switch -a
>
>
> ^C[ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 1.704 MB perf.data (4967 samples) ]
>
> [root@zoo ~]# perf report
> [root@zoo ~]# perf record -g -e sched:sched_switch -a
> ^C[ perf record: Woken up 2 times to write data ]
> [ perf record: Captured and wrote 2.062 MB perf.data (4743 samples) ]
>
> [root@zoo ~]# perf report
> perf: Segmentation fault
> -------- backtrace --------
> perf[0x539f1b]
> /lib64/libc.so.6(+0x34960)[0x7fecb3223960]
> perf(pevent_read_number+0x60)[0x542e28]
> perf(pevent_read_number_field+0x70)[0x542ed3]
> perf(get_field_val+0x6b)[0x548cd5]
> perf(pevent_get_field_val+0x6b)[0x548e77]
> /root/.traceevent/plugins/plugin_sched_switch.so(+0x95b)[0x7fecb194195b]
> perf(pevent_event_info+0x96)[0x547597]
> perf[0x4dce26]
> perf[0x4e0e89]
> perf(hist_entry_iter__add+0xee)[0x4e125e]
> perf[0x4304be]
> perf[0x4c2db3]
> perf[0x4c3301]
> perf[0x4c5fdb]
> perf[0x4c3535]
> perf(perf_session__process_events+0x3a0)[0x4c4b40]
> perf(cmd_report+0x120b)[0x4319cb]
> perf[0x47c871]
> perf(main+0x63f)[0x42242f]
> /lib64/libc.so.6(__libc_start_main+0xf0)[0x7fecb320efe0]
> perf[0x422549]
> [0x0]
> [root@zoo ~]#
>
^ permalink raw reply [flat|nested] 26+ messages in thread
* [PATCH v2.1] perf hist: Save raw_data/size for tracepoint events
2015-12-15 15:35 ` [PATCH 02/10] perf hist: Save raw_data/size for tracepoint events Namhyung Kim
@ 2015-12-17 8:14 ` Namhyung Kim
2015-12-17 12:22 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-17 8:14 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The raw_data and raw_size fields are to provide tracepoint specific
information. They will be used by dynamic sort keys later.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
Fix segfault when --children is used.
tools/perf/util/hist.c | 4 ++++
tools/perf/util/sort.h | 2 ++
2 files changed, 6 insertions(+)
diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 039bb91d0a92..c0c92a3daa69 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -487,6 +487,8 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
.branch_info = bi,
.mem_info = mi,
.transaction = sample->transaction,
+ .raw_data = sample->raw_data,
+ .raw_size = sample->raw_size,
};
return hists__findnew_entry(hists, &entry, al, sample_self);
@@ -801,6 +803,8 @@ iter_add_next_cumulative_entry(struct hist_entry_iter *iter,
.sym = al->sym,
},
.parent = iter->parent,
+ .raw_data = sample->raw_data,
+ .raw_size = sample->raw_size,
};
int i;
struct callchain_cursor cursor;
diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
index 86f05e7a5566..d29898708dbd 100644
--- a/tools/perf/util/sort.h
+++ b/tools/perf/util/sort.h
@@ -122,6 +122,8 @@ struct hist_entry {
struct branch_info *branch_info;
struct hists *hists;
struct mem_info *mem_info;
+ void *raw_data;
+ u32 raw_size;
struct callchain_root callchain[0]; /* must be last member */
};
--
2.6.2
^ permalink raw reply related [flat|nested] 26+ messages in thread
* Re: [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2)
2015-12-17 7:56 ` Namhyung Kim
@ 2015-12-17 12:21 ` Arnaldo Carvalho de Melo
0 siblings, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-12-17 12:21 UTC (permalink / raw)
To: Namhyung Kim
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Em Thu, Dec 17, 2015 at 04:56:31PM +0900, Namhyung Kim escreveu:
> Hi Arnaldo,
>
> On Wed, Dec 16, 2015 at 09:17:59PM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Wed, Dec 16, 2015 at 12:35:33AM +0900, Namhyung Kim escreveu:
> > > Hello,
> > >
> > > This is an attempt to improve perf to deal with tracepoint events
> > > better. The perf tools can handle tracepoint events but perf report
> > > on them is less useful since they're always sampled in a fixed
> > > location and not provide event specific info. We can use perf script
> > > but I always wishes there's more convenient way to see the result.
> > >
> > > * changes in v2)
> > > - add 'trace' sort key and make it default (Jiri)
> > > - add '--raw-trace' option and '/raw' field modifier (Jiri)
> > > - support event name shortcuts (David)
> >
> > Can you take a look if you can reproduce this? Without callchains it works in
> > all tests I did.
>
> Argh, it was because I forgot to set raw_data/size field for
> --children case. I'll send the fix soon.
>
> Maybe we can disable --children for tracepoint sessions (or if it
> doesn't have symbol sort key)?
Looks like a plan, unless we want to have all the callchains that get to
some specific DSO or pid.
- Arnaldo
> Thanks,
> Namhyung
>
>
> >
> > [root@zoo ~]# perf record -g -e kmem:kmalloc -a
> > ^C[ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 1.193 MB perf.data (250 samples) ]
> >
> > [root@zoo ~]# perf report
> > perf: Segmentation fault
> > -------- backtrace --------
> > perf[0x539f1b]
> > /lib64/libc.so.6(+0x34960)[0x7fc8e3752960]
> > perf(pevent_read_number+0x78)[0x542e40]
> > perf(pevent_read_number_field+0x70)[0x542ed3]
> > /root/.traceevent/plugins/plugin_kmem.so(+0x603)[0x7fc8e1a6c603]
> > perf(pevent_event_info+0x96)[0x547597]
> > perf[0x4dce26]
> > perf[0x4e0e89]
> > perf(hist_entry_iter__add+0xee)[0x4e125e]
> > perf[0x4304be]
> > perf[0x4c2db3]
> > perf[0x4c3301]
> > perf[0x4c6089]
> > perf(perf_session__process_events+0x3f1)[0x4c4b91]
> > perf(cmd_report+0x120b)[0x4319cb]
> > perf[0x47c871]
> > perf(main+0x63f)[0x42242f]
> > /lib64/libc.so.6(__libc_start_main+0xf0)[0x7fc8e373dfe0]
> > perf[0x422549]
> > [0x0]
> > [root@zoo ~]# ls -la ~/.traceevent/
> > total 12
> > drwxr-xr-x. 3 acme acme 4096 May 4 2015 .
> > drwx------. 61 acme acme 4096 Dec 16 21:12 ..
> > drwxr-xr-x. 2 acme acme 4096 Nov 23 11:15 plugins
> > [root@zoo ~]# ls -la ~/.traceevent
> > lrwxrwxrwx. 1 root root 23 May 4 2015 /root/.traceevent -> /home/acme/.traceevent/
> > [root@zoo ~]# perf record -e sched:sched_switch -a
> >
> >
> > ^C[ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 1.704 MB perf.data (4967 samples) ]
> >
> > [root@zoo ~]# perf report
> > [root@zoo ~]# perf record -g -e sched:sched_switch -a
> > ^C[ perf record: Woken up 2 times to write data ]
> > [ perf record: Captured and wrote 2.062 MB perf.data (4743 samples) ]
> >
> > [root@zoo ~]# perf report
> > perf: Segmentation fault
> > -------- backtrace --------
> > perf[0x539f1b]
> > /lib64/libc.so.6(+0x34960)[0x7fecb3223960]
> > perf(pevent_read_number+0x60)[0x542e28]
> > perf(pevent_read_number_field+0x70)[0x542ed3]
> > perf(get_field_val+0x6b)[0x548cd5]
> > perf(pevent_get_field_val+0x6b)[0x548e77]
> > /root/.traceevent/plugins/plugin_sched_switch.so(+0x95b)[0x7fecb194195b]
> > perf(pevent_event_info+0x96)[0x547597]
> > perf[0x4dce26]
> > perf[0x4e0e89]
> > perf(hist_entry_iter__add+0xee)[0x4e125e]
> > perf[0x4304be]
> > perf[0x4c2db3]
> > perf[0x4c3301]
> > perf[0x4c5fdb]
> > perf[0x4c3535]
> > perf(perf_session__process_events+0x3a0)[0x4c4b40]
> > perf(cmd_report+0x120b)[0x4319cb]
> > perf[0x47c871]
> > perf(main+0x63f)[0x42242f]
> > /lib64/libc.so.6(__libc_start_main+0xf0)[0x7fecb320efe0]
> > perf[0x422549]
> > [0x0]
> > [root@zoo ~]#
> >
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH v2.1] perf hist: Save raw_data/size for tracepoint events
2015-12-17 8:14 ` [PATCH v2.1] " Namhyung Kim
@ 2015-12-17 12:22 ` Arnaldo Carvalho de Melo
0 siblings, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-12-17 12:22 UTC (permalink / raw)
To: Namhyung Kim
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
Em Thu, Dec 17, 2015 at 05:14:25PM +0900, Namhyung Kim escreveu:
> The raw_data and raw_size fields are to provide tracepoint specific
> information. They will be used by dynamic sort keys later.
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Ok, I'll update this in my local branch and test.
- Arnaldo
> ---
> Fix segfault when --children is used.
>
> tools/perf/util/hist.c | 4 ++++
> tools/perf/util/sort.h | 2 ++
> 2 files changed, 6 insertions(+)
>
> diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> index 039bb91d0a92..c0c92a3daa69 100644
> --- a/tools/perf/util/hist.c
> +++ b/tools/perf/util/hist.c
> @@ -487,6 +487,8 @@ struct hist_entry *__hists__add_entry(struct hists *hists,
> .branch_info = bi,
> .mem_info = mi,
> .transaction = sample->transaction,
> + .raw_data = sample->raw_data,
> + .raw_size = sample->raw_size,
> };
>
> return hists__findnew_entry(hists, &entry, al, sample_self);
> @@ -801,6 +803,8 @@ iter_add_next_cumulative_entry(struct hist_entry_iter *iter,
> .sym = al->sym,
> },
> .parent = iter->parent,
> + .raw_data = sample->raw_data,
> + .raw_size = sample->raw_size,
> };
> int i;
> struct callchain_cursor cursor;
> diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
> index 86f05e7a5566..d29898708dbd 100644
> --- a/tools/perf/util/sort.h
> +++ b/tools/perf/util/sort.h
> @@ -122,6 +122,8 @@ struct hist_entry {
> struct branch_info *branch_info;
> struct hists *hists;
> struct mem_info *mem_info;
> + void *raw_data;
> + u32 raw_size;
> struct callchain_root callchain[0]; /* must be last member */
> };
>
> --
> 2.6.2
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events
2015-12-15 15:35 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
@ 2015-12-20 13:51 ` Jiri Olsa
2015-12-20 14:02 ` Namhyung Kim
0 siblings, 1 reply; 26+ messages in thread
From: Jiri Olsa @ 2015-12-20 13:51 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Wed, Dec 16, 2015 at 12:35:38AM +0900, Namhyung Kim wrote:
SNIP
> +
> + if (!len)
> + len = hde_width(hde);
> +
> + return len;
> +}
> +
> +static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> + struct hist_entry *he)
> +{
> + struct hpp_dynamic_entry *hde;
> + size_t len = fmt->user_len;
> + struct trace_seq seq;
> + int ret;
> +
> + hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
> +
> + if (!len)
> + len = hde_width(hde);
> +
> + if (hists_to_evsel(he->hists) != hde->evsel)
> + return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
hum, how can this happen? ... "hists_to_evsel(he->hists) != hde->evsel"
thanks,
jirka
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events
2015-12-20 13:51 ` Jiri Olsa
@ 2015-12-20 14:02 ` Namhyung Kim
0 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-20 14:02 UTC (permalink / raw)
To: Jiri Olsa
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
Hi Jiri,
On Sun, Dec 20, 2015 at 02:51:32PM +0100, Jiri Olsa wrote:
> On Wed, Dec 16, 2015 at 12:35:38AM +0900, Namhyung Kim wrote:
>
> SNIP
>
> > +
> > + if (!len)
> > + len = hde_width(hde);
> > +
> > + return len;
> > +}
> > +
> > +static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> > + struct hist_entry *he)
> > +{
> > + struct hpp_dynamic_entry *hde;
> > + size_t len = fmt->user_len;
> > + struct trace_seq seq;
> > + int ret;
> > +
> > + hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
> > +
> > + if (!len)
> > + len = hde_width(hde);
> > +
> > + if (hists_to_evsel(he->hists) != hde->evsel)
> > + return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
>
> hum, how can this happen? ... "hists_to_evsel(he->hists) != hde->evsel"
If there's more than one event, a dynamic sort key is defined for one
event. So other events should not be affected by the sort key and
show "N/A" in the output.
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys
2015-12-15 15:35 ` [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys Namhyung Kim
@ 2015-12-20 14:12 ` Jiri Olsa
2015-12-21 8:36 ` Namhyung Kim
0 siblings, 1 reply; 26+ messages in thread
From: Jiri Olsa @ 2015-12-20 14:12 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Wed, Dec 16, 2015 at 12:35:39AM +0900, Namhyung Kim wrote:
SNIP
> struct trace_seq seq;
> + char *str, *pos;
> + struct format_field *field;
> + struct pevent_record rec = {
> + .cpu = he->cpu,
> + .data = he->raw_data,
> + .size = he->raw_size,
> + };
> + size_t namelen;
> int ret;
>
> hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
> @@ -1605,9 +1654,28 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> if (hists_to_evsel(he->hists) != hde->evsel)
> return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
>
> + field = hde->field;
> trace_seq_init(&seq);
> - print_event_field(&seq, he->raw_data, hde->field);
> - ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, seq.buffer);
> + pevent_event_info(&seq, field->event, &rec);
hm, maybe we could cache the seq.buffer data in hist_entry?
IIRC pevent_event_info code does a lot of stuff, so
it might be better to call it just once.. caching
its results in hist_entry seems like small price
jirka
> +
> + namelen = strlen(field->name);
> + str = strtok_r(seq.buffer, " ", &pos);
> + while (str) {
> + if (!strncmp(str, field->name, namelen)) {
> + str += namelen + 1;
> + break;
> + }
> +
> + str = strtok_r(NULL, " ", &pos);
> + }
> +
SNIP
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 08/10] perf tools: Add --raw-trace option
2015-12-15 15:35 ` [PATCH 08/10] perf tools: Add --raw-trace option Namhyung Kim
@ 2015-12-20 14:58 ` Jiri Olsa
2015-12-21 8:44 ` Namhyung Kim
0 siblings, 1 reply; 26+ messages in thread
From: Jiri Olsa @ 2015-12-20 14:58 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Wed, Dec 16, 2015 at 12:35:41AM +0900, Namhyung Kim wrote:
> The --raw-trace option is to prevent pretty printing by event's
> print_fmt or plugin. Besides that, each dynamic sort key now receives
> 'raw' suffix separated by '/' to apply the raw trace to a specific
> field.
>
> $ perf report -s comm,kmem:kmalloc.gfp_flags
> ...
> # Overhead Command gfp_flags
> # ........ ....... ...................
> #
> 99.89% perf GFP_NOFS|GFP_ZERO
> 0.06% sleep GFP_KERNEL
> 0.03% perf GFP_KERNEL|GFP_ZERO
> 0.01% perf GFP_KERNEL
>
> Now
>
> $ perf report -s comm,kmem:kmalloc.gfp_flags --raw-trace
> or
> $ perf report -s comm,kmem:kmalloc.gfp_flags/raw
> ...
> # Overhead Command gfp_flags
> # ........ ....... ..........
> #
> 99.89% perf 32848
> 0.06% sleep 208
> 0.03% perf 32976
> 0.01% perf 208
>
> Suggested-by: Jiri Olsa <jolsa@redhat.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
I think the default is good with the 'trace' sort key as it is now:
$ ./perf report -s trace
27.01% offlineimap:17701 [120] S ==> swapper/1:0 [120]
27.00% swapper/1:0 [120] R ==> offlineimap:17701 [120]
But for '--raw-trace' option rather than displaying fields in the '=' notation:
$ ./perf report -s trace --raw-trace
27.01% prev_comm=offlineimap prev_pid=17701 prev_prio=120 prev_state=1 next_comm=swapper/1 next_pid=0 next_prio=120
27.00% prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=0 next_comm=offlineimap next_pid=17701 next_prio=120
it would be more readable to register all available columns as is possible to do now with:
$ ./perf report -s prev_comm,prev_pid,prev_prio,prev_state,next_comm,next_pid,next_prio
Overhead prev_comm prev_pid prev_prio prev_state next_comm next_pid next_prio
27.01% offlineimap 17701 120 1 swapper/1 0 120
27.00% swapper/1 0 120 0 offlineimap 17701 120
it would be default output for 'perf report -s trace --raw-trace' command
how about that?
thanks,
jirka
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys
2015-12-20 14:12 ` Jiri Olsa
@ 2015-12-21 8:36 ` Namhyung Kim
0 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-21 8:36 UTC (permalink / raw)
To: Jiri Olsa
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
Hi Jiri,
On Sun, Dec 20, 2015 at 03:12:45PM +0100, Jiri Olsa wrote:
> On Wed, Dec 16, 2015 at 12:35:39AM +0900, Namhyung Kim wrote:
>
> SNIP
>
> > struct trace_seq seq;
> > + char *str, *pos;
> > + struct format_field *field;
> > + struct pevent_record rec = {
> > + .cpu = he->cpu,
> > + .data = he->raw_data,
> > + .size = he->raw_size,
> > + };
> > + size_t namelen;
> > int ret;
> >
> > hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
> > @@ -1605,9 +1654,28 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
> > if (hists_to_evsel(he->hists) != hde->evsel)
> > return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
> >
> > + field = hde->field;
> > trace_seq_init(&seq);
> > - print_event_field(&seq, he->raw_data, hde->field);
> > - ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, seq.buffer);
> > + pevent_event_info(&seq, field->event, &rec);
>
> hm, maybe we could cache the seq.buffer data in hist_entry?
>
> IIRC pevent_event_info code does a lot of stuff, so
> it might be better to call it just once.. caching
> its results in hist_entry seems like small price
Right. I did the same thing for 'trace' sort key, so will move it to
here.
Thanks,
Namhyung
>
> > +
> > + namelen = strlen(field->name);
> > + str = strtok_r(seq.buffer, " ", &pos);
> > + while (str) {
> > + if (!strncmp(str, field->name, namelen)) {
> > + str += namelen + 1;
> > + break;
> > + }
> > +
> > + str = strtok_r(NULL, " ", &pos);
> > + }
> > +
>
> SNIP
>
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 08/10] perf tools: Add --raw-trace option
2015-12-20 14:58 ` Jiri Olsa
@ 2015-12-21 8:44 ` Namhyung Kim
2015-12-22 6:57 ` Jiri Olsa
0 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-21 8:44 UTC (permalink / raw)
To: Jiri Olsa
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Sun, Dec 20, 2015 at 03:58:42PM +0100, Jiri Olsa wrote:
> On Wed, Dec 16, 2015 at 12:35:41AM +0900, Namhyung Kim wrote:
> > The --raw-trace option is to prevent pretty printing by event's
> > print_fmt or plugin. Besides that, each dynamic sort key now receives
> > 'raw' suffix separated by '/' to apply the raw trace to a specific
> > field.
> >
> > $ perf report -s comm,kmem:kmalloc.gfp_flags
> > ...
> > # Overhead Command gfp_flags
> > # ........ ....... ...................
> > #
> > 99.89% perf GFP_NOFS|GFP_ZERO
> > 0.06% sleep GFP_KERNEL
> > 0.03% perf GFP_KERNEL|GFP_ZERO
> > 0.01% perf GFP_KERNEL
> >
> > Now
> >
> > $ perf report -s comm,kmem:kmalloc.gfp_flags --raw-trace
> > or
> > $ perf report -s comm,kmem:kmalloc.gfp_flags/raw
> > ...
> > # Overhead Command gfp_flags
> > # ........ ....... ..........
> > #
> > 99.89% perf 32848
> > 0.06% sleep 208
> > 0.03% perf 32976
> > 0.01% perf 208
> >
> > Suggested-by: Jiri Olsa <jolsa@redhat.com>
> > Cc: Steven Rostedt <rostedt@goodmis.org>
> > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
>
> I think the default is good with the 'trace' sort key as it is now:
>
> $ ./perf report -s trace
> 27.01% offlineimap:17701 [120] S ==> swapper/1:0 [120]
> 27.00% swapper/1:0 [120] R ==> offlineimap:17701 [120]
>
>
> But for '--raw-trace' option rather than displaying fields in the '=' notation:
>
> $ ./perf report -s trace --raw-trace
> 27.01% prev_comm=offlineimap prev_pid=17701 prev_prio=120 prev_state=1 next_comm=swapper/1 next_pid=0 next_prio=120
> 27.00% prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=0 next_comm=offlineimap next_pid=17701 next_prio=120
>
>
> it would be more readable to register all available columns as is possible to do now with:
>
> $ ./perf report -s prev_comm,prev_pid,prev_prio,prev_state,next_comm,next_pid,next_prio
> Overhead prev_comm prev_pid prev_prio prev_state next_comm next_pid next_prio
> 27.01% offlineimap 17701 120 1 swapper/1 0 120
> 27.00% swapper/1 0 120 0 offlineimap 17701 120
>
>
> it would be default output for 'perf report -s trace --raw-trace' command
>
> how about that?
I agree with the latter is much more readable. But the dynamic sort
keys are event specific while 'trace' is generic. So if there are
more than one events, dynamic sort keys should be generated for each
event and they'll show "N/A" for other events.
Also I don't like the --raw-trace option affects number of sort keys.
Maybe it'd be better adding 'EVENT.*' dynamic sort key for your case?
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 08/10] perf tools: Add --raw-trace option
2015-12-21 8:44 ` Namhyung Kim
@ 2015-12-22 6:57 ` Jiri Olsa
2015-12-22 16:19 ` Namhyung Kim
0 siblings, 1 reply; 26+ messages in thread
From: Jiri Olsa @ 2015-12-22 6:57 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Mon, Dec 21, 2015 at 05:44:41PM +0900, Namhyung Kim wrote:
SNIP
> >
> > I think the default is good with the 'trace' sort key as it is now:
> >
> > $ ./perf report -s trace
> > 27.01% offlineimap:17701 [120] S ==> swapper/1:0 [120]
> > 27.00% swapper/1:0 [120] R ==> offlineimap:17701 [120]
> >
> >
> > But for '--raw-trace' option rather than displaying fields in the '=' notation:
> >
> > $ ./perf report -s trace --raw-trace
> > 27.01% prev_comm=offlineimap prev_pid=17701 prev_prio=120 prev_state=1 next_comm=swapper/1 next_pid=0 next_prio=120
> > 27.00% prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=0 next_comm=offlineimap next_pid=17701 next_prio=120
> >
> >
> > it would be more readable to register all available columns as is possible to do now with:
> >
> > $ ./perf report -s prev_comm,prev_pid,prev_prio,prev_state,next_comm,next_pid,next_prio
> > Overhead prev_comm prev_pid prev_prio prev_state next_comm next_pid next_prio
> > 27.01% offlineimap 17701 120 1 swapper/1 0 120
> > 27.00% swapper/1 0 120 0 offlineimap 17701 120
> >
> >
> > it would be default output for 'perf report -s trace --raw-trace' command
> >
> > how about that?
>
>
> I agree with the latter is much more readable. But the dynamic sort
> keys are event specific while 'trace' is generic. So if there are
> more than one events, dynamic sort keys should be generated for each
> event and they'll show "N/A" for other events.
I see.. haven't realized that, maybe we should add
columns based in the hists object.. but I guess
that's out of scope of this patchset ;-)
>
> Also I don't like the --raw-trace option affects number of sort keys.
> Maybe it'd be better adding 'EVENT.*' dynamic sort key for your case?
that's good workaround, thanks
jirka
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 08/10] perf tools: Add --raw-trace option
2015-12-22 6:57 ` Jiri Olsa
@ 2015-12-22 16:19 ` Namhyung Kim
0 siblings, 0 replies; 26+ messages in thread
From: Namhyung Kim @ 2015-12-22 16:19 UTC (permalink / raw)
To: Jiri Olsa
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Tue, Dec 22, 2015 at 07:57:12AM +0100, Jiri Olsa wrote:
> On Mon, Dec 21, 2015 at 05:44:41PM +0900, Namhyung Kim wrote:
>
> SNIP
>
> > >
> > > I think the default is good with the 'trace' sort key as it is now:
> > >
> > > $ ./perf report -s trace
> > > 27.01% offlineimap:17701 [120] S ==> swapper/1:0 [120]
> > > 27.00% swapper/1:0 [120] R ==> offlineimap:17701 [120]
> > >
> > >
> > > But for '--raw-trace' option rather than displaying fields in the '=' notation:
> > >
> > > $ ./perf report -s trace --raw-trace
> > > 27.01% prev_comm=offlineimap prev_pid=17701 prev_prio=120 prev_state=1 next_comm=swapper/1 next_pid=0 next_prio=120
> > > 27.00% prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=0 next_comm=offlineimap next_pid=17701 next_prio=120
> > >
> > >
> > > it would be more readable to register all available columns as is possible to do now with:
> > >
> > > $ ./perf report -s prev_comm,prev_pid,prev_prio,prev_state,next_comm,next_pid,next_prio
> > > Overhead prev_comm prev_pid prev_prio prev_state next_comm next_pid next_prio
> > > 27.01% offlineimap 17701 120 1 swapper/1 0 120
> > > 27.00% swapper/1 0 120 0 offlineimap 17701 120
> > >
> > >
> > > it would be default output for 'perf report -s trace --raw-trace' command
> > >
> > > how about that?
> >
> >
> > I agree with the latter is much more readable. But the dynamic sort
> > keys are event specific while 'trace' is generic. So if there are
> > more than one events, dynamic sort keys should be generated for each
> > event and they'll show "N/A" for other events.
>
> I see.. haven't realized that, maybe we should add
> columns based in the hists object.. but I guess
> that's out of scope of this patchset ;-)
Right.
On a second thought, I can make it skip dynamic fields if they're for
other event. Then we don't need to maintain per-event sort keys IMHO.
>
> >
> > Also I don't like the --raw-trace option affects number of sort keys.
> > Maybe it'd be better adding 'EVENT.*' dynamic sort key for your case?
>
> that's good workaround, thanks
With above trick, I think I can add all dynamic fields automatically
as default sort key when --raw-trace is given as you said. Will try.
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events
2015-12-21 14:26 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
@ 2016-01-05 10:38 ` Jiri Olsa
0 siblings, 0 replies; 26+ messages in thread
From: Jiri Olsa @ 2016-01-05 10:38 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, LKML,
David Ahern, Steven Rostedt, Frederic Weisbecker, Andi Kleen,
Wang Nan
On Mon, Dec 21, 2015 at 11:26:48PM +0900, Namhyung Kim wrote:
SNIP
> + free(str);
> + return ret;
> +}
> +
> static int __sort_dimension__add(struct sort_dimension *sd)
> {
> if (sd->taken)
> @@ -1667,6 +1887,9 @@ static int sort_dimension__add(const char *tok,
sort_dimension__add's evlist arg could loose the '__maybe_unused' now
thanks,
jirka
> return 0;
> }
>
> + if (!add_dynamic_entry(evlist, tok))
> + return 0;
> +
> return -ESRCH;
> }
>
> --
> 2.6.4
>
^ permalink raw reply [flat|nested] 26+ messages in thread
* [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events
2015-12-21 14:26 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v3) Namhyung Kim
@ 2015-12-21 14:26 ` Namhyung Kim
2016-01-05 10:38 ` Jiri Olsa
0 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2015-12-21 14:26 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
Steven Rostedt, Frederic Weisbecker, Andi Kleen, Wang Nan
The existing sort keys are less useful for tracepoint events in that
they are always sampled at a same location.
For example, report on sched:sched_switch event looks like following
# Overhead Command Shared Object Symbol
# ........ ............... ................ ..............
#
47.22% swapper [kernel.vmlinux] [k] __schedule
21.67% transmission-gt [kernel.vmlinux] [k] __schedule
8.23% netctl-auto [kernel.vmlinux] [k] __schedule
5.53% kworker/0:1H [kernel.vmlinux] [k] __schedule
1.98% Xephyr [kernel.vmlinux] [k] __schedule
1.33% irq/33-iwlwifi [kernel.vmlinux] [k] __schedule
1.17% wpa_cli [kernel.vmlinux] [k] __schedule
1.13% rcu_preempt [kernel.vmlinux] [k] __schedule
0.85% ksoftirqd/0 [kernel.vmlinux] [k] __schedule
0.77% Timer [kernel.vmlinux] [k] __schedule
In fact, tracepoints have meaningful information in their fields but
there's no way to use in the perf report currently. The dynamic sort
keys are to overcome this problem.
The sched:sched_switch events have following fields:
# sudo cat /sys/kernel/debug/tracing/events/sched/sched_switch/format
name: sched_switch
ID: 268
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:char prev_comm[16]; offset:8; size:16; signed:1;
field:pid_t prev_pid; offset:24; size:4; signed:1;
field:int prev_prio; offset:28; size:4; signed:1;
field:long prev_state; offset:32; size:8; signed:1;
field:char next_comm[16]; offset:40; size:16; signed:1;
field:pid_t next_pid; offset:56; size:4; signed:1;
field:int next_prio; offset:60; size:4; signed:1;
print fmt: "prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==>
next_comm=%s next_pid=%d next_prio=%d",
REC->prev_comm, REC->prev_pid, REC->prev_prio,
REC->prev_state & (2048-1) ? __print_flags(REC->prev_state & (2048-1),
"|", { 1, "S"} , { 2, "D" }, { 4, "T" }, { 8, "t" }, { 16, "Z" }, { 32, "X" },
{ 64, "x" }, { 128, "K"}, { 256, "W" }, { 512, "P" }, { 1024, "N" }) : "R",
REC->prev_state & 2048 ? "+" : "", REC->next_comm, REC->next_pid, REC->next_prio
With dynamic sort keys, you can use <event.field> as a sort key. Those
dynamic keys are checked and created on demand. For instance, below is
to sort by next_pid field on the same data file.
$ perf report -s comm,sched:sched_switch.next_pid --stdio
...
# Overhead Command next_pid
# ........ ............... ..........
#
21.23% transmission-gt 0
20.86% swapper 17773
6.62% netctl-auto 0
5.25% swapper 109
5.21% kworker/0:1H 0
1.98% Xephyr 0
1.98% swapper 6524
1.98% swapper 27478
1.37% swapper 27476
1.17% swapper 233
Multiple dynamic sort keys are also supported:
$ perf report -s comm,sched:sched_switch.next_pid,sched:sched_switch.next_comm --stdio
...
# Overhead Command next_pid next_comm
# ........ ............... .......... ................
#
20.86% swapper 17773 transmission-gt
9.64% transmission-gt 0 swapper/0
9.16% transmission-gt 0 swapper/2
5.25% swapper 109 kworker/0:1H
5.21% kworker/0:1H 0 swapper/0
2.14% netctl-auto 0 swapper/2
1.98% netctl-auto 0 swapper/0
1.98% swapper 6524 Xephyr
1.98% swapper 27478 netctl-auto
1.78% transmission-gt 0 swapper/3
1.53% Xephyr 0 swapper/0
1.29% netctl-auto 0 swapper/1
1.29% swapper 27476 netctl-auto
1.21% netctl-auto 0 swapper/3
1.17% swapper 233 irq/33-iwlwifi
Note that pid 0 exists for each cpu so have comm of 'swapper/N'.
Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/util/sort.c | 223 +++++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 223 insertions(+)
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 0c038a27fe5c..f2bac1c149a9 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1531,6 +1531,226 @@ static int __sort_dimension__add_hpp_output(struct sort_dimension *sd)
return 0;
}
+struct hpp_dynamic_entry {
+ struct perf_hpp_fmt hpp;
+ struct perf_evsel *evsel;
+ struct format_field *field;
+ unsigned dynamic_len;
+};
+
+static int hde_width(struct hpp_dynamic_entry *hde)
+{
+ if (!hde->hpp.len) {
+ int len = hde->dynamic_len;
+ int namelen = strlen(hde->field->name);
+ int fieldlen = hde->field->size;
+
+ if (namelen > len)
+ len = namelen;
+
+ if (!(hde->field->flags & FIELD_IS_STRING)) {
+ /* length for print hex numbers */
+ fieldlen = hde->field->size * 2 + 2;
+ }
+ if (fieldlen > len)
+ len = fieldlen;
+
+ hde->hpp.len = len;
+ }
+ return hde->hpp.len;
+}
+
+static int __sort__hde_header(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
+ struct perf_evsel *evsel __maybe_unused)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, hde->field->name);
+}
+
+static int __sort__hde_width(struct perf_hpp_fmt *fmt,
+ struct perf_hpp *hpp __maybe_unused,
+ struct perf_evsel *evsel __maybe_unused)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ return len;
+}
+
+static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
+ struct hist_entry *he)
+{
+ struct hpp_dynamic_entry *hde;
+ size_t len = fmt->user_len;
+ struct trace_seq seq;
+ int ret;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (!len)
+ len = hde_width(hde);
+
+ if (hists_to_evsel(he->hists) != hde->evsel)
+ return scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, "N/A");
+
+ trace_seq_init(&seq);
+ print_event_field(&seq, he->raw_data, hde->field);
+ ret = scnprintf(hpp->buf, hpp->size, "%*.*s", len, len, seq.buffer);
+ trace_seq_destroy(&seq);
+ return ret;
+}
+
+static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
+ struct hist_entry *a, struct hist_entry *b)
+{
+ struct hpp_dynamic_entry *hde;
+ struct format_field *field;
+ unsigned offset, size;
+
+ hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
+
+ if (hists_to_evsel(a->hists) != hde->evsel)
+ return 0;
+
+ field = hde->field;
+ if (field->flags & FIELD_IS_DYNAMIC) {
+ unsigned long long dyn;
+
+ pevent_read_number_field(field, a->raw_data, &dyn);
+ offset = dyn & 0xffff;
+ size = (dyn >> 16) & 0xffff;
+
+ /* record max width for output */
+ if (size > hde->dynamic_len)
+ hde->dynamic_len = size;
+ } else {
+ offset = field->offset;
+ size = field->size;
+ }
+
+ return memcmp(a->raw_data + offset, b->raw_data + offset, size);
+}
+
+static struct hpp_dynamic_entry *
+__alloc_dynamic_entry(struct perf_evsel *evsel, struct format_field *field)
+{
+ struct hpp_dynamic_entry *hde;
+
+ hde = malloc(sizeof(*hde));
+ if (hde == NULL) {
+ pr_debug("Memory allocation failed\n");
+ return NULL;
+ }
+
+ hde->evsel = evsel;
+ hde->field = field;
+ hde->dynamic_len = 0;
+
+ hde->hpp.name = field->name;
+ hde->hpp.header = __sort__hde_header;
+ hde->hpp.width = __sort__hde_width;
+ hde->hpp.entry = __sort__hde_entry;
+ hde->hpp.color = NULL;
+
+ hde->hpp.cmp = __sort__hde_cmp;
+ hde->hpp.collapse = __sort__hde_cmp;
+ hde->hpp.sort = __sort__hde_cmp;
+
+ INIT_LIST_HEAD(&hde->hpp.list);
+ INIT_LIST_HEAD(&hde->hpp.sort_list);
+ hde->hpp.elide = false;
+ hde->hpp.len = 0;
+ hde->hpp.user_len = 0;
+
+ return hde;
+}
+
+static int add_dynamic_entry(struct perf_evlist *evlist, const char *tok)
+{
+ char *str, *event_name, *field_name;
+ struct perf_evsel *evsel, *pos;
+ struct event_format *format;
+ struct format_field *field;
+ struct hpp_dynamic_entry *hde;
+ int ret = 0;
+
+ if (evlist == NULL)
+ return -ENOENT;
+
+ str = strdup(tok);
+ if (str == NULL)
+ return -ENOMEM;
+
+ event_name = str;
+ field_name = strchr(str, '.');
+ if (field_name == NULL) {
+ ret = -EINVAL;
+ goto out;
+ }
+ *field_name++ = '\0';
+
+ evsel = NULL;
+ evlist__for_each(evlist, pos) {
+ if (!strcmp(pos->name, event_name)) {
+ evsel = pos;
+ break;
+ }
+ }
+
+ if (evsel == NULL) {
+ pr_debug("Cannot find event: %s\n", event_name);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ if (evsel->attr.type != PERF_TYPE_TRACEPOINT) {
+ pr_debug("%s is not a tracepoint event\n", event_name);
+ ret = -EINVAL;
+ goto out;
+ }
+
+ format = pevent_find_event(evsel->tp_format->pevent,
+ evsel->attr.config);
+ if (format == NULL) {
+ pr_debug("Cannot find event format for %s (id: %u)\n",
+ event_name, (unsigned) evsel->attr.config);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ field = pevent_find_any_field(format, field_name);
+ if (field == NULL) {
+ pr_debug("Cannot find event field for %s.%s\n",
+ event_name, field_name);
+ ret = -ENOENT;
+ goto out;
+ }
+
+ hde = __alloc_dynamic_entry(evsel, field);
+ if (hde == NULL) {
+ ret = -ENOMEM;
+ goto out;
+ }
+
+ perf_hpp__register_sort_field(&hde->hpp);
+
+out:
+ free(str);
+ return ret;
+}
+
static int __sort_dimension__add(struct sort_dimension *sd)
{
if (sd->taken)
@@ -1667,6 +1887,9 @@ static int sort_dimension__add(const char *tok,
return 0;
}
+ if (!add_dynamic_entry(evlist, tok))
+ return 0;
+
return -ESRCH;
}
--
2.6.4
^ permalink raw reply related [flat|nested] 26+ messages in thread
end of thread, other threads:[~2016-01-05 10:38 UTC | newest]
Thread overview: 26+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-12-15 15:35 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Namhyung Kim
2015-12-15 15:35 ` [PATCH 01/10] perf hist: Pass struct sample to __hists__add_entry() Namhyung Kim
2015-12-15 15:35 ` [PATCH 02/10] perf hist: Save raw_data/size for tracepoint events Namhyung Kim
2015-12-17 8:14 ` [PATCH v2.1] " Namhyung Kim
2015-12-17 12:22 ` Arnaldo Carvalho de Melo
2015-12-15 15:35 ` [PATCH 03/10] tools lib traceevent: Factor out and export print_event_field[s] Namhyung Kim
2015-12-15 15:35 ` [PATCH 04/10] perf tools: Pass evlist to setup_sorting() Namhyung Kim
2015-12-15 15:35 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
2015-12-20 13:51 ` Jiri Olsa
2015-12-20 14:02 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 06/10] perf tools: Try to show pretty printed output for dynamic sort keys Namhyung Kim
2015-12-20 14:12 ` Jiri Olsa
2015-12-21 8:36 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 07/10] perf tools: Add 'trace' sort key Namhyung Kim
2015-12-15 15:35 ` [PATCH 08/10] perf tools: Add --raw-trace option Namhyung Kim
2015-12-20 14:58 ` Jiri Olsa
2015-12-21 8:44 ` Namhyung Kim
2015-12-22 6:57 ` Jiri Olsa
2015-12-22 16:19 ` Namhyung Kim
2015-12-15 15:35 ` [PATCH 09/10] perf tools: Make 'trace' sort key default for tracepoint events Namhyung Kim
2015-12-15 15:35 ` [PATCH 10/10] perf tools: Support shortcuts for events in dynamic sort keys Namhyung Kim
2015-12-17 0:17 ` [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v2) Arnaldo Carvalho de Melo
2015-12-17 7:56 ` Namhyung Kim
2015-12-17 12:21 ` Arnaldo Carvalho de Melo
2015-12-21 14:26 [PATCHSET 00/10] perf tools: Support dynamic sort keys for tracepoints (v3) Namhyung Kim
2015-12-21 14:26 ` [PATCH 05/10] perf tools: Add dynamic sort key for tracepoint events Namhyung Kim
2016-01-05 10:38 ` Jiri Olsa
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.