1 // SPDX-License-Identifier: GPL-2.0 2 #include <errno.h> 3 #include <inttypes.h> 4 #include "builtin.h" 5 #include "perf.h" 6 7 #include "util/evlist.h" // for struct evsel_str_handler 8 #include "util/evsel.h" 9 #include "util/symbol.h" 10 #include "util/thread.h" 11 #include "util/header.h" 12 13 #include <subcmd/pager.h> 14 #include <subcmd/parse-options.h> 15 #include "util/trace-event.h" 16 17 #include "util/debug.h" 18 #include "util/session.h" 19 #include "util/tool.h" 20 #include "util/data.h" 21 22 #include <sys/types.h> 23 #include <sys/prctl.h> 24 #include <semaphore.h> 25 #include <pthread.h> 26 #include <math.h> 27 #include <limits.h> 28 29 #include <linux/list.h> 30 #include <linux/hash.h> 31 #include <linux/kernel.h> 32 #include <linux/zalloc.h> 33 #include <linux/err.h> 34 35 static struct perf_session *session; 36 37 /* based on kernel/lockdep.c */ 38 #define LOCKHASH_BITS 12 39 #define LOCKHASH_SIZE (1UL << LOCKHASH_BITS) 40 41 static struct hlist_head lockhash_table[LOCKHASH_SIZE]; 42 43 #define __lockhashfn(key) hash_long((unsigned long)key, LOCKHASH_BITS) 44 #define lockhashentry(key) (lockhash_table + __lockhashfn((key))) 45 46 struct lock_stat { 47 struct hlist_node hash_entry; 48 struct rb_node rb; /* used for sorting */ 49 50 u64 addr; /* address of lockdep_map, used as ID */ 51 char *name; /* for strcpy(), we cannot use const */ 52 53 unsigned int nr_acquire; 54 unsigned int nr_acquired; 55 unsigned int nr_contended; 56 unsigned int nr_release; 57 58 unsigned int nr_readlock; 59 unsigned int nr_trylock; 60 61 /* these times are in nano sec. */ 62 u64 avg_wait_time; 63 u64 wait_time_total; 64 u64 wait_time_min; 65 u64 wait_time_max; 66 67 int discard; /* flag of blacklist */ 68 int combined; 69 }; 70 71 /* 72 * States of lock_seq_stat 73 * 74 * UNINITIALIZED is required for detecting first event of acquire. 75 * As the nature of lock events, there is no guarantee 76 * that the first event for the locks are acquire, 77 * it can be acquired, contended or release. 78 */ 79 #define SEQ_STATE_UNINITIALIZED 0 /* initial state */ 80 #define SEQ_STATE_RELEASED 1 81 #define SEQ_STATE_ACQUIRING 2 82 #define SEQ_STATE_ACQUIRED 3 83 #define SEQ_STATE_READ_ACQUIRED 4 84 #define SEQ_STATE_CONTENDED 5 85 86 /* 87 * MAX_LOCK_DEPTH 88 * Imported from include/linux/sched.h. 89 * Should this be synchronized? 90 */ 91 #define MAX_LOCK_DEPTH 48 92 93 /* 94 * struct lock_seq_stat: 95 * Place to put on state of one lock sequence 96 * 1) acquire -> acquired -> release 97 * 2) acquire -> contended -> acquired -> release 98 * 3) acquire (with read or try) -> release 99 * 4) Are there other patterns? 100 */ 101 struct lock_seq_stat { 102 struct list_head list; 103 int state; 104 u64 prev_event_time; 105 u64 addr; 106 107 int read_count; 108 }; 109 110 struct thread_stat { 111 struct rb_node rb; 112 113 u32 tid; 114 struct list_head seq_list; 115 }; 116 117 static struct rb_root thread_stats; 118 119 static bool combine_locks; 120 121 static struct thread_stat *thread_stat_find(u32 tid) 122 { 123 struct rb_node *node; 124 struct thread_stat *st; 125 126 node = thread_stats.rb_node; 127 while (node) { 128 st = container_of(node, struct thread_stat, rb); 129 if (st->tid == tid) 130 return st; 131 else if (tid < st->tid) 132 node = node->rb_left; 133 else 134 node = node->rb_right; 135 } 136 137 return NULL; 138 } 139 140 static void thread_stat_insert(struct thread_stat *new) 141 { 142 struct rb_node **rb = &thread_stats.rb_node; 143 struct rb_node *parent = NULL; 144 struct thread_stat *p; 145 146 while (*rb) { 147 p = container_of(*rb, struct thread_stat, rb); 148 parent = *rb; 149 150 if (new->tid < p->tid) 151 rb = &(*rb)->rb_left; 152 else if (new->tid > p->tid) 153 rb = &(*rb)->rb_right; 154 else 155 BUG_ON("inserting invalid thread_stat\n"); 156 } 157 158 rb_link_node(&new->rb, parent, rb); 159 rb_insert_color(&new->rb, &thread_stats); 160 } 161 162 static struct thread_stat *thread_stat_findnew_after_first(u32 tid) 163 { 164 struct thread_stat *st; 165 166 st = thread_stat_find(tid); 167 if (st) 168 return st; 169 170 st = zalloc(sizeof(struct thread_stat)); 171 if (!st) { 172 pr_err("memory allocation failed\n"); 173 return NULL; 174 } 175 176 st->tid = tid; 177 INIT_LIST_HEAD(&st->seq_list); 178 179 thread_stat_insert(st); 180 181 return st; 182 } 183 184 static struct thread_stat *thread_stat_findnew_first(u32 tid); 185 static struct thread_stat *(*thread_stat_findnew)(u32 tid) = 186 thread_stat_findnew_first; 187 188 static struct thread_stat *thread_stat_findnew_first(u32 tid) 189 { 190 struct thread_stat *st; 191 192 st = zalloc(sizeof(struct thread_stat)); 193 if (!st) { 194 pr_err("memory allocation failed\n"); 195 return NULL; 196 } 197 st->tid = tid; 198 INIT_LIST_HEAD(&st->seq_list); 199 200 rb_link_node(&st->rb, NULL, &thread_stats.rb_node); 201 rb_insert_color(&st->rb, &thread_stats); 202 203 thread_stat_findnew = thread_stat_findnew_after_first; 204 return st; 205 } 206 207 /* build simple key function one is bigger than two */ 208 #define SINGLE_KEY(member) \ 209 static int lock_stat_key_ ## member(struct lock_stat *one, \ 210 struct lock_stat *two) \ 211 { \ 212 return one->member > two->member; \ 213 } 214 215 SINGLE_KEY(nr_acquired) 216 SINGLE_KEY(nr_contended) 217 SINGLE_KEY(avg_wait_time) 218 SINGLE_KEY(wait_time_total) 219 SINGLE_KEY(wait_time_max) 220 221 static int lock_stat_key_wait_time_min(struct lock_stat *one, 222 struct lock_stat *two) 223 { 224 u64 s1 = one->wait_time_min; 225 u64 s2 = two->wait_time_min; 226 if (s1 == ULLONG_MAX) 227 s1 = 0; 228 if (s2 == ULLONG_MAX) 229 s2 = 0; 230 return s1 > s2; 231 } 232 233 struct lock_key { 234 /* 235 * name: the value for specify by user 236 * this should be simpler than raw name of member 237 * e.g. nr_acquired -> acquired, wait_time_total -> wait_total 238 */ 239 const char *name; 240 int (*key)(struct lock_stat*, struct lock_stat*); 241 }; 242 243 static const char *sort_key = "acquired"; 244 245 static int (*compare)(struct lock_stat *, struct lock_stat *); 246 247 static struct rb_root sorted; /* place to store intermediate data */ 248 static struct rb_root result; /* place to store sorted data */ 249 250 #define DEF_KEY_LOCK(name, fn_suffix) \ 251 { #name, lock_stat_key_ ## fn_suffix } 252 struct lock_key keys[] = { 253 DEF_KEY_LOCK(acquired, nr_acquired), 254 DEF_KEY_LOCK(contended, nr_contended), 255 DEF_KEY_LOCK(avg_wait, avg_wait_time), 256 DEF_KEY_LOCK(wait_total, wait_time_total), 257 DEF_KEY_LOCK(wait_min, wait_time_min), 258 DEF_KEY_LOCK(wait_max, wait_time_max), 259 260 /* extra comparisons much complicated should be here */ 261 262 { NULL, NULL } 263 }; 264 265 static int select_key(void) 266 { 267 int i; 268 269 for (i = 0; keys[i].name; i++) { 270 if (!strcmp(keys[i].name, sort_key)) { 271 compare = keys[i].key; 272 return 0; 273 } 274 } 275 276 pr_err("Unknown compare key: %s\n", sort_key); 277 278 return -1; 279 } 280 281 static void combine_lock_stats(struct lock_stat *st) 282 { 283 struct rb_node **rb = &sorted.rb_node; 284 struct rb_node *parent = NULL; 285 struct lock_stat *p; 286 int ret; 287 288 while (*rb) { 289 p = container_of(*rb, struct lock_stat, rb); 290 parent = *rb; 291 292 if (st->name && p->name) 293 ret = strcmp(st->name, p->name); 294 else 295 ret = !!st->name - !!p->name; 296 297 if (ret == 0) { 298 if (st->discard) 299 goto out; 300 301 p->nr_acquired += st->nr_acquired; 302 p->nr_contended += st->nr_contended; 303 p->wait_time_total += st->wait_time_total; 304 305 if (p->nr_contended) 306 p->avg_wait_time = p->wait_time_total / p->nr_contended; 307 308 if (p->wait_time_min > st->wait_time_min) 309 p->wait_time_min = st->wait_time_min; 310 if (p->wait_time_max < st->wait_time_max) 311 p->wait_time_max = st->wait_time_max; 312 313 /* now it got a new !discard record */ 314 p->discard = 0; 315 316 out: 317 st->combined = 1; 318 return; 319 } 320 321 if (ret < 0) 322 rb = &(*rb)->rb_left; 323 else 324 rb = &(*rb)->rb_right; 325 } 326 327 rb_link_node(&st->rb, parent, rb); 328 rb_insert_color(&st->rb, &sorted); 329 330 if (st->discard) { 331 st->nr_acquired = 0; 332 st->nr_contended = 0; 333 st->wait_time_total = 0; 334 st->avg_wait_time = 0; 335 st->wait_time_min = ULLONG_MAX; 336 st->wait_time_max = 0; 337 } 338 } 339 340 static void insert_to_result(struct lock_stat *st, 341 int (*bigger)(struct lock_stat *, struct lock_stat *)) 342 { 343 struct rb_node **rb = &result.rb_node; 344 struct rb_node *parent = NULL; 345 struct lock_stat *p; 346 347 if (combine_locks && st->combined) 348 return; 349 350 while (*rb) { 351 p = container_of(*rb, struct lock_stat, rb); 352 parent = *rb; 353 354 if (bigger(st, p)) 355 rb = &(*rb)->rb_left; 356 else 357 rb = &(*rb)->rb_right; 358 } 359 360 rb_link_node(&st->rb, parent, rb); 361 rb_insert_color(&st->rb, &result); 362 } 363 364 /* returns left most element of result, and erase it */ 365 static struct lock_stat *pop_from_result(void) 366 { 367 struct rb_node *node = result.rb_node; 368 369 if (!node) 370 return NULL; 371 372 while (node->rb_left) 373 node = node->rb_left; 374 375 rb_erase(node, &result); 376 return container_of(node, struct lock_stat, rb); 377 } 378 379 static struct lock_stat *lock_stat_findnew(u64 addr, const char *name) 380 { 381 struct hlist_head *entry = lockhashentry(addr); 382 struct lock_stat *ret, *new; 383 384 hlist_for_each_entry(ret, entry, hash_entry) { 385 if (ret->addr == addr) 386 return ret; 387 } 388 389 new = zalloc(sizeof(struct lock_stat)); 390 if (!new) 391 goto alloc_failed; 392 393 new->addr = addr; 394 new->name = zalloc(sizeof(char) * strlen(name) + 1); 395 if (!new->name) { 396 free(new); 397 goto alloc_failed; 398 } 399 400 strcpy(new->name, name); 401 new->wait_time_min = ULLONG_MAX; 402 403 hlist_add_head(&new->hash_entry, entry); 404 return new; 405 406 alloc_failed: 407 pr_err("memory allocation failed\n"); 408 return NULL; 409 } 410 411 struct trace_lock_handler { 412 int (*acquire_event)(struct evsel *evsel, 413 struct perf_sample *sample); 414 415 int (*acquired_event)(struct evsel *evsel, 416 struct perf_sample *sample); 417 418 int (*contended_event)(struct evsel *evsel, 419 struct perf_sample *sample); 420 421 int (*release_event)(struct evsel *evsel, 422 struct perf_sample *sample); 423 }; 424 425 static struct lock_seq_stat *get_seq(struct thread_stat *ts, u64 addr) 426 { 427 struct lock_seq_stat *seq; 428 429 list_for_each_entry(seq, &ts->seq_list, list) { 430 if (seq->addr == addr) 431 return seq; 432 } 433 434 seq = zalloc(sizeof(struct lock_seq_stat)); 435 if (!seq) { 436 pr_err("memory allocation failed\n"); 437 return NULL; 438 } 439 seq->state = SEQ_STATE_UNINITIALIZED; 440 seq->addr = addr; 441 442 list_add(&seq->list, &ts->seq_list); 443 return seq; 444 } 445 446 enum broken_state { 447 BROKEN_ACQUIRE, 448 BROKEN_ACQUIRED, 449 BROKEN_CONTENDED, 450 BROKEN_RELEASE, 451 BROKEN_MAX, 452 }; 453 454 static int bad_hist[BROKEN_MAX]; 455 456 enum acquire_flags { 457 TRY_LOCK = 1, 458 READ_LOCK = 2, 459 }; 460 461 static int report_lock_acquire_event(struct evsel *evsel, 462 struct perf_sample *sample) 463 { 464 struct lock_stat *ls; 465 struct thread_stat *ts; 466 struct lock_seq_stat *seq; 467 const char *name = evsel__strval(evsel, sample, "name"); 468 u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); 469 int flag = evsel__intval(evsel, sample, "flags"); 470 471 ls = lock_stat_findnew(addr, name); 472 if (!ls) 473 return -ENOMEM; 474 if (ls->discard) 475 return 0; 476 477 ts = thread_stat_findnew(sample->tid); 478 if (!ts) 479 return -ENOMEM; 480 481 seq = get_seq(ts, addr); 482 if (!seq) 483 return -ENOMEM; 484 485 switch (seq->state) { 486 case SEQ_STATE_UNINITIALIZED: 487 case SEQ_STATE_RELEASED: 488 if (!flag) { 489 seq->state = SEQ_STATE_ACQUIRING; 490 } else { 491 if (flag & TRY_LOCK) 492 ls->nr_trylock++; 493 if (flag & READ_LOCK) 494 ls->nr_readlock++; 495 seq->state = SEQ_STATE_READ_ACQUIRED; 496 seq->read_count = 1; 497 ls->nr_acquired++; 498 } 499 break; 500 case SEQ_STATE_READ_ACQUIRED: 501 if (flag & READ_LOCK) { 502 seq->read_count++; 503 ls->nr_acquired++; 504 goto end; 505 } else { 506 goto broken; 507 } 508 break; 509 case SEQ_STATE_ACQUIRED: 510 case SEQ_STATE_ACQUIRING: 511 case SEQ_STATE_CONTENDED: 512 broken: 513 /* broken lock sequence, discard it */ 514 ls->discard = 1; 515 bad_hist[BROKEN_ACQUIRE]++; 516 list_del_init(&seq->list); 517 free(seq); 518 goto end; 519 default: 520 BUG_ON("Unknown state of lock sequence found!\n"); 521 break; 522 } 523 524 ls->nr_acquire++; 525 seq->prev_event_time = sample->time; 526 end: 527 return 0; 528 } 529 530 static int report_lock_acquired_event(struct evsel *evsel, 531 struct perf_sample *sample) 532 { 533 struct lock_stat *ls; 534 struct thread_stat *ts; 535 struct lock_seq_stat *seq; 536 u64 contended_term; 537 const char *name = evsel__strval(evsel, sample, "name"); 538 u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); 539 540 ls = lock_stat_findnew(addr, name); 541 if (!ls) 542 return -ENOMEM; 543 if (ls->discard) 544 return 0; 545 546 ts = thread_stat_findnew(sample->tid); 547 if (!ts) 548 return -ENOMEM; 549 550 seq = get_seq(ts, addr); 551 if (!seq) 552 return -ENOMEM; 553 554 switch (seq->state) { 555 case SEQ_STATE_UNINITIALIZED: 556 /* orphan event, do nothing */ 557 return 0; 558 case SEQ_STATE_ACQUIRING: 559 break; 560 case SEQ_STATE_CONTENDED: 561 contended_term = sample->time - seq->prev_event_time; 562 ls->wait_time_total += contended_term; 563 if (contended_term < ls->wait_time_min) 564 ls->wait_time_min = contended_term; 565 if (ls->wait_time_max < contended_term) 566 ls->wait_time_max = contended_term; 567 break; 568 case SEQ_STATE_RELEASED: 569 case SEQ_STATE_ACQUIRED: 570 case SEQ_STATE_READ_ACQUIRED: 571 /* broken lock sequence, discard it */ 572 ls->discard = 1; 573 bad_hist[BROKEN_ACQUIRED]++; 574 list_del_init(&seq->list); 575 free(seq); 576 goto end; 577 default: 578 BUG_ON("Unknown state of lock sequence found!\n"); 579 break; 580 } 581 582 seq->state = SEQ_STATE_ACQUIRED; 583 ls->nr_acquired++; 584 ls->avg_wait_time = ls->nr_contended ? ls->wait_time_total/ls->nr_contended : 0; 585 seq->prev_event_time = sample->time; 586 end: 587 return 0; 588 } 589 590 static int report_lock_contended_event(struct evsel *evsel, 591 struct perf_sample *sample) 592 { 593 struct lock_stat *ls; 594 struct thread_stat *ts; 595 struct lock_seq_stat *seq; 596 const char *name = evsel__strval(evsel, sample, "name"); 597 u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); 598 599 ls = lock_stat_findnew(addr, name); 600 if (!ls) 601 return -ENOMEM; 602 if (ls->discard) 603 return 0; 604 605 ts = thread_stat_findnew(sample->tid); 606 if (!ts) 607 return -ENOMEM; 608 609 seq = get_seq(ts, addr); 610 if (!seq) 611 return -ENOMEM; 612 613 switch (seq->state) { 614 case SEQ_STATE_UNINITIALIZED: 615 /* orphan event, do nothing */ 616 return 0; 617 case SEQ_STATE_ACQUIRING: 618 break; 619 case SEQ_STATE_RELEASED: 620 case SEQ_STATE_ACQUIRED: 621 case SEQ_STATE_READ_ACQUIRED: 622 case SEQ_STATE_CONTENDED: 623 /* broken lock sequence, discard it */ 624 ls->discard = 1; 625 bad_hist[BROKEN_CONTENDED]++; 626 list_del_init(&seq->list); 627 free(seq); 628 goto end; 629 default: 630 BUG_ON("Unknown state of lock sequence found!\n"); 631 break; 632 } 633 634 seq->state = SEQ_STATE_CONTENDED; 635 ls->nr_contended++; 636 ls->avg_wait_time = ls->wait_time_total/ls->nr_contended; 637 seq->prev_event_time = sample->time; 638 end: 639 return 0; 640 } 641 642 static int report_lock_release_event(struct evsel *evsel, 643 struct perf_sample *sample) 644 { 645 struct lock_stat *ls; 646 struct thread_stat *ts; 647 struct lock_seq_stat *seq; 648 const char *name = evsel__strval(evsel, sample, "name"); 649 u64 addr = evsel__intval(evsel, sample, "lockdep_addr"); 650 651 ls = lock_stat_findnew(addr, name); 652 if (!ls) 653 return -ENOMEM; 654 if (ls->discard) 655 return 0; 656 657 ts = thread_stat_findnew(sample->tid); 658 if (!ts) 659 return -ENOMEM; 660 661 seq = get_seq(ts, addr); 662 if (!seq) 663 return -ENOMEM; 664 665 switch (seq->state) { 666 case SEQ_STATE_UNINITIALIZED: 667 goto end; 668 case SEQ_STATE_ACQUIRED: 669 break; 670 case SEQ_STATE_READ_ACQUIRED: 671 seq->read_count--; 672 BUG_ON(seq->read_count < 0); 673 if (seq->read_count) { 674 ls->nr_release++; 675 goto end; 676 } 677 break; 678 case SEQ_STATE_ACQUIRING: 679 case SEQ_STATE_CONTENDED: 680 case SEQ_STATE_RELEASED: 681 /* broken lock sequence, discard it */ 682 ls->discard = 1; 683 bad_hist[BROKEN_RELEASE]++; 684 goto free_seq; 685 default: 686 BUG_ON("Unknown state of lock sequence found!\n"); 687 break; 688 } 689 690 ls->nr_release++; 691 free_seq: 692 list_del_init(&seq->list); 693 free(seq); 694 end: 695 return 0; 696 } 697 698 /* lock oriented handlers */ 699 /* TODO: handlers for CPU oriented, thread oriented */ 700 static struct trace_lock_handler report_lock_ops = { 701 .acquire_event = report_lock_acquire_event, 702 .acquired_event = report_lock_acquired_event, 703 .contended_event = report_lock_contended_event, 704 .release_event = report_lock_release_event, 705 }; 706 707 static struct trace_lock_handler *trace_handler; 708 709 static int evsel__process_lock_acquire(struct evsel *evsel, struct perf_sample *sample) 710 { 711 if (trace_handler->acquire_event) 712 return trace_handler->acquire_event(evsel, sample); 713 return 0; 714 } 715 716 static int evsel__process_lock_acquired(struct evsel *evsel, struct perf_sample *sample) 717 { 718 if (trace_handler->acquired_event) 719 return trace_handler->acquired_event(evsel, sample); 720 return 0; 721 } 722 723 static int evsel__process_lock_contended(struct evsel *evsel, struct perf_sample *sample) 724 { 725 if (trace_handler->contended_event) 726 return trace_handler->contended_event(evsel, sample); 727 return 0; 728 } 729 730 static int evsel__process_lock_release(struct evsel *evsel, struct perf_sample *sample) 731 { 732 if (trace_handler->release_event) 733 return trace_handler->release_event(evsel, sample); 734 return 0; 735 } 736 737 static void print_bad_events(int bad, int total) 738 { 739 /* Output for debug, this have to be removed */ 740 int i; 741 const char *name[4] = 742 { "acquire", "acquired", "contended", "release" }; 743 744 pr_info("\n=== output for debug===\n\n"); 745 pr_info("bad: %d, total: %d\n", bad, total); 746 pr_info("bad rate: %.2f %%\n", (double)bad / (double)total * 100); 747 pr_info("histogram of events caused bad sequence\n"); 748 for (i = 0; i < BROKEN_MAX; i++) 749 pr_info(" %10s: %d\n", name[i], bad_hist[i]); 750 } 751 752 /* TODO: various way to print, coloring, nano or milli sec */ 753 static void print_result(void) 754 { 755 struct lock_stat *st; 756 char cut_name[20]; 757 int bad, total; 758 759 pr_info("%20s ", "Name"); 760 pr_info("%10s ", "acquired"); 761 pr_info("%10s ", "contended"); 762 763 pr_info("%15s ", "avg wait (ns)"); 764 pr_info("%15s ", "total wait (ns)"); 765 pr_info("%15s ", "max wait (ns)"); 766 pr_info("%15s ", "min wait (ns)"); 767 768 pr_info("\n\n"); 769 770 bad = total = 0; 771 while ((st = pop_from_result())) { 772 total++; 773 if (st->discard) { 774 bad++; 775 continue; 776 } 777 bzero(cut_name, 20); 778 779 if (strlen(st->name) < 20) { 780 /* output raw name */ 781 pr_info("%20s ", st->name); 782 } else { 783 strncpy(cut_name, st->name, 16); 784 cut_name[16] = '.'; 785 cut_name[17] = '.'; 786 cut_name[18] = '.'; 787 cut_name[19] = '\0'; 788 /* cut off name for saving output style */ 789 pr_info("%20s ", cut_name); 790 } 791 792 pr_info("%10u ", st->nr_acquired); 793 pr_info("%10u ", st->nr_contended); 794 795 pr_info("%15" PRIu64 " ", st->avg_wait_time); 796 pr_info("%15" PRIu64 " ", st->wait_time_total); 797 pr_info("%15" PRIu64 " ", st->wait_time_max); 798 pr_info("%15" PRIu64 " ", st->wait_time_min == ULLONG_MAX ? 799 0 : st->wait_time_min); 800 pr_info("\n"); 801 } 802 803 print_bad_events(bad, total); 804 } 805 806 static bool info_threads, info_map; 807 808 static void dump_threads(void) 809 { 810 struct thread_stat *st; 811 struct rb_node *node; 812 struct thread *t; 813 814 pr_info("%10s: comm\n", "Thread ID"); 815 816 node = rb_first(&thread_stats); 817 while (node) { 818 st = container_of(node, struct thread_stat, rb); 819 t = perf_session__findnew(session, st->tid); 820 pr_info("%10d: %s\n", st->tid, thread__comm_str(t)); 821 node = rb_next(node); 822 thread__put(t); 823 } 824 } 825 826 static int compare_maps(struct lock_stat *a, struct lock_stat *b) 827 { 828 int ret; 829 830 if (a->name && b->name) 831 ret = strcmp(a->name, b->name); 832 else 833 ret = !!a->name - !!b->name; 834 835 if (!ret) 836 return a->addr < b->addr; 837 else 838 return ret < 0; 839 } 840 841 static void dump_map(void) 842 { 843 unsigned int i; 844 struct lock_stat *st; 845 846 pr_info("Address of instance: name of class\n"); 847 for (i = 0; i < LOCKHASH_SIZE; i++) { 848 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { 849 insert_to_result(st, compare_maps); 850 } 851 } 852 853 while ((st = pop_from_result())) 854 pr_info(" %#llx: %s\n", (unsigned long long)st->addr, st->name); 855 } 856 857 static int dump_info(void) 858 { 859 int rc = 0; 860 861 if (info_threads) 862 dump_threads(); 863 else if (info_map) 864 dump_map(); 865 else { 866 rc = -1; 867 pr_err("Unknown type of information\n"); 868 } 869 870 return rc; 871 } 872 873 typedef int (*tracepoint_handler)(struct evsel *evsel, 874 struct perf_sample *sample); 875 876 static int process_sample_event(struct perf_tool *tool __maybe_unused, 877 union perf_event *event, 878 struct perf_sample *sample, 879 struct evsel *evsel, 880 struct machine *machine) 881 { 882 int err = 0; 883 struct thread *thread = machine__findnew_thread(machine, sample->pid, 884 sample->tid); 885 886 if (thread == NULL) { 887 pr_debug("problem processing %d event, skipping it.\n", 888 event->header.type); 889 return -1; 890 } 891 892 if (evsel->handler != NULL) { 893 tracepoint_handler f = evsel->handler; 894 err = f(evsel, sample); 895 } 896 897 thread__put(thread); 898 899 return err; 900 } 901 902 static void combine_result(void) 903 { 904 unsigned int i; 905 struct lock_stat *st; 906 907 if (!combine_locks) 908 return; 909 910 for (i = 0; i < LOCKHASH_SIZE; i++) { 911 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { 912 combine_lock_stats(st); 913 } 914 } 915 } 916 917 static void sort_result(void) 918 { 919 unsigned int i; 920 struct lock_stat *st; 921 922 for (i = 0; i < LOCKHASH_SIZE; i++) { 923 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { 924 insert_to_result(st, compare); 925 } 926 } 927 } 928 929 static const struct evsel_str_handler lock_tracepoints[] = { 930 { "lock:lock_acquire", evsel__process_lock_acquire, }, /* CONFIG_LOCKDEP */ 931 { "lock:lock_acquired", evsel__process_lock_acquired, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */ 932 { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */ 933 { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKDEP */ 934 }; 935 936 static bool force; 937 938 static int __cmd_report(bool display_info) 939 { 940 int err = -EINVAL; 941 struct perf_tool eops = { 942 .sample = process_sample_event, 943 .comm = perf_event__process_comm, 944 .namespaces = perf_event__process_namespaces, 945 .ordered_events = true, 946 }; 947 struct perf_data data = { 948 .path = input_name, 949 .mode = PERF_DATA_MODE_READ, 950 .force = force, 951 }; 952 953 session = perf_session__new(&data, &eops); 954 if (IS_ERR(session)) { 955 pr_err("Initializing perf session failed\n"); 956 return PTR_ERR(session); 957 } 958 959 symbol__init(&session->header.env); 960 961 if (!perf_session__has_traces(session, "lock record")) 962 goto out_delete; 963 964 if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) { 965 pr_err("Initializing perf session tracepoint handlers failed\n"); 966 goto out_delete; 967 } 968 969 if (select_key()) 970 goto out_delete; 971 972 err = perf_session__process_events(session); 973 if (err) 974 goto out_delete; 975 976 setup_pager(); 977 if (display_info) /* used for info subcommand */ 978 err = dump_info(); 979 else { 980 combine_result(); 981 sort_result(); 982 print_result(); 983 } 984 985 out_delete: 986 perf_session__delete(session); 987 return err; 988 } 989 990 static int __cmd_record(int argc, const char **argv) 991 { 992 const char *record_args[] = { 993 "record", "-R", "-m", "1024", "-c", "1", 994 }; 995 unsigned int rec_argc, i, j, ret; 996 const char **rec_argv; 997 998 for (i = 0; i < ARRAY_SIZE(lock_tracepoints); i++) { 999 if (!is_valid_tracepoint(lock_tracepoints[i].name)) { 1000 pr_err("tracepoint %s is not enabled. " 1001 "Are CONFIG_LOCKDEP and CONFIG_LOCK_STAT enabled?\n", 1002 lock_tracepoints[i].name); 1003 return 1; 1004 } 1005 } 1006 1007 rec_argc = ARRAY_SIZE(record_args) + argc - 1; 1008 /* factor of 2 is for -e in front of each tracepoint */ 1009 rec_argc += 2 * ARRAY_SIZE(lock_tracepoints); 1010 1011 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 1012 if (!rec_argv) 1013 return -ENOMEM; 1014 1015 for (i = 0; i < ARRAY_SIZE(record_args); i++) 1016 rec_argv[i] = strdup(record_args[i]); 1017 1018 for (j = 0; j < ARRAY_SIZE(lock_tracepoints); j++) { 1019 rec_argv[i++] = "-e"; 1020 rec_argv[i++] = strdup(lock_tracepoints[j].name); 1021 } 1022 1023 for (j = 1; j < (unsigned int)argc; j++, i++) 1024 rec_argv[i] = argv[j]; 1025 1026 BUG_ON(i != rec_argc); 1027 1028 ret = cmd_record(i, rec_argv); 1029 free(rec_argv); 1030 return ret; 1031 } 1032 1033 int cmd_lock(int argc, const char **argv) 1034 { 1035 const struct option lock_options[] = { 1036 OPT_STRING('i', "input", &input_name, "file", "input file name"), 1037 OPT_INCR('v', "verbose", &verbose, "be more verbose (show symbol address, etc)"), 1038 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, "dump raw trace in ASCII"), 1039 OPT_BOOLEAN('f', "force", &force, "don't complain, do it"), 1040 OPT_END() 1041 }; 1042 1043 const struct option info_options[] = { 1044 OPT_BOOLEAN('t', "threads", &info_threads, 1045 "dump thread list in perf.data"), 1046 OPT_BOOLEAN('m', "map", &info_map, 1047 "map of lock instances (address:name table)"), 1048 OPT_PARENT(lock_options) 1049 }; 1050 1051 const struct option report_options[] = { 1052 OPT_STRING('k', "key", &sort_key, "acquired", 1053 "key for sorting (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"), 1054 /* TODO: type */ 1055 OPT_BOOLEAN('c', "combine-locks", &combine_locks, 1056 "combine locks in the same class"), 1057 OPT_PARENT(lock_options) 1058 }; 1059 1060 const char * const info_usage[] = { 1061 "perf lock info [<options>]", 1062 NULL 1063 }; 1064 const char *const lock_subcommands[] = { "record", "report", "script", 1065 "info", NULL }; 1066 const char *lock_usage[] = { 1067 NULL, 1068 NULL 1069 }; 1070 const char * const report_usage[] = { 1071 "perf lock report [<options>]", 1072 NULL 1073 }; 1074 unsigned int i; 1075 int rc = 0; 1076 1077 for (i = 0; i < LOCKHASH_SIZE; i++) 1078 INIT_HLIST_HEAD(lockhash_table + i); 1079 1080 argc = parse_options_subcommand(argc, argv, lock_options, lock_subcommands, 1081 lock_usage, PARSE_OPT_STOP_AT_NON_OPTION); 1082 if (!argc) 1083 usage_with_options(lock_usage, lock_options); 1084 1085 if (!strncmp(argv[0], "rec", 3)) { 1086 return __cmd_record(argc, argv); 1087 } else if (!strncmp(argv[0], "report", 6)) { 1088 trace_handler = &report_lock_ops; 1089 if (argc) { 1090 argc = parse_options(argc, argv, 1091 report_options, report_usage, 0); 1092 if (argc) 1093 usage_with_options(report_usage, report_options); 1094 } 1095 rc = __cmd_report(false); 1096 } else if (!strcmp(argv[0], "script")) { 1097 /* Aliased to 'perf script' */ 1098 return cmd_script(argc, argv); 1099 } else if (!strcmp(argv[0], "info")) { 1100 if (argc) { 1101 argc = parse_options(argc, argv, 1102 info_options, info_usage, 0); 1103 if (argc) 1104 usage_with_options(info_usage, info_options); 1105 } 1106 /* recycling report_lock_ops */ 1107 trace_handler = &report_lock_ops; 1108 rc = __cmd_report(true); 1109 } else { 1110 usage_with_options(lock_usage, lock_options); 1111 } 1112 1113 return rc; 1114 } 1115