tools/perf/builtin-lock.c

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