perf_counter tools: Handle lost events
[linux-block.git] / tools / perf / builtin-report.c
index 82fa93b4db9996d3af08d72b71934053107d70ef..fe66895111b1450c725d9789e6064836f59cf024 100644 (file)
@@ -36,18 +36,24 @@ 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;
+#define eprintf(x...)  do { if (verbose) fprintf(stderr, x); } while (0)
+
 static int             full_paths;
 
 static unsigned long   page_size;
 static unsigned long   mmap_window = 32;
 
+static char            *parent_pattern = "^sys_|^do_page_fault";
+static regex_t         parent_regex;
+
 struct ip_event {
        struct perf_event_header header;
        __u64 ip;
        __u32 pid, tid;
-       __u64 period;
+       unsigned char __more_data[];
 };
 
 struct mmap_event {
@@ -77,6 +83,12 @@ struct period_event {
        __u64 sample_period;
 };
 
+struct lost_event {
+       struct perf_event_header header;
+       __u64 id;
+       __u64 lost;
+};
+
 typedef union event_union {
        struct perf_event_header        header;
        struct ip_event                 ip;
@@ -84,6 +96,7 @@ typedef union event_union {
        struct comm_event               comm;
        struct fork_event               fork;
        struct period_event             period;
+       struct lost_event               lost;
 } event_t;
 
 static LIST_HEAD(dsos);
@@ -119,15 +132,11 @@ static struct dso *dsos__findnew(const char *name)
 
        nr = dso__load(dso, NULL, verbose);
        if (nr < 0) {
-               if (verbose)
-                       fprintf(stderr, "Failed to open: %s\n", name);
+               eprintf("Failed to open: %s\n", name);
                goto out_delete_dso;
        }
-       if (!nr && verbose) {
-               fprintf(stderr,
-               "No symbols found in: %s, maybe install a debug package?\n",
-                               name);
-       }
+       if (!nr)
+               eprintf("No symbols found in: %s, maybe install a debug package?\n", name);
 
        dsos__add(dso);
 
@@ -453,6 +462,7 @@ struct hist_entry {
        struct map       *map;
        struct dso       *dso;
        struct symbol    *sym;
+       struct symbol    *parent;
        __u64            ip;
        char             level;
 
@@ -473,6 +483,16 @@ struct sort_entry {
        size_t  (*print)(FILE *fp, struct hist_entry *);
 };
 
+static int64_t cmp_null(void *l, void *r)
+{
+       if (!l && !r)
+               return 0;
+       else if (!l)
+               return -1;
+       else
+               return 1;
+}
+
 /* --sort pid */
 
 static int64_t
@@ -507,14 +527,8 @@ sort__comm_collapse(struct hist_entry *left, struct hist_entry *right)
        char *comm_l = left->thread->comm;
        char *comm_r = right->thread->comm;
 
-       if (!comm_l || !comm_r) {
-               if (!comm_l && !comm_r)
-                       return 0;
-               else if (!comm_l)
-                       return -1;
-               else
-                       return 1;
-       }
+       if (!comm_l || !comm_r)
+               return cmp_null(comm_l, comm_r);
 
        return strcmp(comm_l, comm_r);
 }
@@ -540,14 +554,8 @@ sort__dso_cmp(struct hist_entry *left, struct hist_entry *right)
        struct dso *dso_l = left->dso;
        struct dso *dso_r = right->dso;
 
-       if (!dso_l || !dso_r) {
-               if (!dso_l && !dso_r)
-                       return 0;
-               else if (!dso_l)
-                       return -1;
-               else
-                       return 1;
-       }
+       if (!dso_l || !dso_r)
+               return cmp_null(dso_l, dso_r);
 
        return strcmp(dso_l->name, dso_r->name);
 }
@@ -607,7 +615,38 @@ static struct sort_entry sort_sym = {
        .print  = sort__sym_print,
 };
 
+/* --sort parent */
+
+static int64_t
+sort__parent_cmp(struct hist_entry *left, struct hist_entry *right)
+{
+       struct symbol *sym_l = left->parent;
+       struct symbol *sym_r = right->parent;
+
+       if (!sym_l || !sym_r)
+               return cmp_null(sym_l, sym_r);
+
+       return strcmp(sym_l->name, sym_r->name);
+}
+
+static size_t
+sort__parent_print(FILE *fp, struct hist_entry *self)
+{
+       size_t ret = 0;
+
+       ret += fprintf(fp, "%-20s", self->parent ? self->parent->name : "[other]");
+
+       return ret;
+}
+
+static struct sort_entry sort_parent = {
+       .header = "Parent symbol       ",
+       .cmp    = sort__parent_cmp,
+       .print  = sort__parent_print,
+};
+
 static int sort__need_collapse = 0;
+static int sort__has_parent = 0;
 
 struct sort_dimension {
        char                    *name;
@@ -620,6 +659,7 @@ static struct sort_dimension sort_dimensions[] = {
        { .name = "comm",       .entry = &sort_comm,    },
        { .name = "dso",        .entry = &sort_dso,     },
        { .name = "symbol",     .entry = &sort_sym,     },
+       { .name = "parent",     .entry = &sort_parent,  },
 };
 
 static LIST_HEAD(hist_entry__sort_list);
@@ -640,6 +680,19 @@ static int sort_dimension__add(char *tok)
                if (sd->entry->collapse)
                        sort__need_collapse = 1;
 
+               if (sd->entry == &sort_parent) {
+                       int ret = regcomp(&parent_regex, parent_pattern, REG_EXTENDED);
+                       if (ret) {
+                               char err[BUFSIZ];
+
+                               regerror(ret, &parent_regex, err, sizeof(err));
+                               fprintf(stderr, "Invalid regex: %s\n%s",
+                                       parent_pattern, err);
+                               exit(-1);
+                       }
+                       sort__has_parent = 1;
+               }
+
                list_add_tail(&sd->entry->list, &hist_entry__sort_list);
                sd->taken = 1;
 
@@ -720,13 +773,76 @@ hist_entry__fprintf(FILE *fp, struct hist_entry *self, __u64 total_samples)
        return ret;
 }
 
+/*
+ *
+ */
+
+static struct symbol *
+resolve_symbol(struct thread *thread, struct map **mapp,
+              struct dso **dsop, __u64 *ipp)
+{
+       struct dso *dso = dsop ? *dsop : NULL;
+       struct map *map = mapp ? *mapp : NULL;
+       uint64_t ip = *ipp;
+
+       if (!thread)
+               return NULL;
+
+       if (dso)
+               goto got_dso;
+
+       if (map)
+               goto got_map;
+
+       map = thread__find_map(thread, ip);
+       if (map != NULL) {
+               if (mapp)
+                       *mapp = map;
+got_map:
+               ip = map->map_ip(map, ip);
+               *ipp  = ip;
+
+               dso = map->dso;
+       } else {
+               /*
+                * If this is outside of all known maps,
+                * and is a negative address, try to look it
+                * up in the kernel dso, as it might be a
+                * vsyscall (which executes in user-mode):
+                */
+               if ((long long)ip < 0)
+               dso = kernel_dso;
+       }
+       dprintf(" ...... dso: %s\n", dso ? dso->name : "<not found>");
+
+       if (dsop)
+               *dsop = dso;
+
+       if (!dso)
+               return NULL;
+got_dso:
+       return dso->find_symbol(dso, ip);
+}
+
+static struct symbol *call__match(struct symbol *sym)
+{
+       if (!sym)
+               return NULL;
+
+       if (sym->name && !regexec(&parent_regex, sym->name, 0, NULL, 0))
+               return sym;
+
+       return NULL;
+}
+
 /*
  * collect histogram counts
  */
 
 static int
 hist_entry__add(struct thread *thread, struct map *map, struct dso *dso,
-               struct symbol *sym, __u64 ip, char level, __u64 count)
+               struct symbol *sym, __u64 ip, struct perf_callchain_entry *chain,
+               char level, __u64 count)
 {
        struct rb_node **p = &hist.rb_node;
        struct rb_node *parent = NULL;
@@ -742,6 +858,33 @@ hist_entry__add(struct thread *thread, struct map *map, struct dso *dso,
        };
        int cmp;
 
+       if (sort__has_parent && chain) {
+               int i, nr = chain->hv;
+               struct symbol *sym;
+               struct dso *dso;
+               __u64 ip;
+
+               for (i = 0; i < chain->kernel; i++) {
+                       ip = chain->ip[nr + i];
+                       dso = kernel_dso;
+                       sym = resolve_symbol(thread, NULL, &dso, &ip);
+                       entry.parent = call__match(sym);
+                       if (entry.parent)
+                               goto got_parent;
+               }
+               nr += i;
+
+               for (i = 0; i < chain->user; i++) {
+                       ip = chain->ip[nr + i];
+                       sym = resolve_symbol(thread, NULL, NULL, &ip);
+                       entry.parent = call__match(sym);
+                       if (entry.parent)
+                               goto got_parent;
+               }
+               nr += i;
+       }
+got_parent:
+
        while (*p != NULL) {
                parent = *p;
                he = rb_entry(parent, struct hist_entry, rb_node);
@@ -932,7 +1075,32 @@ static unsigned long total = 0,
                     total_mmap = 0,
                     total_comm = 0,
                     total_fork = 0,
-                    total_unknown = 0;
+                    total_unknown = 0,
+                    total_lost = 0;
+
+static int validate_chain(struct perf_callchain_entry *chain, event_t *event)
+{
+       unsigned int chain_size;
+
+       if (chain->nr > MAX_STACK_DEPTH)
+               return -1;
+       if (chain->hv > MAX_STACK_DEPTH)
+               return -1;
+       if (chain->kernel > MAX_STACK_DEPTH)
+               return -1;
+       if (chain->user > MAX_STACK_DEPTH)
+               return -1;
+       if (chain->hv + chain->kernel + chain->user != chain->nr)
+               return -1;
+
+       chain_size = event->header.size;
+       chain_size -= (unsigned long)&event->ip.__more_data - (unsigned long)event;
+
+       if (chain->nr*sizeof(__u64) > chain_size)
+               return -1;
+
+       return 0;
+}
 
 static int
 process_overflow_event(event_t *event, unsigned long offset, unsigned long head)
@@ -944,9 +1112,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 perf_callchain_entry *chain = NULL;
 
-       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,10 +1128,31 @@ 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;
+
+               dprintf("... chain: u:%d, k:%d, nr:%d\n",
+                       chain->user,
+                       chain->kernel,
+                       chain->nr);
+
+               if (validate_chain(chain, event) < 0) {
+                       eprintf("call-chain problem with event, skipping it.\n");
+                       return 0;
+               }
+
+               if (dump_trace) {
+                       for (i = 0; i < chain->nr; i++)
+                               dprintf("..... %2d: %016Lx\n", i, chain->ip[i]);
+               }
+       }
+
        dprintf(" ... thread: %s:%d\n", thread->comm, thread->pid);
 
        if (thread == NULL) {
-               fprintf(stderr, "problem processing %d event, skipping it.\n",
+               eprintf("problem processing %d event, skipping it.\n",
                        event->header.type);
                return -1;
        }
@@ -977,22 +1170,6 @@ process_overflow_event(event_t *event, unsigned long offset, unsigned long head)
                show = SHOW_USER;
                level = '.';
 
-               map = thread__find_map(thread, ip);
-               if (map != NULL) {
-                       ip = map->map_ip(map, ip);
-                       dso = map->dso;
-               } else {
-                       /*
-                        * If this is outside of all known maps,
-                        * and is a negative address, try to look it
-                        * up in the kernel dso, as it might be a
-                        * vsyscall (which executes in user-mode):
-                        */
-                       if ((long long)ip < 0)
-                               dso = kernel_dso;
-               }
-               dprintf(" ...... dso: %s\n", dso ? dso->name : "<not found>");
-
        } else {
                show = SHOW_HV;
                level = 'H';
@@ -1000,14 +1177,10 @@ process_overflow_event(event_t *event, unsigned long offset, unsigned long head)
        }
 
        if (show & show_mask) {
-               struct symbol *sym = NULL;
-
-               if (dso)
-                       sym = dso->find_symbol(dso, ip);
+               struct symbol *sym = resolve_symbol(thread, &map, &dso, &ip);
 
-               if (hist_entry__add(thread, map, dso, sym, ip, level, period)) {
-                       fprintf(stderr,
-               "problem incrementing symbol count, skipping event\n");
+               if (hist_entry__add(thread, map, dso, sym, ip, chain, level, period)) {
+                       eprintf("problem incrementing symbol count, skipping event\n");
                        return -1;
                }
        }
@@ -1095,9 +1268,61 @@ process_period_event(event_t *event, unsigned long offset, unsigned long head)
        return 0;
 }
 
+static int
+process_lost_event(event_t *event, unsigned long offset, unsigned long head)
+{
+       dprintf("%p [%p]: PERF_EVENT_LOST: id:%Ld: lost:%Ld\n",
+               (void *)(offset + head),
+               (void *)(long)(event->header.size),
+               event->lost.id,
+               event->lost.lost);
+
+       total_lost += event->lost.lost;
+
+       return 0;
+}
+
+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(".");
+       cdprintf("\n. ... raw event: size %d bytes\n", event->header.size);
+
+       for (i = 0; i < event->header.size; i++) {
+               if ((i & 15) == 0) {
+                       dprintf(".");
+                       cdprintf("  %04x: ", i);
+               }
+
+               cdprintf(" %02x", raw_event[i]);
+
+               if (((i & 15) == 15) || i == event->header.size-1) {
+                       cdprintf("  ");
+                       for (j = 0; j < 15-(i & 15); j++)
+                               cdprintf("   ");
+                       for (j = 0; j < (i & 15); j++) {
+                               if (isprint(raw_event[i-15+j]))
+                                       cdprintf("%c", raw_event[i-15+j]);
+                               else
+                                       cdprintf(".");
+                       }
+                       cdprintf("\n");
+               }
+       }
+       dprintf(".\n");
+}
+
 static int
 process_event(event_t *event, unsigned long offset, unsigned long head)
 {
+       trace_event(event);
+
        if (event->header.misc & PERF_EVENT_MISC_OVERFLOW)
                return process_overflow_event(event, offset, head);
 
@@ -1113,6 +1338,10 @@ process_event(event_t *event, unsigned long offset, unsigned long head)
 
        case PERF_EVENT_PERIOD:
                return process_period_event(event, offset, head);
+
+       case PERF_EVENT_LOST:
+               return process_lost_event(event, offset, head);
+
        /*
         * We dont process them right now but they are fine:
         */
@@ -1204,7 +1433,7 @@ more:
 
        size = event->header.size;
 
-       dprintf("%p [%p]: event: %d\n",
+       dprintf("\n%p [%p]: event: %d\n",
                        (void *)(offset + head),
                        (void *)(long)event->header.size,
                        event->header.type);
@@ -1241,6 +1470,7 @@ more:
        dprintf("    mmap events: %10ld\n", total_mmap);
        dprintf("    comm events: %10ld\n", total_comm);
        dprintf("    fork events: %10ld\n", total_fork);
+       dprintf("    lost events: %10ld\n", total_lost);
        dprintf(" unknown events: %10ld\n", total_unknown);
 
        if (dump_trace)
@@ -1273,9 +1503,11 @@ static const struct option options[] = {
                    "dump raw trace in ASCII"),
        OPT_STRING('k', "vmlinux", &vmlinux, "file", "vmlinux pathname"),
        OPT_STRING('s', "sort", &sort_order, "key[,key2...]",
-                  "sort by key(s): pid, comm, dso, symbol. Default: pid,symbol"),
+                  "sort by key(s): pid, comm, dso, symbol, parent"),
        OPT_BOOLEAN('P', "full-paths", &full_paths,
                    "Don't shorten the pathnames taking into account the cwd"),
+       OPT_STRING('p', "parent", &parent_pattern, "regex",
+                  "regex filter to identify parent, see: '--sort parent'"),
        OPT_END()
 };