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