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