This patch series adds more features to the perf timechart command:
* -n option that adds possibility to limit number of tasks on SVG
* -T option that adds possibility to show only tasks related info
* -T and -P options now work with `perf timechart record` command to keep
perf.data small
* -g option that adds possibility to record and add callchain to the SVG so
it's now possible to understand why some task went to sleep or what code
path woke it up
* add titles to the SVG blocks so it's possible to see how long task is
running/sleeping/blocked
Stanislav Fomichev (6):
perf timechart: always try to print at least 15 tasks
perf timechart: use proc_num to implement --power-only
perf timechart: add support for displaying only tasks related data
perf timechart: group figures and add title with details
perf timechart: add support for -P and -T in timechart recording
perf timechart: add backtrace support
tools/perf/builtin-timechart.c | 289 ++++++++++++++++++++++++++++++++---------
tools/perf/util/svghelper.c | 77 ++++++++++-
tools/perf/util/svghelper.h | 11 +-
3 files changed, 305 insertions(+), 72 deletions(-)
--
1.8.1.2
Always try to print at least 15 tasks no matter how long they run.
Add -n option to specify desired number of tasks to print.
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 22 +++++++++++++++-------
1 file changed, 15 insertions(+), 7 deletions(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index c2e02319347a..d965f26308ed 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -40,6 +40,8 @@
#define SUPPORT_OLD_POWER_EVENTS 1
#define PWR_EVENT_EXIT -1
+static int proc_num = 15;
+
static unsigned int numcpus;
static u64 min_freq; /* Lowest CPU frequency seen */
@@ -944,15 +946,17 @@ static void write_svg_file(const char *filename)
{
u64 i;
int count;
+ int thresh = TIME_THRESH;
numcpus++;
- count = determine_display_tasks(TIME_THRESH);
-
- /* We'd like to show at least 15 tasks; be less picky if we have fewer */
- if (count < 15)
- count = determine_display_tasks(TIME_THRESH / 10);
+ /* We'd like to show at least proc_num tasks;
+ * be less picky if we have fewer */
+ do {
+ count = determine_display_tasks(thresh);
+ thresh /= 10;
+ } while (thresh && count < proc_num);
open_svg(filename, numcpus, count, first_time, last_time);
@@ -963,9 +967,11 @@ static void write_svg_file(const char *filename)
svg_cpu_box(i, max_freq, turbo_frequency);
draw_cpu_usage();
- draw_process_bars();
+ if (proc_num)
+ draw_process_bars();
draw_c_p_states();
- draw_wakeups();
+ if (proc_num)
+ draw_wakeups();
svg_close();
}
@@ -1094,6 +1100,8 @@ int cmd_timechart(int argc, const char **argv,
parse_process),
OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
"Look for files with symbols relative to this directory"),
+ OPT_INTEGER('n', "number", &proc_num,
+ "min. number of tasks to print"),
OPT_END()
};
const char * const timechart_usage[] = {
--
1.8.1.2
In order to make SVG smaller and faster to browse add possibility to
switch off power related information with -T switch.
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 15 ++++++++++++++-
1 file changed, 14 insertions(+), 1 deletion(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index e6c041301aa4..c7b30a8c7f3b 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -41,6 +41,7 @@
#define PWR_EVENT_EXIT -1
static int proc_num = 15;
+static bool no_power;
static unsigned int numcpus;
@@ -967,7 +968,8 @@ static void write_svg_file(const char *filename)
draw_cpu_usage();
if (proc_num)
draw_process_bars();
- draw_c_p_states();
+ if (!no_power)
+ draw_c_p_states();
if (proc_num)
draw_wakeups();
@@ -1076,6 +1078,15 @@ static int __cmd_record(int argc, const char **argv)
}
static int
+parse_tasks(const struct option *opt __maybe_unused,
+ const char *arg __maybe_unused,
+ int unset __maybe_unused)
+{
+ no_power = 1;
+ return 0;
+}
+
+static int
parse_process(const struct option *opt __maybe_unused, const char *arg,
int __maybe_unused unset)
{
@@ -1103,6 +1114,8 @@ int cmd_timechart(int argc, const char **argv,
OPT_INTEGER('w', "width", &svg_page_width, "page width"),
OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
"output power data only", parse_power),
+ OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
+ "output processes data only", parse_tasks),
OPT_CALLBACK('p', "process", NULL, "process",
"process selector. Pass a pid or process name.",
parse_process),
--
1.8.1.2
Add titles to figures so we can run SVG interactively in Firefox
and check event details in the tooltips.
This also aids exploring SVG with Inkscape because when user clicks on
one part of logical figure, all parts are selected.
It's also possible to read titles with Inkscape in the object details.
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 4 ++--
tools/perf/util/svghelper.c | 54 +++++++++++++++++++++++++++++++++++++++++-
tools/perf/util/svghelper.h | 3 ++-
3 files changed, 57 insertions(+), 4 deletions(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index c7b30a8c7f3b..4d2ac96b75b1 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -798,9 +798,9 @@ static void draw_process_bars(void)
if (sample->type == TYPE_RUNNING)
svg_sample(Y, sample->cpu, sample->start_time, sample->end_time);
if (sample->type == TYPE_BLOCKED)
- svg_box(Y, sample->start_time, sample->end_time, "blocked");
+ svg_blocked(Y, sample->cpu, sample->start_time, sample->end_time);
if (sample->type == TYPE_WAITING)
- svg_waiting(Y, sample->start_time, sample->end_time);
+ svg_waiting(Y, sample->cpu, sample->start_time, sample->end_time);
sample = sample->next;
}
diff --git a/tools/perf/util/svghelper.c b/tools/perf/util/svghelper.c
index 96c866045d60..c41be3c5722b 100644
--- a/tools/perf/util/svghelper.c
+++ b/tools/perf/util/svghelper.c
@@ -95,6 +95,7 @@ void open_svg(const char *filename, int cpus, int rows, u64 start, u64 end)
total_height = (1 + rows + cpu2slot(cpus)) * SLOT_MULT;
fprintf(svgfile, "<?xml version=\"1.0\" standalone=\"no\"?> \n");
+ fprintf(svgfile, "<!DOCTYPE svg SYSTEM \"http://www.w3.org/Graphics/SVG/1.1/DTD/svg11.dtd\">\n");
fprintf(svgfile, "<svg width=\"%i\" height=\"%" PRIu64 "\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n", svg_page_width, total_height);
fprintf(svgfile, "<defs>\n <style type=\"text/css\">\n <![CDATA[\n");
@@ -128,12 +129,29 @@ void svg_box(int Yslot, u64 start, u64 end, const char *type)
time2pixels(start), time2pixels(end)-time2pixels(start), Yslot * SLOT_MULT, SLOT_HEIGHT, type);
}
+static char *time_to_string(u64 duration);
+void svg_blocked(int Yslot, int cpu, u64 start, u64 end)
+{
+ if (!svgfile)
+ return;
+
+ fprintf(svgfile, "<g>\n");
+ fprintf(svgfile, "<title>#%d blocked %s</title>\n", cpu,
+ time_to_string(end - start));
+ svg_box(Yslot, start, end, "blocked");
+ fprintf(svgfile, "</g>\n");
+}
+
void svg_sample(int Yslot, int cpu, u64 start, u64 end)
{
double text_size;
if (!svgfile)
return;
+ fprintf(svgfile, "<g>\n");
+
+ fprintf(svgfile, "<title>#%d running %s</title>\n",
+ cpu, time_to_string(end - start));
fprintf(svgfile, "<rect x=\"%4.8f\" width=\"%4.8f\" y=\"%4.1f\" height=\"%4.1f\" class=\"sample\"/>\n",
time2pixels(start), time2pixels(end)-time2pixels(start), Yslot * SLOT_MULT, SLOT_HEIGHT);
@@ -148,6 +166,7 @@ void svg_sample(int Yslot, int cpu, u64 start, u64 end)
fprintf(svgfile, "<text x=\"%1.8f\" y=\"%1.8f\" font-size=\"%1.8fpt\">%i</text>\n",
time2pixels(start), Yslot * SLOT_MULT + SLOT_HEIGHT - 1, text_size, cpu + 1);
+ fprintf(svgfile, "</g>\n");
}
static char *time_to_string(u64 duration)
@@ -168,7 +187,7 @@ static char *time_to_string(u64 duration)
return text;
}
-void svg_waiting(int Yslot, u64 start, u64 end)
+void svg_waiting(int Yslot, int cpu, u64 start, u64 end)
{
char *text;
const char *style;
@@ -192,6 +211,7 @@ void svg_waiting(int Yslot, u64 start, u64 end)
font_size = round_text_size(font_size);
fprintf(svgfile, "<g transform=\"translate(%4.8f,%4.8f)\">\n", time2pixels(start), Yslot * SLOT_MULT);
+ fprintf(svgfile, "<title>#%d waiting %s</title>\n", cpu, time_to_string(end - start));
fprintf(svgfile, "<rect x=\"0\" width=\"%4.8f\" y=\"0\" height=\"%4.1f\" class=\"%s\"/>\n",
time2pixels(end)-time2pixels(start), SLOT_HEIGHT, style);
if (font_size > MIN_TEXT_SIZE)
@@ -242,6 +262,8 @@ void svg_cpu_box(int cpu, u64 __max_freq, u64 __turbo_freq)
max_freq = __max_freq;
turbo_frequency = __turbo_freq;
+ fprintf(svgfile, "<g>\n");
+
fprintf(svgfile, "<rect x=\"%4.8f\" width=\"%4.8f\" y=\"%4.1f\" height=\"%4.1f\" class=\"cpu\"/>\n",
time2pixels(first_time),
time2pixels(last_time)-time2pixels(first_time),
@@ -253,6 +275,8 @@ void svg_cpu_box(int cpu, u64 __max_freq, u64 __turbo_freq)
fprintf(svgfile, "<text transform=\"translate(%4.8f,%4.8f)\" font-size=\"1.25pt\">%s</text>\n",
10+time2pixels(first_time), cpu2y(cpu) + SLOT_MULT + SLOT_HEIGHT - 4, cpu_model());
+
+ fprintf(svgfile, "</g>\n");
}
void svg_process(int cpu, u64 start, u64 end, const char *type, const char *name)
@@ -264,6 +288,7 @@ void svg_process(int cpu, u64 start, u64 end, const char *type, const char *name
fprintf(svgfile, "<g transform=\"translate(%4.8f,%4.8f)\">\n", time2pixels(start), cpu2y(cpu));
+ fprintf(svgfile, "<title>%s %s</title>\n", name, time_to_string(end - start));
fprintf(svgfile, "<rect x=\"0\" width=\"%4.8f\" y=\"0\" height=\"%4.1f\" class=\"%s\"/>\n",
time2pixels(end)-time2pixels(start), SLOT_MULT+SLOT_HEIGHT, type);
width = time2pixels(end)-time2pixels(start);
@@ -288,6 +313,8 @@ void svg_cstate(int cpu, u64 start, u64 end, int type)
return;
+ fprintf(svgfile, "<g>\n");
+
if (type > 6)
type = 6;
sprintf(style, "c%i", type);
@@ -306,6 +333,8 @@ void svg_cstate(int cpu, u64 start, u64 end, int type)
if (width > MIN_TEXT_SIZE)
fprintf(svgfile, "<text x=\"%4.8f\" y=\"%4.8f\" font-size=\"%3.8fpt\">C%i</text>\n",
time2pixels(start), cpu2y(cpu)+width, width, type);
+
+ fprintf(svgfile, "</g>\n");
}
static char *HzToHuman(unsigned long hz)
@@ -339,6 +368,8 @@ void svg_pstate(int cpu, u64 start, u64 end, u64 freq)
if (!svgfile)
return;
+ fprintf(svgfile, "<g>\n");
+
if (max_freq)
height = freq * 1.0 / max_freq * (SLOT_HEIGHT + SLOT_MULT);
height = 1 + cpu2y(cpu) + SLOT_MULT + SLOT_HEIGHT - height;
@@ -347,6 +378,7 @@ void svg_pstate(int cpu, u64 start, u64 end, u64 freq)
fprintf(svgfile, "<text x=\"%4.8f\" y=\"%4.8f\" font-size=\"0.25pt\">%s</text>\n",
time2pixels(start), height+0.9, HzToHuman(freq));
+ fprintf(svgfile, "</g>\n");
}
@@ -358,6 +390,12 @@ void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc
return;
+ fprintf(svgfile, "<g>\n");
+
+ fprintf(svgfile, "<title>%s wakes up %s</title>\n",
+ desc1 ? desc1 : "?",
+ desc2 ? desc2 : "?");
+
if (row1 < row2) {
if (row1) {
fprintf(svgfile, "<line x1=\"%4.8f\" y1=\"%4.2f\" x2=\"%4.8f\" y2=\"%4.2f\" style=\"stroke:rgb(32,255,32);stroke-width:0.009\"/>\n",
@@ -395,6 +433,8 @@ void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc
if (row1)
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(32,255,32)\"/>\n",
time2pixels(start), height);
+
+ fprintf(svgfile, "</g>\n");
}
void svg_wakeline(u64 start, int row1, int row2)
@@ -405,6 +445,8 @@ void svg_wakeline(u64 start, int row1, int row2)
return;
+ fprintf(svgfile, "<g>\n");
+
if (row1 < row2)
fprintf(svgfile, "<line x1=\"%4.8f\" y1=\"%4.2f\" x2=\"%4.8f\" y2=\"%4.2f\" style=\"stroke:rgb(32,255,32);stroke-width:0.009\"/>\n",
time2pixels(start), row1 * SLOT_MULT + SLOT_HEIGHT, time2pixels(start), row2 * SLOT_MULT);
@@ -417,6 +459,8 @@ void svg_wakeline(u64 start, int row1, int row2)
height += SLOT_HEIGHT;
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(32,255,32)\"/>\n",
time2pixels(start), height);
+
+ fprintf(svgfile, "</g>\n");
}
void svg_interrupt(u64 start, int row)
@@ -424,10 +468,16 @@ void svg_interrupt(u64 start, int row)
if (!svgfile)
return;
+ fprintf(svgfile, "<g>\n");
+
+ fprintf(svgfile, "<title>Wakeup from interrupt</title>\n");
+
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(255,128,128)\"/>\n",
time2pixels(start), row * SLOT_MULT);
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(255,128,128)\"/>\n",
time2pixels(start), row * SLOT_MULT + SLOT_HEIGHT);
+
+ fprintf(svgfile, "</g>\n");
}
void svg_text(int Yslot, u64 start, const char *text)
@@ -455,6 +505,7 @@ void svg_legenda(void)
if (!svgfile)
return;
+ fprintf(svgfile, "<g>\n");
svg_legenda_box(0, "Running", "sample");
svg_legenda_box(100, "Idle","c1");
svg_legenda_box(200, "Deeper Idle", "c3");
@@ -462,6 +513,7 @@ void svg_legenda(void)
svg_legenda_box(550, "Sleeping", "process2");
svg_legenda_box(650, "Waiting for cpu", "waiting");
svg_legenda_box(800, "Blocked on IO", "blocked");
+ fprintf(svgfile, "</g>\n");
}
void svg_time_grid(void)
diff --git a/tools/perf/util/svghelper.h b/tools/perf/util/svghelper.h
index e0781989cc31..630114b847d0 100644
--- a/tools/perf/util/svghelper.h
+++ b/tools/perf/util/svghelper.h
@@ -5,8 +5,9 @@
extern void open_svg(const char *filename, int cpus, int rows, u64 start, u64 end);
extern void svg_box(int Yslot, u64 start, u64 end, const char *type);
+extern void svg_blocked(int Yslot, int cpu, u64 start, u64 end);
extern void svg_sample(int Yslot, int cpu, u64 start, u64 end);
-extern void svg_waiting(int Yslot, u64 start, u64 end);
+extern void svg_waiting(int Yslot, int cpu, u64 start, u64 end);
extern void svg_cpu_box(int cpu, u64 max_frequency, u64 turbo_frequency);
--
1.8.1.2
Don't use special flag to indicate power-only mode, use proc_num == 0.
-P now equals to -n 0
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 18 +++++++++++++-----
1 file changed, 13 insertions(+), 5 deletions(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index d965f26308ed..e6c041301aa4 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -50,8 +50,6 @@ static u64 turbo_frequency;
static u64 first_time, last_time;
-static bool power_only;
-
struct per_pid;
struct per_pidcomm;
@@ -912,7 +910,7 @@ static int determine_display_tasks(u64 threshold)
/* no exit marker, task kept running to the end */
if (p->end_time == 0)
p->end_time = last_time;
- if (p->total_time >= threshold && !power_only)
+ if (p->total_time >= threshold)
p->display = 1;
c = p->all;
@@ -923,7 +921,7 @@ static int determine_display_tasks(u64 threshold)
if (c->start_time == 1)
c->start_time = first_time;
- if (c->total_time >= threshold && !power_only) {
+ if (c->total_time >= threshold) {
c->display = 1;
count++;
}
@@ -1086,6 +1084,15 @@ parse_process(const struct option *opt __maybe_unused, const char *arg,
return 0;
}
+static int
+parse_power(const struct option *opt __maybe_unused,
+ const char *arg __maybe_unused,
+ int unset __maybe_unused)
+{
+ proc_num = 0;
+ return 0;
+}
+
int cmd_timechart(int argc, const char **argv,
const char *prefix __maybe_unused)
{
@@ -1094,7 +1101,8 @@ int cmd_timechart(int argc, const char **argv,
OPT_STRING('i', "input", &input_name, "file", "input file name"),
OPT_STRING('o', "output", &output_name, "file", "output file name"),
OPT_INTEGER('w', "width", &svg_page_width, "page width"),
- OPT_BOOLEAN('P', "power-only", &power_only, "output power data only"),
+ OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
+ "output power data only", parse_power),
OPT_CALLBACK('p', "process", NULL, "process",
"process selector. Pass a pid or process name.",
parse_process),
--
1.8.1.2
Add -g flag to `perf timechart record` which saves callchain info in
the perf.data.
When generating SVG, add backtrace information to the figure details,
so now it's possible to see which code path woke up the task and why some
task went to sleep.
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 138 ++++++++++++++++++++++++++++++++++-------
tools/perf/util/svghelper.c | 27 ++++++--
tools/perf/util/svghelper.h | 12 ++--
3 files changed, 141 insertions(+), 36 deletions(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index 54bdebea4c6b..9a275db0f8cb 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -42,6 +42,7 @@
static int proc_num = 15;
static bool no_power;
+static bool with_backtrace;
static unsigned int numcpus;
@@ -124,6 +125,7 @@ struct cpu_sample {
u64 end_time;
int type;
int cpu;
+ const char *backtrace;
};
static struct per_pid *all_data;
@@ -145,6 +147,7 @@ struct wake_event {
int waker;
int wakee;
u64 time;
+ const char *backtrace;
};
static struct power_event *power_events;
@@ -229,7 +232,8 @@ static void pid_exit(int pid, u64 timestamp)
}
static void
-pid_put_sample(int pid, int type, unsigned int cpu, u64 start, u64 end)
+pid_put_sample(int pid, int type, unsigned int cpu, u64 start, u64 end,
+ const char *backtrace)
{
struct per_pid *p;
struct per_pidcomm *c;
@@ -252,6 +256,7 @@ pid_put_sample(int pid, int type, unsigned int cpu, u64 start, u64 end)
sample->type = type;
sample->next = c->samples;
sample->cpu = cpu;
+ sample->backtrace = backtrace;
c->samples = sample;
if (sample->type == TYPE_RUNNING && end > start && start > 0) {
@@ -403,7 +408,8 @@ static void p_state_change(int cpu, u64 timestamp, u64 new_freq)
}
static void
-sched_wakeup(int cpu, u64 timestamp, int pid, struct trace_entry *te)
+sched_wakeup(int cpu, u64 timestamp, int pid, struct trace_entry *te,
+ const char *backtrace)
{
struct per_pid *p;
struct wakeup_entry *wake = (void *)te;
@@ -414,6 +420,7 @@ sched_wakeup(int cpu, u64 timestamp, int pid, struct trace_entry *te)
we->time = timestamp;
we->waker = pid;
+ we->backtrace = backtrace;
if ((te->flags & TRACE_FLAG_HARDIRQ) || (te->flags & TRACE_FLAG_SOFTIRQ))
we->waker = -1;
@@ -428,13 +435,15 @@ sched_wakeup(int cpu, u64 timestamp, int pid, struct trace_entry *te)
p->current->state = TYPE_WAITING;
}
if (p && p->current && p->current->state == TYPE_BLOCKED) {
- pid_put_sample(p->pid, p->current->state, cpu, p->current->state_since, timestamp);
+ pid_put_sample(p->pid, p->current->state, cpu,
+ p->current->state_since, timestamp, NULL);
p->current->state_since = timestamp;
p->current->state = TYPE_WAITING;
}
}
-static void sched_switch(int cpu, u64 timestamp, struct trace_entry *te)
+static void sched_switch(int cpu, u64 timestamp, struct trace_entry *te,
+ const char *backtrace)
{
struct per_pid *p = NULL, *prev_p;
struct sched_switch *sw = (void *)te;
@@ -445,10 +454,14 @@ static void sched_switch(int cpu, u64 timestamp, struct trace_entry *te)
p = find_create_pid(sw->next_pid);
if (prev_p->current && prev_p->current->state != TYPE_NONE)
- pid_put_sample(sw->prev_pid, TYPE_RUNNING, cpu, prev_p->current->state_since, timestamp);
+ pid_put_sample(sw->prev_pid, TYPE_RUNNING, cpu,
+ prev_p->current->state_since, timestamp,
+ backtrace);
if (p && p->current) {
if (p->current->state != TYPE_NONE)
- pid_put_sample(sw->next_pid, p->current->state, cpu, p->current->state_since, timestamp);
+ pid_put_sample(sw->next_pid, p->current->state, cpu,
+ p->current->state_since, timestamp,
+ backtrace);
p->current->state_since = timestamp;
p->current->state = TYPE_RUNNING;
@@ -464,8 +477,55 @@ static void sched_switch(int cpu, u64 timestamp, struct trace_entry *te)
}
}
+static const char *cat_backtrace(union perf_event *event,
+ struct perf_sample *sample,
+ struct machine *machine)
+{
+ struct addr_location al;
+ unsigned int i;
+ char *p = NULL;
+ size_t p_len;
+ u8 cpumode = PERF_RECORD_MISC_USER;
+ struct addr_location tal;
+ struct ip_callchain *chain = sample->callchain;
+ FILE *f = open_memstream(&p, &p_len);
+
+ if (!chain)
+ return NULL;
+
+ if (perf_event__preprocess_sample(event, machine, &al, sample) < 0) {
+ fprintf(stderr, "problem processing %d event, skipping it.\n",
+ event->header.type);
+ return NULL;
+ }
+
+ for (i = 0; i < chain->nr; i++) {
+ u64 ip;
+
+ if (callchain_param.order == ORDER_CALLEE)
+ ip = chain->ips[i];
+ else
+ ip = chain->ips[chain->nr - i - 1];
+
+ tal.filtered = false;
+ thread__find_addr_location(al.thread, machine, cpumode,
+ MAP__FUNCTION, ip, &tal);
+
+ if (tal.sym)
+ fprintf(f, "..... %016" PRIx64 " %s\n", ip,
+ tal.sym->name);
+ else
+ fprintf(f, "..... %016" PRIx64 "\n", ip);
+ }
+
+ fclose(f);
+
+ return p;
+}
+
typedef int (*tracepoint_handler)(struct perf_evsel *evsel,
- struct perf_sample *sample);
+ struct perf_sample *sample,
+ const char *backtrace);
static int process_sample_event(struct perf_tool *tool __maybe_unused,
union perf_event *event __maybe_unused,
@@ -485,7 +545,8 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
if (evsel->handler.func != NULL) {
tracepoint_handler f = evsel->handler.func;
- return f(evsel, sample);
+ return f(evsel, sample,
+ cat_backtrace(event, sample, machine));
}
return 0;
@@ -493,7 +554,8 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
static int
process_sample_cpu_idle(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct power_processor_entry *ppe = sample->raw_data;
@@ -506,7 +568,8 @@ process_sample_cpu_idle(struct perf_evsel *evsel __maybe_unused,
static int
process_sample_cpu_frequency(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct power_processor_entry *ppe = sample->raw_data;
@@ -516,28 +579,31 @@ process_sample_cpu_frequency(struct perf_evsel *evsel __maybe_unused,
static int
process_sample_sched_wakeup(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct trace_entry *te = sample->raw_data;
- sched_wakeup(sample->cpu, sample->time, sample->pid, te);
+ sched_wakeup(sample->cpu, sample->time, sample->pid, te, backtrace);
return 0;
}
static int
process_sample_sched_switch(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct trace_entry *te = sample->raw_data;
- sched_switch(sample->cpu, sample->time, te);
+ sched_switch(sample->cpu, sample->time, te, backtrace);
return 0;
}
#ifdef SUPPORT_OLD_POWER_EVENTS
static int
process_sample_power_start(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct power_entry_old *peo = sample->raw_data;
@@ -547,7 +613,8 @@ process_sample_power_start(struct perf_evsel *evsel __maybe_unused,
static int
process_sample_power_end(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
c_state_end(sample->cpu, sample->time);
return 0;
@@ -555,7 +622,8 @@ process_sample_power_end(struct perf_evsel *evsel __maybe_unused,
static int
process_sample_power_frequency(struct perf_evsel *evsel __maybe_unused,
- struct perf_sample *sample)
+ struct perf_sample *sample,
+ const char *backtrace __maybe_unused)
{
struct power_entry_old *peo = sample->raw_data;
@@ -739,11 +807,12 @@ static void draw_wakeups(void)
}
if (we->waker == -1)
- svg_interrupt(we->time, to);
+ svg_interrupt(we->time, to, we->backtrace);
else if (from && to && abs(from - to) == 1)
- svg_wakeline(we->time, from, to);
+ svg_wakeline(we->time, from, to, we->backtrace);
else
- svg_partial_wakeline(we->time, from, task_from, to, task_to);
+ svg_partial_wakeline(we->time, from, task_from, to,
+ task_to, we->backtrace);
we = we->next;
free(task_from);
@@ -796,11 +865,20 @@ static void draw_process_bars(void)
sample = c->samples;
while (sample) {
if (sample->type == TYPE_RUNNING)
- svg_sample(Y, sample->cpu, sample->start_time, sample->end_time);
+ svg_sample(Y, sample->cpu,
+ sample->start_time,
+ sample->end_time,
+ sample->backtrace);
if (sample->type == TYPE_BLOCKED)
- svg_blocked(Y, sample->cpu, sample->start_time, sample->end_time);
+ svg_blocked(Y, sample->cpu,
+ sample->start_time,
+ sample->end_time,
+ sample->backtrace);
if (sample->type == TYPE_WAITING)
- svg_waiting(Y, sample->cpu, sample->start_time, sample->end_time);
+ svg_waiting(Y, sample->cpu,
+ sample->start_time,
+ sample->end_time,
+ sample->backtrace);
sample = sample->next;
}
@@ -1041,6 +1119,11 @@ static int __cmd_record(int argc, const char **argv)
};
unsigned int common_args_no = ARRAY_SIZE(common_args);
+ const char * const backtrace_args[] = {
+ "-g",
+ };
+ unsigned int backtrace_args_no = ARRAY_SIZE(backtrace_args);
+
const char * const power_args[] = {
"-e", "power:cpu_frequency",
"-e", "power:cpu_idle",
@@ -1080,8 +1163,11 @@ static int __cmd_record(int argc, const char **argv)
old_power_args_no = 0;
}
+ if (!with_backtrace)
+ backtrace_args_no = 0;
+
record_elems = common_args_no + tasks_args_no +
- power_args_no + old_power_args_no;
+ power_args_no + old_power_args_no + backtrace_args_no;
rec_argc = record_elems + argc;
rec_argv = calloc(rec_argc + 1, sizeof(char *));
@@ -1093,6 +1179,9 @@ static int __cmd_record(int argc, const char **argv)
for (i = 0; i < common_args_no; i++)
*p++ = strdup(common_args[i]);
+ for (i = 0; i < backtrace_args_no; i++)
+ *p++ = strdup(backtrace_args[i]);
+
for (i = 0; i < tasks_args_no; i++)
*p++ = strdup(tasks_args[i]);
@@ -1166,6 +1255,7 @@ int cmd_timechart(int argc, const char **argv,
"record power data only", parse_power),
OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
"record processes data only", parse_tasks),
+ OPT_BOOLEAN('g', "callchain", &with_backtrace, "record callchain"),
OPT_END()
};
const char * const record_usage[] = {
diff --git a/tools/perf/util/svghelper.c b/tools/perf/util/svghelper.c
index c41be3c5722b..702d41e34576 100644
--- a/tools/perf/util/svghelper.c
+++ b/tools/perf/util/svghelper.c
@@ -130,7 +130,7 @@ void svg_box(int Yslot, u64 start, u64 end, const char *type)
}
static char *time_to_string(u64 duration);
-void svg_blocked(int Yslot, int cpu, u64 start, u64 end)
+void svg_blocked(int Yslot, int cpu, u64 start, u64 end, const char *backtrace)
{
if (!svgfile)
return;
@@ -138,11 +138,13 @@ void svg_blocked(int Yslot, int cpu, u64 start, u64 end)
fprintf(svgfile, "<g>\n");
fprintf(svgfile, "<title>#%d blocked %s</title>\n", cpu,
time_to_string(end - start));
+ if (backtrace)
+ fprintf(svgfile, "<desc>Blocked on:\n%s</desc>\n", backtrace);
svg_box(Yslot, start, end, "blocked");
fprintf(svgfile, "</g>\n");
}
-void svg_sample(int Yslot, int cpu, u64 start, u64 end)
+void svg_sample(int Yslot, int cpu, u64 start, u64 end, const char *backtrace)
{
double text_size;
if (!svgfile)
@@ -152,6 +154,8 @@ void svg_sample(int Yslot, int cpu, u64 start, u64 end)
fprintf(svgfile, "<title>#%d running %s</title>\n",
cpu, time_to_string(end - start));
+ if (backtrace)
+ fprintf(svgfile, "<desc>Switched because:\n%s</desc>\n", backtrace);
fprintf(svgfile, "<rect x=\"%4.8f\" width=\"%4.8f\" y=\"%4.1f\" height=\"%4.1f\" class=\"sample\"/>\n",
time2pixels(start), time2pixels(end)-time2pixels(start), Yslot * SLOT_MULT, SLOT_HEIGHT);
@@ -187,7 +191,7 @@ static char *time_to_string(u64 duration)
return text;
}
-void svg_waiting(int Yslot, int cpu, u64 start, u64 end)
+void svg_waiting(int Yslot, int cpu, u64 start, u64 end, const char *backtrace)
{
char *text;
const char *style;
@@ -212,6 +216,8 @@ void svg_waiting(int Yslot, int cpu, u64 start, u64 end)
fprintf(svgfile, "<g transform=\"translate(%4.8f,%4.8f)\">\n", time2pixels(start), Yslot * SLOT_MULT);
fprintf(svgfile, "<title>#%d waiting %s</title>\n", cpu, time_to_string(end - start));
+ if (backtrace)
+ fprintf(svgfile, "<desc>Waiting on:\n%s</desc>\n", backtrace);
fprintf(svgfile, "<rect x=\"0\" width=\"%4.8f\" y=\"0\" height=\"%4.1f\" class=\"%s\"/>\n",
time2pixels(end)-time2pixels(start), SLOT_HEIGHT, style);
if (font_size > MIN_TEXT_SIZE)
@@ -382,7 +388,7 @@ void svg_pstate(int cpu, u64 start, u64 end, u64 freq)
}
-void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc2)
+void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc2, const char *backtrace)
{
double height;
@@ -396,6 +402,9 @@ void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc
desc1 ? desc1 : "?",
desc2 ? desc2 : "?");
+ if (backtrace)
+ fprintf(svgfile, "<desc>%s</desc>\n", backtrace);
+
if (row1 < row2) {
if (row1) {
fprintf(svgfile, "<line x1=\"%4.8f\" y1=\"%4.2f\" x2=\"%4.8f\" y2=\"%4.2f\" style=\"stroke:rgb(32,255,32);stroke-width:0.009\"/>\n",
@@ -437,7 +446,7 @@ void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc
fprintf(svgfile, "</g>\n");
}
-void svg_wakeline(u64 start, int row1, int row2)
+void svg_wakeline(u64 start, int row1, int row2, const char *backtrace)
{
double height;
@@ -447,6 +456,9 @@ void svg_wakeline(u64 start, int row1, int row2)
fprintf(svgfile, "<g>\n");
+ if (backtrace)
+ fprintf(svgfile, "<desc>%s</desc>\n", backtrace);
+
if (row1 < row2)
fprintf(svgfile, "<line x1=\"%4.8f\" y1=\"%4.2f\" x2=\"%4.8f\" y2=\"%4.2f\" style=\"stroke:rgb(32,255,32);stroke-width:0.009\"/>\n",
time2pixels(start), row1 * SLOT_MULT + SLOT_HEIGHT, time2pixels(start), row2 * SLOT_MULT);
@@ -463,7 +475,7 @@ void svg_wakeline(u64 start, int row1, int row2)
fprintf(svgfile, "</g>\n");
}
-void svg_interrupt(u64 start, int row)
+void svg_interrupt(u64 start, int row, const char *backtrace)
{
if (!svgfile)
return;
@@ -472,6 +484,9 @@ void svg_interrupt(u64 start, int row)
fprintf(svgfile, "<title>Wakeup from interrupt</title>\n");
+ if (backtrace)
+ fprintf(svgfile, "<desc>%s</desc>\n", backtrace);
+
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(255,128,128)\"/>\n",
time2pixels(start), row * SLOT_MULT);
fprintf(svgfile, "<circle cx=\"%4.8f\" cy=\"%4.2f\" r = \"0.01\" style=\"fill:rgb(255,128,128)\"/>\n",
diff --git a/tools/perf/util/svghelper.h b/tools/perf/util/svghelper.h
index 630114b847d0..045fa087cf04 100644
--- a/tools/perf/util/svghelper.h
+++ b/tools/perf/util/svghelper.h
@@ -5,9 +5,9 @@
extern void open_svg(const char *filename, int cpus, int rows, u64 start, u64 end);
extern void svg_box(int Yslot, u64 start, u64 end, const char *type);
-extern void svg_blocked(int Yslot, int cpu, u64 start, u64 end);
-extern void svg_sample(int Yslot, int cpu, u64 start, u64 end);
-extern void svg_waiting(int Yslot, int cpu, u64 start, u64 end);
+extern void svg_blocked(int Yslot, int cpu, u64 start, u64 end, const char *backtrace);
+extern void svg_sample(int Yslot, int cpu, u64 start, u64 end, const char *backtrace);
+extern void svg_waiting(int Yslot, int cpu, u64 start, u64 end, const char *backtrace);
extern void svg_cpu_box(int cpu, u64 max_frequency, u64 turbo_frequency);
@@ -18,9 +18,9 @@ extern void svg_pstate(int cpu, u64 start, u64 end, u64 freq);
extern void svg_time_grid(void);
extern void svg_legenda(void);
-extern void svg_wakeline(u64 start, int row1, int row2);
-extern void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc2);
-extern void svg_interrupt(u64 start, int row);
+extern void svg_wakeline(u64 start, int row1, int row2, const char *backtrace);
+extern void svg_partial_wakeline(u64 start, int row1, char *desc1, int row2, char *desc2, const char *backtrace);
+extern void svg_interrupt(u64 start, int row, const char *backtrace);
extern void svg_text(int Yslot, u64 start, const char *text);
extern void svg_close(void);
--
1.8.1.2
If we don't want either power or task events we may use -T or -P
with the `perf timechart record` command to filter out events while
recording to keep perf.data small.
Signed-off-by: Stanislav Fomichev <[email protected]>
---
tools/perf/builtin-timechart.c | 98 +++++++++++++++++++++++++++++++-----------
1 file changed, 72 insertions(+), 26 deletions(-)
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index 4d2ac96b75b1..54bdebea4c6b 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -1031,50 +1031,81 @@ out_delete:
static int __cmd_record(int argc, const char **argv)
{
-#ifdef SUPPORT_OLD_POWER_EVENTS
- const char * const record_old_args[] = {
+ unsigned int rec_argc, i, j;
+ const char **rec_argv;
+ const char **p;
+ unsigned int record_elems;
+
+ const char * const common_args[] = {
"record", "-a", "-R", "-c", "1",
+ };
+ unsigned int common_args_no = ARRAY_SIZE(common_args);
+
+ const char * const power_args[] = {
+ "-e", "power:cpu_frequency",
+ "-e", "power:cpu_idle",
+ };
+ unsigned int power_args_no = ARRAY_SIZE(power_args);
+
+ const char * const old_power_args[] = {
+#ifdef SUPPORT_OLD_POWER_EVENTS
"-e", "power:power_start",
"-e", "power:power_end",
"-e", "power:power_frequency",
- "-e", "sched:sched_wakeup",
- "-e", "sched:sched_switch",
- };
#endif
- const char * const record_new_args[] = {
- "record", "-a", "-R", "-c", "1",
- "-e", "power:cpu_frequency",
- "-e", "power:cpu_idle",
+ };
+ unsigned int old_power_args_no = ARRAY_SIZE(power_args);
+
+ const char * const tasks_args[] = {
"-e", "sched:sched_wakeup",
"-e", "sched:sched_switch",
};
- unsigned int rec_argc, i, j;
- const char **rec_argv;
- const char * const *record_args = record_new_args;
- unsigned int record_elems = ARRAY_SIZE(record_new_args);
+ unsigned int tasks_args_no = ARRAY_SIZE(tasks_args);
#ifdef SUPPORT_OLD_POWER_EVENTS
if (!is_valid_tracepoint("power:cpu_idle") &&
is_valid_tracepoint("power:power_start")) {
use_old_power_events = 1;
- record_args = record_old_args;
- record_elems = ARRAY_SIZE(record_old_args);
+ power_args_no = 0;
+ } else {
+ old_power_args_no = 0;
}
#endif
- rec_argc = record_elems + argc - 1;
+ if (!proc_num)
+ tasks_args_no = 0;
+
+ if (no_power) {
+ power_args_no = 0;
+ old_power_args_no = 0;
+ }
+
+ record_elems = common_args_no + tasks_args_no +
+ power_args_no + old_power_args_no;
+
+ rec_argc = record_elems + argc;
rec_argv = calloc(rec_argc + 1, sizeof(char *));
if (rec_argv == NULL)
return -ENOMEM;
- for (i = 0; i < record_elems; i++)
- rec_argv[i] = strdup(record_args[i]);
+ p = rec_argv;
+ for (i = 0; i < common_args_no; i++)
+ *p++ = strdup(common_args[i]);
+
+ for (i = 0; i < tasks_args_no; i++)
+ *p++ = strdup(tasks_args[i]);
+
+ for (i = 0; i < power_args_no; i++)
+ *p++ = strdup(power_args[i]);
- for (j = 1; j < (unsigned int)argc; j++, i++)
- rec_argv[i] = argv[j];
+ for (i = 0; i < old_power_args_no; i++)
+ *p++ = strdup(old_power_args[i]);
- return cmd_record(i, rec_argv, NULL);
+ for (j = 1; j < (unsigned int)argc; j++)
+ *p++ = argv[j];
+
+ return cmd_record(rec_argc, rec_argv, NULL);
}
static int
@@ -1108,7 +1139,7 @@ int cmd_timechart(int argc, const char **argv,
const char *prefix __maybe_unused)
{
const char *output_name = "output.svg";
- const struct option options[] = {
+ const struct option timechart_options[] = {
OPT_STRING('i', "input", &input_name, "file", "input file name"),
OPT_STRING('o', "output", &output_name, "file", "output file name"),
OPT_INTEGER('w', "width", &svg_page_width, "page width"),
@@ -1130,15 +1161,30 @@ int cmd_timechart(int argc, const char **argv,
NULL
};
- argc = parse_options(argc, argv, options, timechart_usage,
+ const struct option record_options[] = {
+ OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
+ "record power data only", parse_power),
+ OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
+ "record processes data only", parse_tasks),
+ OPT_END()
+ };
+ const char * const record_usage[] = {
+ "perf timechart record [<options>]",
+ NULL
+ };
+ argc = parse_options(argc, argv, timechart_options, timechart_usage,
PARSE_OPT_STOP_AT_NON_OPTION);
symbol__init();
- if (argc && !strncmp(argv[0], "rec", 3))
+ if (argc && !strncmp(argv[0], "rec", 3)) {
+ argc = parse_options(argc, argv, record_options, record_usage,
+ PARSE_OPT_STOP_AT_NON_OPTION);
+
return __cmd_record(argc, argv);
- else if (argc)
- usage_with_options(timechart_usage, options);
+ } else if (argc) {
+ usage_with_options(timechart_usage, timechart_options);
+ }
setup_pager();
--
1.8.1.2
Hi Stanislav,
On Tue, 22 Oct 2013 14:56:47 +0400, Stanislav Fomichev wrote:
> Always try to print at least 15 tasks no matter how long they run.
> Add -n option to specify desired number of tasks to print.
Hmm.. I think that this patch tried to do many things at once.
1. introduce while loop: it's a behavioral change so that it can be a
separate patch. But it seems not checking the process filter - in that
case the loop is almost useless IMHO.
2. new -n option: it should update Documentation/perf-timechart.txt
also. And the long option name "number" is too general.
3. two if(proc_num): what is this? Is it for patch 2?
Thanks,
Namhyung
>
> Signed-off-by: Stanislav Fomichev <[email protected]>
> ---
> tools/perf/builtin-timechart.c | 22 +++++++++++++++-------
> 1 file changed, 15 insertions(+), 7 deletions(-)
>
> diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
> index c2e02319347a..d965f26308ed 100644
> --- a/tools/perf/builtin-timechart.c
> +++ b/tools/perf/builtin-timechart.c
> @@ -40,6 +40,8 @@
> #define SUPPORT_OLD_POWER_EVENTS 1
> #define PWR_EVENT_EXIT -1
>
> +static int proc_num = 15;
> +
>
> static unsigned int numcpus;
> static u64 min_freq; /* Lowest CPU frequency seen */
> @@ -944,15 +946,17 @@ static void write_svg_file(const char *filename)
> {
> u64 i;
> int count;
> + int thresh = TIME_THRESH;
>
> numcpus++;
>
>
> - count = determine_display_tasks(TIME_THRESH);
> -
> - /* We'd like to show at least 15 tasks; be less picky if we have fewer */
> - if (count < 15)
> - count = determine_display_tasks(TIME_THRESH / 10);
> + /* We'd like to show at least proc_num tasks;
> + * be less picky if we have fewer */
> + do {
> + count = determine_display_tasks(thresh);
> + thresh /= 10;
> + } while (thresh && count < proc_num);
>
> open_svg(filename, numcpus, count, first_time, last_time);
>
> @@ -963,9 +967,11 @@ static void write_svg_file(const char *filename)
> svg_cpu_box(i, max_freq, turbo_frequency);
>
> draw_cpu_usage();
> - draw_process_bars();
> + if (proc_num)
> + draw_process_bars();
> draw_c_p_states();
> - draw_wakeups();
> + if (proc_num)
> + draw_wakeups();
>
> svg_close();
> }
> @@ -1094,6 +1100,8 @@ int cmd_timechart(int argc, const char **argv,
> parse_process),
> OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
> "Look for files with symbols relative to this directory"),
> + OPT_INTEGER('n', "number", &proc_num,
> + "min. number of tasks to print"),
> OPT_END()
> };
> const char * const timechart_usage[] = {
On Tue, 22 Oct 2013 14:56:48 +0400, Stanislav Fomichev wrote:
> Don't use special flag to indicate power-only mode, use proc_num == 0.
> -P now equals to -n 0
I don't see how it does same thing. You mean it by skipping
draw_process_bars() and draw_wakeups() on patch 1? It'd be better
changelog explains the details.
>
> Signed-off-by: Stanislav Fomichev <[email protected]>
> ---
> tools/perf/builtin-timechart.c | 18 +++++++++++++-----
> 1 file changed, 13 insertions(+), 5 deletions(-)
>
> diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
> index d965f26308ed..e6c041301aa4 100644
> --- a/tools/perf/builtin-timechart.c
> +++ b/tools/perf/builtin-timechart.c
> @@ -50,8 +50,6 @@ static u64 turbo_frequency;
>
> static u64 first_time, last_time;
>
> -static bool power_only;
> -
>
> struct per_pid;
> struct per_pidcomm;
> @@ -912,7 +910,7 @@ static int determine_display_tasks(u64 threshold)
> /* no exit marker, task kept running to the end */
> if (p->end_time == 0)
> p->end_time = last_time;
> - if (p->total_time >= threshold && !power_only)
> + if (p->total_time >= threshold)
> p->display = 1;
>
> c = p->all;
> @@ -923,7 +921,7 @@ static int determine_display_tasks(u64 threshold)
> if (c->start_time == 1)
> c->start_time = first_time;
>
> - if (c->total_time >= threshold && !power_only) {
> + if (c->total_time >= threshold) {
> c->display = 1;
> count++;
> }
> @@ -1086,6 +1084,15 @@ parse_process(const struct option *opt __maybe_unused, const char *arg,
> return 0;
> }
>
> +static int
> +parse_power(const struct option *opt __maybe_unused,
> + const char *arg __maybe_unused,
> + int unset __maybe_unused)
> +{
> + proc_num = 0;
> + return 0;
> +}
> +
> int cmd_timechart(int argc, const char **argv,
> const char *prefix __maybe_unused)
> {
> @@ -1094,7 +1101,8 @@ int cmd_timechart(int argc, const char **argv,
> OPT_STRING('i', "input", &input_name, "file", "input file name"),
> OPT_STRING('o', "output", &output_name, "file", "output file name"),
> OPT_INTEGER('w', "width", &svg_page_width, "page width"),
> - OPT_BOOLEAN('P', "power-only", &power_only, "output power data only"),
> + OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
> + "output power data only", parse_power),
And I'd like to keep it as BOOLEAN option - it's simpler and more
straight-forward IMHO.
How about adding
if (power_only)
proc_num = 0;
after parsing the command line options?
Thanks,
Namhyung
> OPT_CALLBACK('p', "process", NULL, "process",
> "process selector. Pass a pid or process name.",
> parse_process),
On Tue, 22 Oct 2013 14:56:49 +0400, Stanislav Fomichev wrote:
> In order to make SVG smaller and faster to browse add possibility to
> switch off power related information with -T switch.
>
> Signed-off-by: Stanislav Fomichev <[email protected]>
> ---
> tools/perf/builtin-timechart.c | 15 ++++++++++++++-
> 1 file changed, 14 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
> index e6c041301aa4..c7b30a8c7f3b 100644
> --- a/tools/perf/builtin-timechart.c
> +++ b/tools/perf/builtin-timechart.c
> @@ -41,6 +41,7 @@
> #define PWR_EVENT_EXIT -1
>
> static int proc_num = 15;
> +static bool no_power;
>
>
> static unsigned int numcpus;
> @@ -967,7 +968,8 @@ static void write_svg_file(const char *filename)
> draw_cpu_usage();
> if (proc_num)
> draw_process_bars();
> - draw_c_p_states();
> + if (!no_power)
> + draw_c_p_states();
Hmm.. double negation is always confusing to me. :-/ How about making
it a boolean option that sets "task_only" variable?
> if (proc_num)
> draw_wakeups();
>
> @@ -1076,6 +1078,15 @@ static int __cmd_record(int argc, const char **argv)
> }
>
> static int
> +parse_tasks(const struct option *opt __maybe_unused,
> + const char *arg __maybe_unused,
> + int unset __maybe_unused)
> +{
> + no_power = 1;
> + return 0;
> +}
> +
> +static int
> parse_process(const struct option *opt __maybe_unused, const char *arg,
> int __maybe_unused unset)
> {
> @@ -1103,6 +1114,8 @@ int cmd_timechart(int argc, const char **argv,
> OPT_INTEGER('w', "width", &svg_page_width, "page width"),
> OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
> "output power data only", parse_power),
> + OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
> + "output processes data only", parse_tasks),
Also need to update the doc. And what if user gives -P and -T options
at the same time?
Thanks,
Namhyung
> OPT_CALLBACK('p', "process", NULL, "process",
> "process selector. Pass a pid or process name.",
> parse_process),
On Tue, 22 Oct 2013 14:56:50 +0400, Stanislav Fomichev wrote:
> Add titles to figures so we can run SVG interactively in Firefox
> and check event details in the tooltips.
> This also aids exploring SVG with Inkscape because when user clicks on
> one part of logical figure, all parts are selected.
> It's also possible to read titles with Inkscape in the object details.
I have a trivial nitpick below, other than that
Acked-by: Namhyung Kim <[email protected]>
>
> Signed-off-by: Stanislav Fomichev <[email protected]>
> ---
> tools/perf/builtin-timechart.c | 4 ++--
> tools/perf/util/svghelper.c | 54 +++++++++++++++++++++++++++++++++++++++++-
> tools/perf/util/svghelper.h | 3 ++-
> 3 files changed, 57 insertions(+), 4 deletions(-)
>
> diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
> index c7b30a8c7f3b..4d2ac96b75b1 100644
> --- a/tools/perf/builtin-timechart.c
> +++ b/tools/perf/builtin-timechart.c
> @@ -798,9 +798,9 @@ static void draw_process_bars(void)
> if (sample->type == TYPE_RUNNING)
> svg_sample(Y, sample->cpu, sample->start_time, sample->end_time);
For consistency, wouldn't it be better renaming svg_sample() to
svg_running()?
Thanks,
Namhyung
> if (sample->type == TYPE_BLOCKED)
> - svg_box(Y, sample->start_time, sample->end_time, "blocked");
> + svg_blocked(Y, sample->cpu, sample->start_time, sample->end_time);
> if (sample->type == TYPE_WAITING)
> - svg_waiting(Y, sample->start_time, sample->end_time);
> + svg_waiting(Y, sample->cpu, sample->start_time, sample->end_time);
> sample = sample->next;
> }
On Tue, 22 Oct 2013 14:56:51 +0400, Stanislav Fomichev wrote:
> If we don't want either power or task events we may use -T or -P
> with the `perf timechart record` command to filter out events while
> recording to keep perf.data small.
>
> Signed-off-by: Stanislav Fomichev <[email protected]>
> ---
> tools/perf/builtin-timechart.c | 98 +++++++++++++++++++++++++++++++-----------
> 1 file changed, 72 insertions(+), 26 deletions(-)
>
> diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
> index 4d2ac96b75b1..54bdebea4c6b 100644
> --- a/tools/perf/builtin-timechart.c
> +++ b/tools/perf/builtin-timechart.c
> @@ -1031,50 +1031,81 @@ out_delete:
>
> static int __cmd_record(int argc, const char **argv)
> {
> -#ifdef SUPPORT_OLD_POWER_EVENTS
> - const char * const record_old_args[] = {
> + unsigned int rec_argc, i, j;
> + const char **rec_argv;
> + const char **p;
> + unsigned int record_elems;
> +
> + const char * const common_args[] = {
> "record", "-a", "-R", "-c", "1",
> + };
> + unsigned int common_args_no = ARRAY_SIZE(common_args);
It's preferred to use "nr" in the position of "no". Or we can use
'common_argc' instead. Same goes to the below.
> +
> + const char * const power_args[] = {
> + "-e", "power:cpu_frequency",
> + "-e", "power:cpu_idle",
> + };
> + unsigned int power_args_no = ARRAY_SIZE(power_args);
> +
> + const char * const old_power_args[] = {
> +#ifdef SUPPORT_OLD_POWER_EVENTS
> "-e", "power:power_start",
> "-e", "power:power_end",
> "-e", "power:power_frequency",
> - "-e", "sched:sched_wakeup",
> - "-e", "sched:sched_switch",
> - };
> #endif
> - const char * const record_new_args[] = {
> - "record", "-a", "-R", "-c", "1",
> - "-e", "power:cpu_frequency",
> - "-e", "power:cpu_idle",
> + };
> + unsigned int old_power_args_no = ARRAY_SIZE(power_args);
It should be ARRAY_SIZE(old_power_args).
> +
> + const char * const tasks_args[] = {
> "-e", "sched:sched_wakeup",
> "-e", "sched:sched_switch",
> };
> - unsigned int rec_argc, i, j;
> - const char **rec_argv;
> - const char * const *record_args = record_new_args;
> - unsigned int record_elems = ARRAY_SIZE(record_new_args);
> + unsigned int tasks_args_no = ARRAY_SIZE(tasks_args);
>
> #ifdef SUPPORT_OLD_POWER_EVENTS
> if (!is_valid_tracepoint("power:cpu_idle") &&
> is_valid_tracepoint("power:power_start")) {
> use_old_power_events = 1;
> - record_args = record_old_args;
> - record_elems = ARRAY_SIZE(record_old_args);
> + power_args_no = 0;
> + } else {
> + old_power_args_no = 0;
> }
> #endif
>
> - rec_argc = record_elems + argc - 1;
> + if (!proc_num)
> + tasks_args_no = 0;
> +
> + if (no_power) {
> + power_args_no = 0;
> + old_power_args_no = 0;
> + }
> +
> + record_elems = common_args_no + tasks_args_no +
> + power_args_no + old_power_args_no;
> +
> + rec_argc = record_elems + argc;
> rec_argv = calloc(rec_argc + 1, sizeof(char *));
>
> if (rec_argv == NULL)
> return -ENOMEM;
>
> - for (i = 0; i < record_elems; i++)
> - rec_argv[i] = strdup(record_args[i]);
> + p = rec_argv;
> + for (i = 0; i < common_args_no; i++)
> + *p++ = strdup(common_args[i]);
> +
> + for (i = 0; i < tasks_args_no; i++)
> + *p++ = strdup(tasks_args[i]);
> +
> + for (i = 0; i < power_args_no; i++)
> + *p++ = strdup(power_args[i]);
>
> - for (j = 1; j < (unsigned int)argc; j++, i++)
> - rec_argv[i] = argv[j];
> + for (i = 0; i < old_power_args_no; i++)
> + *p++ = strdup(old_power_args[i]);
>
> - return cmd_record(i, rec_argv, NULL);
> + for (j = 1; j < (unsigned int)argc; j++)
> + *p++ = argv[j];
> +
> + return cmd_record(rec_argc, rec_argv, NULL);
> }
>
> static int
> @@ -1108,7 +1139,7 @@ int cmd_timechart(int argc, const char **argv,
> const char *prefix __maybe_unused)
> {
> const char *output_name = "output.svg";
> - const struct option options[] = {
> + const struct option timechart_options[] = {
> OPT_STRING('i', "input", &input_name, "file", "input file name"),
> OPT_STRING('o', "output", &output_name, "file", "output file name"),
> OPT_INTEGER('w', "width", &svg_page_width, "page width"),
> @@ -1130,15 +1161,30 @@ int cmd_timechart(int argc, const char **argv,
> NULL
> };
>
> - argc = parse_options(argc, argv, options, timechart_usage,
> + const struct option record_options[] = {
> + OPT_CALLBACK_NOOPT('P', "power-only", NULL, NULL,
> + "record power data only", parse_power),
> + OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
> + "record processes data only", parse_tasks),
> + OPT_END()
> + };
> + const char * const record_usage[] = {
> + "perf timechart record [<options>]",
> + NULL
> + };
Do we really need to separate the option and usage for record? AFAICS
it does exactly same thing..
Thanks,
Namhyung
> + argc = parse_options(argc, argv, timechart_options, timechart_usage,
> PARSE_OPT_STOP_AT_NON_OPTION);
>
> symbol__init();
>
> - if (argc && !strncmp(argv[0], "rec", 3))
> + if (argc && !strncmp(argv[0], "rec", 3)) {
> + argc = parse_options(argc, argv, record_options, record_usage,
> + PARSE_OPT_STOP_AT_NON_OPTION);
> +
> return __cmd_record(argc, argv);
> - else if (argc)
> - usage_with_options(timechart_usage, options);
> + } else if (argc) {
> + usage_with_options(timechart_usage, timechart_options);
> + }
>
> setup_pager();
On Tue, 22 Oct 2013 14:56:52 +0400, Stanislav Fomichev wrote:
> Add -g flag to `perf timechart record` which saves callchain info in
> the perf.data.
> When generating SVG, add backtrace information to the figure details,
> so now it's possible to see which code path woke up the task and why some
> task went to sleep.
[SNIP]
> +static const char *cat_backtrace(union perf_event *event,
> + struct perf_sample *sample,
> + struct machine *machine)
> +{
> + struct addr_location al;
> + unsigned int i;
> + char *p = NULL;
> + size_t p_len;
> + u8 cpumode = PERF_RECORD_MISC_USER;
> + struct addr_location tal;
> + struct ip_callchain *chain = sample->callchain;
> + FILE *f = open_memstream(&p, &p_len);
It is safer to check the return value.
> +
> + if (!chain)
> + return NULL;
> +
> + if (perf_event__preprocess_sample(event, machine, &al, sample) < 0) {
> + fprintf(stderr, "problem processing %d event, skipping it.\n",
> + event->header.type);
> + return NULL;
> + }
Above two returns should close 'f'.
> +
> + for (i = 0; i < chain->nr; i++) {
> + u64 ip;
> +
> + if (callchain_param.order == ORDER_CALLEE)
> + ip = chain->ips[i];
> + else
> + ip = chain->ips[chain->nr - i - 1];
The ip might carry context information rather than the actual
instruction pointer. Please see machine__resolve_callchain_sample().
> +
> + tal.filtered = false;
> + thread__find_addr_location(al.thread, machine, cpumode,
> + MAP__FUNCTION, ip, &tal);
> +
> + if (tal.sym)
> + fprintf(f, "..... %016" PRIx64 " %s\n", ip,
> + tal.sym->name);
> + else
> + fprintf(f, "..... %016" PRIx64 "\n", ip);
> + }
> +
> + fclose(f);
> +
> + return p;
> +}
> +
> typedef int (*tracepoint_handler)(struct perf_evsel *evsel,
> - struct perf_sample *sample);
> + struct perf_sample *sample,
> + const char *backtrace);
>
> static int process_sample_event(struct perf_tool *tool __maybe_unused,
> union perf_event *event __maybe_unused,
> @@ -485,7 +545,8 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
>
> if (evsel->handler.func != NULL) {
> tracepoint_handler f = evsel->handler.func;
> - return f(evsel, sample);
> + return f(evsel, sample,
> + cat_backtrace(event, sample, machine));
> }
>
> return 0;
> @@ -493,7 +554,8 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
>
> static int
> process_sample_cpu_idle(struct perf_evsel *evsel __maybe_unused,
> - struct perf_sample *sample)
> + struct perf_sample *sample,
> + const char *backtrace __maybe_unused)
> {
> struct power_processor_entry *ppe = sample->raw_data;
>
> @@ -506,7 +568,8 @@ process_sample_cpu_idle(struct perf_evsel *evsel __maybe_unused,
>
> static int
> process_sample_cpu_frequency(struct perf_evsel *evsel __maybe_unused,
> - struct perf_sample *sample)
> + struct perf_sample *sample,
> + const char *backtrace __maybe_unused)
> {
> struct power_processor_entry *ppe = sample->raw_data;
>
> @@ -516,28 +579,31 @@ process_sample_cpu_frequency(struct perf_evsel *evsel __maybe_unused,
>
> static int
> process_sample_sched_wakeup(struct perf_evsel *evsel __maybe_unused,
> - struct perf_sample *sample)
> + struct perf_sample *sample,
> + const char *backtrace __maybe_unused)
You don't need to add __maybe_unused if it's used. :)
> {
> struct trace_entry *te = sample->raw_data;
>
> - sched_wakeup(sample->cpu, sample->time, sample->pid, te);
> + sched_wakeup(sample->cpu, sample->time, sample->pid, te, backtrace);
> return 0;
> }
>
[SNIP]
> @@ -1166,6 +1255,7 @@ int cmd_timechart(int argc, const char **argv,
> "record power data only", parse_power),
> OPT_CALLBACK_NOOPT('T', "tasks-only", NULL, NULL,
> "record processes data only", parse_tasks),
> + OPT_BOOLEAN('g', "callchain", &with_backtrace, "record callchain"),
Please update the doc also.
Thanks,
Namhyung
> OPT_END()
> };
> const char * const record_usage[] = {
> 1. introduce while loop: it's a behavioral change so that it can be a
> separate patch. But it seems not checking the process filter - in that
> case the loop is almost useless IMHO.
Could you please elaborate on 'not checking the process filter'?
This loop is for the case when process filter is not set, but when the
filter is set it should also work (because determine_display_tasks calls
determine_display_tasks_filtered in case of process filter).
We just check the return value and loop while number of tasks is not
within the desired range (or thresh is zero).
> 2. new -n option: it should update Documentation/perf-timechart.txt
> also. And the long option name "number" is too general.
Does renaming "number" to "proc-num" sounds ok?
> 3. two if(proc_num): what is this? Is it for patch 2?
That's for the '-n 0' case, to completely skip tasks information.
Thanks for your comments, I'll split this patch into two parts and
update the docs.
> I don't see how it does same thing. You mean it by skipping
> draw_process_bars() and draw_wakeups() on patch 1? It'd be better
> changelog explains the details.
Yes, it depends on the previous patch, I'll add more info to the
changelog.
> And I'd like to keep it as BOOLEAN option - it's simpler and more
> straight-forward IMHO.
>
> How about adding
>
> if (power_only)
> proc_num = 0;
>
> after parsing the command line options?
Ok, this works too.
> Hmm.. double negation is always confusing to me. :-/ How about making
> it a boolean option that sets "task_only" variable?
Ok.
> Also need to update the doc. And what if user gives -P and -T options
> at the same time?
Is something like this is enough (or you'd like some printout with error
details)?
if (!proc_num && task_only)
usage_with_options(timechart_usage, options);
> For consistency, wouldn't it be better renaming svg_sample() to
> svg_running()?
Makes sense. I'll resend the whole series with updates later.
> It should be ARRAY_SIZE(old_power_args).
Thanks :-)
> Do we really need to separate the option and usage for record? AFAICS
> it does exactly same thing..
Yes, we do. Some options which are defined for timechart are undefined
for record (like -i, -o, etc), so we want to get an error in case of wrong
options.
And we separate usage, because it's different in timechart:
"perf timechart [<options>] {record}",
and record:
"perf timechart record [<options>]",
We may share usage, but we need it to be something (confusing?) like:
"perf timechart [<options>] {record [<options>]}",