4 files changed, 175 insertions, 36 deletions

diff --git a/tools/perf/Documentation/perf-timechart.txt b/tools/perf/Documentation/perf-timechart.txt
index 8359cfadf0ac..271dd4ed5b05 100644
--- a/tools/perf/Documentation/perf-timechart.txt
+++ b/tools/perf/Documentation/perf-timechart.txt
@@ -68,6 +68,9 @@ RECORD OPTIONS
 -T::
 --tasks-only::
         Record only tasks-related events
+-g::
+--callchain::
+        Do call-graph (stack chain/backtrace) recording
 
 SEE ALSO
 --------
diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c
index 1c60ed3f5b97..491662bdfe0b 100644
--- a/tools/perf/builtin-timechart.c
+++ b/tools/perf/builtin-timechart.c
@@ -52,6 +52,7 @@ static u64		first_time, last_time;
 
 static bool             power_only;
 static bool             tasks_only;
+static bool             with_backtrace;
 
 
 struct per_pid;
@@ -126,6 +127,7 @@ struct cpu_sample {
         u64 end_time;
         int type;
         int cpu;
+        const char *backtrace;
 };
 
 static struct per_pid *all_data;
@@ -147,6 +149,7 @@ struct wake_event {
         int waker;
         int wakee;
         u64 time;
+        const char *backtrace;
 };
 
 static struct power_event    *power_events;
@@ -231,7 +234,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;
@@ -254,6 +258,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) {
@@ -405,7 +410,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;
@@ -416,6 +422,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;
@@ -430,13 +437,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;
@@ -447,10 +456,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;
@@ -466,8 +479,87 @@ 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 (!f) {
+                perror("open_memstream error");
+                return NULL;
+        }
+
+        if (!chain)
+                goto exit;
+
+        if (perf_event__preprocess_sample(event, machine, &al, sample) < 0) {
+                fprintf(stderr, "problem processing %d event, skipping it.\n",
+                        event->header.type);
+                goto exit;
+        }
+
+        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];
+
+                if (ip >= PERF_CONTEXT_MAX) {
+                        switch (ip) {
+                        case PERF_CONTEXT_HV:
+                                cpumode = PERF_RECORD_MISC_HYPERVISOR;
+                                break;
+                        case PERF_CONTEXT_KERNEL:
+                                cpumode = PERF_RECORD_MISC_KERNEL;
+                                break;
+                        case PERF_CONTEXT_USER:
+                                cpumode = PERF_RECORD_MISC_USER;
+                                break;
+                        default:
+                                pr_debug("invalid callchain context: "
+                                         "%"PRId64"\n", (s64) ip);
+
+                                /*
+                                 * It seems the callchain is corrupted.
+                                 * Discard all.
+                                 */
+                                free(p);
+                                p = NULL;
+                                goto exit;
+                        }
+                        continue;
+                }
+
+                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);
+        }
+
+exit:
+        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,
@@ -487,7 +579,7 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
 
         if (evsel->handler != NULL) {
                 tracepoint_handler f = evsel->handler;
-                return f(evsel, sample);
+                return f(evsel, sample, cat_backtrace(event, sample, machine));
         }
 
         return 0;
@@ -495,7 +587,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;
 
@@ -508,7 +601,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;
 
@@ -518,28 +612,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)
 {
         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)
 {
         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;
 
@@ -549,7 +646,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;
@@ -557,7 +655,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;
 
@@ -741,11 +840,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);
@@ -798,11 +898,20 @@ static void draw_process_bars(void)
                         sample = c->samples;
                         while (sample) {
                                 if (sample->type == TYPE_RUNNING)
-                                        svg_running(Y, sample->cpu, sample->start_time, sample->end_time);
+                                        svg_running(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;
                         }
 
@@ -1050,6 +1159,11 @@ static int __cmd_record(int argc, const char **argv)
         };
         unsigned int common_args_nr = 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",
@@ -1089,8 +1203,11 @@ static int __cmd_record(int argc, const char **argv)
                 old_power_args_nr = 0;
         }
 
+        if (!with_backtrace)
+                backtrace_args_no = 0;
+
         record_elems = common_args_nr + tasks_args_nr +
-                power_args_nr + old_power_args_nr;
+                power_args_nr + old_power_args_nr + backtrace_args_no;
 
         rec_argc = record_elems + argc;
         rec_argv = calloc(rec_argc + 1, sizeof(char *));
@@ -1102,6 +1219,9 @@ static int __cmd_record(int argc, const char **argv)
         for (i = 0; i < common_args_nr; 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_nr; i++)
                 *p++ = strdup(tasks_args[i]);
 
@@ -1155,6 +1275,7 @@ int cmd_timechart(int argc, const char **argv,
         OPT_BOOLEAN('P', "power-only", &power_only, "output power data only"),
         OPT_BOOLEAN('T', "tasks-only", &tasks_only,
                     "output processes data only"),
+        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 9a5b41392e01..8b79d3ad1246 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_running(int Yslot, int cpu, u64 start, u64 end)
+void svg_running(int Yslot, int cpu, u64 start, u64 end, const char *backtrace)
 {
         double text_size;
         if (!svgfile)
@@ -152,6 +154,8 @@ void svg_running(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 aa533459ab76..fad79ceeac1a 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_running(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_running(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);