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                     discard; /* 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                         if (st->discard)
 388                                 goto out;
 389
 390                         p->nr_acquired += st->nr_acquired;
 391                         p->nr_contended += st->nr_contended;
 392                         p->wait_time_total += st->wait_time_total;
 393
 394                         if (p->nr_contended)
 395                                 p->avg_wait_time = p->wait_time_total / p->nr_contended;
 396
 397                         if (p->wait_time_min > st->wait_time_min)
 398                                 p->wait_time_min = st->wait_time_min;
 399                         if (p->wait_time_max < st->wait_time_max)
 400                                 p->wait_time_max = st->wait_time_max;
 401
 402                         /* now it got a new !discard record */
 403                         p->discard = 0;
 404
 405 out:
 406                         st->combined = 1;
 407                         return;
 408                 }
 409
 410                 if (ret < 0)
 411                         rb = &(*rb)->rb_left;
 412                 else
 413                         rb = &(*rb)->rb_right;
 414         }
 415
 416         rb_link_node(&st->rb, parent, rb);
 417         rb_insert_color(&st->rb, &sorted);
 418
 419         if (st->discard) {
 420                 st->nr_acquired = 0;
 421                 st->nr_contended = 0;
 422                 st->wait_time_total = 0;
 423                 st->avg_wait_time = 0;
 424                 st->wait_time_min = ULLONG_MAX;
 425                 st->wait_time_max = 0;
 426         }
 427 }
 428
 429 static void insert_to_result(struct lock_stat *st,
 430                              int (*bigger)(struct lock_stat *, struct lock_stat *))
 431 {
 432         struct rb_node **rb = &result.rb_node;
 433         struct rb_node *parent = NULL;
 434         struct lock_stat *p;
 435
 436         if (combine_locks && st->combined)
 437                 return;
 438
 439         while (*rb) {
 440                 p = container_of(*rb, struct lock_stat, rb);
 441                 parent = *rb;
 442
 443                 if (bigger(st, p))
 444                         rb = &(*rb)->rb_left;
 445                 else
 446                         rb = &(*rb)->rb_right;
 447         }
 448
 449         rb_link_node(&st->rb, parent, rb);
 450         rb_insert_color(&st->rb, &result);
 451 }
 452
 453 /* returns left most element of result, and erase it */
 454 static struct lock_stat *pop_from_result(void)
 455 {
 456         struct rb_node *node = result.rb_node;
 457
 458         if (!node)
 459                 return NULL;
 460
 461         while (node->rb_left)
 462                 node = node->rb_left;
 463
 464         rb_erase(node, &result);
 465         return container_of(node, struct lock_stat, rb);
 466 }
 467
 468 static struct lock_stat *lock_stat_findnew(u64 addr, const char *name)
 469 {
 470         struct hlist_head *entry = lockhashentry(addr);
 471         struct lock_stat *ret, *new;
 472
 473         hlist_for_each_entry(ret, entry, hash_entry) {
 474                 if (ret->addr == addr)
 475                         return ret;
 476         }
 477
 478         new = zalloc(sizeof(struct lock_stat));
 479         if (!new)
 480                 goto alloc_failed;
 481
 482         new->addr = addr;
 483         new->name = zalloc(sizeof(char) * strlen(name) + 1);
 484         if (!new->name) {
 485                 free(new);
 486                 goto alloc_failed;
 487         }
 488
 489         strcpy(new->name, name);
 490         new->wait_time_min = ULLONG_MAX;
 491
 492         hlist_add_head(&new->hash_entry, entry);
 493         return new;
 494
 495 alloc_failed:
 496         pr_err("memory allocation failed\n");
 497         return NULL;
 498 }
 499
 500 struct trace_lock_handler {
 501         int (*acquire_event)(struct evsel *evsel,
 502                              struct perf_sample *sample);
 503
 504         int (*acquired_event)(struct evsel *evsel,
 505                               struct perf_sample *sample);
 506
 507         int (*contended_event)(struct evsel *evsel,
 508                                struct perf_sample *sample);
 509
 510         int (*release_event)(struct evsel *evsel,
 511                              struct perf_sample *sample);
 512 };
 513
 514 static struct lock_seq_stat *get_seq(struct thread_stat *ts, u64 addr)
 515 {
 516         struct lock_seq_stat *seq;
 517
 518         list_for_each_entry(seq, &ts->seq_list, list) {
 519                 if (seq->addr == addr)
 520                         return seq;
 521         }
 522
 523         seq = zalloc(sizeof(struct lock_seq_stat));
 524         if (!seq) {
 525                 pr_err("memory allocation failed\n");
 526                 return NULL;
 527         }
 528         seq->state = SEQ_STATE_UNINITIALIZED;
 529         seq->addr = addr;
 530
 531         list_add(&seq->list, &ts->seq_list);
 532         return seq;
 533 }
 534
 535 enum broken_state {
 536         BROKEN_ACQUIRE,
 537         BROKEN_ACQUIRED,
 538         BROKEN_CONTENDED,
 539         BROKEN_RELEASE,
 540         BROKEN_MAX,
 541 };
 542
 543 static int bad_hist[BROKEN_MAX];
 544
 545 enum acquire_flags {
 546         TRY_LOCK = 1,
 547         READ_LOCK = 2,
 548 };
 549
 550 static int report_lock_acquire_event(struct evsel *evsel,
 551                                      struct perf_sample *sample)
 552 {
 553         struct lock_stat *ls;
 554         struct thread_stat *ts;
 555         struct lock_seq_stat *seq;
 556         const char *name = evsel__strval(evsel, sample, "name");
 557         u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
 558         int flag = evsel__intval(evsel, sample, "flags");
 559
 560         ls = lock_stat_findnew(addr, name);
 561         if (!ls)
 562                 return -ENOMEM;
 563         if (ls->discard)
 564                 return 0;
 565
 566         ts = thread_stat_findnew(sample->tid);
 567         if (!ts)
 568                 return -ENOMEM;
 569
 570         seq = get_seq(ts, addr);
 571         if (!seq)
 572                 return -ENOMEM;
 573
 574         switch (seq->state) {
 575         case SEQ_STATE_UNINITIALIZED:
 576         case SEQ_STATE_RELEASED:
 577                 if (!flag) {
 578                         seq->state = SEQ_STATE_ACQUIRING;
 579                 } else {
 580                         if (flag & TRY_LOCK)
 581                                 ls->nr_trylock++;
 582                         if (flag & READ_LOCK)
 583                                 ls->nr_readlock++;
 584                         seq->state = SEQ_STATE_READ_ACQUIRED;
 585                         seq->read_count = 1;
 586                         ls->nr_acquired++;
 587                 }
 588                 break;
 589         case SEQ_STATE_READ_ACQUIRED:
 590                 if (flag & READ_LOCK) {
 591                         seq->read_count++;
 592                         ls->nr_acquired++;
 593                         goto end;
 594                 } else {
 595                         goto broken;
 596                 }
 597                 break;
 598         case SEQ_STATE_ACQUIRED:
 599         case SEQ_STATE_ACQUIRING:
 600         case SEQ_STATE_CONTENDED:
 601 broken:
 602                 /* broken lock sequence, discard it */
 603                 ls->discard = 1;
 604                 bad_hist[BROKEN_ACQUIRE]++;
 605                 list_del_init(&seq->list);
 606                 free(seq);
 607                 goto end;
 608         default:
 609                 BUG_ON("Unknown state of lock sequence found!\n");
 610                 break;
 611         }
 612
 613         ls->nr_acquire++;
 614         seq->prev_event_time = sample->time;
 615 end:
 616         return 0;
 617 }
 618
 619 static int report_lock_acquired_event(struct evsel *evsel,
 620                                       struct perf_sample *sample)
 621 {
 622         struct lock_stat *ls;
 623         struct thread_stat *ts;
 624         struct lock_seq_stat *seq;
 625         u64 contended_term;
 626         const char *name = evsel__strval(evsel, sample, "name");
 627         u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
 628
 629         ls = lock_stat_findnew(addr, name);
 630         if (!ls)
 631                 return -ENOMEM;
 632         if (ls->discard)
 633                 return 0;
 634
 635         ts = thread_stat_findnew(sample->tid);
 636         if (!ts)
 637                 return -ENOMEM;
 638
 639         seq = get_seq(ts, addr);
 640         if (!seq)
 641                 return -ENOMEM;
 642
 643         switch (seq->state) {
 644         case SEQ_STATE_UNINITIALIZED:
 645                 /* orphan event, do nothing */
 646                 return 0;
 647         case SEQ_STATE_ACQUIRING:
 648                 break;
 649         case SEQ_STATE_CONTENDED:
 650                 contended_term = sample->time - seq->prev_event_time;
 651                 ls->wait_time_total += contended_term;
 652                 if (contended_term < ls->wait_time_min)
 653                         ls->wait_time_min = contended_term;
 654                 if (ls->wait_time_max < contended_term)
 655                         ls->wait_time_max = contended_term;
 656                 break;
 657         case SEQ_STATE_RELEASED:
 658         case SEQ_STATE_ACQUIRED:
 659         case SEQ_STATE_READ_ACQUIRED:
 660                 /* broken lock sequence, discard it */
 661                 ls->discard = 1;
 662                 bad_hist[BROKEN_ACQUIRED]++;
 663                 list_del_init(&seq->list);
 664                 free(seq);
 665                 goto end;
 666         default:
 667                 BUG_ON("Unknown state of lock sequence found!\n");
 668                 break;
 669         }
 670
 671         seq->state = SEQ_STATE_ACQUIRED;
 672         ls->nr_acquired++;
 673         ls->avg_wait_time = ls->nr_contended ? ls->wait_time_total/ls->nr_contended : 0;
 674         seq->prev_event_time = sample->time;
 675 end:
 676         return 0;
 677 }
 678
 679 static int report_lock_contended_event(struct evsel *evsel,
 680                                        struct perf_sample *sample)
 681 {
 682         struct lock_stat *ls;
 683         struct thread_stat *ts;
 684         struct lock_seq_stat *seq;
 685         const char *name = evsel__strval(evsel, sample, "name");
 686         u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
 687
 688         ls = lock_stat_findnew(addr, name);
 689         if (!ls)
 690                 return -ENOMEM;
 691         if (ls->discard)
 692                 return 0;
 693
 694         ts = thread_stat_findnew(sample->tid);
 695         if (!ts)
 696                 return -ENOMEM;
 697
 698         seq = get_seq(ts, addr);
 699         if (!seq)
 700                 return -ENOMEM;
 701
 702         switch (seq->state) {
 703         case SEQ_STATE_UNINITIALIZED:
 704                 /* orphan event, do nothing */
 705                 return 0;
 706         case SEQ_STATE_ACQUIRING:
 707                 break;
 708         case SEQ_STATE_RELEASED:
 709         case SEQ_STATE_ACQUIRED:
 710         case SEQ_STATE_READ_ACQUIRED:
 711         case SEQ_STATE_CONTENDED:
 712                 /* broken lock sequence, discard it */
 713                 ls->discard = 1;
 714                 bad_hist[BROKEN_CONTENDED]++;
 715                 list_del_init(&seq->list);
 716                 free(seq);
 717                 goto end;
 718         default:
 719                 BUG_ON("Unknown state of lock sequence found!\n");
 720                 break;
 721         }
 722
 723         seq->state = SEQ_STATE_CONTENDED;
 724         ls->nr_contended++;
 725         ls->avg_wait_time = ls->wait_time_total/ls->nr_contended;
 726         seq->prev_event_time = sample->time;
 727 end:
 728         return 0;
 729 }
 730
 731 static int report_lock_release_event(struct evsel *evsel,
 732                                      struct perf_sample *sample)
 733 {
 734         struct lock_stat *ls;
 735         struct thread_stat *ts;
 736         struct lock_seq_stat *seq;
 737         const char *name = evsel__strval(evsel, sample, "name");
 738         u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
 739
 740         ls = lock_stat_findnew(addr, name);
 741         if (!ls)
 742                 return -ENOMEM;
 743         if (ls->discard)
 744                 return 0;
 745
 746         ts = thread_stat_findnew(sample->tid);
 747         if (!ts)
 748                 return -ENOMEM;
 749
 750         seq = get_seq(ts, addr);
 751         if (!seq)
 752                 return -ENOMEM;
 753
 754         switch (seq->state) {
 755         case SEQ_STATE_UNINITIALIZED:
 756                 goto end;
 757         case SEQ_STATE_ACQUIRED:
 758                 break;
 759         case SEQ_STATE_READ_ACQUIRED:
 760                 seq->read_count--;
 761                 BUG_ON(seq->read_count < 0);
 762                 if (seq->read_count) {
 763                         ls->nr_release++;
 764                         goto end;
 765                 }
 766                 break;
 767         case SEQ_STATE_ACQUIRING:
 768         case SEQ_STATE_CONTENDED:
 769         case SEQ_STATE_RELEASED:
 770                 /* broken lock sequence, discard it */
 771                 ls->discard = 1;
 772                 bad_hist[BROKEN_RELEASE]++;
 773                 goto free_seq;
 774         default:
 775                 BUG_ON("Unknown state of lock sequence found!\n");
 776                 break;
 777         }
 778
 779         ls->nr_release++;
 780 free_seq:
 781         list_del_init(&seq->list);
 782         free(seq);
 783 end:
 784         return 0;
 785 }
 786
 787 /* lock oriented handlers */
 788 /* TODO: handlers for CPU oriented, thread oriented */
 789 static struct trace_lock_handler report_lock_ops  = {
 790         .acquire_event          = report_lock_acquire_event,
 791         .acquired_event         = report_lock_acquired_event,
 792         .contended_event        = report_lock_contended_event,
 793         .release_event          = report_lock_release_event,
 794 };
 795
 796 static struct trace_lock_handler *trace_handler;
 797
 798 static int evsel__process_lock_acquire(struct evsel *evsel, struct perf_sample *sample)
 799 {
 800         if (trace_handler->acquire_event)
 801                 return trace_handler->acquire_event(evsel, sample);
 802         return 0;
 803 }
 804
 805 static int evsel__process_lock_acquired(struct evsel *evsel, struct perf_sample *sample)
 806 {
 807         if (trace_handler->acquired_event)
 808                 return trace_handler->acquired_event(evsel, sample);
 809         return 0;
 810 }
 811
 812 static int evsel__process_lock_contended(struct evsel *evsel, struct perf_sample *sample)
 813 {
 814         if (trace_handler->contended_event)
 815                 return trace_handler->contended_event(evsel, sample);
 816         return 0;
 817 }
 818
 819 static int evsel__process_lock_release(struct evsel *evsel, struct perf_sample *sample)
 820 {
 821         if (trace_handler->release_event)
 822                 return trace_handler->release_event(evsel, sample);
 823         return 0;
 824 }
 825
 826 static void print_bad_events(int bad, int total)
 827 {
 828         /* Output for debug, this have to be removed */
 829         int i;
 830         const char *name[4] =
 831                 { "acquire", "acquired", "contended", "release" };
 832
 833         pr_info("\n=== output for debug===\n\n");
 834         pr_info("bad: %d, total: %d\n", bad, total);
 835         pr_info("bad rate: %.2f %%\n", (double)bad / (double)total * 100);
 836         pr_info("histogram of events caused bad sequence\n");
 837         for (i = 0; i < BROKEN_MAX; i++)
 838                 pr_info(" %10s: %d\n", name[i], bad_hist[i]);
 839 }
 840
 841 /* TODO: various way to print, coloring, nano or milli sec */
 842 static void print_result(void)
 843 {
 844         struct lock_stat *st;
 845         struct lock_key *key;
 846         char cut_name[20];
 847         int bad, total;
 848
 849         pr_info("%20s ", "Name");
 850         list_for_each_entry(key, &lock_keys, list)
 851                 pr_info("%*s ", key->len, key->header);
 852         pr_info("\n\n");
 853
 854         bad = total = 0;
 855         while ((st = pop_from_result())) {
 856                 total++;
 857                 if (st->discard) {
 858                         bad++;
 859                         continue;
 860                 }
 861                 bzero(cut_name, 20);
 862
 863                 if (strlen(st->name) < 20) {
 864                         /* output raw name */
 865                         pr_info("%20s ", st->name);
 866                 } else {
 867                         strncpy(cut_name, st->name, 16);
 868                         cut_name[16] = '.';
 869                         cut_name[17] = '.';
 870                         cut_name[18] = '.';
 871                         cut_name[19] = '\0';
 872                         /* cut off name for saving output style */
 873                         pr_info("%20s ", cut_name);
 874                 }
 875
 876                 list_for_each_entry(key, &lock_keys, list) {
 877                         key->print(key, st);
 878                         pr_info(" ");
 879                 }
 880                 pr_info("\n");
 881         }
 882
 883         print_bad_events(bad, total);
 884 }
 885
 886 static bool info_threads, info_map;
 887
 888 static void dump_threads(void)
 889 {
 890         struct thread_stat *st;
 891         struct rb_node *node;
 892         struct thread *t;
 893
 894         pr_info("%10s: comm\n", "Thread ID");
 895
 896         node = rb_first(&thread_stats);
 897         while (node) {
 898                 st = container_of(node, struct thread_stat, rb);
 899                 t = perf_session__findnew(session, st->tid);
 900                 pr_info("%10d: %s\n", st->tid, thread__comm_str(t));
 901                 node = rb_next(node);
 902                 thread__put(t);
 903         }
 904 }
 905
 906 static int compare_maps(struct lock_stat *a, struct lock_stat *b)
 907 {
 908         int ret;
 909
 910         if (a->name && b->name)
 911                 ret = strcmp(a->name, b->name);
 912         else
 913                 ret = !!a->name - !!b->name;
 914
 915         if (!ret)
 916                 return a->addr < b->addr;
 917         else
 918                 return ret < 0;
 919 }
 920
 921 static void dump_map(void)
 922 {
 923         unsigned int i;
 924         struct lock_stat *st;
 925
 926         pr_info("Address of instance: name of class\n");
 927         for (i = 0; i < LOCKHASH_SIZE; i++) {
 928                 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
 929                         insert_to_result(st, compare_maps);
 930                 }
 931         }
 932
 933         while ((st = pop_from_result()))
 934                 pr_info(" %#llx: %s\n", (unsigned long long)st->addr, st->name);
 935 }
 936
 937 static int dump_info(void)
 938 {
 939         int rc = 0;
 940
 941         if (info_threads)
 942                 dump_threads();
 943         else if (info_map)
 944                 dump_map();
 945         else {
 946                 rc = -1;
 947                 pr_err("Unknown type of information\n");
 948         }
 949
 950         return rc;
 951 }
 952
 953 typedef int (*tracepoint_handler)(struct evsel *evsel,
 954                                   struct perf_sample *sample);
 955
 956 static int process_sample_event(struct perf_tool *tool __maybe_unused,
 957                                 union perf_event *event,
 958                                 struct perf_sample *sample,
 959                                 struct evsel *evsel,
 960                                 struct machine *machine)
 961 {
 962         int err = 0;
 963         struct thread *thread = machine__findnew_thread(machine, sample->pid,
 964                                                         sample->tid);
 965
 966         if (thread == NULL) {
 967                 pr_debug("problem processing %d event, skipping it.\n",
 968                         event->header.type);
 969                 return -1;
 970         }
 971
 972         if (evsel->handler != NULL) {
 973                 tracepoint_handler f = evsel->handler;
 974                 err = f(evsel, sample);
 975         }
 976
 977         thread__put(thread);
 978
 979         return err;
 980 }
 981
 982 static void combine_result(void)
 983 {
 984         unsigned int i;
 985         struct lock_stat *st;
 986
 987         if (!combine_locks)
 988                 return;
 989
 990         for (i = 0; i < LOCKHASH_SIZE; i++) {
 991                 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
 992                         combine_lock_stats(st);
 993                 }
 994         }
 995 }
 996
 997 static void sort_result(void)
 998 {
 999         unsigned int i;
1000         struct lock_stat *st;
1001
1002         for (i = 0; i < LOCKHASH_SIZE; i++) {
1003                 hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
1004                         insert_to_result(st, compare);
1005                 }
1006         }
1007 }
1008
1009 static const struct evsel_str_handler lock_tracepoints[] = {
1010         { "lock:lock_acquire",   evsel__process_lock_acquire,   }, /* CONFIG_LOCKDEP */
1011         { "lock:lock_acquired",  evsel__process_lock_acquired,  }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
1012         { "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
1013         { "lock:lock_release",   evsel__process_lock_release,   }, /* CONFIG_LOCKDEP */
1014 };
1015
1016 static bool force;
1017
1018 static int __cmd_report(bool display_info)
1019 {
1020         int err = -EINVAL;
1021         struct perf_tool eops = {
1022                 .sample          = process_sample_event,
1023                 .comm            = perf_event__process_comm,
1024                 .namespaces      = perf_event__process_namespaces,
1025                 .ordered_events  = true,
1026         };
1027         struct perf_data data = {
1028                 .path  = input_name,
1029                 .mode  = PERF_DATA_MODE_READ,
1030                 .force = force,
1031         };
1032
1033         session = perf_session__new(&data, &eops);
1034         if (IS_ERR(session)) {
1035                 pr_err("Initializing perf session failed\n");
1036                 return PTR_ERR(session);
1037         }
1038
1039         symbol__init(&session->header.env);
1040
1041         if (!perf_session__has_traces(session, "lock record"))
1042                 goto out_delete;
1043
1044         if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
1045                 pr_err("Initializing perf session tracepoint handlers failed\n");
1046                 goto out_delete;
1047         }
1048
1049         if (setup_output_field(output_fields))
1050                 goto out_delete;
1051
1052         if (select_key())
1053                 goto out_delete;
1054
1055         err = perf_session__process_events(session);
1056         if (err)
1057                 goto out_delete;
1058
1059         setup_pager();
1060         if (display_info) /* used for info subcommand */
1061                 err = dump_info();
1062         else {
1063                 combine_result();
1064                 sort_result();
1065                 print_result();
1066         }
1067
1068 out_delete:
1069         perf_session__delete(session);
1070         return err;
1071 }
1072
1073 static int __cmd_record(int argc, const char **argv)
1074 {
1075         const char *record_args[] = {
1076                 "record", "-R", "-m", "1024", "-c", "1", "--synth", "no",
1077         };
1078         unsigned int rec_argc, i, j, ret;
1079         const char **rec_argv;
1080
1081         for (i = 0; i < ARRAY_SIZE(lock_tracepoints); i++) {
1082                 if (!is_valid_tracepoint(lock_tracepoints[i].name)) {
1083                                 pr_err("tracepoint %s is not enabled. "
1084                                        "Are CONFIG_LOCKDEP and CONFIG_LOCK_STAT enabled?\n",
1085                                        lock_tracepoints[i].name);
1086                                 return 1;
1087                 }
1088         }
1089
1090         rec_argc = ARRAY_SIZE(record_args) + argc - 1;
1091         /* factor of 2 is for -e in front of each tracepoint */
1092         rec_argc += 2 * ARRAY_SIZE(lock_tracepoints);
1093
1094         rec_argv = calloc(rec_argc + 1, sizeof(char *));
1095         if (!rec_argv)
1096                 return -ENOMEM;
1097
1098         for (i = 0; i < ARRAY_SIZE(record_args); i++)
1099                 rec_argv[i] = strdup(record_args[i]);
1100
1101         for (j = 0; j < ARRAY_SIZE(lock_tracepoints); j++) {
1102                 rec_argv[i++] = "-e";
1103                 rec_argv[i++] = strdup(lock_tracepoints[j].name);
1104         }
1105
1106         for (j = 1; j < (unsigned int)argc; j++, i++)
1107                 rec_argv[i] = argv[j];
1108
1109         BUG_ON(i != rec_argc);
1110
1111         ret = cmd_record(i, rec_argv);
1112         free(rec_argv);
1113         return ret;
1114 }
1115
1116 int cmd_lock(int argc, const char **argv)
1117 {
1118         const struct option lock_options[] = {
1119         OPT_STRING('i', "input", &input_name, "file", "input file name"),
1120         OPT_INCR('v', "verbose", &verbose, "be more verbose (show symbol address, etc)"),
1121         OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, "dump raw trace in ASCII"),
1122         OPT_BOOLEAN('f', "force", &force, "don't complain, do it"),
1123         OPT_END()
1124         };
1125
1126         const struct option info_options[] = {
1127         OPT_BOOLEAN('t', "threads", &info_threads,
1128                     "dump thread list in perf.data"),
1129         OPT_BOOLEAN('m', "map", &info_map,
1130                     "map of lock instances (address:name table)"),
1131         OPT_PARENT(lock_options)
1132         };
1133
1134         const struct option report_options[] = {
1135         OPT_STRING('k', "key", &sort_key, "acquired",
1136                     "key for sorting (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"),
1137         OPT_STRING('F', "field", &output_fields, NULL,
1138                     "output fields (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"),
1139         /* TODO: type */
1140         OPT_BOOLEAN('c', "combine-locks", &combine_locks,
1141                     "combine locks in the same class"),
1142         OPT_PARENT(lock_options)
1143         };
1144
1145         const char * const info_usage[] = {
1146                 "perf lock info [<options>]",
1147                 NULL
1148         };
1149         const char *const lock_subcommands[] = { "record", "report", "script",
1150                                                  "info", NULL };
1151         const char *lock_usage[] = {
1152                 NULL,
1153                 NULL
1154         };
1155         const char * const report_usage[] = {
1156                 "perf lock report [<options>]",
1157                 NULL
1158         };
1159         unsigned int i;
1160         int rc = 0;
1161
1162         for (i = 0; i < LOCKHASH_SIZE; i++)
1163                 INIT_HLIST_HEAD(lockhash_table + i);
1164
1165         argc = parse_options_subcommand(argc, argv, lock_options, lock_subcommands,
1166                                         lock_usage, PARSE_OPT_STOP_AT_NON_OPTION);
1167         if (!argc)
1168                 usage_with_options(lock_usage, lock_options);
1169
1170         if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) {
1171                 return __cmd_record(argc, argv);
1172         } else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) {
1173                 trace_handler = &report_lock_ops;
1174                 if (argc) {
1175                         argc = parse_options(argc, argv,
1176                                              report_options, report_usage, 0);
1177                         if (argc)
1178                                 usage_with_options(report_usage, report_options);
1179                 }
1180                 rc = __cmd_report(false);
1181         } else if (!strcmp(argv[0], "script")) {
1182                 /* Aliased to 'perf script' */
1183                 return cmd_script(argc, argv);
1184         } else if (!strcmp(argv[0], "info")) {
1185                 if (argc) {
1186                         argc = parse_options(argc, argv,
1187                                              info_options, info_usage, 0);
1188                         if (argc)
1189                                 usage_with_options(info_usage, info_options);
1190                 }
1191                 /* recycling report_lock_ops */
1192                 trace_handler = &report_lock_ops;
1193                 rc = __cmd_report(true);
1194         } else {
1195                 usage_with_options(lock_usage, lock_options);
1196         }
1197
1198         return rc;
1199 }