From 52d422de22b26d96bbdfbc605eb31c2994df6d0b Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Fri, 10 Jul 2009 22:47:28 -0300 Subject: perf report: Adjust column width to the values sampled Auto-adjust column width of perf report output to the longest occuring string length. Example: [acme@doppio pahole]$ perf report --sort comm,dso,symbol | head -13 12.79% pahole /usr/lib64/libdw-0.141.so [.] __libdw_find_attr 8.90% pahole /lib64/libc-2.10.1.so [.] _int_malloc 8.68% pahole /usr/lib64/libdw-0.141.so [.] __libdw_form_val_len 8.15% pahole /lib64/libc-2.10.1.so [.] __GI_strcmp 6.80% pahole /lib64/libc-2.10.1.so [.] __tsearch 5.54% pahole ./build/libdwarves.so.1.0.0 [.] tag__recode_dwarf_type [acme@doppio pahole]$ [acme@doppio pahole]$ perf report --sort comm,dso,symbol -d /lib64/libc-2.10.1.so | head -10 21.92% pahole /lib64/libc-2.10.1.so [.] _int_malloc 20.08% pahole /lib64/libc-2.10.1.so [.] __GI_strcmp 16.75% pahole /lib64/libc-2.10.1.so [.] __tsearch [acme@doppio pahole]$ Also add these extra options to control the new behaviour: -w, --field-width Force each column width to the provided list, for large terminal readability. -t, --field-separator: Use a special separator character and don't pad with spaces, replacing all occurances of this separator in symbol names (and other output) with a '.' character, that thus it's the only non valid separator. Signed-off-by: Arnaldo Carvalho de Melo Cc: Frederic Weisbecker Cc: Mike Galbraith Cc: Peter Zijlstra Cc: Paul Mackerras LKML-Reference: <20090711014728.GH3452@ghostprotocols.net> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 174 ++++++++++++++++++++++++++++++++++++-------- 1 file changed, 142 insertions(+), 32 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 4e5cc266311e..740da43f313e 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -33,8 +33,10 @@ static char *vmlinux = NULL; static char default_sort_order[] = "comm,dso"; static char *sort_order = default_sort_order; -static char *dso_list_str, *comm_list_str, *sym_list_str; +static char *dso_list_str, *comm_list_str, *sym_list_str, + *col_width_list_str; static struct strlist *dso_list, *comm_list, *sym_list; +static char *field_sep; static int input; static int show_mask = SHOW_KERNEL | SHOW_USER | SHOW_HV; @@ -129,6 +131,33 @@ typedef union event_union { struct read_event read; } event_t; +static int repsep_fprintf(FILE *fp, const char *fmt, ...) +{ + int n; + va_list ap; + + va_start(ap, fmt); + if (!field_sep) + n = vfprintf(fp, fmt, ap); + else { + char *bf = NULL; + n = vasprintf(&bf, fmt, ap); + if (n > 0) { + char *sep = bf; + while (1) { + sep = strchr(sep, *field_sep); + if (sep == NULL) + break; + *sep = '.'; + } + } + fputs(bf, fp); + free(bf); + } + va_end(ap); + return n; +} + static LIST_HEAD(dsos); static struct dso *kernel_dso; static struct dso *vdso; @@ -360,12 +389,28 @@ static struct thread *thread__new(pid_t pid) return self; } +static unsigned int dsos__col_width, + comms__col_width, + threads__col_width; + static int thread__set_comm(struct thread *self, const char *comm) { if (self->comm) free(self->comm); self->comm = strdup(comm); - return self->comm ? 0 : -ENOMEM; + if (!self->comm) + return -ENOMEM; + + if (!col_width_list_str && !field_sep && + (!comm_list || strlist__has_entry(comm_list, comm))) { + unsigned int slen = strlen(comm); + if (slen > comms__col_width) { + comms__col_width = slen; + threads__col_width = slen + 6; + } + } + + return 0; } static size_t thread__fprintf(struct thread *self, FILE *fp) @@ -536,7 +581,8 @@ struct sort_entry { int64_t (*cmp)(struct hist_entry *, struct hist_entry *); int64_t (*collapse)(struct hist_entry *, struct hist_entry *); - size_t (*print)(FILE *fp, struct hist_entry *); + size_t (*print)(FILE *fp, struct hist_entry *, unsigned int width); + unsigned int *width; }; static int64_t cmp_null(void *l, void *r) @@ -558,15 +604,17 @@ sort__thread_cmp(struct hist_entry *left, struct hist_entry *right) } static size_t -sort__thread_print(FILE *fp, struct hist_entry *self) +sort__thread_print(FILE *fp, struct hist_entry *self, unsigned int width) { - return fprintf(fp, "%16s:%5d", self->thread->comm ?: "", self->thread->pid); + return repsep_fprintf(fp, "%*s:%5d", width - 6, + self->thread->comm ?: "", self->thread->pid); } static struct sort_entry sort_thread = { - .header = " Command: Pid", + .header = "Command: Pid", .cmp = sort__thread_cmp, .print = sort__thread_print, + .width = &threads__col_width, }; /* --sort comm */ @@ -590,16 +638,17 @@ sort__comm_collapse(struct hist_entry *left, struct hist_entry *right) } static size_t -sort__comm_print(FILE *fp, struct hist_entry *self) +sort__comm_print(FILE *fp, struct hist_entry *self, unsigned int width) { - return fprintf(fp, "%16s", self->thread->comm); + return repsep_fprintf(fp, "%*s", width, self->thread->comm); } static struct sort_entry sort_comm = { - .header = " Command", + .header = "Command", .cmp = sort__comm_cmp, .collapse = sort__comm_collapse, .print = sort__comm_print, + .width = &comms__col_width, }; /* --sort dso */ @@ -617,18 +666,19 @@ sort__dso_cmp(struct hist_entry *left, struct hist_entry *right) } static size_t -sort__dso_print(FILE *fp, struct hist_entry *self) +sort__dso_print(FILE *fp, struct hist_entry *self, unsigned int width) { if (self->dso) - return fprintf(fp, "%-25s", self->dso->name); + return repsep_fprintf(fp, "%-*s", width, self->dso->name); - return fprintf(fp, "%016llx ", (u64)self->ip); + return repsep_fprintf(fp, "%*llx", width, (u64)self->ip); } static struct sort_entry sort_dso = { - .header = "Shared Object ", + .header = "Shared Object", .cmp = sort__dso_cmp, .print = sort__dso_print, + .width = &dsos__col_width, }; /* --sort symbol */ @@ -648,22 +698,23 @@ sort__sym_cmp(struct hist_entry *left, struct hist_entry *right) } static size_t -sort__sym_print(FILE *fp, struct hist_entry *self) +sort__sym_print(FILE *fp, struct hist_entry *self, unsigned int width __used) { size_t ret = 0; if (verbose) - ret += fprintf(fp, "%#018llx ", (u64)self->ip); + ret += repsep_fprintf(fp, "%#018llx ", (u64)self->ip); if (self->sym) { - ret += fprintf(fp, "[%c] %s", + ret += repsep_fprintf(fp, "[%c] %s", self->dso == kernel_dso ? 'k' : self->dso == hypervisor_dso ? 'h' : '.', self->sym->name); if (self->sym->module) - ret += fprintf(fp, "\t[%s]", self->sym->module->name); + ret += repsep_fprintf(fp, "\t[%s]", + self->sym->module->name); } else { - ret += fprintf(fp, "%#016llx", (u64)self->ip); + ret += repsep_fprintf(fp, "%#016llx", (u64)self->ip); } return ret; @@ -690,19 +741,19 @@ sort__parent_cmp(struct hist_entry *left, struct hist_entry *right) } static size_t -sort__parent_print(FILE *fp, struct hist_entry *self) +sort__parent_print(FILE *fp, struct hist_entry *self, unsigned int width) { - size_t ret = 0; - - ret += fprintf(fp, "%-20s", self->parent ? self->parent->name : "[other]"); - - return ret; + return repsep_fprintf(fp, "%-*s", width, + self->parent ? self->parent->name : "[other]"); } +static unsigned int parent_symbol__col_width; + static struct sort_entry sort_parent = { - .header = "Parent symbol ", + .header = "Parent symbol", .cmp = sort__parent_cmp, .print = sort__parent_print, + .width = &parent_symbol__col_width, }; static int sort__need_collapse = 0; @@ -967,17 +1018,18 @@ hist_entry__fprintf(FILE *fp, struct hist_entry *self, u64 total_samples) return 0; if (total_samples) - ret = percent_color_fprintf(fp, " %6.2f%%", - (self->count * 100.0) / total_samples); + ret = percent_color_fprintf(fp, + field_sep ? "%.2f" : " %6.2f%%", + (self->count * 100.0) / total_samples); else - ret = fprintf(fp, "%12Ld ", self->count); + ret = fprintf(fp, field_sep ? "%lld" : "%12lld ", self->count); list_for_each_entry(se, &hist_entry__sort_list, list) { if (exclude_other && (se == &sort_parent)) continue; - fprintf(fp, " "); - ret += se->print(fp, self); + fprintf(fp, "%s", field_sep ?: " "); + ret += se->print(fp, self, se->width ? *se->width : 0); } ret += fprintf(fp, "\n"); @@ -992,6 +1044,18 @@ hist_entry__fprintf(FILE *fp, struct hist_entry *self, u64 total_samples) * */ +static void dso__calc_col_width(struct dso *self) +{ + if (!col_width_list_str && !field_sep && + (!dso_list || strlist__has_entry(dso_list, self->name))) { + unsigned int slen = strlen(self->name); + if (slen > dsos__col_width) + dsos__col_width = slen; + } + + self->slen_calculated = 1; +} + static struct symbol * resolve_symbol(struct thread *thread, struct map **mapp, struct dso **dsop, u64 *ipp) @@ -1011,6 +1075,14 @@ resolve_symbol(struct thread *thread, struct map **mapp, map = thread__find_map(thread, ip); if (map != NULL) { + /* + * We have to do this here as we may have a dso + * with no symbol hit that has a name longer than + * the ones with symbols sampled. + */ + if (!map->dso->slen_calculated) + dso__calc_col_width(map->dso); + if (mapp) *mapp = map; got_map: @@ -1282,6 +1354,8 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) struct sort_entry *se; struct rb_node *nd; size_t ret = 0; + unsigned int width; + char *col_width = col_width_list_str; fprintf(fp, "\n"); fprintf(fp, "#\n"); @@ -1292,10 +1366,29 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) list_for_each_entry(se, &hist_entry__sort_list, list) { if (exclude_other && (se == &sort_parent)) continue; - fprintf(fp, " %s", se->header); + if (field_sep) { + fprintf(fp, "%c%s", *field_sep, se->header); + continue; + } + width = strlen(se->header); + if (se->width) { + if (col_width_list_str) { + if (col_width) { + *se->width = atoi(col_width); + col_width = strchr(col_width, ','); + if (col_width) + ++col_width; + } + } + width = *se->width = max(*se->width, width); + } + fprintf(fp, " %*s", width, se->header); } fprintf(fp, "\n"); + if (field_sep) + goto print_entries; + fprintf(fp, "# ........"); list_for_each_entry(se, &hist_entry__sort_list, list) { unsigned int i; @@ -1304,13 +1397,18 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) continue; fprintf(fp, " "); - for (i = 0; i < strlen(se->header); i++) + if (se->width) + width = *se->width; + else + width = strlen(se->header); + for (i = 0; i < width; i++) fprintf(fp, "."); } fprintf(fp, "\n"); fprintf(fp, "#\n"); +print_entries: for (nd = rb_first(&output_hists); nd; nd = rb_next(nd)) { pos = rb_entry(nd, struct hist_entry, rb_node); ret += hist_entry__fprintf(fp, pos, total_samples); @@ -1900,6 +1998,12 @@ static const struct option options[] = { "only consider symbols in these comms"), OPT_STRING('S', "symbols", &sym_list_str, "symbol[,symbol...]", "only consider these symbols"), + OPT_STRING('w', "column-widths", &col_width_list_str, + "width[,width...]", + "don't try to adjust column width, use these fixed values"), + OPT_STRING('t', "field-separator", &field_sep, "separator", + "separator for columns, no spaces will be added between " + "columns '.' is reserved."), OPT_END() }; @@ -1956,6 +2060,12 @@ int cmd_report(int argc, const char **argv, const char *prefix __used) setup_list(&comm_list, comm_list_str, "comm"); setup_list(&sym_list, sym_list_str, "symbol"); + if (field_sep && *field_sep == '.') { + fputs("'.' is the only non valid --field-separator argument\n", + stderr); + exit(129); + } + setup_pager(); return __cmd_report(); -- cgit v1.2.3 From 60c1baf1248e00d423604f018c8af1cf750ad885 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Sat, 11 Jul 2009 12:18:33 -0300 Subject: perf report: Tidy up reporting of symbols not found Always printing the level info about if it is in the kernel, hypervisor or userspace as that is in the hist_entry. Signed-off-by: Arnaldo Carvalho de Melo LKML-Reference: <1247325517-12272-1-git-send-email-acme@redhat.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 740da43f313e..617f4cb7f163 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -705,10 +705,9 @@ sort__sym_print(FILE *fp, struct hist_entry *self, unsigned int width __used) if (verbose) ret += repsep_fprintf(fp, "%#018llx ", (u64)self->ip); + ret += repsep_fprintf(fp, "[%c] ", self->level); if (self->sym) { - ret += repsep_fprintf(fp, "[%c] %s", - self->dso == kernel_dso ? 'k' : - self->dso == hypervisor_dso ? 'h' : '.', self->sym->name); + ret += repsep_fprintf(fp, "%s", self->sym->name); if (self->sym->module) ret += repsep_fprintf(fp, "\t[%s]", -- cgit v1.2.3 From 021191b35cdfb1b5ee6e78ed5ae010114a40902c Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Sat, 11 Jul 2009 12:18:35 -0300 Subject: perf report: Make the output more compact When we filter by column content we may end up with a column that has the same value for all the lines. So remove that column and tell its unique value on the top, as a comment. Example: [acme@doppio pahole]$ perf report --sort comm,dso,symbol -d ./build/libdwarves.so.1.0.0 -C pahole | head -15 # dso: ./build/libdwarves.so.1.0.0 # comm: pahole # Samples: 58409 # # Overhead Symbol # ........ ...... # 20.93% [.] tag__recode_dwarf_type 14.94% [.] namespace__recode_dwarf_types 10.38% [.] cu__table_add_tag 6.69% [.] __die__process_tag 5.05% [.] die__process_function 4.70% [.] list__for_all_tags 3.68% [.] tag__init 3.48% [.] die__create_new_parameter [acme@doppio pahole]$ Signed-off-by: Arnaldo Carvalho de Melo LKML-Reference: <1247325517-12272-3-git-send-email-acme@redhat.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 36 +++++++++++++++++++++--------------- 1 file changed, 21 insertions(+), 15 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 617f4cb7f163..f3422121d858 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -583,6 +583,7 @@ struct sort_entry { int64_t (*collapse)(struct hist_entry *, struct hist_entry *); size_t (*print)(FILE *fp, struct hist_entry *, unsigned int width); unsigned int *width; + bool elide; }; static int64_t cmp_null(void *l, void *r) @@ -1024,7 +1025,7 @@ hist_entry__fprintf(FILE *fp, struct hist_entry *self, u64 total_samples) ret = fprintf(fp, field_sep ? "%lld" : "%12lld ", self->count); list_for_each_entry(se, &hist_entry__sort_list, list) { - if (exclude_other && (se == &sort_parent)) + if (se->elide) continue; fprintf(fp, "%s", field_sep ?: " "); @@ -1079,7 +1080,7 @@ resolve_symbol(struct thread *thread, struct map **mapp, * with no symbol hit that has a name longer than * the ones with symbols sampled. */ - if (!map->dso->slen_calculated) + if (!sort_dso.elide && !map->dso->slen_calculated) dso__calc_col_width(map->dso); if (mapp) @@ -1356,14 +1357,12 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) unsigned int width; char *col_width = col_width_list_str; - fprintf(fp, "\n"); - fprintf(fp, "#\n"); - fprintf(fp, "# (%Ld samples)\n", (u64)total_samples); + fprintf(fp, "# Samples: %Ld\n", (u64)total_samples); fprintf(fp, "#\n"); fprintf(fp, "# Overhead"); list_for_each_entry(se, &hist_entry__sort_list, list) { - if (exclude_other && (se == &sort_parent)) + if (se->elide) continue; if (field_sep) { fprintf(fp, "%c%s", *field_sep, se->header); @@ -1392,7 +1391,7 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) list_for_each_entry(se, &hist_entry__sort_list, list) { unsigned int i; - if (exclude_other && (se == &sort_parent)) + if (se->elide) continue; fprintf(fp, " "); @@ -2022,7 +2021,8 @@ static void setup_sorting(void) } static void setup_list(struct strlist **list, const char *list_str, - const char *list_name) + struct sort_entry *se, const char *list_name, + FILE *fp) { if (list_str) { *list = strlist__new(true, list_str); @@ -2031,6 +2031,11 @@ static void setup_list(struct strlist **list, const char *list_str, list_name); exit(129); } + if (strlist__nr_entries(*list) == 1) { + fprintf(fp, "# %s: %s\n", list_name, + strlist__entry(*list, 0)->s); + se->elide = true; + } } } @@ -2044,9 +2049,10 @@ int cmd_report(int argc, const char **argv, const char *prefix __used) setup_sorting(); - if (parent_pattern != default_parent_pattern) + if (parent_pattern != default_parent_pattern) { sort_dimension__add("parent"); - else + sort_parent.elide = 1; + } else exclude_other = 0; /* @@ -2055,9 +2061,11 @@ int cmd_report(int argc, const char **argv, const char *prefix __used) if (argc) usage_with_options(report_usage, options); - setup_list(&dso_list, dso_list_str, "dso"); - setup_list(&comm_list, comm_list_str, "comm"); - setup_list(&sym_list, sym_list_str, "symbol"); + setup_pager(); + + setup_list(&dso_list, dso_list_str, &sort_dso, "dso", stdout); + setup_list(&comm_list, comm_list_str, &sort_comm, "comm", stdout); + setup_list(&sym_list, sym_list_str, &sort_sym, "symbol", stdout); if (field_sep && *field_sep == '.') { fputs("'.' is the only non valid --field-separator argument\n", @@ -2065,7 +2073,5 @@ int cmd_report(int argc, const char **argv, const char *prefix __used) exit(129); } - setup_pager(); - return __cmd_report(); } -- cgit v1.2.3 From e3d7e183dc276df2fcaf02af173a49ad119ba9f9 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Sat, 11 Jul 2009 12:18:37 -0300 Subject: perf report: Introduce -n/--show-nr-samples [acme@doppio pahole]$ perf report -ns comm,dso,symbol -d /lib64/libc-2.10.1.so -C pahole | head -17 21.94% 32101 [.] _int_malloc 20.10% 29402 [.] __GI_strcmp 16.77% 24533 [.] __tsearch 12.61% 18450 [.] malloc_consolidate 6.42% 9394 [.] _int_free 6.28% 9191 [.] __tfind 4.56% 6678 [.] __GI___libc_free 4.46% 6520 [.] _IO_vfprintf_internal 2.59% 3786 [.] __malloc 1.17% 1716 [.] __GI_memcpy [acme@doppio pahole]$ Signed-off-by: Arnaldo Carvalho de Melo LKML-Reference: <1247325517-12272-5-git-send-email-acme@redhat.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index f3422121d858..430a195b8589 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -51,6 +51,7 @@ static int verbose; static int modules; static int full_paths; +static int show_nr_samples; static unsigned long page_size; static unsigned long mmap_window = 32; @@ -1024,6 +1025,13 @@ hist_entry__fprintf(FILE *fp, struct hist_entry *self, u64 total_samples) else ret = fprintf(fp, field_sep ? "%lld" : "%12lld ", self->count); + if (show_nr_samples) { + if (field_sep) + fprintf(fp, "%c%lld", *field_sep, self->count); + else + fprintf(fp, "%11lld", self->count); + } + list_for_each_entry(se, &hist_entry__sort_list, list) { if (se->elide) continue; @@ -1361,6 +1369,12 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) fprintf(fp, "#\n"); fprintf(fp, "# Overhead"); + if (show_nr_samples) { + if (field_sep) + fprintf(fp, "%cSamples", *field_sep); + else + fputs(" Samples ", fp); + } list_for_each_entry(se, &hist_entry__sort_list, list) { if (se->elide) continue; @@ -1388,6 +1402,8 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) goto print_entries; fprintf(fp, "# ........"); + if (show_nr_samples) + fprintf(fp, " .........."); list_for_each_entry(se, &hist_entry__sort_list, list) { unsigned int i; @@ -1979,6 +1995,8 @@ static const struct option options[] = { OPT_STRING('k', "vmlinux", &vmlinux, "file", "vmlinux pathname"), OPT_BOOLEAN('m', "modules", &modules, "load module symbols - WARNING: use only with -k and LIVE kernel"), + OPT_BOOLEAN('n', "show-nr-samples", &show_nr_samples, + "Show a column with the number of samples"), OPT_STRING('s', "sort", &sort_order, "key[,key2...]", "sort by key(s): pid, comm, dso, symbol, parent"), OPT_BOOLEAN('P', "full-paths", &full_paths, -- cgit v1.2.3 From 1483b19f8f5e8ad0c8816de368b099322dad4db5 Mon Sep 17 00:00:00 2001 From: Anton Blanchard Date: Thu, 16 Jul 2009 15:44:29 +0200 Subject: perf_counter: Make call graph option consistent perf record uses -g for logging call graph data but perf report uses -c to print call graph data. Be consistent and use -g everywhere for call graph data. Also update the help text to reflect the current default - fractal,0.5 Signed-off-by: Anton Blanchard Acked-by: Frederic Weisbecker Signed-off-by: Peter Zijlstra LKML-Reference: <20090716104817.803604373@samba.org> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 4e5cc266311e..4b980cce7055 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -1891,9 +1891,9 @@ static const struct option options[] = { "regex filter to identify parent, see: '--sort parent'"), OPT_BOOLEAN('x', "exclude-other", &exclude_other, "Only display entries with parent-match"), - OPT_CALLBACK_DEFAULT('c', "callchain", NULL, "output_type,min_percent", + OPT_CALLBACK_DEFAULT('g', "call-graph", NULL, "output_type,min_percent", "Display callchains using output_type and min percent threshold. " - "Default: flat,0", &parse_callchain_opt, callchain_default_opt), + "Default: fractal,0.5", &parse_callchain_opt, callchain_default_opt), OPT_STRING('d', "dsos", &dso_list_str, "dso[,dso...]", "only consider symbols in these dsos"), OPT_STRING('C', "comms", &comm_list_str, "comm[,comm...]", -- cgit v1.2.3 From 7f453c24b95a085fc7bd35d53b33abc4dc5a048b Mon Sep 17 00:00:00 2001 From: Peter Zijlstra Date: Tue, 21 Jul 2009 13:19:40 +0200 Subject: perf_counter: PERF_SAMPLE_ID and inherited counters Anton noted that for inherited counters the counter-id as provided by PERF_SAMPLE_ID isn't mappable to the id found through PERF_RECORD_ID because each inherited counter gets its own id. His suggestion was to always return the parent counter id, since that is the primary counter id as exposed. However, these inherited counters have a unique identifier so that events like PERF_EVENT_PERIOD and PERF_EVENT_THROTTLE can be specific about which counter gets modified, which is important when trying to normalize the sample streams. This patch removes PERF_EVENT_PERIOD in favour of PERF_SAMPLE_PERIOD, which is more useful anyway, since changing periods became a lot more common than initially thought -- rendering PERF_EVENT_PERIOD the less useful solution (also, PERF_SAMPLE_PERIOD reports the more accurate value, since it reports the value used to trigger the overflow, whereas PERF_EVENT_PERIOD simply reports the requested period changed, which might only take effect on the next cycle). This still leaves us PERF_EVENT_THROTTLE to consider, but since that _should_ be a rare occurrence, and linking it to a primary id is the most useful bit to diagnose the problem, we introduce a PERF_SAMPLE_STREAM_ID, for those few cases where the full reconstruction is important. [Does change the ABI a little, but I see no other way out] Suggested-by: Anton Blanchard Signed-off-by: Peter Zijlstra LKML-Reference: <1248095846.15751.8781.camel@twins> --- tools/perf/builtin-report.c | 24 ------------------------ 1 file changed, 24 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index a118bc77286d..b20a4b6e31b7 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -101,13 +101,6 @@ struct fork_event { u32 pid, ppid; }; -struct period_event { - struct perf_event_header header; - u64 time; - u64 id; - u64 sample_period; -}; - struct lost_event { struct perf_event_header header; u64 id; @@ -127,7 +120,6 @@ typedef union event_union { struct mmap_event mmap; struct comm_event comm; struct fork_event fork; - struct period_event period; struct lost_event lost; struct read_event read; } event_t; @@ -1635,19 +1627,6 @@ process_fork_event(event_t *event, unsigned long offset, unsigned long head) return 0; } -static int -process_period_event(event_t *event, unsigned long offset, unsigned long head) -{ - dprintf("%p [%p]: PERF_EVENT_PERIOD: time:%Ld, id:%Ld: period:%Ld\n", - (void *)(offset + head), - (void *)(long)(event->header.size), - event->period.time, - event->period.id, - event->period.sample_period); - - return 0; -} - static int process_lost_event(event_t *event, unsigned long offset, unsigned long head) { @@ -1729,9 +1708,6 @@ process_event(event_t *event, unsigned long offset, unsigned long head) case PERF_EVENT_FORK: return process_fork_event(event, offset, head); - case PERF_EVENT_PERIOD: - return process_period_event(event, offset, head); - case PERF_EVENT_LOST: return process_lost_event(event, offset, head); -- cgit v1.2.3 From 27d028de64bd7e1f8e72bdeae6b0586939574fcb Mon Sep 17 00:00:00 2001 From: Peter Zijlstra Date: Thu, 23 Jul 2009 16:52:41 +0200 Subject: perf report: Update for the new FORK/EXIT events Since FORK is now also issued for threads, detect those by comparing the parent and child PID. Teach it about EXIT events and ignore them. Signed-off-by: Peter Zijlstra Cc: Paul Mackerras Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 22 ++++++++++++++++++---- 1 file changed, 18 insertions(+), 4 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index b20a4b6e31b7..95fd06cdaa99 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -99,6 +99,7 @@ struct comm_event { struct fork_event { struct perf_event_header header; u32 pid, ppid; + u32 tid, ptid; }; struct lost_event { @@ -1608,15 +1609,27 @@ process_comm_event(event_t *event, unsigned long offset, unsigned long head) } static int -process_fork_event(event_t *event, unsigned long offset, unsigned long head) +process_task_event(event_t *event, unsigned long offset, unsigned long head) { struct thread *thread = threads__findnew(event->fork.pid); struct thread *parent = threads__findnew(event->fork.ppid); - dprintf("%p [%p]: PERF_EVENT_FORK: %d:%d\n", + dprintf("%p [%p]: PERF_EVENT_%s: (%d:%d):(%d:%d)\n", (void *)(offset + head), (void *)(long)(event->header.size), - event->fork.pid, event->fork.ppid); + event->header.type == PERF_EVENT_FORK ? "FORK" : "EXIT", + event->fork.pid, event->fork.tid, + event->fork.ppid, event->fork.ptid); + + /* + * A thread clone will have the same PID for both + * parent and child. + */ + if (thread == parent) + return 0; + + if (event->header.type == PERF_EVENT_EXIT) + return 0; if (!thread || !parent || thread__fork(thread, parent)) { dprintf("problem processing PERF_EVENT_FORK, skipping event.\n"); @@ -1706,7 +1719,8 @@ process_event(event_t *event, unsigned long offset, unsigned long head) return process_comm_event(event, offset, head); case PERF_EVENT_FORK: - return process_fork_event(event, offset, head); + case PERF_EVENT_EXIT: + return process_task_event(event, offset, head); case PERF_EVENT_LOST: return process_lost_event(event, offset, head); -- cgit v1.2.3 From 7e030655dda5b5efc4305e2a8f46c4967d32eb3d Mon Sep 17 00:00:00 2001 From: Roel Kluin Date: Sun, 2 Aug 2009 13:43:11 +0200 Subject: perf: Fix read buffer overflow Check whether index is within bounds before testing the element. Signed-off-by: Roel Kluin Cc: a.p.zijlstra@chello.nl Cc: Andrew Morton LKML-Reference: <4A757BCF.40101@gmail.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 95fd06cdaa99..ce4f28645e64 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -253,7 +253,7 @@ static int strcommon(const char *pathname) { int n = 0; - while (pathname[n] == cwd[n] && n < cwdlen) + while (n < cwdlen && pathname[n] == cwd[n]) ++n; return n; -- cgit v1.2.3 From 114cfab222233f50f46d7162cf7d99fdc6c271e5 Mon Sep 17 00:00:00 2001 From: Pekka Enberg Date: Wed, 5 Aug 2009 13:25:21 +0300 Subject: perf report: Make --sort comm,dso,symbol the default If you're doing performance testing, you're interested in the symbols anyway so lets make "--sort comm,dso,symbol" the default sort option. Signed-off-by: Pekka Enberg Acked-by: Peter Zijlstra Cc: acme@redhat.com LKML-Reference: <1249467921-10450-1-git-send-email-penberg@cs.helsinki.fi> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index ce4f28645e64..8cb58d68a006 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -31,7 +31,7 @@ static char const *input_name = "perf.data"; static char *vmlinux = NULL; -static char default_sort_order[] = "comm,dso"; +static char default_sort_order[] = "comm,dso,symbol"; static char *sort_order = default_sort_order; static char *dso_list_str, *comm_list_str, *sym_list_str, *col_width_list_str; @@ -1424,7 +1424,7 @@ print_entries: if (sort_order == default_sort_order && parent_pattern == default_parent_pattern) { fprintf(fp, "#\n"); - fprintf(fp, "# (For more details, try: perf report --sort comm,dso,symbol)\n"); + fprintf(fp, "# (For a higher level overview, try: perf report --sort comm,dso)\n"); fprintf(fp, "#\n"); } fprintf(fp, "\n"); -- cgit v1.2.3 From 1953287bfe8afcbbd235bd6c42c9df06d52438dc Mon Sep 17 00:00:00 2001 From: Frederic Weisbecker Date: Fri, 7 Aug 2009 07:11:05 +0200 Subject: perf tools: Fix call-chain cumul hit based sub-total (fractal mode) The callchain fractal mode builds each new total hits in a new branch of profiling by using the parent's hits of the current branch plus the hits of the children. This is wrong, the total hits of a branch should be made of the sum of every children hits, we must ignore the parent hits in this scope. This patch also fixes another mistake with the hit counting. Now the rates are correct. Signed-off-by: Frederic Weisbecker Cc: Frederic Weisbecker Cc: Peter Zijlstra Cc: Arnaldo Carvalho de Melo Cc: Mike Galbraith Cc: Pekka Enberg Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 8cb58d68a006..da402e186561 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -901,7 +901,7 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, int i; if (callchain_param.mode == CHAIN_GRAPH_REL) - new_total = self->cumul_hit; + new_total = self->children_hit; else new_total = total_samples; @@ -930,7 +930,7 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, ret += ipchain__fprintf_graph(fp, chain, depth, new_depth_mask, i++, new_total, - child->cumul_hit); + cumul_hits(child)); } ret += callchain__fprintf_graph(fp, child, new_total, depth + 1, -- cgit v1.2.3 From 8f18aec535b5ca513dd13b531730177d35175ffa Mon Sep 17 00:00:00 2001 From: Peter Zijlstra Date: Thu, 6 Aug 2009 19:40:28 +0200 Subject: perf report: Fix per task mult-counter stat reporting Brice Goglin reported: > I can easily sort them by thread id, but I don't know how to match > my 4 events with each group of 4 lines. Also report the counter id and the time running/enabled stats (in case the counter got time-shared). Reported-by: Brice Goglin Signed-off-by: Peter Zijlstra Tested-by: Brice Goglin Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 31 +++++++++++++++++++++++++++---- 1 file changed, 27 insertions(+), 4 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index da402e186561..84205462e07b 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -112,7 +112,9 @@ struct read_event { struct perf_event_header header; u32 pid,tid; u64 value; - u64 format[3]; + u64 time_enabled; + u64 time_running; + u64 id; }; typedef union event_union { @@ -1690,14 +1692,37 @@ static void trace_event(event_t *event) dprintf(".\n"); } +static struct perf_header *header; + +static struct perf_counter_attr *perf_header__find_attr(u64 id) +{ + int i; + + for (i = 0; i < header->attrs; i++) { + struct perf_header_attr *attr = header->attr[i]; + int j; + + for (j = 0; j < attr->ids; j++) { + if (attr->id[j] == id) + return &attr->attr; + } + } + + return NULL; +} + static int process_read_event(event_t *event, unsigned long offset, unsigned long head) { - dprintf("%p [%p]: PERF_EVENT_READ: %d %d %Lu\n", + struct perf_counter_attr *attr = perf_header__find_attr(event->read.id); + + dprintf("%p [%p]: PERF_EVENT_READ: %d %d %s %Lu\n", (void *)(offset + head), (void *)(long)(event->header.size), event->read.pid, event->read.tid, + attr ? __event_name(attr->type, attr->config) + : "FAIL", event->read.value); return 0; @@ -1743,8 +1768,6 @@ process_event(event_t *event, unsigned long offset, unsigned long head) return 0; } -static struct perf_header *header; - static u64 perf_header__sample_type(void) { u64 sample_type = 0; -- cgit v1.2.3 From 94cb9e385d5b4d55a5ae389baa10ad2835ea39bb Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Thu, 6 Aug 2009 14:43:17 -0300 Subject: perf report: Add debug help for the finding of symbol bugs - show the symtab origin (DSO, build-id, kernel, etc) Used with perf report --verbose: [acme@doppio linux-2.6-tip]$ perf report -v | head -16 5.17% firefox /usr/lib64/xulrunner-1.9.1/libxul.so 0x00000000005d8eee f [.] imgContainer::DrawFrameTo(gfxIImageFrame*, gfxIImageFrame*, nsRect&) 2.56% firefox /lib64/libpthread-2.10.1.so 0x0000000000008e02 d [.] __pthread_mutex_lock_internal 1.94% firefox /usr/lib64/xulrunner-1.9.1/libxul.so 0x0000000000d0af8f f [.] SearchTable 1.75% firefox [kernel] 0xffffffffff60013b k [.] vread_hpet 1.63% firefox /lib64/libpthread-2.10.1.so 0x000000000000a404 d [.] __pthread_mutex_unlock 1.47% firefox /usr/lib64/xulrunner-1.9.1/libmozjs.so 0x00000000000482ea f [.] js_Interpret 1.42% firefox /usr/lib64/xulrunner-1.9.1/libmozjs.so 0x000000000003eda3 f [.] JS_CallTracer 1.24% firefox [kernel] 0xffffffff8102ca4a k [k] read_hpet 1.16% firefox [kernel] 0xffffffff810f3dd4 k [k] fget_light 1.11% firefox /usr/lib64/xulrunner-1.9.1/libmozjs.so 0x00000000000567ff f [.] js_TraceObject 0.98% firefox /usr/lib64/firefox-3.5.2/firefox 0x000000000000dd23 b [.] arena_ralloc [acme@doppio linux-2.6-tip]$ The new field is just after the symbol address. To help in figuring out symbol resolution bugs. Signed-off-by: Arnaldo Carvalho de Melo Acked-by: Peter Zijlstra Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 84205462e07b..a5e2f8df411c 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -700,7 +700,8 @@ sort__sym_print(FILE *fp, struct hist_entry *self, unsigned int width __used) size_t ret = 0; if (verbose) - ret += repsep_fprintf(fp, "%#018llx ", (u64)self->ip); + ret += repsep_fprintf(fp, "%#018llx %c ", (u64)self->ip, + dso__symtab_origin(self->dso)); ret += repsep_fprintf(fp, "[%c] ", self->level); if (self->sym) { -- cgit v1.2.3 From b1a88349c37624755b28ac3b3152b48f52c1f487 Mon Sep 17 00:00:00 2001 From: Frederic Weisbecker Date: Sat, 8 Aug 2009 02:16:24 +0200 Subject: perf tools: callchain: Fix 'perf report' display to be callchain by default If we recorded with -g option to record the callchain, right now we require a -g option to perf report as well - and people reported this as unnecessary complication: the user already specified -g once, no need to require it a second time. So if the recording includes call-chains, display the callchain by default from perf report. ( The user can override this default using "-g none" option from perf report. ) Reported-by: Ingo Molnar Signed-off-by: Frederic Weisbecker Cc: Peter Zijlstra Cc: Arnaldo Carvalho de Melo Cc: Mike Galbraith LKML-Reference: <1249690585-9145-3-git-send-email-fweisbec@gmail.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index a5e2f8df411c..c4a8e108e521 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -68,7 +68,7 @@ static int callchain; static struct callchain_param callchain_param = { - .mode = CHAIN_GRAPH_ABS, + .mode = CHAIN_GRAPH_REL, .min_percent = 0.5 }; @@ -1836,6 +1836,13 @@ static int __cmd_report(void) " -g?\n"); exit(-1); } + } else if (callchain_param.mode != CHAIN_NONE && !callchain) { + callchain = 1; + if (register_callchain_param(&callchain_param) < 0) { + fprintf(stderr, "Can't register callchain" + " params\n"); + exit(-1); + } } if (load_kernel() < 0) { @@ -1974,6 +1981,13 @@ parse_callchain_opt(const struct option *opt __used, const char *arg, else if (!strncmp(tok, "fractal", strlen(arg))) callchain_param.mode = CHAIN_GRAPH_REL; + else if (!strncmp(tok, "none", strlen(arg))) { + callchain_param.mode = CHAIN_NONE; + callchain = 0; + + return 0; + } + else return -1; -- cgit v1.2.3 From 25446036cbfc2c89faacdb4fb4603943d2197dc6 Mon Sep 17 00:00:00 2001 From: Frederic Weisbecker Date: Sat, 8 Aug 2009 02:16:25 +0200 Subject: perf tools: callchain: Fix sum of percentages to be 100% by displaying amount of ignored chains in fractal mode When we filter the callchains below a given percentage, we ignore them and the end result only shows entries that have an upper percentage than the filter threshold. It seems to users then that we have an imbalance in the percentage, as if the sum inside a profiled branch doesn't reach 100%. Since in the past there have been real perf report bugs that showed the same sypmtom, it would be nice to assure the user that the data is perfect and trustable and it all sums up to 100.00%. So fix this by displaying the remaining hits that have been filtered but without more detail than their amount in each branches. Example while filtering below 50%: 7.73% [k] delay_tsc | |--98.22%-- __const_udelay | | | |--86.37%-- ath5k_hw_register_timeout | | ath5k_hw_noise_floor_calibration | | ath5k_hw_reset | | ath5k_reset | | ath5k_config | | ieee80211_hw_config | | | | | |--88.53%-- ieee80211_scan_work | | | worker_thread | | | kthread | | | child_rip | | --11.47%-- [...] | --13.63%-- [...] --1.78%-- [...] Reported-by: Ingo Molnar Signed-off-by: Frederic Weisbecker Cc: Peter Zijlstra Cc: Arnaldo Carvalho de Melo Cc: Mike Galbraith LKML-Reference: <1249690585-9145-4-git-send-email-fweisbec@gmail.com> Signed-off-by: Ingo Molnar --- tools/perf/builtin-report.c | 47 ++++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 44 insertions(+), 3 deletions(-) (limited to 'tools/perf/builtin-report.c') diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index c4a8e108e521..99274cec0adb 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -891,6 +891,21 @@ ipchain__fprintf_graph(FILE *fp, struct callchain_list *chain, int depth, return ret; } +static struct symbol *rem_sq_bracket; +static struct callchain_list rem_hits; + +static void init_rem_hits(void) +{ + rem_sq_bracket = malloc(sizeof(*rem_sq_bracket) + 6); + if (!rem_sq_bracket) { + fprintf(stderr, "Not enough memory to display remaining hits\n"); + return; + } + + strcpy(rem_sq_bracket->name, "[...]"); + rem_hits.sym = rem_sq_bracket; +} + static size_t callchain__fprintf_graph(FILE *fp, struct callchain_node *self, u64 total_samples, int depth, int depth_mask) @@ -900,6 +915,7 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, struct callchain_list *chain; int new_depth_mask = depth_mask; u64 new_total; + u64 remaining; size_t ret = 0; int i; @@ -908,17 +924,25 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, else new_total = total_samples; + remaining = new_total; + node = rb_first(&self->rb_root); while (node) { + u64 cumul; + child = rb_entry(node, struct callchain_node, rb_node); + cumul = cumul_hits(child); + remaining -= cumul; /* * The depth mask manages the output of pipes that show * the depth. We don't want to keep the pipes of the current - * level for the last child of this depth + * level for the last child of this depth. + * Except if we have remaining filtered hits. They will + * supersede the last child */ next = rb_next(node); - if (!next) + if (!next && (callchain_param.mode != CHAIN_GRAPH_REL || !remaining)) new_depth_mask &= ~(1 << (depth - 1)); /* @@ -933,7 +957,7 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, ret += ipchain__fprintf_graph(fp, chain, depth, new_depth_mask, i++, new_total, - cumul_hits(child)); + cumul); } ret += callchain__fprintf_graph(fp, child, new_total, depth + 1, @@ -941,6 +965,19 @@ callchain__fprintf_graph(FILE *fp, struct callchain_node *self, node = next; } + if (callchain_param.mode == CHAIN_GRAPH_REL && + remaining && remaining != new_total) { + + if (!rem_sq_bracket) + return ret; + + new_depth_mask &= ~(1 << (depth - 1)); + + ret += ipchain__fprintf_graph(fp, &rem_hits, depth, + new_depth_mask, 0, new_total, + remaining); + } + return ret; } @@ -1361,6 +1398,8 @@ static size_t output__fprintf(FILE *fp, u64 total_samples) unsigned int width; char *col_width = col_width_list_str; + init_rem_hits(); + fprintf(fp, "# Samples: %Ld\n", (u64)total_samples); fprintf(fp, "#\n"); @@ -1432,6 +1471,8 @@ print_entries: } fprintf(fp, "\n"); + free(rem_sq_bracket); + return ret; } -- cgit v1.2.3