tools/perf/builtin-lock.c

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