perf record/report: Add call graph / call chain profiling
authorIngo Molnar <mingo@elte.hu>
Sun, 14 Jun 2009 13:04:15 +0000 (15:04 +0200)
committerIngo Molnar <mingo@elte.hu>
Sun, 14 Jun 2009 18:34:06 +0000 (20:34 +0200)
Add the first steps of call-graph profiling:

 - add the -c (--call-graph) option to perf record
 - parse the call-graph record and printout out under -D (--dump-trace)

The call-graph data is not put into the histogram yet, but it
can be seen that it's being processed correctly:

0x3ce0 [0x38]: event: 35
.
. ... raw event: size 56 bytes
.  0000:  23 00 00 00 05 00 38 00 d4 df 0e 81 ff ff ff ff  #.....8........
.  0010:  60 0b 00 00 60 0b 00 00 03 00 00 00 01 00 02 00  `...`..........
.  0020:  d4 df 0e 81 ff ff ff ff a0 61 ed 41 36 00 00 00  .........a.A6..
.  0030:  04 92 e6 41 36 00 00 00                          .a.A6..
.
0x3ce0 [0x38]: PERF_EVENT (IP, 5): 2912: 0xffffffff810edfd4 period: 1
... chain: u:2, k:1, nr:3
.....  0: 0xffffffff810edfd4
.....  1: 0x3641ed61a0
.....  2: 0x3641e69204
 ... thread: perf:2912
 ...... dso: [kernel]

This shows a 3-entry call-graph: with 1 kernel-space and two user-space
entries

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Pekka Enberg <penberg@cs.helsinki.fi>
Cc: Arjan van de Ven <arjan@infradead.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
LKML-Reference: <new-submission>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
tools/perf/builtin-record.c
tools/perf/builtin-report.c

index 0f5771f615dae24cd9a4073eb9b5ee95419f1124..a177a591b52cdb377b7eee330be286d102d16fa5 100644 (file)
@@ -37,6 +37,7 @@ static pid_t                  target_pid                      = -1;
 static int                     inherit                         = 1;
 static int                     force                           = 0;
 static int                     append_file                     = 0;
+static int                     call_graph                      = 0;
 static int                     verbose                         = 0;
 
 static long                    samples;
@@ -351,11 +352,16 @@ static void create_counter(int counter, int cpu, pid_t pid)
        int track = 1;
 
        attr->sample_type       = PERF_SAMPLE_IP | PERF_SAMPLE_TID;
+
        if (freq) {
                attr->sample_type       |= PERF_SAMPLE_PERIOD;
                attr->freq              = 1;
                attr->sample_freq       = freq;
        }
+
+       if (call_graph)
+               attr->sample_type       |= PERF_SAMPLE_CALLCHAIN;
+
        attr->mmap              = track;
        attr->comm              = track;
        attr->inherit           = (cpu < 0) && inherit;
@@ -555,6 +561,8 @@ static const struct option options[] = {
                    "profile at this frequency"),
        OPT_INTEGER('m', "mmap-pages", &mmap_pages,
                    "number of mmap data pages"),
+       OPT_BOOLEAN('g', "call-graph", &call_graph,
+                   "do call-graph (stack chain/backtrace) recording"),
        OPT_BOOLEAN('v', "verbose", &verbose,
                    "be more verbose (show counter open errors, etc)"),
        OPT_END()
index 37515da637f741f46e41db049acc55ede003982e..aebba565934534b4a2c1fa8112088ace284f946f 100644 (file)
@@ -36,6 +36,7 @@ static int            show_mask = SHOW_KERNEL | SHOW_USER | SHOW_HV;
 
 static int             dump_trace = 0;
 #define dprintf(x...)  do { if (dump_trace) printf(x); } while (0)
+#define cdprintf(x...) do { if (dump_trace) color_fprintf(stdout, color, x); } while (0)
 
 static int             verbose;
 static int             full_paths;
@@ -43,11 +44,19 @@ static int          full_paths;
 static unsigned long   page_size;
 static unsigned long   mmap_window = 32;
 
+struct ip_chain_event {
+       __u16 nr;
+       __u16 hv;
+       __u16 kernel;
+       __u16 user;
+       __u64 ips[];
+};
+
 struct ip_event {
        struct perf_event_header header;
        __u64 ip;
        __u32 pid, tid;
-       __u64 period;
+       unsigned char __more_data[];
 };
 
 struct mmap_event {
@@ -944,9 +953,13 @@ process_overflow_event(event_t *event, unsigned long offset, unsigned long head)
        __u64 ip = event->ip.ip;
        __u64 period = 1;
        struct map *map = NULL;
+       void *more_data = event->ip.__more_data;
+       struct ip_chain_event *chain;
 
-       if (event->header.type & PERF_SAMPLE_PERIOD)
-               period = event->ip.period;
+       if (event->header.type & PERF_SAMPLE_PERIOD) {
+               period = *(__u64 *)more_data;
+               more_data += sizeof(__u64);
+       }
 
        dprintf("%p [%p]: PERF_EVENT (IP, %d): %d: %p period: %Ld\n",
                (void *)(offset + head),
@@ -956,6 +969,22 @@ process_overflow_event(event_t *event, unsigned long offset, unsigned long head)
                (void *)(long)ip,
                (long long)period);
 
+       if (event->header.type & PERF_SAMPLE_CALLCHAIN) {
+               int i;
+
+               chain = (void *)more_data;
+
+               if (dump_trace) {
+                       dprintf("... chain: u:%d, k:%d, nr:%d\n",
+                               chain->user,
+                               chain->kernel,
+                               chain->nr);
+
+                       for (i = 0; i < chain->nr; i++)
+                               dprintf("..... %2d: %p\n", i, (void *)chain->ips[i]);
+               }
+       }
+
        dprintf(" ... thread: %s:%d\n", thread->comm, thread->pid);
 
        if (thread == NULL) {
@@ -1098,30 +1127,34 @@ process_period_event(event_t *event, unsigned long offset, unsigned long head)
 static void trace_event(event_t *event)
 {
        unsigned char *raw_event = (void *)event;
+       char *color = PERF_COLOR_BLUE;
        int i, j;
 
        if (!dump_trace)
                return;
 
-       dprintf(".\n. ... raw event: size %d bytes\n", event->header.size);
+       dprintf(".");
+       cdprintf("\n. ... raw event: size %d bytes\n", event->header.size);
 
        for (i = 0; i < event->header.size; i++) {
-               if ((i & 15) == 0)
-                       dprintf(".  %04x: ", i);
+               if ((i & 15) == 0) {
+                       dprintf(".");
+                       cdprintf("  %04x: ", i);
+               }
 
-               dprintf(" %02x", raw_event[i]);
+               cdprintf(" %02x", raw_event[i]);
 
                if (((i & 15) == 15) || i == event->header.size-1) {
-                       dprintf("  ");
+                       cdprintf("  ");
                        for (j = 0; j < 15-(i & 15); j++)
-                               dprintf("   ");
+                               cdprintf("   ");
                        for (j = 0; j < (i & 15); j++) {
                                if (isprint(raw_event[i-15+j]))
-                                       dprintf("%c", raw_event[i-15+j]);
+                                       cdprintf("%c", raw_event[i-15+j]);
                                else
-                                       dprintf(".");
+                                       cdprintf(".");
                        }
-                       dprintf("\n");
+                       cdprintf("\n");
                }
        }
        dprintf(".\n");