From 9484b86e9cad903d3295d75c03961c3bdd1444a8 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Fri, 25 Nov 2016 15:48:25 -0300 Subject: [PATCH 01/19] perf ui helpline: Provide a printf variant To print some values, like in the annotation code with invalid jump offsets. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-1vk0g5twas2ioswn1mmvnvwq@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/ui/helpline.c | 10 ++++++++++ tools/perf/ui/helpline.h | 1 + 2 files changed, 11 insertions(+) diff --git a/tools/perf/ui/helpline.c b/tools/perf/ui/helpline.c index 5b74a7eba210..379039ab00d8 100644 --- a/tools/perf/ui/helpline.c +++ b/tools/perf/ui/helpline.c @@ -72,3 +72,13 @@ int ui_helpline__vshow(const char *fmt, va_list ap) { return helpline_fns->show(fmt, ap); } + +void ui_helpline__printf(const char *fmt, ...) +{ + va_list ap; + + ui_helpline__pop(); + va_start(ap, fmt); + ui_helpline__vpush(fmt, ap); + va_end(ap); +} diff --git a/tools/perf/ui/helpline.h b/tools/perf/ui/helpline.h index 46181f4fc07e..d52d0a1a881b 100644 --- a/tools/perf/ui/helpline.h +++ b/tools/perf/ui/helpline.h @@ -21,6 +21,7 @@ void ui_helpline__push(const char *msg); void ui_helpline__vpush(const char *fmt, va_list ap); void ui_helpline__fpush(const char *fmt, ...); void ui_helpline__puts(const char *msg); +void ui_helpline__printf(const char *fmt, ...); int ui_helpline__vshow(const char *fmt, va_list ap); extern char ui_helpline__current[512]; From 5252b1aeabd0ae794cfaf323c10968443f10a363 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Fri, 25 Nov 2016 15:56:34 -0300 Subject: [PATCH 02/19] perf annotate: Show invalid jump offset in error message MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit To help in debugging when the wrong offset is being used, like in: │13d98: ↓ jne 13dd1 That is the full line from objdump, and it seems what should be used is 13dd1, not 28e1. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-4nc0marsgst1ft6inmvqber7@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/ui/browsers/annotate.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/tools/perf/ui/browsers/annotate.c b/tools/perf/ui/browsers/annotate.c index cee0eee31ce6..ec7a30fad149 100644 --- a/tools/perf/ui/browsers/annotate.c +++ b/tools/perf/ui/browsers/annotate.c @@ -543,14 +543,16 @@ struct disasm_line *annotate_browser__find_offset(struct annotate_browser *brows static bool annotate_browser__jump(struct annotate_browser *browser) { struct disasm_line *dl = browser->selection; + u64 offset; s64 idx; if (!ins__is_jump(&dl->ins)) return false; - dl = annotate_browser__find_offset(browser, dl->ops.target.offset, &idx); + offset = dl->ops.target.offset; + dl = annotate_browser__find_offset(browser, offset, &idx); if (dl == NULL) { - ui_helpline__puts("Invalid jump offset"); + ui_helpline__printf("Invalid jump offset: %" PRIx64, offset); return true; } From 350f54fab2afd7f819e64fbeecdf980086fa59f2 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Fri, 25 Nov 2016 09:28:41 -0700 Subject: [PATCH 03/19] perf sched timehist: Handle cpu migration events Add handlers for sched:sched_migrate_task event. Total number of migrations is added to summary display and -M/--migrations can be used to show migration events. Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Cc: Namhyung Kim Link: http://lkml.kernel.org/r/1480091321-35591-1-git-send-email-dsa@cumulusnetworks.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-sched.txt | 4 + tools/perf/builtin-sched.c | 97 ++++++++++++++++++++++++- 2 files changed, 99 insertions(+), 2 deletions(-) diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index fb9e52d65fca..121c60da03e5 100644 --- a/tools/perf/Documentation/perf-sched.txt +++ b/tools/perf/Documentation/perf-sched.txt @@ -128,6 +128,10 @@ OPTIONS for 'perf sched timehist' --wakeups:: Show wakeup events. +-M:: +--migrations:: + Show migration events. + SEE ALSO -------- linkperf:perf-record[1] diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index a49a032f5b15..4f9e7cba4ebf 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c @@ -203,6 +203,7 @@ struct perf_sched { unsigned int max_stack; bool show_cpu_visual; bool show_wakeups; + bool show_migrations; u64 skipped_samples; }; @@ -216,6 +217,8 @@ struct thread_runtime { struct stats run_stats; u64 total_run_time; + + u64 migrations; }; /* per event run time data */ @@ -2197,6 +2200,87 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool, return 0; } +static void timehist_print_migration_event(struct perf_sched *sched, + struct perf_evsel *evsel, + struct perf_sample *sample, + struct machine *machine, + struct thread *migrated) +{ + struct thread *thread; + char tstr[64]; + u32 max_cpus = sched->max_cpu + 1; + u32 ocpu, dcpu; + + if (sched->summary_only) + return; + + max_cpus = sched->max_cpu + 1; + ocpu = perf_evsel__intval(evsel, sample, "orig_cpu"); + dcpu = perf_evsel__intval(evsel, sample, "dest_cpu"); + + thread = machine__findnew_thread(machine, sample->pid, sample->tid); + if (thread == NULL) + return; + + if (timehist_skip_sample(sched, thread) && + timehist_skip_sample(sched, migrated)) { + return; + } + + timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); + printf("%15s [%04d] ", tstr, sample->cpu); + + if (sched->show_cpu_visual) { + u32 i; + char c; + + printf(" "); + for (i = 0; i < max_cpus; ++i) { + c = (i == sample->cpu) ? 'm' : ' '; + printf("%c", c); + } + printf(" "); + } + + printf(" %-*s ", comm_width, timehist_get_commstr(thread)); + + /* dt spacer */ + printf(" %9s %9s %9s ", "", "", ""); + + printf("migrated: %s", timehist_get_commstr(migrated)); + printf(" cpu %d => %d", ocpu, dcpu); + + printf("\n"); +} + +static int timehist_migrate_task_event(struct perf_tool *tool, + union perf_event *event __maybe_unused, + struct perf_evsel *evsel, + struct perf_sample *sample, + struct machine *machine) +{ + struct perf_sched *sched = container_of(tool, struct perf_sched, tool); + struct thread *thread; + struct thread_runtime *tr = NULL; + /* want pid of migrated task not pid in sample */ + const u32 pid = perf_evsel__intval(evsel, sample, "pid"); + + thread = machine__findnew_thread(machine, 0, pid); + if (thread == NULL) + return -1; + + tr = thread__get_runtime(thread); + if (tr == NULL) + return -1; + + tr->migrations++; + + /* show migrations if requested */ + timehist_print_migration_event(sched, evsel, sample, machine, thread); + + return 0; +} + static int timehist_sched_change_event(struct perf_tool *tool, union perf_event *event, struct perf_evsel *evsel, @@ -2295,6 +2379,7 @@ static void print_thread_runtime(struct thread *t, print_sched_time(r->run_stats.max, 6); printf(" "); printf("%5.2f", stddev); + printf(" %5" PRIu64, r->migrations); printf("\n"); } @@ -2356,10 +2441,10 @@ static void timehist_print_summary(struct perf_sched *sched, printf("\nRuntime summary\n"); printf("%*s parent sched-in ", comm_width, "comm"); - printf(" run-time min-run avg-run max-run stddev\n"); + printf(" run-time min-run avg-run max-run stddev migrations\n"); printf("%*s (count) ", comm_width, ""); printf(" (msec) (msec) (msec) (msec) %%\n"); - printf("%.105s\n", graph_dotted_line); + printf("%.117s\n", graph_dotted_line); machine__for_each_thread(m, show_thread_runtime, &totals); task_count = totals.task_count; @@ -2460,6 +2545,9 @@ static int perf_sched__timehist(struct perf_sched *sched) { "sched:sched_wakeup", timehist_sched_wakeup_event, }, { "sched:sched_wakeup_new", timehist_sched_wakeup_event, }, }; + const struct perf_evsel_str_handler migrate_handlers[] = { + { "sched:sched_migrate_task", timehist_migrate_task_event, }, + }; struct perf_data_file file = { .path = input_name, .mode = PERF_DATA_MODE_READ, @@ -2507,6 +2595,10 @@ static int perf_sched__timehist(struct perf_sched *sched) if (!perf_session__has_traces(session, "record -R")) goto out; + if (sched->show_migrations && + perf_session__set_tracepoints_handlers(session, migrate_handlers)) + goto out; + /* pre-allocate struct for per-CPU idle stats */ sched->max_cpu = session->header.env.nr_cpus_online; if (sched->max_cpu == 0) @@ -2903,6 +2995,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) OPT_BOOLEAN('S', "with-summary", &sched.summary, "Show all syscalls and summary with statistics"), OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"), + OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"), OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"), OPT_PARENT(sched_options) }; From aa07df6eb5061eed3f5d0820dc646d7f6ddface2 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Fri, 25 Nov 2016 09:29:52 -0700 Subject: [PATCH 04/19] perf trace: Update tid/pid filtering option to leverage symbol_conf Leverage pid/tid filtering done by symbol_conf hooks. Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Link: http://lkml.kernel.org/r/1480091392-35645-1-git-send-email-dsa@cumulusnetworks.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 49 +++++++------------------------------- 1 file changed, 9 insertions(+), 40 deletions(-) diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 5f45166c892d..206bf72b77fc 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -74,8 +74,6 @@ struct trace { size_t nr; int *entries; } ev_qualifier_ids; - struct intlist *tid_list; - struct intlist *pid_list; struct { size_t nr; pid_t *entries; @@ -1890,18 +1888,6 @@ out_put: return err; } -static bool skip_sample(struct trace *trace, struct perf_sample *sample) -{ - if ((trace->pid_list && intlist__find(trace->pid_list, sample->pid)) || - (trace->tid_list && intlist__find(trace->tid_list, sample->tid))) - return false; - - if (trace->pid_list || trace->tid_list) - return true; - - return false; -} - static void trace__set_base_time(struct trace *trace, struct perf_evsel *evsel, struct perf_sample *sample) @@ -1926,11 +1912,13 @@ static int trace__process_sample(struct perf_tool *tool, struct machine *machine __maybe_unused) { struct trace *trace = container_of(tool, struct trace, tool); + struct thread *thread; int err = 0; tracepoint_handler handler = evsel->handler; - if (skip_sample(trace, sample)) + thread = machine__findnew_thread(trace->host, sample->pid, sample->tid); + if (thread && thread__is_filtered(thread)) return 0; trace__set_base_time(trace, evsel, sample); @@ -1943,27 +1931,6 @@ static int trace__process_sample(struct perf_tool *tool, return err; } -static int parse_target_str(struct trace *trace) -{ - if (trace->opts.target.pid) { - trace->pid_list = intlist__new(trace->opts.target.pid); - if (trace->pid_list == NULL) { - pr_err("Error parsing process id string\n"); - return -EINVAL; - } - } - - if (trace->opts.target.tid) { - trace->tid_list = intlist__new(trace->opts.target.tid); - if (trace->tid_list == NULL) { - pr_err("Error parsing thread id string\n"); - return -EINVAL; - } - } - - return 0; -} - static int trace__record(struct trace *trace, int argc, const char **argv) { unsigned int rec_argc, i, j; @@ -2460,6 +2427,12 @@ static int trace__replay(struct trace *trace) if (session == NULL) return -1; + if (trace->opts.target.pid) + symbol_conf.pid_list_str = strdup(trace->opts.target.pid); + + if (trace->opts.target.tid) + symbol_conf.tid_list_str = strdup(trace->opts.target.tid); + if (symbol__init(&session->header.env) < 0) goto out; @@ -2503,10 +2476,6 @@ static int trace__replay(struct trace *trace) evsel->handler = trace__pgfault; } - err = parse_target_str(trace); - if (err != 0) - goto out; - setup_pager(); err = perf_session__process_events(session); From 9742da0150788e6ea7796372c3e643f876a49741 Mon Sep 17 00:00:00 2001 From: Wang Nan Date: Sat, 26 Nov 2016 07:03:25 +0000 Subject: [PATCH 05/19] tools lib bpf: Add missing BPF functions Add more BPF map operations to libbpf. Also add bpf_obj_{pin,get}(). They can be used on not only BPF maps but also BPF programs. Signed-off-by: Wang Nan Acked-by: Alexei Starovoitov Cc: He Kuang Cc: Joe Stringer Cc: Zefan Li Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/20161126070354.141764-2-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/bpf/bpf.c | 56 +++++++++++++++++++++++++++++++++++++++++++++ tools/lib/bpf/bpf.h | 7 ++++++ 2 files changed, 63 insertions(+) diff --git a/tools/lib/bpf/bpf.c b/tools/lib/bpf/bpf.c index 4212ed62235b..8143536b462a 100644 --- a/tools/lib/bpf/bpf.c +++ b/tools/lib/bpf/bpf.c @@ -110,3 +110,59 @@ int bpf_map_update_elem(int fd, void *key, void *value, return sys_bpf(BPF_MAP_UPDATE_ELEM, &attr, sizeof(attr)); } + +int bpf_map_lookup_elem(int fd, void *key, void *value) +{ + union bpf_attr attr; + + bzero(&attr, sizeof(attr)); + attr.map_fd = fd; + attr.key = ptr_to_u64(key); + attr.value = ptr_to_u64(value); + + return sys_bpf(BPF_MAP_LOOKUP_ELEM, &attr, sizeof(attr)); +} + +int bpf_map_delete_elem(int fd, void *key) +{ + union bpf_attr attr; + + bzero(&attr, sizeof(attr)); + attr.map_fd = fd; + attr.key = ptr_to_u64(key); + + return sys_bpf(BPF_MAP_DELETE_ELEM, &attr, sizeof(attr)); +} + +int bpf_map_get_next_key(int fd, void *key, void *next_key) +{ + union bpf_attr attr; + + bzero(&attr, sizeof(attr)); + attr.map_fd = fd; + attr.key = ptr_to_u64(key); + attr.next_key = ptr_to_u64(next_key); + + return sys_bpf(BPF_MAP_GET_NEXT_KEY, &attr, sizeof(attr)); +} + +int bpf_obj_pin(int fd, const char *pathname) +{ + union bpf_attr attr; + + bzero(&attr, sizeof(attr)); + attr.pathname = ptr_to_u64((void *)pathname); + attr.bpf_fd = fd; + + return sys_bpf(BPF_OBJ_PIN, &attr, sizeof(attr)); +} + +int bpf_obj_get(const char *pathname) +{ + union bpf_attr attr; + + bzero(&attr, sizeof(attr)); + attr.pathname = ptr_to_u64((void *)pathname); + + return sys_bpf(BPF_OBJ_GET, &attr, sizeof(attr)); +} diff --git a/tools/lib/bpf/bpf.h b/tools/lib/bpf/bpf.h index e8ba54087497..253c3dbb06b4 100644 --- a/tools/lib/bpf/bpf.h +++ b/tools/lib/bpf/bpf.h @@ -35,4 +35,11 @@ int bpf_load_program(enum bpf_prog_type type, struct bpf_insn *insns, int bpf_map_update_elem(int fd, void *key, void *value, u64 flags); + +int bpf_map_lookup_elem(int fd, void *key, void *value); +int bpf_map_delete_elem(int fd, void *key); +int bpf_map_get_next_key(int fd, void *key, void *next_key); +int bpf_obj_pin(int fd, const char *pathname); +int bpf_obj_get(const char *pathname); + #endif From 10931d2413478239bdceac5546cce85d7a497a4e Mon Sep 17 00:00:00 2001 From: Wang Nan Date: Sat, 26 Nov 2016 07:03:26 +0000 Subject: [PATCH 06/19] tools lib bpf: Add private field for bpf_object Similar to other classes defined in libbpf.h (map and program), allow 'object' class has its own private data. Signed-off-by: Wang Nan Acked-by: Alexei Starovoitov Cc: He Kuang Cc: Joe Stringer Cc: Zefan Li Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/20161126070354.141764-3-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/bpf/libbpf.c | 23 +++++++++++++++++++++++ tools/lib/bpf/libbpf.h | 5 +++++ 2 files changed, 28 insertions(+) diff --git a/tools/lib/bpf/libbpf.c b/tools/lib/bpf/libbpf.c index 96a2b2ff1212..866d5cdeffc7 100644 --- a/tools/lib/bpf/libbpf.c +++ b/tools/lib/bpf/libbpf.c @@ -229,6 +229,10 @@ struct bpf_object { * all objects. */ struct list_head list; + + void *priv; + bpf_object_clear_priv_t clear_priv; + char path[]; }; #define obj_elf_valid(o) ((o)->efile.elf) @@ -1229,6 +1233,9 @@ void bpf_object__close(struct bpf_object *obj) if (!obj) return; + if (obj->clear_priv) + obj->clear_priv(obj, obj->priv); + bpf_object__elf_finish(obj); bpf_object__unload(obj); @@ -1282,6 +1289,22 @@ unsigned int bpf_object__kversion(struct bpf_object *obj) return obj ? obj->kern_version : 0; } +int bpf_object__set_priv(struct bpf_object *obj, void *priv, + bpf_object_clear_priv_t clear_priv) +{ + if (obj->priv && obj->clear_priv) + obj->clear_priv(obj, obj->priv); + + obj->priv = priv; + obj->clear_priv = clear_priv; + return 0; +} + +void *bpf_object__priv(struct bpf_object *obj) +{ + return obj ? obj->priv : ERR_PTR(-EINVAL); +} + struct bpf_program * bpf_program__next(struct bpf_program *prev, struct bpf_object *obj) { diff --git a/tools/lib/bpf/libbpf.h b/tools/lib/bpf/libbpf.h index dd7a513efb10..0c0b0127e03e 100644 --- a/tools/lib/bpf/libbpf.h +++ b/tools/lib/bpf/libbpf.h @@ -79,6 +79,11 @@ struct bpf_object *bpf_object__next(struct bpf_object *prev); (pos) != NULL; \ (pos) = (tmp), (tmp) = bpf_object__next(tmp)) +typedef void (*bpf_object_clear_priv_t)(struct bpf_object *, void *); +int bpf_object__set_priv(struct bpf_object *obj, void *priv, + bpf_object_clear_priv_t clear_priv); +void *bpf_object__priv(struct bpf_object *prog); + /* Accessors of bpf_program. */ struct bpf_program; struct bpf_program *bpf_program__next(struct bpf_program *prog, From 5a6acad17d2e81765dd4c2fce7346a6f045eab25 Mon Sep 17 00:00:00 2001 From: Wang Nan Date: Sat, 26 Nov 2016 07:03:27 +0000 Subject: [PATCH 07/19] tools lib bpf: Retrive bpf_map through offset of bpf_map_def Add a new API to libbpf, caller is able to get bpf_map through the offset of bpf_map_def to 'maps' section. The API will be used to help jitted perf hook code find fd of a map. Signed-off-by: Wang Nan Acked-by: Alexei Starovoitov Cc: He Kuang Cc: Jiri Olsa Cc: Joe Stringer Cc: Zefan Li Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/20161126070354.141764-4-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/bpf/libbpf.c | 12 ++++++++++++ tools/lib/bpf/libbpf.h | 8 ++++++++ 2 files changed, 20 insertions(+) diff --git a/tools/lib/bpf/libbpf.c b/tools/lib/bpf/libbpf.c index 866d5cdeffc7..2e974593f3e8 100644 --- a/tools/lib/bpf/libbpf.c +++ b/tools/lib/bpf/libbpf.c @@ -1524,3 +1524,15 @@ bpf_object__find_map_by_name(struct bpf_object *obj, const char *name) } return NULL; } + +struct bpf_map * +bpf_object__find_map_by_offset(struct bpf_object *obj, size_t offset) +{ + int i; + + for (i = 0; i < obj->nr_maps; i++) { + if (obj->maps[i].offset == offset) + return &obj->maps[i]; + } + return ERR_PTR(-ENOENT); +} diff --git a/tools/lib/bpf/libbpf.h b/tools/lib/bpf/libbpf.h index 0c0b0127e03e..a5a8b86a06fe 100644 --- a/tools/lib/bpf/libbpf.h +++ b/tools/lib/bpf/libbpf.h @@ -24,6 +24,7 @@ #include #include #include +#include // for size_t enum libbpf_errno { __LIBBPF_ERRNO__START = 4000, @@ -200,6 +201,13 @@ struct bpf_map; struct bpf_map * bpf_object__find_map_by_name(struct bpf_object *obj, const char *name); +/* + * Get bpf_map through the offset of corresponding struct bpf_map_def + * in the bpf object file. + */ +struct bpf_map * +bpf_object__find_map_by_offset(struct bpf_object *obj, size_t offset); + struct bpf_map * bpf_map__next(struct bpf_map *map, struct bpf_object *obj); #define bpf_map__for_each(pos, obj) \ From a074865e60edd762b99ec5dacec69b406f702e66 Mon Sep 17 00:00:00 2001 From: Wang Nan Date: Sat, 26 Nov 2016 07:03:28 +0000 Subject: [PATCH 08/19] perf tools: Introduce perf hooks Perf hooks allow hooking user code at perf events. They can be used for manipulation of BPF maps, taking snapshot and reporting results. In this patch two perf hook points are introduced: record_start and record_end. To avoid buggy user actions, a SIGSEGV signal handler is introduced into 'perf record'. It turns off perf hook if it causes a segfault and report an error to help debugging. A test case for perf hook is introduced. Test result: $ ./buildperf/perf test -v hook 50: Test perf hooks : --- start --- test child forked, pid 10311 SIGSEGV is observed as expected, try to recover. Fatal error (SEGFAULT) in perf hook 'test' test child finished with 0 ---- end ---- Test perf hooks: Ok Signed-off-by: Wang Nan Cc: Alexei Starovoitov Cc: He Kuang Cc: Jiri Olsa Cc: Joe Stringer Cc: Zefan Li Cc: pi3orama@163.com Link: http://lkml.kernel.org/r/20161126070354.141764-5-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-record.c | 11 ++++ tools/perf/tests/Build | 1 + tools/perf/tests/builtin-test.c | 4 ++ tools/perf/tests/perf-hooks.c | 44 ++++++++++++++++ tools/perf/tests/tests.h | 1 + tools/perf/util/Build | 2 + tools/perf/util/perf-hooks-list.h | 3 ++ tools/perf/util/perf-hooks.c | 84 +++++++++++++++++++++++++++++++ tools/perf/util/perf-hooks.h | 37 ++++++++++++++ 9 files changed, 187 insertions(+) create mode 100644 tools/perf/tests/perf-hooks.c create mode 100644 tools/perf/util/perf-hooks-list.h create mode 100644 tools/perf/util/perf-hooks.c create mode 100644 tools/perf/util/perf-hooks.h diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c index 67d2a9003294..fa26865364b6 100644 --- a/tools/perf/builtin-record.c +++ b/tools/perf/builtin-record.c @@ -37,6 +37,7 @@ #include "util/llvm-utils.h" #include "util/bpf-loader.h" #include "util/trigger.h" +#include "util/perf-hooks.h" #include "asm/bug.h" #include @@ -206,6 +207,12 @@ static void sig_handler(int sig) done = 1; } +static void sigsegv_handler(int sig) +{ + perf_hooks__recover(); + sighandler_dump_stack(sig); +} + static void record__sig_exit(void) { if (signr == -1) @@ -833,6 +840,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) signal(SIGCHLD, sig_handler); signal(SIGINT, sig_handler); signal(SIGTERM, sig_handler); + signal(SIGSEGV, sigsegv_handler); if (rec->opts.auxtrace_snapshot_mode || rec->switch_output) { signal(SIGUSR2, snapshot_sig_handler); @@ -970,6 +978,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) trigger_ready(&auxtrace_snapshot_trigger); trigger_ready(&switch_output_trigger); + perf_hooks__invoke_record_start(); for (;;) { unsigned long long hits = rec->samples; @@ -1114,6 +1123,8 @@ out_child: } } + perf_hooks__invoke_record_end(); + if (!err && !quiet) { char samples[128]; const char *postfix = rec->timestamp_filename ? diff --git a/tools/perf/tests/Build b/tools/perf/tests/Build index 8a4ce492f7b2..af3ec94869aa 100644 --- a/tools/perf/tests/Build +++ b/tools/perf/tests/Build @@ -42,6 +42,7 @@ perf-y += backward-ring-buffer.o perf-y += sdt.o perf-y += is_printable_array.o perf-y += bitmap.o +perf-y += perf-hooks.o $(OUTPUT)tests/llvm-src-base.c: tests/bpf-script-example.c tests/Build $(call rule_mkdir) diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c index 778668a2a966..dab83f7042fa 100644 --- a/tools/perf/tests/builtin-test.c +++ b/tools/perf/tests/builtin-test.c @@ -229,6 +229,10 @@ static struct test generic_tests[] = { .desc = "Test bitmap print", .func = test__bitmap_print, }, + { + .desc = "Test perf hooks", + .func = test__perf_hooks, + }, { .func = NULL, }, diff --git a/tools/perf/tests/perf-hooks.c b/tools/perf/tests/perf-hooks.c new file mode 100644 index 000000000000..9338cb2c25ab --- /dev/null +++ b/tools/perf/tests/perf-hooks.c @@ -0,0 +1,44 @@ +#include +#include + +#include "tests.h" +#include "debug.h" +#include "util.h" +#include "perf-hooks.h" + +static void sigsegv_handler(int sig __maybe_unused) +{ + pr_debug("SIGSEGV is observed as expected, try to recover.\n"); + perf_hooks__recover(); + signal(SIGSEGV, SIG_DFL); + raise(SIGSEGV); + exit(-1); +} + +static int hook_flags; + +static void the_hook(void) +{ + int *p = NULL; + + hook_flags = 1234; + + /* Generate a segfault, test perf_hooks__recover */ + *p = 0; +} + +int test__perf_hooks(int subtest __maybe_unused) +{ + signal(SIGSEGV, sigsegv_handler); + perf_hooks__set_hook("test", the_hook); + perf_hooks__invoke_test(); + + /* hook is triggered? */ + if (hook_flags != 1234) + return TEST_FAIL; + + /* the buggy hook is removed? */ + if (perf_hooks__get_hook("test")) + return TEST_FAIL; + return TEST_OK; +} diff --git a/tools/perf/tests/tests.h b/tools/perf/tests/tests.h index 7c196c585472..3a1f98f291ba 100644 --- a/tools/perf/tests/tests.h +++ b/tools/perf/tests/tests.h @@ -91,6 +91,7 @@ int test__cpu_map_print(int subtest); int test__sdt_event(int subtest); int test__is_printable_array(int subtest); int test__bitmap_print(int subtest); +int test__perf_hooks(int subtest); #if defined(__arm__) || defined(__aarch64__) #ifdef HAVE_DWARF_UNWIND_SUPPORT diff --git a/tools/perf/util/Build b/tools/perf/util/Build index 1dc67efad634..b2a47aac8d1c 100644 --- a/tools/perf/util/Build +++ b/tools/perf/util/Build @@ -123,6 +123,8 @@ libperf-$(CONFIG_LIBELF) += genelf.o libperf-$(CONFIG_DWARF) += genelf_debug.o endif +libperf-y += perf-hooks.o + CFLAGS_config.o += -DETC_PERFCONFIG="BUILD_STR($(ETC_PERFCONFIG_SQ))" # avoid compiler warnings in 32-bit mode CFLAGS_genelf_debug.o += -Wno-packed diff --git a/tools/perf/util/perf-hooks-list.h b/tools/perf/util/perf-hooks-list.h new file mode 100644 index 000000000000..2867c07ee84e --- /dev/null +++ b/tools/perf/util/perf-hooks-list.h @@ -0,0 +1,3 @@ +PERF_HOOK(record_start) +PERF_HOOK(record_end) +PERF_HOOK(test) diff --git a/tools/perf/util/perf-hooks.c b/tools/perf/util/perf-hooks.c new file mode 100644 index 000000000000..4ce88e37dd63 --- /dev/null +++ b/tools/perf/util/perf-hooks.c @@ -0,0 +1,84 @@ +/* + * perf_hooks.c + * + * Copyright (C) 2016 Wang Nan + * Copyright (C) 2016 Huawei Inc. + */ + +#include +#include +#include +#include +#include "util/util.h" +#include "util/debug.h" +#include "util/perf-hooks.h" + +static sigjmp_buf jmpbuf; +static const struct perf_hook_desc *current_perf_hook; + +void perf_hooks__invoke(const struct perf_hook_desc *desc) +{ + if (!(desc && desc->p_hook_func && *desc->p_hook_func)) + return; + + if (sigsetjmp(jmpbuf, 1)) { + pr_warning("Fatal error (SEGFAULT) in perf hook '%s'\n", + desc->hook_name); + *(current_perf_hook->p_hook_func) = NULL; + } else { + current_perf_hook = desc; + (**desc->p_hook_func)(); + } + current_perf_hook = NULL; +} + +void perf_hooks__recover(void) +{ + if (current_perf_hook) + siglongjmp(jmpbuf, 1); +} + +#define PERF_HOOK(name) \ +perf_hook_func_t __perf_hook_func_##name = NULL; \ +struct perf_hook_desc __perf_hook_desc_##name = \ + {.hook_name = #name, .p_hook_func = &__perf_hook_func_##name}; +#include "perf-hooks-list.h" +#undef PERF_HOOK + +#define PERF_HOOK(name) \ + &__perf_hook_desc_##name, + +static struct perf_hook_desc *perf_hooks[] = { +#include "perf-hooks-list.h" +}; +#undef PERF_HOOK + +int perf_hooks__set_hook(const char *hook_name, + perf_hook_func_t hook_func) +{ + unsigned int i; + + for (i = 0; i < ARRAY_SIZE(perf_hooks); i++) { + if (strcmp(hook_name, perf_hooks[i]->hook_name) != 0) + continue; + + if (*(perf_hooks[i]->p_hook_func)) + pr_warning("Overwrite existing hook: %s\n", hook_name); + *(perf_hooks[i]->p_hook_func) = hook_func; + return 0; + } + return -ENOENT; +} + +perf_hook_func_t perf_hooks__get_hook(const char *hook_name) +{ + unsigned int i; + + for (i = 0; i < ARRAY_SIZE(perf_hooks); i++) { + if (strcmp(hook_name, perf_hooks[i]->hook_name) != 0) + continue; + + return *(perf_hooks[i]->p_hook_func); + } + return ERR_PTR(-ENOENT); +} diff --git a/tools/perf/util/perf-hooks.h b/tools/perf/util/perf-hooks.h new file mode 100644 index 000000000000..1d482b26b4b9 --- /dev/null +++ b/tools/perf/util/perf-hooks.h @@ -0,0 +1,37 @@ +#ifndef PERF_UTIL_PERF_HOOKS_H +#define PERF_UTIL_PERF_HOOKS_H + +#ifdef __cplusplus +extern "C" { +#endif + +typedef void (*perf_hook_func_t)(void); +struct perf_hook_desc { + const char * const hook_name; + perf_hook_func_t * const p_hook_func; +}; + +extern void perf_hooks__invoke(const struct perf_hook_desc *); +extern void perf_hooks__recover(void); + +#define PERF_HOOK(name) \ +extern struct perf_hook_desc __perf_hook_desc_##name; \ +static inline void perf_hooks__invoke_##name(void) \ +{ \ + perf_hooks__invoke(&__perf_hook_desc_##name); \ +} + +#include "perf-hooks-list.h" +#undef PERF_HOOK + +extern int +perf_hooks__set_hook(const char *hook_name, + perf_hook_func_t hook_func); + +extern perf_hook_func_t +perf_hooks__get_hook(const char *hook_name); + +#ifdef __cplusplus +} +#endif +#endif From 030910c085467c7f08f49735c19c66c1baa53f76 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Tue, 29 Nov 2016 12:38:14 -0300 Subject: [PATCH 09/19] perf test: Remove "test" and similar strings from test descriptions Having "test" in almost all test descriptions is redundant, simplify it removing and rewriting tests with such descriptions. End result: # perf test 1: vmlinux symtab matches kallsyms : Ok 2: Detect openat syscall event : Ok 3: Detect openat syscall event on all cpus : Ok 4: Read samples using the mmap interface : Ok 5: Parse event definition strings : Ok 6: PERF_RECORD_* events & perf_sample fields : Ok 7: Parse perf pmu format : Ok 8: DSO data read : Ok 9: DSO data cache : Ok 10: DSO data reopen : Ok 11: Roundtrip evsel->name : Ok 12: Parse sched tracepoints fields : Ok 13: syscalls:sys_enter_openat event fields : Ok 14: Setup struct perf_event_attr : Ok 15: Match and link multiple hists : Ok 16: 'import perf' in python : Ok 17: Breakpoint overflow signal handler : Ok 18: Breakpoint overflow sampling : Ok 19: Number of exit events of a simple workload : Ok 20: Software clock events period values : Ok 21: Object code reading : Ok 22: Sample parsing : Ok 23: Use a dummy software event to keep tracking: Ok 24: Parse with no sample_id_all bit set : Ok 25: Filter hist entries : Ok 26: Lookup mmap thread : Ok 27: Share thread mg : Ok 28: Sort output of hist entries : Ok 29: Cumulate child hist entries : Ok 30: Track with sched_switch : Ok 31: Filter fds with revents mask in a fdarray : Ok 32: Add fd to a fdarray, making it autogrow : Ok 33: kmod_path__parse : Ok 34: Thread map : Ok 35: LLVM search and compile : 35.1: Basic BPF llvm compile : Ok 35.2: kbuild searching : Ok 35.3: Compile source for BPF prologue generation: Ok 35.4: Compile source for BPF relocation : Ok 36: Session topology : Ok 37: BPF filter : 37.1: Basic BPF filtering : Ok 37.2: BPF prologue generation : Ok 37.3: BPF relocation checker : Ok 38: Synthesize thread map : Ok 39: Synthesize cpu map : Ok 40: Synthesize stat config : Ok 41: Synthesize stat : Ok 42: Synthesize stat round : Ok 43: Synthesize attr update : Ok 44: Event times : Ok 45: Read backward ring buffer : Ok 46: Print cpu map : Ok 47: Probe SDT events : Ok 48: is_printable_array : Ok 49: Print bitmap : Ok 50: perf hooks : Ok 51: x86 rdpmc : Ok 52: Convert perf time to TSC : Ok 53: DWARF unwind : Ok 54: x86 instruction decoder - new instructions : Ok 55: Intel cqm nmi context read : Skip # Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-rx2lbfcrrio2yx1fxcljqy0e@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/arch/x86/tests/arch-tests.c | 10 +-- tools/perf/tests/bpf.c | 6 +- tools/perf/tests/builtin-test.c | 94 +++++++++++++------------- tools/perf/tests/llvm.c | 8 +-- 4 files changed, 59 insertions(+), 59 deletions(-) diff --git a/tools/perf/arch/x86/tests/arch-tests.c b/tools/perf/arch/x86/tests/arch-tests.c index 2218cb64f840..99d66191e56c 100644 --- a/tools/perf/arch/x86/tests/arch-tests.c +++ b/tools/perf/arch/x86/tests/arch-tests.c @@ -4,27 +4,27 @@ struct test arch_tests[] = { { - .desc = "x86 rdpmc test", + .desc = "x86 rdpmc", .func = test__rdpmc, }, { - .desc = "Test converting perf time to TSC", + .desc = "Convert perf time to TSC", .func = test__perf_time_to_tsc, }, #ifdef HAVE_DWARF_UNWIND_SUPPORT { - .desc = "Test dwarf unwind", + .desc = "DWARF unwind", .func = test__dwarf_unwind, }, #endif #ifdef HAVE_AUXTRACE_SUPPORT { - .desc = "Test x86 instruction decoder - new instructions", + .desc = "x86 instruction decoder - new instructions", .func = test__insn_x86, }, #endif { - .desc = "Test intel cqm nmi context read", + .desc = "Intel cqm nmi context read", .func = test__intel_cqm_count_nmi_context, }, { diff --git a/tools/perf/tests/bpf.c b/tools/perf/tests/bpf.c index 8f0298aff222..92343f43e44a 100644 --- a/tools/perf/tests/bpf.c +++ b/tools/perf/tests/bpf.c @@ -57,7 +57,7 @@ static struct { } bpf_testcase_table[] = { { LLVM_TESTCASE_BASE, - "Test basic BPF filtering", + "Basic BPF filtering", "[basic_bpf_test]", "fix 'perf test LLVM' first", "load bpf object failed", @@ -67,7 +67,7 @@ static struct { #ifdef HAVE_BPF_PROLOGUE { LLVM_TESTCASE_BPF_PROLOGUE, - "Test BPF prologue generation", + "BPF prologue generation", "[bpf_prologue_test]", "fix kbuild first", "check your vmlinux setting?", @@ -77,7 +77,7 @@ static struct { #endif { LLVM_TESTCASE_BPF_RELOCATION, - "Test BPF relocation checker", + "BPF relocation checker", "[bpf_relocation_test]", "fix 'perf test LLVM' first", "libbpf error when dealing with relocation", diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c index dab83f7042fa..d1bec0444be7 100644 --- a/tools/perf/tests/builtin-test.c +++ b/tools/perf/tests/builtin-test.c @@ -28,119 +28,119 @@ static struct test generic_tests[] = { .func = test__vmlinux_matches_kallsyms, }, { - .desc = "detect openat syscall event", + .desc = "Detect openat syscall event", .func = test__openat_syscall_event, }, { - .desc = "detect openat syscall event on all cpus", + .desc = "Detect openat syscall event on all cpus", .func = test__openat_syscall_event_on_all_cpus, }, { - .desc = "read samples using the mmap interface", + .desc = "Read samples using the mmap interface", .func = test__basic_mmap, }, { - .desc = "parse events tests", + .desc = "Parse event definition strings", .func = test__parse_events, }, { - .desc = "Validate PERF_RECORD_* events & perf_sample fields", + .desc = "PERF_RECORD_* events & perf_sample fields", .func = test__PERF_RECORD, }, { - .desc = "Test perf pmu format parsing", + .desc = "Parse perf pmu format", .func = test__pmu, }, { - .desc = "Test dso data read", + .desc = "DSO data read", .func = test__dso_data, }, { - .desc = "Test dso data cache", + .desc = "DSO data cache", .func = test__dso_data_cache, }, { - .desc = "Test dso data reopen", + .desc = "DSO data reopen", .func = test__dso_data_reopen, }, { - .desc = "roundtrip evsel->name check", + .desc = "Roundtrip evsel->name", .func = test__perf_evsel__roundtrip_name_test, }, { - .desc = "Check parsing of sched tracepoints fields", + .desc = "Parse sched tracepoints fields", .func = test__perf_evsel__tp_sched_test, }, { - .desc = "Generate and check syscalls:sys_enter_openat event fields", + .desc = "syscalls:sys_enter_openat event fields", .func = test__syscall_openat_tp_fields, }, { - .desc = "struct perf_event_attr setup", + .desc = "Setup struct perf_event_attr", .func = test__attr, }, { - .desc = "Test matching and linking multiple hists", + .desc = "Match and link multiple hists", .func = test__hists_link, }, { - .desc = "Try 'import perf' in python, checking link problems", + .desc = "'import perf' in python", .func = test__python_use, }, { - .desc = "Test breakpoint overflow signal handler", + .desc = "Breakpoint overflow signal handler", .func = test__bp_signal, }, { - .desc = "Test breakpoint overflow sampling", + .desc = "Breakpoint overflow sampling", .func = test__bp_signal_overflow, }, { - .desc = "Test number of exit event of a simple workload", + .desc = "Number of exit events of a simple workload", .func = test__task_exit, }, { - .desc = "Test software clock events have valid period values", + .desc = "Software clock events period values", .func = test__sw_clock_freq, }, { - .desc = "Test object code reading", + .desc = "Object code reading", .func = test__code_reading, }, { - .desc = "Test sample parsing", + .desc = "Sample parsing", .func = test__sample_parsing, }, { - .desc = "Test using a dummy software event to keep tracking", + .desc = "Use a dummy software event to keep tracking", .func = test__keep_tracking, }, { - .desc = "Test parsing with no sample_id_all bit set", + .desc = "Parse with no sample_id_all bit set", .func = test__parse_no_sample_id_all, }, { - .desc = "Test filtering hist entries", + .desc = "Filter hist entries", .func = test__hists_filter, }, { - .desc = "Test mmap thread lookup", + .desc = "Lookup mmap thread", .func = test__mmap_thread_lookup, }, { - .desc = "Test thread mg sharing", + .desc = "Share thread mg", .func = test__thread_mg_share, }, { - .desc = "Test output sorting of hist entries", + .desc = "Sort output of hist entries", .func = test__hists_output, }, { - .desc = "Test cumulation of child hist entries", + .desc = "Cumulate child hist entries", .func = test__hists_cumulate, }, { - .desc = "Test tracking with sched_switch", + .desc = "Track with sched_switch", .func = test__switch_tracking, }, { @@ -152,15 +152,15 @@ static struct test generic_tests[] = { .func = test__fdarray__add, }, { - .desc = "Test kmod_path__parse function", + .desc = "kmod_path__parse", .func = test__kmod_path__parse, }, { - .desc = "Test thread map", + .desc = "Thread map", .func = test__thread_map, }, { - .desc = "Test LLVM searching and compiling", + .desc = "LLVM search and compile", .func = test__llvm, .subtest = { .skip_if_fail = true, @@ -169,11 +169,11 @@ static struct test generic_tests[] = { }, }, { - .desc = "Test topology in session", + .desc = "Session topology", .func = test_session_topology, }, { - .desc = "Test BPF filter", + .desc = "BPF filter", .func = test__bpf, .subtest = { .skip_if_fail = true, @@ -182,55 +182,55 @@ static struct test generic_tests[] = { }, }, { - .desc = "Test thread map synthesize", + .desc = "Synthesize thread map", .func = test__thread_map_synthesize, }, { - .desc = "Test cpu map synthesize", + .desc = "Synthesize cpu map", .func = test__cpu_map_synthesize, }, { - .desc = "Test stat config synthesize", + .desc = "Synthesize stat config", .func = test__synthesize_stat_config, }, { - .desc = "Test stat synthesize", + .desc = "Synthesize stat", .func = test__synthesize_stat, }, { - .desc = "Test stat round synthesize", + .desc = "Synthesize stat round", .func = test__synthesize_stat_round, }, { - .desc = "Test attr update synthesize", + .desc = "Synthesize attr update", .func = test__event_update, }, { - .desc = "Test events times", + .desc = "Event times", .func = test__event_times, }, { - .desc = "Test backward reading from ring buffer", + .desc = "Read backward ring buffer", .func = test__backward_ring_buffer, }, { - .desc = "Test cpu map print", + .desc = "Print cpu map", .func = test__cpu_map_print, }, { - .desc = "Test SDT event probing", + .desc = "Probe SDT events", .func = test__sdt_event, }, { - .desc = "Test is_printable_array function", + .desc = "is_printable_array", .func = test__is_printable_array, }, { - .desc = "Test bitmap print", + .desc = "Print bitmap", .func = test__bitmap_print, }, { - .desc = "Test perf hooks", + .desc = "perf hooks", .func = test__perf_hooks, }, { diff --git a/tools/perf/tests/llvm.c b/tools/perf/tests/llvm.c index b798a4bfd238..02a33ebcd992 100644 --- a/tools/perf/tests/llvm.c +++ b/tools/perf/tests/llvm.c @@ -34,19 +34,19 @@ static struct { } bpf_source_table[__LLVM_TESTCASE_MAX] = { [LLVM_TESTCASE_BASE] = { .source = test_llvm__bpf_base_prog, - .desc = "Basic BPF llvm compiling test", + .desc = "Basic BPF llvm compile", }, [LLVM_TESTCASE_KBUILD] = { .source = test_llvm__bpf_test_kbuild_prog, - .desc = "Test kbuild searching", + .desc = "kbuild searching", }, [LLVM_TESTCASE_BPF_PROLOGUE] = { .source = test_llvm__bpf_test_prologue_prog, - .desc = "Compile source for BPF prologue generation test", + .desc = "Compile source for BPF prologue generation", }, [LLVM_TESTCASE_BPF_RELOCATION] = { .source = test_llvm__bpf_test_relocation, - .desc = "Compile source for BPF relocation test", + .desc = "Compile source for BPF relocation", .should_load_fail = true, }, }; From aa58e9afb613fab74f33292705bb43beb0f1828d Mon Sep 17 00:00:00 2001 From: David Ahern Date: Fri, 25 Nov 2016 14:42:13 -0700 Subject: [PATCH 10/19] perf kmem stat: Track memory freed Track freed memory as well as allocations and show the net in the summary. Committer notes: Testing it: # perf kmem record usleep 1 [ perf record: Woken up 0 times to write data ] [ perf record: Captured and wrote 1.626 MB perf.data (4208 samples) ] [root@jouet ~]# perf kmem stat --slab SUMMARY (SLAB allocator) ======================== Total bytes requested: 234,011 Total bytes allocated: 234,504 Total bytes freed: 213,328 <------ Net total bytes allocated: 21,176 Total bytes wasted on internal fragmentation: 493 Internal fragmentation: 0.210231% Cross CPU allocations: 4/1,963 # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480110133-37039-1-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-kmem.c | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/tools/perf/builtin-kmem.c b/tools/perf/builtin-kmem.c index d426dcb18ce9..7fd6f1e1e293 100644 --- a/tools/perf/builtin-kmem.c +++ b/tools/perf/builtin-kmem.c @@ -49,6 +49,7 @@ struct alloc_stat { u64 ptr; u64 bytes_req; u64 bytes_alloc; + u64 last_alloc; u32 hit; u32 pingpong; @@ -62,7 +63,7 @@ static struct rb_root root_alloc_sorted; static struct rb_root root_caller_stat; static struct rb_root root_caller_sorted; -static unsigned long total_requested, total_allocated; +static unsigned long total_requested, total_allocated, total_freed; static unsigned long nr_allocs, nr_cross_allocs; static int insert_alloc_stat(unsigned long call_site, unsigned long ptr, @@ -105,6 +106,8 @@ static int insert_alloc_stat(unsigned long call_site, unsigned long ptr, } data->call_site = call_site; data->alloc_cpu = cpu; + data->last_alloc = bytes_alloc; + return 0; } @@ -223,6 +226,8 @@ static int perf_evsel__process_free_event(struct perf_evsel *evsel, if (!s_alloc) return 0; + total_freed += s_alloc->last_alloc; + if ((short)sample->cpu != s_alloc->alloc_cpu) { s_alloc->pingpong++; @@ -1128,6 +1133,11 @@ static void print_slab_summary(void) printf("\n========================\n"); printf("Total bytes requested: %'lu\n", total_requested); printf("Total bytes allocated: %'lu\n", total_allocated); + printf("Total bytes freed: %'lu\n", total_freed); + if (total_allocated > total_freed) { + printf("Net total bytes allocated: %'lu\n", + total_allocated - total_freed); + } printf("Total bytes wasted on internal fragmentation: %'lu\n", total_allocated - total_requested); printf("Internal fragmentation: %f%%\n", From 64eff7d9c4469b7e24fb7e5416a67ee5959c3f76 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Fri, 25 Nov 2016 13:00:21 -0700 Subject: [PATCH 11/19] perf script: Add option to stop printing callchain Allow user to specify list of symbols which cause the dump of callchains to stop at that symbol. Committer notes: Testing it: # perf record -ag usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 1.177 MB perf.data (33 samples) ] # # # Without it: # # perf script swapper 0 [000] 9693.370039: 1 cycles:ppp: 2072ad x86_pmu_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 326978 flush_smp_call_function_queue (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 327413 generic_smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 249b37 smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a04b2c call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 889427 cpuidle_enter (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e534a call_cpuidle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e5730 cpu_startup_entry (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 9f5167 rest_init (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 137ffeb start_kernel ([kernel.vmlinux].init.text) 137f2ca x86_64_start_reservations ([kernel.vmlinux].init.text) 137f419 x86_64_start_kernel ([kernel.vmlinux].init.text) swapper 0 [000] 9693.370044: 1 cycles:ppp: 20ca1b intel_pmu_handle_irq (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 205b0c perf_event_nmi_handler (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a14a nmi_handle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a6b3 default_do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a83c do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a03fb1 end_repeat_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 326978 flush_smp_call_function_queue (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 327413 generic_smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 249b37 smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a04b2c call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 889427 cpuidle_enter (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e534a call_cpuidle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e5730 cpu_startup_entry (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 9f5167 rest_init (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 137ffeb start_kernel ([kernel.vmlinux].init.text) 137f2ca x86_64_start_reservations ([kernel.vmlinux].init.text) # # # Using it to see just what are the calls from the 'remote_function' function: # # perf script --stop-bt remote_function swapper 0 [000] 9693.370039: 1 cycles:ppp: 2072ad x86_pmu_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [000] 9693.370044: 1 cycles:ppp: 20ca1b intel_pmu_handle_irq (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 205b0c perf_event_nmi_handler (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a14a nmi_handle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a6b3 default_do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a83c do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a03fb1 end_repeat_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Cc: Jiri Olsa Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480104021-36275-1-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-script.txt | 3 +++ tools/perf/builtin-script.c | 2 ++ tools/perf/util/evsel_fprintf.c | 8 ++++++++ tools/perf/util/symbol.c | 8 ++++++++ tools/perf/util/symbol.h | 6 ++++-- 5 files changed, 25 insertions(+), 2 deletions(-) diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt index c01904f388ce..0f6ee09f7256 100644 --- a/tools/perf/Documentation/perf-script.txt +++ b/tools/perf/Documentation/perf-script.txt @@ -212,6 +212,9 @@ OPTIONS --hide-call-graph:: When printing symbols do not display call chain. +--stop-bt:: + Stop display of callgraph at these symbols + -C:: --cpu:: Only report samples for the list of CPUs provided. Multiple CPUs can be provided as a comma-separated list with no space: 0,1. Ranges of diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c index e1daff36d070..066b4bf73780 100644 --- a/tools/perf/builtin-script.c +++ b/tools/perf/builtin-script.c @@ -2151,6 +2151,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused) "system-wide collection from all CPUs"), OPT_STRING('S', "symbols", &symbol_conf.sym_list_str, "symbol[,symbol...]", "only consider these symbols"), + OPT_STRING(0, "stop-bt", &symbol_conf.bt_stop_list_str, "symbol[,symbol...]", + "Stop display of callgraph at these symbols"), OPT_STRING('C', "cpu", &cpu_list, "cpu", "list of cpus to profile"), OPT_STRING('c', "comms", &symbol_conf.comm_list_str, "comm[,comm...]", "only display events for these comms"), diff --git a/tools/perf/util/evsel_fprintf.c b/tools/perf/util/evsel_fprintf.c index 5a6f52284452..6b2925542c0a 100644 --- a/tools/perf/util/evsel_fprintf.c +++ b/tools/perf/util/evsel_fprintf.c @@ -166,6 +166,14 @@ int sample__fprintf_callchain(struct perf_sample *sample, int left_alignment, if (!print_oneline) printed += fprintf(fp, "\n"); + if (symbol_conf.bt_stop_list && + node->sym && + node->sym->name && + strlist__has_entry(symbol_conf.bt_stop_list, + node->sym->name)) { + break; + } + first = false; next: callchain_cursor_advance(cursor); diff --git a/tools/perf/util/symbol.c b/tools/perf/util/symbol.c index 420ada9de22f..df2482b2ba45 100644 --- a/tools/perf/util/symbol.c +++ b/tools/perf/util/symbol.c @@ -2032,6 +2032,10 @@ int symbol__init(struct perf_env *env) symbol_conf.sym_list_str, "symbol") < 0) goto out_free_tid_list; + if (setup_list(&symbol_conf.bt_stop_list, + symbol_conf.bt_stop_list_str, "symbol") < 0) + goto out_free_sym_list; + /* * A path to symbols of "/" is identical to "" * reset here for simplicity. @@ -2049,6 +2053,8 @@ int symbol__init(struct perf_env *env) symbol_conf.initialized = true; return 0; +out_free_sym_list: + strlist__delete(symbol_conf.sym_list); out_free_tid_list: intlist__delete(symbol_conf.tid_list); out_free_pid_list: @@ -2064,6 +2070,7 @@ void symbol__exit(void) { if (!symbol_conf.initialized) return; + strlist__delete(symbol_conf.bt_stop_list); strlist__delete(symbol_conf.sym_list); strlist__delete(symbol_conf.dso_list); strlist__delete(symbol_conf.comm_list); @@ -2071,6 +2078,7 @@ void symbol__exit(void) intlist__delete(symbol_conf.pid_list); vmlinux_path__exit(); symbol_conf.sym_list = symbol_conf.dso_list = symbol_conf.comm_list = NULL; + symbol_conf.bt_stop_list = NULL; symbol_conf.initialized = false; } diff --git a/tools/perf/util/symbol.h b/tools/perf/util/symbol.h index 1bcbefc0c325..6c358b7ed336 100644 --- a/tools/perf/util/symbol.h +++ b/tools/perf/util/symbol.h @@ -132,14 +132,16 @@ struct symbol_conf { *pid_list_str, *tid_list_str, *sym_list_str, - *col_width_list_str; + *col_width_list_str, + *bt_stop_list_str; struct strlist *dso_list, *comm_list, *sym_list, *dso_from_list, *dso_to_list, *sym_from_list, - *sym_to_list; + *sym_to_list, + *bt_stop_list; struct intlist *pid_list, *tid_list; const char *symfs; From fdf9dc4b34f5f40919370c4601eccfd0db726aa5 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:41 -0700 Subject: [PATCH 12/19] perf tools: Add time-based utility functions Add function to parse a user time string of the form , where start and stop are time in sec.nsec format. Both start and stop times are optional. Add function to determine if a sample time is within a given time time window of interest. Signed-off-by: David Ahern Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-2-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/util/Build | 1 + tools/perf/util/time-utils.c | 85 ++++++++++++++++++++++++++++++++++++ tools/perf/util/time-utils.h | 12 +++++ 3 files changed, 98 insertions(+) create mode 100644 tools/perf/util/time-utils.c create mode 100644 tools/perf/util/time-utils.h diff --git a/tools/perf/util/Build b/tools/perf/util/Build index b2a47aac8d1c..bdad82a9812d 100644 --- a/tools/perf/util/Build +++ b/tools/perf/util/Build @@ -87,6 +87,7 @@ libperf-y += help-unknown-cmd.o libperf-y += mem-events.o libperf-y += vsprintf.o libperf-y += drv_configs.o +libperf-y += time-utils.o libperf-$(CONFIG_LIBBPF) += bpf-loader.o libperf-$(CONFIG_BPF_PROLOGUE) += bpf-prologue.o diff --git a/tools/perf/util/time-utils.c b/tools/perf/util/time-utils.c new file mode 100644 index 000000000000..0443b2afd0cf --- /dev/null +++ b/tools/perf/util/time-utils.c @@ -0,0 +1,85 @@ +#include +#include +#include +#include +#include + +#include "perf.h" +#include "debug.h" +#include "time-utils.h" +#include "util.h" + +static int parse_timestr_sec_nsec(struct perf_time_interval *ptime, + char *start_str, char *end_str) +{ + if (start_str && (*start_str != '\0') && + (parse_nsec_time(start_str, &ptime->start) != 0)) { + return -1; + } + + if (end_str && (*end_str != '\0') && + (parse_nsec_time(end_str, &ptime->end) != 0)) { + return -1; + } + + return 0; +} + +int perf_time__parse_str(struct perf_time_interval *ptime, const char *ostr) +{ + char *start_str, *end_str; + char *d, *str; + int rc = 0; + + if (ostr == NULL || *ostr == '\0') + return 0; + + /* copy original string because we need to modify it */ + str = strdup(ostr); + if (str == NULL) + return -ENOMEM; + + ptime->start = 0; + ptime->end = 0; + + /* str has the format: , + * variations: , + * , + * , + */ + start_str = str; + d = strchr(start_str, ','); + if (d) { + *d = '\0'; + ++d; + } + end_str = d; + + rc = parse_timestr_sec_nsec(ptime, start_str, end_str); + + free(str); + + /* make sure end time is after start time if it was given */ + if (rc == 0 && ptime->end && ptime->end < ptime->start) + return -EINVAL; + + pr_debug("start time %" PRIu64 ", ", ptime->start); + pr_debug("end time %" PRIu64 "\n", ptime->end); + + return rc; +} + +bool perf_time__skip_sample(struct perf_time_interval *ptime, u64 timestamp) +{ + /* if time is not set don't drop sample */ + if (timestamp == 0) + return false; + + /* otherwise compare sample time to time window */ + if ((ptime->start && timestamp < ptime->start) || + (ptime->end && timestamp > ptime->end)) { + return true; + } + + return false; +} diff --git a/tools/perf/util/time-utils.h b/tools/perf/util/time-utils.h new file mode 100644 index 000000000000..8f3e0e370be8 --- /dev/null +++ b/tools/perf/util/time-utils.h @@ -0,0 +1,12 @@ +#ifndef _TIME_UTILS_H_ +#define _TIME_UTILS_H_ + +struct perf_time_interval { + u64 start, end; +}; + +int perf_time__parse_str(struct perf_time_interval *ptime, const char *ostr); + +bool perf_time__skip_sample(struct perf_time_interval *ptime, u64 timestamp); + +#endif From c284d669a20d408b70ce0dc9b2d995971f5fe0c7 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:42 -0700 Subject: [PATCH 13/19] perf tools: Move parse_nsec_time to time-utils.c Code move only; no functional change intended. Committer notes: Fix the build on Ubuntu 16.04 x86-64 cross-compiling to S/390, with this set of auto-detected features: ... dwarf: [ on ] ... dwarf_getlocations: [ on ] ... glibc: [ on ] ... gtk2: [ OFF ] ... libaudit: [ OFF ] ... libbfd: [ OFF ] ... libelf: [ on ] ... libnuma: [ OFF ] ... numa_num_possible_cpus: [ OFF ] ... libperl: [ OFF ] ... libpython: [ OFF ] ... libslang: [ OFF ] ... libcrypto: [ OFF ] ... libunwind: [ OFF ] ... libdw-dwarf-unwind: [ on ] ... zlib: [ on ] ... lzma: [ OFF ] ... get_cpuid: [ OFF ] ... bpf: [ on ] Where it was failing with: CC /tmp/build/perf/util/time-utils.o util/time-utils.c: In function 'parse_nsec_time': util/time-utils.c:17:13: error: implicit declaration of function 'strtoul' [-Werror=implicit-function-declaration] time_sec = strtoul(str, &end, 10); ^ util/time-utils.c:17:2: error: nested extern declaration of 'strtoul' [-Werror=nested-externs] time_sec = strtoul(str, &end, 10); ^ util/time-utils.c: In function 'perf_time__parse_str': util/time-utils.c:93:2: error: implicit declaration of function 'free' [-Werror=implicit-function-declaration] free(str); ^ util/time-utils.c:93:2: error: incompatible implicit declaration of built-in function 'free' [-Werror] util/time-utils.c:93:2: note: include '' or provide a declaration of 'free' Do as suggested and add a '#include ' to get the free() and strtoul() declarations and fix the build. Signed-off-by: David Ahern Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-3-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/util/time-utils.c | 36 +++++++++++++++++++++++++++++++++++- tools/perf/util/time-utils.h | 2 ++ tools/perf/util/util.c | 33 --------------------------------- tools/perf/util/util.h | 2 -- 4 files changed, 37 insertions(+), 36 deletions(-) diff --git a/tools/perf/util/time-utils.c b/tools/perf/util/time-utils.c index 0443b2afd0cf..d1b21c72206d 100644 --- a/tools/perf/util/time-utils.c +++ b/tools/perf/util/time-utils.c @@ -1,5 +1,7 @@ +#include #include #include +#include #include #include #include @@ -7,7 +9,39 @@ #include "perf.h" #include "debug.h" #include "time-utils.h" -#include "util.h" + +int parse_nsec_time(const char *str, u64 *ptime) +{ + u64 time_sec, time_nsec; + char *end; + + time_sec = strtoul(str, &end, 10); + if (*end != '.' && *end != '\0') + return -1; + + if (*end == '.') { + int i; + char nsec_buf[10]; + + if (strlen(++end) > 9) + return -1; + + strncpy(nsec_buf, end, 9); + nsec_buf[9] = '\0'; + + /* make it nsec precision */ + for (i = strlen(nsec_buf); i < 9; i++) + nsec_buf[i] = '0'; + + time_nsec = strtoul(nsec_buf, &end, 10); + if (*end != '\0') + return -1; + } else + time_nsec = 0; + + *ptime = time_sec * NSEC_PER_SEC + time_nsec; + return 0; +} static int parse_timestr_sec_nsec(struct perf_time_interval *ptime, char *start_str, char *end_str) diff --git a/tools/perf/util/time-utils.h b/tools/perf/util/time-utils.h index 8f3e0e370be8..c1f197c4af6c 100644 --- a/tools/perf/util/time-utils.h +++ b/tools/perf/util/time-utils.h @@ -5,6 +5,8 @@ struct perf_time_interval { u64 start, end; }; +int parse_nsec_time(const char *str, u64 *ptime); + int perf_time__parse_str(struct perf_time_interval *ptime, const char *ostr); bool perf_time__skip_sample(struct perf_time_interval *ptime, u64 timestamp); diff --git a/tools/perf/util/util.c b/tools/perf/util/util.c index 67ac765da27a..9ddd98827d12 100644 --- a/tools/perf/util/util.c +++ b/tools/perf/util/util.c @@ -400,39 +400,6 @@ void sighandler_dump_stack(int sig) raise(sig); } -int parse_nsec_time(const char *str, u64 *ptime) -{ - u64 time_sec, time_nsec; - char *end; - - time_sec = strtoul(str, &end, 10); - if (*end != '.' && *end != '\0') - return -1; - - if (*end == '.') { - int i; - char nsec_buf[10]; - - if (strlen(++end) > 9) - return -1; - - strncpy(nsec_buf, end, 9); - nsec_buf[9] = '\0'; - - /* make it nsec precision */ - for (i = strlen(nsec_buf); i < 9; i++) - nsec_buf[i] = '0'; - - time_nsec = strtoul(nsec_buf, &end, 10); - if (*end != '\0') - return -1; - } else - time_nsec = 0; - - *ptime = time_sec * NSEC_PER_SEC + time_nsec; - return 0; -} - int timestamp__scnprintf_usec(u64 timestamp, char *buf, size_t sz) { u64 sec = timestamp / NSEC_PER_SEC; diff --git a/tools/perf/util/util.h b/tools/perf/util/util.h index 79662d67891e..1d639e38aa82 100644 --- a/tools/perf/util/util.h +++ b/tools/perf/util/util.h @@ -179,8 +179,6 @@ static inline void *zalloc(size_t size) #undef tolower #undef toupper -int parse_nsec_time(const char *str, u64 *ptime); - extern unsigned char sane_ctype[256]; #define GIT_SPACE 0x01 #define GIT_DIGIT 0x02 From a91f4c473fa1655a2a5f1ceba46f76a95eef35bb Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:43 -0700 Subject: [PATCH 14/19] perf script: Add option to specify time window of interest Add option to allow user to control analysis window. e.g., collect data for some amount of time and analyze a segment of interest within that window. Committer notes: Testing it: # perf evlist -v cycles:ppp: size: 112, { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|CALLCHAIN|CPU|PERIOD, disabled: 1, inherit: 1, mmap: 1, comm: 1, freq: 1, task: 1, precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1 # # perf script --hide-call-graph | head -15 swapper 0 [0] 9693.370039: 1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370044: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370046: 7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370048: 126 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370049: 2701 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370051: 58823 cycles:ppp: ffffffffb90cd2e0 idle_cpu (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370059: 1 cycles:ppp: ffffffffb91a713a ctx_resched (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370062: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370064: 13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370065: 250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370067: 5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370076: 1 cycles:ppp: ffffffffb91a76c1 __perf_event_enable (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370091: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370095: 3 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) # # perf script --hide-call-graph --time ,9693.370048 swapper 0 [0] 9693.370039: 1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370044: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370046: 7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) # perf script --hide-call-graph --time 9693.370064,9693.370076 swapper 0 [1] 9693.370064: 13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370065: 250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370067: 5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux) # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-4-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-script.txt | 7 +++++++ tools/perf/builtin-script.c | 15 ++++++++++++++- 2 files changed, 21 insertions(+), 1 deletion(-) diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt index 0f6ee09f7256..5dc5c6a09ac4 100644 --- a/tools/perf/Documentation/perf-script.txt +++ b/tools/perf/Documentation/perf-script.txt @@ -292,6 +292,13 @@ include::itrace.txt[] --force:: Don't do ownership validation. +--time:: + Only analyze samples within given time window: ,. Times + have the format seconds.microseconds. If start is not given (i.e., time + string is ',x.y') then analysis starts at the beginning of the file. If + stop time is not given (i.e, time string is 'x.y,') then analysis goes + to end of file. + SEE ALSO -------- linkperf:perf-record[1], linkperf:perf-script-perl[1], diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c index 066b4bf73780..2f3ff69fc4e7 100644 --- a/tools/perf/builtin-script.c +++ b/tools/perf/builtin-script.c @@ -22,6 +22,7 @@ #include "util/thread_map.h" #include "util/stat.h" #include "util/thread-stack.h" +#include "util/time-utils.h" #include #include #include @@ -833,6 +834,8 @@ struct perf_script { struct cpu_map *cpus; struct thread_map *threads; int name_width; + const char *time_str; + struct perf_time_interval ptime; }; static int perf_evlist__max_name_len(struct perf_evlist *evlist) @@ -1014,6 +1017,9 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool); struct addr_location al; + if (perf_time__skip_sample(&scr->ptime, sample->time)) + return 0; + if (debug_mode) { if (sample->time < last_timestamp) { pr_err("Samples misordered, previous: %" PRIu64 @@ -2186,7 +2192,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused) "Enable symbol demangling"), OPT_BOOLEAN(0, "demangle-kernel", &symbol_conf.demangle_kernel, "Enable kernel symbol demangling"), - + OPT_STRING(0, "time", &script.time_str, "str", + "Time span of interest (start,stop)"), OPT_END() }; const char * const script_subcommands[] = { "record", "report", NULL }; @@ -2465,6 +2472,12 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused) if (err < 0) goto out_delete; + /* needs to be parsed after looking up reference time */ + if (perf_time__parse_str(&script.ptime, script.time_str) != 0) { + pr_err("Invalid time string\n"); + return -EINVAL; + } + err = __cmd_script(&script); flush_scripting(); From 853b74071110bed344bad1ca9d8de27731b1c574 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:44 -0700 Subject: [PATCH 15/19] perf sched timehist: Add option to specify time window of interest Add option to allow user to control analysis window. e.g., collect data for time window and analyze a segment of interest within that window. Committer notes: Testing it: # perf sched record -a usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 1.593 MB perf.data (25 samples) ] # # perf sched timehist | head -18 Samples do not have callchains. time cpu task name wait time sch delay run time [tid/pid] (msec) (msec) (msec) ------------- ------ --------------- --------- --------- -------- 19818.635579 [0002] 0.000 0.000 0.000 19818.635613 [0000] perf[9116] 0.000 0.000 0.000 19818.635676 [0000] 0.000 0.000 0.063 19818.635678 [0000] rcuos/2[29] 0.000 0.002 0.001 19818.635696 [0002] perf[9117] 0.000 0.004 0.116 19818.635702 [0000] 0.001 0.000 0.024 19818.635709 [0002] migration/2[25] 0.000 0.003 0.012 19818.636263 [0000] usleep[9117] 0.005 0.000 0.560 19818.636316 [0000] 0.560 0.000 0.053 19818.636358 [0002] 0.129 0.000 0.649 19818.636358 [0000] usleep[9117] 0.053 0.002 0.042 # # perf sched timehist --time 19818.635696, Samples do not have callchains. time cpu task name wait time sch delay run time [tid/pid] (msec) (msec) (msec) ------------- ------ --------------- -------- --------- --------- 19818.635696 [0002] perf[9117] 0.000 0.120 0.000 19818.635702 [0000] 0.019 0.000 0.006 19818.635709 [0002] migration/2[25] 0.000 0.003 0.012 19818.636263 [0000] usleep[9117] 0.005 0.000 0.560 19818.636316 [0000] 0.560 0.000 0.053 19818.636358 [0002] 0.129 0.000 0.649 19818.636358 [0000] usleep[9117] 0.053 0.002 0.042 # # perf sched timehist --time 19818.635696,19818.635709 Samples do not have callchains. time cpu task name wait time sch delay run time [tid/pid] (msec) (msec) (msec) ------------- ------ --------------- --------- --------- --------- 19818.635696 [0002] perf[9117] 0.000 0.120 0.000 19818.635702 [0000] 0.019 0.000 0.006 19818.635709 [0002] migration/2[25] 0.000 0.003 0.012 19818.635709 [0000] usleep[9117] 0.005 0.000 0.006 # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-5-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-sched.txt | 8 ++++ tools/perf/builtin-sched.c | 51 ++++++++++++++++++++++--- 2 files changed, 53 insertions(+), 6 deletions(-) diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index 121c60da03e5..7775b1eb2bee 100644 --- a/tools/perf/Documentation/perf-sched.txt +++ b/tools/perf/Documentation/perf-sched.txt @@ -132,6 +132,14 @@ OPTIONS for 'perf sched timehist' --migrations:: Show migration events. +--time:: + Only analyze samples within given time window: ,. Times + have the format seconds.microseconds. If start is not given (i.e., time + string is ',x.y') then analysis starts at the beginning of the file. If + stop time is not given (i.e, time string is 'x.y,') then analysis goes + to end of file. + + SEE ALSO -------- linkperf:perf-record[1] diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index 4f9e7cba4ebf..870d94cd20ba 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c @@ -15,6 +15,7 @@ #include "util/color.h" #include "util/stat.h" #include "util/callchain.h" +#include "util/time-utils.h" #include #include "util/trace-event.h" @@ -205,6 +206,8 @@ struct perf_sched { bool show_wakeups; bool show_migrations; u64 skipped_samples; + const char *time_str; + struct perf_time_interval ptime; }; /* per thread run time data */ @@ -1837,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched) static void timehist_print_sample(struct perf_sched *sched, struct perf_sample *sample, struct addr_location *al, - struct thread *thread) + struct thread *thread, + u64 t) { struct thread_runtime *tr = thread__priv(thread); u32 max_cpus = sched->max_cpu + 1; char tstr[64]; - timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); + timestamp__scnprintf_usec(t, tstr, sizeof(tstr)); printf("%15s [%04d] ", tstr, sample->cpu); if (sched->show_cpu_visual) { @@ -2194,7 +2198,8 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool, tr->ready_to_run = sample->time; /* show wakeups if requested */ - if (sched->show_wakeups) + if (sched->show_wakeups && + !perf_time__skip_sample(&sched->ptime, sample->time)) timehist_print_wakeup_event(sched, sample, machine, thread); return 0; @@ -2288,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool, struct machine *machine) { struct perf_sched *sched = container_of(tool, struct perf_sched, tool); + struct perf_time_interval *ptime = &sched->ptime; struct addr_location al; struct thread *thread; struct thread_runtime *tr = NULL; - u64 tprev; + u64 tprev, t = sample->time; int rc = 0; if (machine__resolve(machine, &al, sample) < 0) { @@ -2318,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool, tprev = perf_evsel__get_time(evsel, sample->cpu); - timehist_update_runtime_stats(tr, sample->time, tprev); + /* + * If start time given: + * - sample time is under window user cares about - skip sample + * - tprev is under window user cares about - reset to start of window + */ + if (ptime->start && ptime->start > t) + goto out; + + if (ptime->start > tprev) + tprev = ptime->start; + + /* + * If end time given: + * - previous sched event is out of window - we are done + * - sample time is beyond window user cares about - reset it + * to close out stats for time window interest + */ + if (ptime->end) { + if (tprev > ptime->end) + goto out; + + if (t > ptime->end) + t = ptime->end; + } + + timehist_update_runtime_stats(tr, t, tprev); + if (!sched->summary_only) - timehist_print_sample(sched, sample, &al, thread); + timehist_print_sample(sched, sample, &al, thread, t); out: if (tr) { @@ -2583,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched) symbol__init(&session->header.env); + if (perf_time__parse_str(&sched->ptime, sched->time_str) != 0) { + pr_err("Invalid time string\n"); + return -EINVAL; + } + if (timehist_check_attr(sched, evlist) != 0) goto out; @@ -2997,6 +3034,8 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"), OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"), OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"), + OPT_STRING(0, "time", &sched.time_str, "str", + "Time span for analysis (start,stop)"), OPT_PARENT(sched_options) }; From 2a865bd8dddd44315c88bf922761e4fd3374d046 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:45 -0700 Subject: [PATCH 16/19] perf kmem: Add option to specify time window of interest Add option to allow user to control analysis window. e.g., collect data for time window and analyze a segment of interest within that window. Committer notes: Testing it: # perf kmem record usleep 1 [ perf record: Woken up 0 times to write data ] [ perf record: Captured and wrote 1.540 MB perf.data (2049 samples) ] # perf evlist kmem:kmalloc kmem:kmalloc_node kmem:kfree kmem:kmem_cache_alloc kmem:kmem_cache_alloc_node kmem:kmem_cache_free # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events # # # Use 'perf script' to get a first approach, select a chunk for then using # # with 'perf kmem stat --time' # # perf script | tail -15 usleep 9889 [0] 20119.782088: kmem:kmem_cache_free: (selinux_file_free_security+0x27) call_site=ffffffffb936aa07 ptr=0xffff888a1df49fc0 perf 9888 [3] 20119.782088: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782089: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782090: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782090: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO usleep 9889 [0] 20119.782091: kmem:kmem_cache_alloc: (__sigqueue_alloc+0x4a) call_site=ffffffffb90ad33a ptr=0xffff8889f071f6e0 bytes_req=160 bytes_alloc=160 gfp_flags=GFP_ATOMIC|__GFP_NOTRACK perf 9888 [3] 20119.782091: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782093: kmem:kmem_cache_free: (__sigqueue_free.part.17+0x33) call_site=ffffffffb90ad3f3 ptr=0xffff8889f071f6e0 perf 9888 [3] 20119.782098: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782098: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782099: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782100: kmem:kmem_cache_alloc: (alloc_buffer_head+0x21) call_site=ffffffffb9287cc1 ptr=0xffff8889b12722d8 bytes_req=104 bytes_alloc=104 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782101: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782102: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782103: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 # # # stats for the whole perf.data file, i.e. no interval specified # # perf kmem stat SUMMARY (SLAB allocator) ======================== Total bytes requested: 172,628 Total bytes allocated: 173,088 Total bytes freed: 161,280 Net total bytes allocated: 11,808 Total bytes wasted on internal fragmentation: 460 Internal fragmentation: 0.265761% Cross CPU allocations: 0/851 # # # stats for an end open interval, after a certain time: # # perf kmem stat --time 20119.782088, SUMMARY (SLAB allocator) ======================== Total bytes requested: 552 Total bytes allocated: 552 Total bytes freed: 448 Net total bytes allocated: 104 Total bytes wasted on internal fragmentation: 0 Internal fragmentation: 0.000000% Cross CPU allocations: 0/8 # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-6-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-kmem.txt | 7 +++++++ tools/perf/builtin-kmem.c | 24 ++++++++++++++++++++++++ 2 files changed, 31 insertions(+) diff --git a/tools/perf/Documentation/perf-kmem.txt b/tools/perf/Documentation/perf-kmem.txt index ff0f433b3fce..479fc3261a50 100644 --- a/tools/perf/Documentation/perf-kmem.txt +++ b/tools/perf/Documentation/perf-kmem.txt @@ -61,6 +61,13 @@ OPTIONS default, but this option shows live (currently allocated) pages instead. (This option works with --page option only) +--time:: + Only analyze samples within given time window: ,. Times + have the format seconds.microseconds. If start is not given (i.e., time + string is ',x.y') then analysis starts at the beginning of the file. If + stop time is not given (i.e, time string is 'x.y,') then analysis goes + to end of file. + SEE ALSO -------- linkperf:perf-record[1] diff --git a/tools/perf/builtin-kmem.c b/tools/perf/builtin-kmem.c index 7fd6f1e1e293..35a02f8e5a4a 100644 --- a/tools/perf/builtin-kmem.c +++ b/tools/perf/builtin-kmem.c @@ -11,6 +11,7 @@ #include "util/session.h" #include "util/tool.h" #include "util/callchain.h" +#include "util/time-utils.h" #include #include "util/trace-event.h" @@ -66,6 +67,10 @@ static struct rb_root root_caller_sorted; static unsigned long total_requested, total_allocated, total_freed; static unsigned long nr_allocs, nr_cross_allocs; +/* filters for controlling start and stop of time of analysis */ +static struct perf_time_interval ptime; +const char *time_str; + static int insert_alloc_stat(unsigned long call_site, unsigned long ptr, int bytes_req, int bytes_alloc, int cpu) { @@ -912,6 +917,15 @@ static int perf_evsel__process_page_free_event(struct perf_evsel *evsel, return 0; } +static bool perf_kmem__skip_sample(struct perf_sample *sample) +{ + /* skip sample based on time? */ + if (perf_time__skip_sample(&ptime, sample->time)) + return true; + + return false; +} + typedef int (*tracepoint_handler)(struct perf_evsel *evsel, struct perf_sample *sample); @@ -931,6 +945,9 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused, return -1; } + if (perf_kmem__skip_sample(sample)) + return 0; + dump_printf(" ... thread: %s:%d\n", thread__comm_str(thread), thread->tid); if (evsel->handler != NULL) { @@ -1894,6 +1911,8 @@ int cmd_kmem(int argc, const char **argv, const char *prefix __maybe_unused) OPT_CALLBACK_NOOPT(0, "page", NULL, NULL, "Analyze page allocator", parse_page_opt), OPT_BOOLEAN(0, "live", &live_page, "Show live page stat"), + OPT_STRING(0, "time", &time_str, "str", + "Time span of interest (start,stop)"), OPT_END() }; const char *const kmem_subcommands[] = { "record", "stat", NULL }; @@ -1954,6 +1973,11 @@ int cmd_kmem(int argc, const char **argv, const char *prefix __maybe_unused) symbol__init(&session->header.env); + if (perf_time__parse_str(&ptime, time_str) != 0) { + pr_err("Invalid time string\n"); + return -EINVAL; + } + if (!strcmp(argv[0], "stat")) { setlocale(LC_ALL, ""); From 46690a8051e4b5901a49080443a17a270e0bd8a2 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Tue, 29 Nov 2016 10:15:46 -0700 Subject: [PATCH 17/19] perf report: Add option to specify time window of interest Add option to allow user to control analysis window. e.g., collect data for time window and analyze a segment of interest within that window. Committer notes: Testing it: Using the perf.data file captured via 'perf kmem record': # perf report --header-only # ======== # captured on: Tue Nov 29 16:01:53 2016 # hostname : jouet # os release : 4.8.8-300.fc25.x86_64 # perf version : 4.9.rc6.g5a6aca # arch : x86_64 # nrcpus online : 4 # nrcpus avail : 4 # cpudesc : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz # cpuid : GenuineIntel,6,61,4 # total memory : 20254660 kB # cmdline : /home/acme/bin/perf kmem record usleep 1 # event : name = kmem:kmalloc, , id = { 931980, 931981, 931982, 931983 }, type = 2, size = 112, config = 0x1b9, { sample_period, sample_freq } = 1, sample_typ # event : name = kmem:kmalloc_node, , id = { 931984, 931985, 931986, 931987 }, type = 2, size = 112, config = 0x1b7, { sample_period, sample_freq } = 1, sampl # event : name = kmem:kfree, , id = { 931988, 931989, 931990, 931991 }, type = 2, size = 112, config = 0x1b5, { sample_period, sample_freq } = 1, sample_type # event : name = kmem:kmem_cache_alloc, , id = { 931992, 931993, 931994, 931995 }, type = 2, size = 112, config = 0x1b8, { sample_period, sample_freq } = 1, s # event : name = kmem:kmem_cache_alloc_node, , id = { 931996, 931997, 931998, 931999 }, type = 2, size = 112, config = 0x1b6, { sample_period, sample_freq } = # event : name = kmem:kmem_cache_free, , id = { 932000, 932001, 932002, 932003 }, type = 2, size = 112, config = 0x1b4, { sample_period, sample_freq } = 1, sa # HEADER_CPU_TOPOLOGY info available, use -I to display # HEADER_NUMA_TOPOLOGY info available, use -I to display # pmu mappings: cpu = 4, intel_pt = 7, intel_bts = 6, uncore_arb = 13, cstate_pkg = 15, breakpoint = 5, uncore_cbox_1 = 12, power = 9, software = 1, uncore_im # HEADER_CACHE info available, use -I to display # missing features: HEADER_BRANCH_STACK HEADER_GROUP_DESC HEADER_AUXTRACE HEADER_STAT # ======== # # # Looking at just the histogram entries for the first event: # # perf report | head -33 # To display the perf.data header info, please use --header/--header-only options. # # # Total Lost Samples: 0 # # Samples: 40 of event 'kmem:kmalloc' # Event count (approx.): 40 # # Overhead Trace output # ........ ............................................................................................................... # 37.50% call_site=ffffffffb91ad3c7 ptr=0xffff88895fc05000 bytes_req=4096 bytes_alloc=4096 gfp_flags=GFP_KERNEL 10.00% call_site=ffffffffb9258416 ptr=0xffff888a1dc61f00 bytes_req=240 bytes_alloc=256 gfp_flags=GFP_KERNEL|__GFP_ZERO 7.50% call_site=ffffffffb9258416 ptr=0xffff888a2640ac00 bytes_req=240 bytes_alloc=256 gfp_flags=GFP_KERNEL|__GFP_ZERO 2.50% call_site=ffffffffb92759ba ptr=0xffff888a26776000 bytes_req=4096 bytes_alloc=4096 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb9276864 ptr=0xffff8886f6b82600 bytes_req=136 bytes_alloc=192 gfp_flags=GFP_KERNEL|__GFP_ZERO 2.50% call_site=ffffffffb9276903 ptr=0xffff888aefcf0460 bytes_req=32 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb92ad0ce ptr=0xffff888756c98a00 bytes_req=392 bytes_alloc=512 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb92ad0ce ptr=0xffff888756c9ba00 bytes_req=504 bytes_alloc=512 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb92ad301 ptr=0xffff888a31747600 bytes_req=128 bytes_alloc=128 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb92ad511 ptr=0xffff888a9d26a2a0 bytes_req=28 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c11a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c12c0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c1540 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c15a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c15e0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c16e0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c1c20 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb936a7fb ptr=0xffff888a9d26a2a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL 2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931240 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO 2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931980 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO 2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931a00 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO # # # And then limiting using the example for 'perf kmem stat --time' used # # in the previous changeset committer note we see that there were no # # kmem:kmalloc in that last part of the file, but there were some # # kmem:kmem_cache_alloc ones: # # perf report --time 20119.782088, --stdio # # Total Lost Samples: 0 # # Samples: 0 of event 'kmem:kmalloc' # Event count (approx.): 0 # # Overhead Trace output # ........ ............ # # Samples: 0 of event 'kmem:kmalloc_node' # Event count (approx.): 0 # # Overhead Trace output # ........ ............ # # Samples: 0 of event 'kmem:kfree' # Event count (approx.): 0 # # Overhead Trace output # ........ ............ # # Samples: 8 of event 'kmem:kmem_cache_alloc' # Event count (approx.): 8 # # Overhead Trace output # ........ .................................................................................................................. # 75.00% call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO 12.50% call_site=ffffffffb90ad33a ptr=0xffff8889f071f6e0 bytes_req=160 bytes_alloc=160 gfp_flags=GFP_ATOMIC|__GFP_NOTRACK 12.50% call_site=ffffffffb9287cc1 ptr=0xffff8889b12722d8 bytes_req=104 bytes_alloc=104 gfp_flags=GFP_NOFS|__GFP_ZERO # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-7-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-report.txt | 7 +++++++ tools/perf/builtin-report.c | 14 +++++++++++++- 2 files changed, 20 insertions(+), 1 deletion(-) diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt index 2d1746295abf..3a166ae4a4d3 100644 --- a/tools/perf/Documentation/perf-report.txt +++ b/tools/perf/Documentation/perf-report.txt @@ -382,6 +382,13 @@ OPTIONS --header-only:: Show only perf.data header (forces --stdio). +--time:: + Only analyze samples within given time window: ,. Times + have the format seconds.microseconds. If start is not given (i.e., time + string is ',x.y') then analysis starts at the beginning of the file. If + stop time is not given (i.e, time string is 'x.y,') then analysis goes + to end of file. + --itrace:: Options for decoding instruction tracing data. The options are: diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 3dfbfffe2ecd..d2afbe4a240d 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -36,7 +36,7 @@ #include "util/hist.h" #include "util/data.h" #include "arch/common.h" - +#include "util/time-utils.h" #include "util/auxtrace.h" #include @@ -59,6 +59,8 @@ struct report { const char *pretty_printing_style; const char *cpu_list; const char *symbol_filter_str; + const char *time_str; + struct perf_time_interval ptime; float min_percent; u64 nr_entries; u64 queue_size; @@ -158,6 +160,9 @@ static int process_sample_event(struct perf_tool *tool, }; int ret = 0; + if (perf_time__skip_sample(&rep->ptime, sample->time)) + return 0; + if (machine__resolve(machine, &al, sample) < 0) { pr_debug("problem processing %d event, skipping it.\n", event->header.type); @@ -830,6 +835,8 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused) OPT_CALLBACK_DEFAULT(0, "stdio-color", NULL, "mode", "'always' (default), 'never' or 'auto' only applicable to --stdio mode", stdio__config_color, "always"), + OPT_STRING(0, "time", &report.time_str, "str", + "Time span of interest (start,stop)"), OPT_END() }; struct perf_data_file file = { @@ -1015,6 +1022,11 @@ repeat: if (symbol__init(&session->header.env) < 0) goto error; + if (perf_time__parse_str(&report.ptime, report.time_str) != 0) { + pr_err("Invalid time string\n"); + return -EINVAL; + } + sort__setup_elide(stdout); ret = __cmd_report(&report); From 859afa6ca9321346800bac0ee478c9a99c4babaf Mon Sep 17 00:00:00 2001 From: Kim Phillips Date: Wed, 30 Nov 2016 09:23:33 -0600 Subject: [PATCH 18/19] perf annotate: Use arch->objdump.comment_char in dec__parse() Presume neglected in commit 786c1b5 "perf annotate: Start supporting cross arch annotation". This doesn't fix a bug since none of the affected arches support parsing dec/inc instructions yet. Signed-off-by: Kim Phillips Cc: Alexander Shishkin Cc: Chris Ryder Cc: Mark Rutland Cc: Pawel Moll Cc: Peter Zijlstra Cc: Will Deacon Link: http://lkml.kernel.org/r/20161130092333.1cca5dd2c77e1790d61c1e9c@arm.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/util/annotate.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tools/perf/util/annotate.c b/tools/perf/util/annotate.c index 3e34ee0fde28..191599eca807 100644 --- a/tools/perf/util/annotate.c +++ b/tools/perf/util/annotate.c @@ -408,7 +408,7 @@ static int dec__parse(struct arch *arch __maybe_unused, struct ins_operands *ops if (ops->target.raw == NULL) return -1; - comment = strchr(s, '#'); + comment = strchr(s, arch->objdump.comment_char); if (comment == NULL) return 0; From 0fcb1da4aba6e6c7b32de5e0948b740b31ad822d Mon Sep 17 00:00:00 2001 From: Kim Phillips Date: Wed, 30 Nov 2016 09:23:44 -0600 Subject: [PATCH 19/19] perf annotate: AArch64 support MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This is a regex converted version from the original: https://lkml.org/lkml/2016/5/19/461 Add basic support to recognise AArch64 assembly. This allows perf to identify AArch64 instructions that branch to other parts within the same function, thereby properly annotating them. Rebased onto new cross-arch annotation bits: https://lkml.org/lkml/2016/11/25/546 Sample output: security_file_permission vmlinux 5.80 │ ← ret ▒ │70: ldr w0, [x21,#68] ▒ 4.44 │ ↓ tbnz d0 ▒ │ mov w0, #0x24 // #36 ▒ 1.37 │ ands w0, w22, w0 ▒ │ ↑ b.eq 60 ▒ 1.37 │ ↓ tbnz e4 ▒ │ mov w19, #0x20000 // #131072 ▒ 1.02 │ ↓ tbz ec ▒ │90:┌─→ldr x3, [x21,#24] ▒ 1.37 │ │ add x21, x21, #0x10 ▒ │ │ mov w2, w19 ▒ 1.02 │ │ mov x0, x21 ▒ │ │ mov x1, x3 ▒ 1.71 │ │ ldr x20, [x3,#48] ▒ │ │→ bl __fsnotify_parent ▒ 0.68 │ │↑ cbnz 60 ▒ │ │ mov x2, x21 ▒ 1.37 │ │ mov w1, w19 ▒ │ │ mov x0, x20 ▒ 0.68 │ │ mov w5, #0x0 // #0 ▒ │ │ mov x4, #0x0 // #0 ▒ 1.71 │ │ mov w3, #0x1 // #1 ▒ │ │→ bl fsnotify ▒ 1.37 │ │↑ b 60 ▒ │d0:│ mov w0, #0x0 // #0 ▒ │ │ ldp x19, x20, [sp,#16] ▒ │ │ ldp x21, x22, [sp,#32] ▒ │ │ ldp x29, x30, [sp],#48 ▒ │ │← ret ▒ │e4:│ mov w19, #0x10000 // #65536 ▒ │ └──b 90 ◆ │ec: brk #0x800 ▒ Press 'h' for help on key bindings Signed-off-by: Kim Phillips Signed-off-by: Chris Ryder Cc: Alexander Shishkin Cc: Mark Rutland Cc: Pawel Moll Cc: Peter Zijlstra Cc: Will Deacon Link: http://lkml.kernel.org/r/20161130092344.012e18e3e623bea395162f95@arm.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/arch/arm64/annotate/instructions.c | 62 +++++++++++++++++++ tools/perf/util/annotate.c | 5 ++ 2 files changed, 67 insertions(+) create mode 100644 tools/perf/arch/arm64/annotate/instructions.c diff --git a/tools/perf/arch/arm64/annotate/instructions.c b/tools/perf/arch/arm64/annotate/instructions.c new file mode 100644 index 000000000000..44eafd6f2d50 --- /dev/null +++ b/tools/perf/arch/arm64/annotate/instructions.c @@ -0,0 +1,62 @@ +#include +#include + +struct arm64_annotate { + regex_t call_insn, + jump_insn; +}; + +static struct ins_ops *arm64__associate_instruction_ops(struct arch *arch, const char *name) +{ + struct arm64_annotate *arm = arch->priv; + struct ins_ops *ops; + regmatch_t match[2]; + + if (!regexec(&arm->jump_insn, name, 2, match, 0)) + ops = &jump_ops; + else if (!regexec(&arm->call_insn, name, 2, match, 0)) + ops = &call_ops; + else if (!strcmp(name, "ret")) + ops = &ret_ops; + else + return NULL; + + arch__associate_ins_ops(arch, name, ops); + return ops; +} + +static int arm64__annotate_init(struct arch *arch) +{ + struct arm64_annotate *arm; + int err; + + if (arch->initialized) + return 0; + + arm = zalloc(sizeof(*arm)); + if (!arm) + return -1; + + /* bl, blr */ + err = regcomp(&arm->call_insn, "^blr?$", REG_EXTENDED); + if (err) + goto out_free_arm; + /* b, b.cond, br, cbz/cbnz, tbz/tbnz */ + err = regcomp(&arm->jump_insn, "^[ct]?br?\\.?(cc|cs|eq|ge|gt|hi|le|ls|lt|mi|ne|pl)?n?z?$", + REG_EXTENDED); + if (err) + goto out_free_call; + + arch->initialized = true; + arch->priv = arm; + arch->associate_instruction_ops = arm64__associate_instruction_ops; + arch->objdump.comment_char = ';'; + arch->objdump.skip_functions_char = '+'; + return 0; + +out_free_call: + regfree(&arm->call_insn); +out_free_arm: + free(arm); + return -1; +} diff --git a/tools/perf/util/annotate.c b/tools/perf/util/annotate.c index 191599eca807..4012b1de2813 100644 --- a/tools/perf/util/annotate.c +++ b/tools/perf/util/annotate.c @@ -105,6 +105,7 @@ static int arch__associate_ins_ops(struct arch* arch, const char *name, struct i } #include "arch/arm/annotate/instructions.c" +#include "arch/arm64/annotate/instructions.c" #include "arch/x86/annotate/instructions.c" #include "arch/powerpc/annotate/instructions.c" @@ -113,6 +114,10 @@ static struct arch architectures[] = { .name = "arm", .init = arm__annotate_init, }, + { + .name = "arm64", + .init = arm64__annotate_init, + }, { .name = "x86", .instructions = x86__instructions,