diff options
Diffstat (limited to 'tools/perf/builtin-lock.c')
-rw-r--r-- | tools/perf/builtin-lock.c | 350 |
1 files changed, 266 insertions, 84 deletions
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index d70131b7b1b1..b1200b7340a6 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -18,6 +18,7 @@ #include "util/session.h" #include "util/tool.h" #include "util/data.h" +#include "util/string2.h" #include <sys/types.h> #include <sys/prctl.h> @@ -38,21 +39,16 @@ static struct perf_session *session; #define LOCKHASH_BITS 12 #define LOCKHASH_SIZE (1UL << LOCKHASH_BITS) -static struct list_head lockhash_table[LOCKHASH_SIZE]; +static struct hlist_head lockhash_table[LOCKHASH_SIZE]; #define __lockhashfn(key) hash_long((unsigned long)key, LOCKHASH_BITS) #define lockhashentry(key) (lockhash_table + __lockhashfn((key))) struct lock_stat { - struct list_head hash_entry; + struct hlist_node hash_entry; struct rb_node rb; /* used for sorting */ - /* - * FIXME: evsel__intval() returns u64, - * so address of lockdep_map should be treated as 64bit. - * Is there more better solution? - */ - void *addr; /* address of lockdep_map, used as ID */ + u64 addr; /* address of lockdep_map, used as ID */ char *name; /* for strcpy(), we cannot use const */ unsigned int nr_acquire; @@ -69,7 +65,8 @@ struct lock_stat { u64 wait_time_min; u64 wait_time_max; - int discard; /* flag of blacklist */ + int broken; /* flag of blacklist */ + int combined; }; /* @@ -106,7 +103,7 @@ struct lock_seq_stat { struct list_head list; int state; u64 prev_event_time; - void *addr; + u64 addr; int read_count; }; @@ -120,6 +117,9 @@ struct thread_stat { static struct rb_root thread_stats; +static bool combine_locks; +static bool show_thread_stats; + static struct thread_stat *thread_stat_find(u32 tid) { struct rb_node *node; @@ -239,28 +239,65 @@ struct lock_key { * e.g. nr_acquired -> acquired, wait_time_total -> wait_total */ const char *name; + /* header: the string printed on the header line */ + const char *header; + /* len: the printing width of the field */ + int len; + /* key: a pointer to function to compare two lock stats for sorting */ int (*key)(struct lock_stat*, struct lock_stat*); + /* print: a pointer to function to print a given lock stats */ + void (*print)(struct lock_key*, struct lock_stat*); + /* list: list entry to link this */ + struct list_head list; }; +#define PRINT_KEY(member) \ +static void lock_stat_key_print_ ## member(struct lock_key *key, \ + struct lock_stat *ls) \ +{ \ + pr_info("%*llu", key->len, (unsigned long long)ls->member); \ +} + +PRINT_KEY(nr_acquired) +PRINT_KEY(nr_contended) +PRINT_KEY(avg_wait_time) +PRINT_KEY(wait_time_total) +PRINT_KEY(wait_time_max) + +static void lock_stat_key_print_wait_time_min(struct lock_key *key, + struct lock_stat *ls) +{ + u64 wait_time = ls->wait_time_min; + + if (wait_time == ULLONG_MAX) + wait_time = 0; + + pr_info("%*"PRIu64, key->len, wait_time); +} + + static const char *sort_key = "acquired"; static int (*compare)(struct lock_stat *, struct lock_stat *); +static struct rb_root sorted; /* place to store intermediate data */ static struct rb_root result; /* place to store sorted data */ -#define DEF_KEY_LOCK(name, fn_suffix) \ - { #name, lock_stat_key_ ## fn_suffix } +static LIST_HEAD(lock_keys); +static const char *output_fields; + +#define DEF_KEY_LOCK(name, header, fn_suffix, len) \ + { #name, header, len, lock_stat_key_ ## fn_suffix, lock_stat_key_print_ ## fn_suffix, {} } struct lock_key keys[] = { - DEF_KEY_LOCK(acquired, nr_acquired), - DEF_KEY_LOCK(contended, nr_contended), - DEF_KEY_LOCK(avg_wait, avg_wait_time), - DEF_KEY_LOCK(wait_total, wait_time_total), - DEF_KEY_LOCK(wait_min, wait_time_min), - DEF_KEY_LOCK(wait_max, wait_time_max), + DEF_KEY_LOCK(acquired, "acquired", nr_acquired, 10), + DEF_KEY_LOCK(contended, "contended", nr_contended, 10), + DEF_KEY_LOCK(avg_wait, "avg wait (ns)", avg_wait_time, 15), + DEF_KEY_LOCK(wait_total, "total wait (ns)", wait_time_total, 15), + DEF_KEY_LOCK(wait_max, "max wait (ns)", wait_time_max, 15), + DEF_KEY_LOCK(wait_min, "min wait (ns)", wait_time_min, 15), /* extra comparisons much complicated should be here */ - - { NULL, NULL } + { } }; static int select_key(void) @@ -270,15 +307,111 @@ static int select_key(void) for (i = 0; keys[i].name; i++) { if (!strcmp(keys[i].name, sort_key)) { compare = keys[i].key; + + /* selected key should be in the output fields */ + if (list_empty(&keys[i].list)) + list_add_tail(&keys[i].list, &lock_keys); + return 0; } } pr_err("Unknown compare key: %s\n", sort_key); + return -1; +} + +static int add_output_field(struct list_head *head, char *name) +{ + int i; + + for (i = 0; keys[i].name; i++) { + if (strcmp(keys[i].name, name)) + continue; + + /* prevent double link */ + if (list_empty(&keys[i].list)) + list_add_tail(&keys[i].list, head); + return 0; + } + + pr_err("Unknown output field: %s\n", name); return -1; } +static int setup_output_field(const char *str) +{ + char *tok, *tmp, *orig; + int i, ret = 0; + + /* no output field given: use all of them */ + if (str == NULL) { + for (i = 0; keys[i].name; i++) + list_add_tail(&keys[i].list, &lock_keys); + return 0; + } + + for (i = 0; keys[i].name; i++) + INIT_LIST_HEAD(&keys[i].list); + + orig = tmp = strdup(str); + if (orig == NULL) + return -ENOMEM; + + while ((tok = strsep(&tmp, ",")) != NULL){ + ret = add_output_field(&lock_keys, tok); + if (ret < 0) + break; + } + free(orig); + + return ret; +} + +static void combine_lock_stats(struct lock_stat *st) +{ + struct rb_node **rb = &sorted.rb_node; + struct rb_node *parent = NULL; + struct lock_stat *p; + int ret; + + while (*rb) { + p = container_of(*rb, struct lock_stat, rb); + parent = *rb; + + if (st->name && p->name) + ret = strcmp(st->name, p->name); + else + ret = !!st->name - !!p->name; + + if (ret == 0) { + p->nr_acquired += st->nr_acquired; + p->nr_contended += st->nr_contended; + p->wait_time_total += st->wait_time_total; + + if (p->nr_contended) + p->avg_wait_time = p->wait_time_total / p->nr_contended; + + if (p->wait_time_min > st->wait_time_min) + p->wait_time_min = st->wait_time_min; + if (p->wait_time_max < st->wait_time_max) + p->wait_time_max = st->wait_time_max; + + p->broken |= st->broken; + st->combined = 1; + return; + } + + if (ret < 0) + rb = &(*rb)->rb_left; + else + rb = &(*rb)->rb_right; + } + + rb_link_node(&st->rb, parent, rb); + rb_insert_color(&st->rb, &sorted); +} + static void insert_to_result(struct lock_stat *st, int (*bigger)(struct lock_stat *, struct lock_stat *)) { @@ -286,6 +419,9 @@ static void insert_to_result(struct lock_stat *st, struct rb_node *parent = NULL; struct lock_stat *p; + if (combine_locks && st->combined) + return; + while (*rb) { p = container_of(*rb, struct lock_stat, rb); parent = *rb; @@ -315,12 +451,12 @@ static struct lock_stat *pop_from_result(void) return container_of(node, struct lock_stat, rb); } -static struct lock_stat *lock_stat_findnew(void *addr, const char *name) +static struct lock_stat *lock_stat_findnew(u64 addr, const char *name) { - struct list_head *entry = lockhashentry(addr); + struct hlist_head *entry = lockhashentry(addr); struct lock_stat *ret, *new; - list_for_each_entry(ret, entry, hash_entry) { + hlist_for_each_entry(ret, entry, hash_entry) { if (ret->addr == addr) return ret; } @@ -339,7 +475,7 @@ static struct lock_stat *lock_stat_findnew(void *addr, const char *name) strcpy(new->name, name); new->wait_time_min = ULLONG_MAX; - list_add(&new->hash_entry, entry); + hlist_add_head(&new->hash_entry, entry); return new; alloc_failed: @@ -361,7 +497,7 @@ struct trace_lock_handler { struct perf_sample *sample); }; -static struct lock_seq_stat *get_seq(struct thread_stat *ts, void *addr) +static struct lock_seq_stat *get_seq(struct thread_stat *ts, u64 addr) { struct lock_seq_stat *seq; @@ -400,21 +536,20 @@ enum acquire_flags { static int report_lock_acquire_event(struct evsel *evsel, struct perf_sample *sample) { - void *addr; struct lock_stat *ls; struct thread_stat *ts; struct lock_seq_stat *seq; const char *name = evsel__strval(evsel, sample, "name"); - u64 tmp = evsel__intval(evsel, sample, "lockdep_addr"); + u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); int flag = evsel__intval(evsel, sample, "flags"); - memcpy(&addr, &tmp, sizeof(void *)); + /* abuse ls->addr for tid */ + if (show_thread_stats) + addr = sample->tid; ls = lock_stat_findnew(addr, name); if (!ls) return -ENOMEM; - if (ls->discard) - return 0; ts = thread_stat_findnew(sample->tid); if (!ts) @@ -452,9 +587,11 @@ static int report_lock_acquire_event(struct evsel *evsel, case SEQ_STATE_ACQUIRING: case SEQ_STATE_CONTENDED: broken: - /* broken lock sequence, discard it */ - ls->discard = 1; - bad_hist[BROKEN_ACQUIRE]++; + /* broken lock sequence */ + if (!ls->broken) { + ls->broken = 1; + bad_hist[BROKEN_ACQUIRE]++; + } list_del_init(&seq->list); free(seq); goto end; @@ -472,21 +609,19 @@ end: static int report_lock_acquired_event(struct evsel *evsel, struct perf_sample *sample) { - void *addr; struct lock_stat *ls; struct thread_stat *ts; struct lock_seq_stat *seq; u64 contended_term; const char *name = evsel__strval(evsel, sample, "name"); - u64 tmp = evsel__intval(evsel, sample, "lockdep_addr"); + u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); - memcpy(&addr, &tmp, sizeof(void *)); + if (show_thread_stats) + addr = sample->tid; ls = lock_stat_findnew(addr, name); if (!ls) return -ENOMEM; - if (ls->discard) - return 0; ts = thread_stat_findnew(sample->tid); if (!ts) @@ -513,9 +648,11 @@ static int report_lock_acquired_event(struct evsel *evsel, case SEQ_STATE_RELEASED: case SEQ_STATE_ACQUIRED: case SEQ_STATE_READ_ACQUIRED: - /* broken lock sequence, discard it */ - ls->discard = 1; - bad_hist[BROKEN_ACQUIRED]++; + /* broken lock sequence */ + if (!ls->broken) { + ls->broken = 1; + bad_hist[BROKEN_ACQUIRED]++; + } list_del_init(&seq->list); free(seq); goto end; @@ -535,20 +672,18 @@ end: static int report_lock_contended_event(struct evsel *evsel, struct perf_sample *sample) { - void *addr; struct lock_stat *ls; struct thread_stat *ts; struct lock_seq_stat *seq; const char *name = evsel__strval(evsel, sample, "name"); - u64 tmp = evsel__intval(evsel, sample, "lockdep_addr"); + u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); - memcpy(&addr, &tmp, sizeof(void *)); + if (show_thread_stats) + addr = sample->tid; ls = lock_stat_findnew(addr, name); if (!ls) return -ENOMEM; - if (ls->discard) - return 0; ts = thread_stat_findnew(sample->tid); if (!ts) @@ -568,9 +703,11 @@ static int report_lock_contended_event(struct evsel *evsel, case SEQ_STATE_ACQUIRED: case SEQ_STATE_READ_ACQUIRED: case SEQ_STATE_CONTENDED: - /* broken lock sequence, discard it */ - ls->discard = 1; - bad_hist[BROKEN_CONTENDED]++; + /* broken lock sequence */ + if (!ls->broken) { + ls->broken = 1; + bad_hist[BROKEN_CONTENDED]++; + } list_del_init(&seq->list); free(seq); goto end; @@ -590,20 +727,18 @@ end: static int report_lock_release_event(struct evsel *evsel, struct perf_sample *sample) { - void *addr; struct lock_stat *ls; struct thread_stat *ts; struct lock_seq_stat *seq; const char *name = evsel__strval(evsel, sample, "name"); - u64 tmp = evsel__intval(evsel, sample, "lockdep_addr"); + u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); - memcpy(&addr, &tmp, sizeof(void *)); + if (show_thread_stats) + addr = sample->tid; ls = lock_stat_findnew(addr, name); if (!ls) return -ENOMEM; - if (ls->discard) - return 0; ts = thread_stat_findnew(sample->tid); if (!ts) @@ -629,9 +764,11 @@ static int report_lock_release_event(struct evsel *evsel, case SEQ_STATE_ACQUIRING: case SEQ_STATE_CONTENDED: case SEQ_STATE_RELEASED: - /* broken lock sequence, discard it */ - ls->discard = 1; - bad_hist[BROKEN_RELEASE]++; + /* broken lock sequence */ + if (!ls->broken) { + ls->broken = 1; + bad_hist[BROKEN_RELEASE]++; + } goto free_seq; default: BUG_ON("Unknown state of lock sequence found!\n"); @@ -704,32 +841,38 @@ static void print_bad_events(int bad, int total) static void print_result(void) { struct lock_stat *st; + struct lock_key *key; char cut_name[20]; int bad, total; pr_info("%20s ", "Name"); - pr_info("%10s ", "acquired"); - pr_info("%10s ", "contended"); - - pr_info("%15s ", "avg wait (ns)"); - pr_info("%15s ", "total wait (ns)"); - pr_info("%15s ", "max wait (ns)"); - pr_info("%15s ", "min wait (ns)"); - + list_for_each_entry(key, &lock_keys, list) + pr_info("%*s ", key->len, key->header); pr_info("\n\n"); bad = total = 0; while ((st = pop_from_result())) { total++; - if (st->discard) { + if (st->broken) bad++; + if (!st->nr_acquired) continue; - } + bzero(cut_name, 20); - if (strlen(st->name) < 16) { + if (strlen(st->name) < 20) { /* output raw name */ - pr_info("%20s ", st->name); + const char *name = st->name; + + if (show_thread_stats) { + struct thread *t; + + /* st->addr contains tid of thread */ + t = perf_session__findnew(session, st->addr); + name = thread__comm_str(t); + } + + pr_info("%20s ", name); } else { strncpy(cut_name, st->name, 16); cut_name[16] = '.'; @@ -740,14 +883,10 @@ static void print_result(void) pr_info("%20s ", cut_name); } - pr_info("%10u ", st->nr_acquired); - pr_info("%10u ", st->nr_contended); - - pr_info("%15" PRIu64 " ", st->avg_wait_time); - pr_info("%15" PRIu64 " ", st->wait_time_total); - pr_info("%15" PRIu64 " ", st->wait_time_max); - pr_info("%15" PRIu64 " ", st->wait_time_min == ULLONG_MAX ? - 0 : st->wait_time_min); + list_for_each_entry(key, &lock_keys, list) { + key->print(key, st); + pr_info(" "); + } pr_info("\n"); } @@ -774,6 +913,21 @@ static void dump_threads(void) } } +static int compare_maps(struct lock_stat *a, struct lock_stat *b) +{ + int ret; + + if (a->name && b->name) + ret = strcmp(a->name, b->name); + else + ret = !!a->name - !!b->name; + + if (!ret) + return a->addr < b->addr; + else + return ret < 0; +} + static void dump_map(void) { unsigned int i; @@ -781,10 +935,13 @@ static void dump_map(void) pr_info("Address of instance: name of class\n"); for (i = 0; i < LOCKHASH_SIZE; i++) { - list_for_each_entry(st, &lockhash_table[i], hash_entry) { - pr_info(" %p: %s\n", st->addr, st->name); + hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { + insert_to_result(st, compare_maps); } } + + while ((st = pop_from_result())) + pr_info(" %#llx: %s\n", (unsigned long long)st->addr, st->name); } static int dump_info(void) @@ -832,13 +989,28 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused, return err; } +static void combine_result(void) +{ + unsigned int i; + struct lock_stat *st; + + if (!combine_locks) + return; + + for (i = 0; i < LOCKHASH_SIZE; i++) { + hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { + combine_lock_stats(st); + } + } +} + static void sort_result(void) { unsigned int i; struct lock_stat *st; for (i = 0; i < LOCKHASH_SIZE; i++) { - list_for_each_entry(st, &lockhash_table[i], hash_entry) { + hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { insert_to_result(st, compare); } } @@ -884,6 +1056,9 @@ static int __cmd_report(bool display_info) goto out_delete; } + if (setup_output_field(output_fields)) + goto out_delete; + if (select_key()) goto out_delete; @@ -895,6 +1070,7 @@ static int __cmd_report(bool display_info) if (display_info) /* used for info subcommand */ err = dump_info(); else { + combine_result(); sort_result(); print_result(); } @@ -907,7 +1083,7 @@ out_delete: static int __cmd_record(int argc, const char **argv) { const char *record_args[] = { - "record", "-R", "-m", "1024", "-c", "1", + "record", "-R", "-m", "1024", "-c", "1", "--synth", "no", }; unsigned int rec_argc, i, j, ret; const char **rec_argv; @@ -968,7 +1144,13 @@ int cmd_lock(int argc, const char **argv) const struct option report_options[] = { OPT_STRING('k', "key", &sort_key, "acquired", "key for sorting (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"), + OPT_STRING('F', "field", &output_fields, NULL, + "output fields (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"), /* TODO: type */ + OPT_BOOLEAN('c', "combine-locks", &combine_locks, + "combine locks in the same class"), + OPT_BOOLEAN('t', "threads", &show_thread_stats, + "show per-thread lock stats"), OPT_PARENT(lock_options) }; @@ -990,16 +1172,16 @@ int cmd_lock(int argc, const char **argv) int rc = 0; for (i = 0; i < LOCKHASH_SIZE; i++) - INIT_LIST_HEAD(lockhash_table + i); + INIT_HLIST_HEAD(lockhash_table + i); argc = parse_options_subcommand(argc, argv, lock_options, lock_subcommands, lock_usage, PARSE_OPT_STOP_AT_NON_OPTION); if (!argc) usage_with_options(lock_usage, lock_options); - if (!strncmp(argv[0], "rec", 3)) { + if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) { return __cmd_record(argc, argv); - } else if (!strncmp(argv[0], "report", 6)) { + } else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) { trace_handler = &report_lock_ops; if (argc) { argc = parse_options(argc, argv, |