builtin-lock.c 22.4 KB
Newer Older
1 2 3
#include "builtin.h"
#include "perf.h"

4
#include "util/evsel.h"
5 6 7 8 9 10 11 12 13 14 15
#include "util/util.h"
#include "util/cache.h"
#include "util/symbol.h"
#include "util/thread.h"
#include "util/header.h"

#include "util/parse-options.h"
#include "util/trace-event.h"

#include "util/debug.h"
#include "util/session.h"
16
#include "util/tool.h"
17 18 19 20 21 22 23 24 25 26 27

#include <sys/types.h>
#include <sys/prctl.h>
#include <semaphore.h>
#include <pthread.h>
#include <math.h>
#include <limits.h>

#include <linux/list.h>
#include <linux/hash.h>

28 29
static struct perf_session *session;

30 31 32 33 34 35 36 37 38 39
/* based on kernel/lockdep.c */
#define LOCKHASH_BITS		12
#define LOCKHASH_SIZE		(1UL << LOCKHASH_BITS)

static struct list_head lockhash_table[LOCKHASH_SIZE];

#define __lockhashfn(key)	hash_long((unsigned long)key, LOCKHASH_BITS)
#define lockhashentry(key)	(lockhash_table + __lockhashfn((key)))

struct lock_stat {
40 41
	struct list_head	hash_entry;
	struct rb_node		rb;		/* used for sorting */
42

43 44
	/*
	 * FIXME: raw_field_value() returns unsigned long long,
45
	 * so address of lockdep_map should be dealed as 64bit.
46 47 48 49
	 * Is there more better solution?
	 */
	void			*addr;		/* address of lockdep_map, used as ID */
	char			*name;		/* for strcpy(), we cannot use const */
50

51
	unsigned int		nr_acquire;
52
	unsigned int		nr_acquired;
53 54
	unsigned int		nr_contended;
	unsigned int		nr_release;
55

56 57
	unsigned int		nr_readlock;
	unsigned int		nr_trylock;
58
	/* these times are in nano sec. */
59 60 61
	u64			wait_time_total;
	u64			wait_time_min;
	u64			wait_time_max;
62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102

	int			discard; /* flag of blacklist */
};

/*
 * States of lock_seq_stat
 *
 * UNINITIALIZED is required for detecting first event of acquire.
 * As the nature of lock events, there is no guarantee
 * that the first event for the locks are acquire,
 * it can be acquired, contended or release.
 */
#define SEQ_STATE_UNINITIALIZED      0	       /* initial state */
#define SEQ_STATE_RELEASED	1
#define SEQ_STATE_ACQUIRING	2
#define SEQ_STATE_ACQUIRED	3
#define SEQ_STATE_READ_ACQUIRED	4
#define SEQ_STATE_CONTENDED	5

/*
 * MAX_LOCK_DEPTH
 * Imported from include/linux/sched.h.
 * Should this be synchronized?
 */
#define MAX_LOCK_DEPTH 48

/*
 * struct lock_seq_stat:
 * Place to put on state of one lock sequence
 * 1) acquire -> acquired -> release
 * 2) acquire -> contended -> acquired -> release
 * 3) acquire (with read or try) -> release
 * 4) Are there other patterns?
 */
struct lock_seq_stat {
	struct list_head        list;
	int			state;
	u64			prev_event_time;
	void                    *addr;

	int                     read_count;
103 104
};

105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195
struct thread_stat {
	struct rb_node		rb;

	u32                     tid;
	struct list_head        seq_list;
};

static struct rb_root		thread_stats;

static struct thread_stat *thread_stat_find(u32 tid)
{
	struct rb_node *node;
	struct thread_stat *st;

	node = thread_stats.rb_node;
	while (node) {
		st = container_of(node, struct thread_stat, rb);
		if (st->tid == tid)
			return st;
		else if (tid < st->tid)
			node = node->rb_left;
		else
			node = node->rb_right;
	}

	return NULL;
}

static void thread_stat_insert(struct thread_stat *new)
{
	struct rb_node **rb = &thread_stats.rb_node;
	struct rb_node *parent = NULL;
	struct thread_stat *p;

	while (*rb) {
		p = container_of(*rb, struct thread_stat, rb);
		parent = *rb;

		if (new->tid < p->tid)
			rb = &(*rb)->rb_left;
		else if (new->tid > p->tid)
			rb = &(*rb)->rb_right;
		else
			BUG_ON("inserting invalid thread_stat\n");
	}

	rb_link_node(&new->rb, parent, rb);
	rb_insert_color(&new->rb, &thread_stats);
}

static struct thread_stat *thread_stat_findnew_after_first(u32 tid)
{
	struct thread_stat *st;

	st = thread_stat_find(tid);
	if (st)
		return st;

	st = zalloc(sizeof(struct thread_stat));
	if (!st)
		die("memory allocation failed\n");

	st->tid = tid;
	INIT_LIST_HEAD(&st->seq_list);

	thread_stat_insert(st);

	return st;
}

static struct thread_stat *thread_stat_findnew_first(u32 tid);
static struct thread_stat *(*thread_stat_findnew)(u32 tid) =
	thread_stat_findnew_first;

static struct thread_stat *thread_stat_findnew_first(u32 tid)
{
	struct thread_stat *st;

	st = zalloc(sizeof(struct thread_stat));
	if (!st)
		die("memory allocation failed\n");
	st->tid = tid;
	INIT_LIST_HEAD(&st->seq_list);

	rb_link_node(&st->rb, NULL, &thread_stats.rb_node);
	rb_insert_color(&st->rb, &thread_stats);

	thread_stat_findnew = thread_stat_findnew_after_first;
	return st;
}

196
/* build simple key function one is bigger than two */
197
#define SINGLE_KEY(member)						\
198 199 200 201 202 203 204 205 206 207 208
	static int lock_stat_key_ ## member(struct lock_stat *one,	\
					 struct lock_stat *two)		\
	{								\
		return one->member > two->member;			\
	}

SINGLE_KEY(nr_acquired)
SINGLE_KEY(nr_contended)
SINGLE_KEY(wait_time_total)
SINGLE_KEY(wait_time_max)

209 210 211 212 213 214 215 216 217 218 219 220
static int lock_stat_key_wait_time_min(struct lock_stat *one,
					struct lock_stat *two)
{
	u64 s1 = one->wait_time_min;
	u64 s2 = two->wait_time_min;
	if (s1 == ULLONG_MAX)
		s1 = 0;
	if (s2 == ULLONG_MAX)
		s2 = 0;
	return s1 > s2;
}

221 222 223 224 225 226
struct lock_key {
	/*
	 * name: the value for specify by user
	 * this should be simpler than raw name of member
	 * e.g. nr_acquired -> acquired, wait_time_total -> wait_total
	 */
227 228
	const char		*name;
	int			(*key)(struct lock_stat*, struct lock_stat*);
229 230
};

231 232 233 234 235
static const char		*sort_key = "acquired";

static int			(*compare)(struct lock_stat *, struct lock_stat *);

static struct rb_root		result;	/* place to store sorted data */
236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265

#define DEF_KEY_LOCK(name, fn_suffix)	\
	{ #name, lock_stat_key_ ## fn_suffix }
struct lock_key keys[] = {
	DEF_KEY_LOCK(acquired, nr_acquired),
	DEF_KEY_LOCK(contended, nr_contended),
	DEF_KEY_LOCK(wait_total, wait_time_total),
	DEF_KEY_LOCK(wait_min, wait_time_min),
	DEF_KEY_LOCK(wait_max, wait_time_max),

	/* extra comparisons much complicated should be here */

	{ NULL, NULL }
};

static void select_key(void)
{
	int i;

	for (i = 0; keys[i].name; i++) {
		if (!strcmp(keys[i].name, sort_key)) {
			compare = keys[i].key;
			return;
		}
	}

	die("Unknown compare key:%s\n", sort_key);
}

static void insert_to_result(struct lock_stat *st,
266
			     int (*bigger)(struct lock_stat *, struct lock_stat *))
267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300
{
	struct rb_node **rb = &result.rb_node;
	struct rb_node *parent = NULL;
	struct lock_stat *p;

	while (*rb) {
		p = container_of(*rb, struct lock_stat, rb);
		parent = *rb;

		if (bigger(st, p))
			rb = &(*rb)->rb_left;
		else
			rb = &(*rb)->rb_right;
	}

	rb_link_node(&st->rb, parent, rb);
	rb_insert_color(&st->rb, &result);
}

/* returns left most element of result, and erase it */
static struct lock_stat *pop_from_result(void)
{
	struct rb_node *node = result.rb_node;

	if (!node)
		return NULL;

	while (node->rb_left)
		node = node->rb_left;

	rb_erase(node, &result);
	return container_of(node, struct lock_stat, rb);
}

301
static struct lock_stat *lock_stat_findnew(void *addr, const char *name)
302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329
{
	struct list_head *entry = lockhashentry(addr);
	struct lock_stat *ret, *new;

	list_for_each_entry(ret, entry, hash_entry) {
		if (ret->addr == addr)
			return ret;
	}

	new = zalloc(sizeof(struct lock_stat));
	if (!new)
		goto alloc_failed;

	new->addr = addr;
	new->name = zalloc(sizeof(char) * strlen(name) + 1);
	if (!new->name)
		goto alloc_failed;
	strcpy(new->name, name);

	new->wait_time_min = ULLONG_MAX;

	list_add(&new->hash_entry, entry);
	return new;

alloc_failed:
	die("memory allocation failed\n");
}

330
static const char *input_name;
331 332

struct raw_event_sample {
333 334
	u32			size;
	char			data[0];
335 336 337
};

struct trace_acquire_event {
338 339
	void			*addr;
	const char		*name;
340
	int			flag;
341 342 343
};

struct trace_acquired_event {
344 345
	void			*addr;
	const char		*name;
346 347 348
};

struct trace_contended_event {
349 350
	void			*addr;
	const char		*name;
351 352 353
};

struct trace_release_event {
354 355
	void			*addr;
	const char		*name;
356 357 358 359
};

struct trace_lock_handler {
	void (*acquire_event)(struct trace_acquire_event *,
360
			      const struct perf_sample *sample);
361 362

	void (*acquired_event)(struct trace_acquired_event *,
363
			       const struct perf_sample *sample);
364 365

	void (*contended_event)(struct trace_contended_event *,
366
				const struct perf_sample *sample);
367 368

	void (*release_event)(struct trace_release_event *,
369
			      const struct perf_sample *sample);
370 371
};

372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390
static struct lock_seq_stat *get_seq(struct thread_stat *ts, void *addr)
{
	struct lock_seq_stat *seq;

	list_for_each_entry(seq, &ts->seq_list, list) {
		if (seq->addr == addr)
			return seq;
	}

	seq = zalloc(sizeof(struct lock_seq_stat));
	if (!seq)
		die("Not enough memory\n");
	seq->state = SEQ_STATE_UNINITIALIZED;
	seq->addr = addr;

	list_add(&seq->list, &ts->seq_list);
	return seq;
}

391 392 393 394 395 396 397 398 399
enum broken_state {
	BROKEN_ACQUIRE,
	BROKEN_ACQUIRED,
	BROKEN_CONTENDED,
	BROKEN_RELEASE,
	BROKEN_MAX,
};

static int bad_hist[BROKEN_MAX];
400

401 402 403 404 405
enum acquire_flags {
	TRY_LOCK = 1,
	READ_LOCK = 2,
};

406 407
static void
report_lock_acquire_event(struct trace_acquire_event *acquire_event,
408
			  const struct perf_sample *sample)
409
{
410 411 412 413 414 415 416
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;

	ls = lock_stat_findnew(acquire_event->addr, acquire_event->name);
	if (ls->discard)
		return;
417

418
	ts = thread_stat_findnew(sample->tid);
419
	seq = get_seq(ts, acquire_event->addr);
420

421 422 423 424 425 426
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
	case SEQ_STATE_RELEASED:
		if (!acquire_event->flag) {
			seq->state = SEQ_STATE_ACQUIRING;
		} else {
427
			if (acquire_event->flag & TRY_LOCK)
428
				ls->nr_trylock++;
429
			if (acquire_event->flag & READ_LOCK)
430 431 432 433 434 435 436
				ls->nr_readlock++;
			seq->state = SEQ_STATE_READ_ACQUIRED;
			seq->read_count = 1;
			ls->nr_acquired++;
		}
		break;
	case SEQ_STATE_READ_ACQUIRED:
437
		if (acquire_event->flag & READ_LOCK) {
438 439 440 441 442 443
			seq->read_count++;
			ls->nr_acquired++;
			goto end;
		} else {
			goto broken;
		}
444
		break;
445 446 447 448 449 450
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_CONTENDED:
broken:
		/* broken lock sequence, discard it */
		ls->discard = 1;
451
		bad_hist[BROKEN_ACQUIRE]++;
452 453 454
		list_del(&seq->list);
		free(seq);
		goto end;
455 456
		break;
	default:
457
		BUG_ON("Unknown state of lock sequence found!\n");
458 459 460
		break;
	}

461
	ls->nr_acquire++;
462
	seq->prev_event_time = sample->time;
463 464
end:
	return;
465 466
}

467 468
static void
report_lock_acquired_event(struct trace_acquired_event *acquired_event,
469
			   const struct perf_sample *sample)
470
{
471
	u64 timestamp = sample->time;
472 473 474 475
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
	u64 contended_term;
476

477 478 479 480
	ls = lock_stat_findnew(acquired_event->addr, acquired_event->name);
	if (ls->discard)
		return;

481
	ts = thread_stat_findnew(sample->tid);
482
	seq = get_seq(ts, acquired_event->addr);
483

484 485 486 487 488
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		/* orphan event, do nothing */
		return;
	case SEQ_STATE_ACQUIRING:
489
		break;
490 491 492 493 494
	case SEQ_STATE_CONTENDED:
		contended_term = timestamp - seq->prev_event_time;
		ls->wait_time_total += contended_term;
		if (contended_term < ls->wait_time_min)
			ls->wait_time_min = contended_term;
495
		if (ls->wait_time_max < contended_term)
496
			ls->wait_time_max = contended_term;
497
		break;
498 499 500 501 502
	case SEQ_STATE_RELEASED:
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_READ_ACQUIRED:
		/* broken lock sequence, discard it */
		ls->discard = 1;
503
		bad_hist[BROKEN_ACQUIRED]++;
504 505 506 507 508
		list_del(&seq->list);
		free(seq);
		goto end;
		break;

509
	default:
510
		BUG_ON("Unknown state of lock sequence found!\n");
511 512 513
		break;
	}

514 515 516 517 518
	seq->state = SEQ_STATE_ACQUIRED;
	ls->nr_acquired++;
	seq->prev_event_time = timestamp;
end:
	return;
519 520
}

521 522
static void
report_lock_contended_event(struct trace_contended_event *contended_event,
523
			    const struct perf_sample *sample)
524
{
525 526 527 528 529 530 531
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;

	ls = lock_stat_findnew(contended_event->addr, contended_event->name);
	if (ls->discard)
		return;
532

533
	ts = thread_stat_findnew(sample->tid);
534
	seq = get_seq(ts, contended_event->addr);
535

536 537 538 539 540
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		/* orphan event, do nothing */
		return;
	case SEQ_STATE_ACQUIRING:
541
		break;
542 543 544 545 546 547
	case SEQ_STATE_RELEASED:
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_READ_ACQUIRED:
	case SEQ_STATE_CONTENDED:
		/* broken lock sequence, discard it */
		ls->discard = 1;
548
		bad_hist[BROKEN_CONTENDED]++;
549 550 551
		list_del(&seq->list);
		free(seq);
		goto end;
552 553
		break;
	default:
554
		BUG_ON("Unknown state of lock sequence found!\n");
555 556 557
		break;
	}

558 559
	seq->state = SEQ_STATE_CONTENDED;
	ls->nr_contended++;
560
	seq->prev_event_time = sample->time;
561 562
end:
	return;
563 564
}

565 566
static void
report_lock_release_event(struct trace_release_event *release_event,
567
			  const struct perf_sample *sample)
568
{
569 570 571
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
572

573 574 575
	ls = lock_stat_findnew(release_event->addr, release_event->name);
	if (ls->discard)
		return;
576

577
	ts = thread_stat_findnew(sample->tid);
578
	seq = get_seq(ts, release_event->addr);
579

580 581 582 583 584 585 586 587 588 589 590
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		goto end;
		break;
	case SEQ_STATE_ACQUIRED:
		break;
	case SEQ_STATE_READ_ACQUIRED:
		seq->read_count--;
		BUG_ON(seq->read_count < 0);
		if (!seq->read_count) {
			ls->nr_release++;
591 592
			goto end;
		}
593 594 595 596 597 598
		break;
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_CONTENDED:
	case SEQ_STATE_RELEASED:
		/* broken lock sequence, discard it */
		ls->discard = 1;
599
		bad_hist[BROKEN_RELEASE]++;
600
		goto free_seq;
601 602
		break;
	default:
603
		BUG_ON("Unknown state of lock sequence found!\n");
604 605 606
		break;
	}

607 608 609 610
	ls->nr_release++;
free_seq:
	list_del(&seq->list);
	free(seq);
611
end:
612
	return;
613 614 615 616
}

/* lock oriented handlers */
/* TODO: handlers for CPU oriented, thread oriented */
617 618 619 620 621
static struct trace_lock_handler report_lock_ops  = {
	.acquire_event		= report_lock_acquire_event,
	.acquired_event		= report_lock_acquired_event,
	.contended_event	= report_lock_contended_event,
	.release_event		= report_lock_release_event,
622 623 624 625
};

static struct trace_lock_handler *trace_handler;

626 627
static void perf_evsel__process_lock_acquire(struct perf_evsel *evsel,
					     struct perf_sample *sample)
628 629
{
	struct trace_acquire_event acquire_event;
630 631
	struct event_format *event = evsel->tp_format;
	void *data = sample->raw_data;
632 633 634 635 636
	u64 tmp;		/* this is required for casting... */

	tmp = raw_field_value(event, "lockdep_addr", data);
	memcpy(&acquire_event.addr, &tmp, sizeof(void *));
	acquire_event.name = (char *)raw_field_ptr(event, "name", data);
637
	acquire_event.flag = (int)raw_field_value(event, "flag", data);
638

639
	if (trace_handler->acquire_event)
640
		trace_handler->acquire_event(&acquire_event, sample);
641 642
}

643 644
static void perf_evsel__process_lock_acquired(struct perf_evsel *evsel,
					      struct perf_sample *sample)
645 646
{
	struct trace_acquired_event acquired_event;
647 648
	struct event_format *event = evsel->tp_format;
	void *data = sample->raw_data;
649 650 651 652 653 654
	u64 tmp;		/* this is required for casting... */

	tmp = raw_field_value(event, "lockdep_addr", data);
	memcpy(&acquired_event.addr, &tmp, sizeof(void *));
	acquired_event.name = (char *)raw_field_ptr(event, "name", data);

655
	if (trace_handler->acquire_event)
656
		trace_handler->acquired_event(&acquired_event, sample);
657 658
}

659 660
static void perf_evsel__process_lock_contended(struct perf_evsel *evsel,
					       struct perf_sample *sample)
661 662
{
	struct trace_contended_event contended_event;
663 664
	struct event_format *event = evsel->tp_format;
	void *data = sample->raw_data;
665 666 667 668 669 670
	u64 tmp;		/* this is required for casting... */

	tmp = raw_field_value(event, "lockdep_addr", data);
	memcpy(&contended_event.addr, &tmp, sizeof(void *));
	contended_event.name = (char *)raw_field_ptr(event, "name", data);

671
	if (trace_handler->acquire_event)
672
		trace_handler->contended_event(&contended_event, sample);
673 674
}

675 676
static void perf_evsel__process_lock_release(struct perf_evsel *evsel,
					     struct perf_sample *sample)
677 678
{
	struct trace_release_event release_event;
679 680
	struct event_format *event = evsel->tp_format;
	void *data = sample->raw_data;
681 682 683 684 685 686
	u64 tmp;		/* this is required for casting... */

	tmp = raw_field_value(event, "lockdep_addr", data);
	memcpy(&release_event.addr, &tmp, sizeof(void *));
	release_event.name = (char *)raw_field_ptr(event, "name", data);

687
	if (trace_handler->acquire_event)
688
		trace_handler->release_event(&release_event, sample);
689 690
}

691 692
static void perf_evsel__process_lock_event(struct perf_evsel *evsel,
					   struct perf_sample *sample)
693
{
694
	struct event_format *event = evsel->tp_format;
695 696

	if (!strcmp(event->name, "lock_acquire"))
697
		perf_evsel__process_lock_acquire(evsel, sample);
698
	if (!strcmp(event->name, "lock_acquired"))
699
		perf_evsel__process_lock_acquired(evsel, sample);
700
	if (!strcmp(event->name, "lock_contended"))
701
		perf_evsel__process_lock_contended(evsel, sample);
702
	if (!strcmp(event->name, "lock_release"))
703
		perf_evsel__process_lock_release(evsel, sample);
704 705
}

706 707 708 709 710 711 712 713
static void print_bad_events(int bad, int total)
{
	/* Output for debug, this have to be removed */
	int i;
	const char *name[4] =
		{ "acquire", "acquired", "contended", "release" };

	pr_info("\n=== output for debug===\n\n");
714 715
	pr_info("bad: %d, total: %d\n", bad, total);
	pr_info("bad rate: %f %%\n", (double)bad / (double)total * 100);
716 717 718 719 720
	pr_info("histogram of events caused bad sequence\n");
	for (i = 0; i < BROKEN_MAX; i++)
		pr_info(" %10s: %d\n", name[i], bad_hist[i]);
}

721 722 723 724 725
/* TODO: various way to print, coloring, nano or milli sec */
static void print_result(void)
{
	struct lock_stat *st;
	char cut_name[20];
726
	int bad, total;
727

728 729 730
	pr_info("%20s ", "Name");
	pr_info("%10s ", "acquired");
	pr_info("%10s ", "contended");
731

732 733 734
	pr_info("%15s ", "total wait (ns)");
	pr_info("%15s ", "max wait (ns)");
	pr_info("%15s ", "min wait (ns)");
735

736
	pr_info("\n\n");
737

738
	bad = total = 0;
739
	while ((st = pop_from_result())) {
740 741 742 743 744
		total++;
		if (st->discard) {
			bad++;
			continue;
		}
745 746 747 748
		bzero(cut_name, 20);

		if (strlen(st->name) < 16) {
			/* output raw name */
749
			pr_info("%20s ", st->name);
750 751 752 753 754 755 756
		} else {
			strncpy(cut_name, st->name, 16);
			cut_name[16] = '.';
			cut_name[17] = '.';
			cut_name[18] = '.';
			cut_name[19] = '\0';
			/* cut off name for saving output style */
757
			pr_info("%20s ", cut_name);
758 759
		}

760 761
		pr_info("%10u ", st->nr_acquired);
		pr_info("%10u ", st->nr_contended);
762

763 764 765
		pr_info("%15" PRIu64 " ", st->wait_time_total);
		pr_info("%15" PRIu64 " ", st->wait_time_max);
		pr_info("%15" PRIu64 " ", st->wait_time_min == ULLONG_MAX ?
766
		       0 : st->wait_time_min);
767
		pr_info("\n");
768
	}
769

770
	print_bad_events(bad, total);
771 772
}

773
static bool info_threads, info_map;
774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791

static void dump_threads(void)
{
	struct thread_stat *st;
	struct rb_node *node;
	struct thread *t;

	pr_info("%10s: comm\n", "Thread ID");

	node = rb_first(&thread_stats);
	while (node) {
		st = container_of(node, struct thread_stat, rb);
		t = perf_session__findnew(session, st->tid);
		pr_info("%10d: %s\n", st->tid, t->comm);
		node = rb_next(node);
	};
}

792 793 794 795 796
static void dump_map(void)
{
	unsigned int i;
	struct lock_stat *st;

797
	pr_info("Address of instance: name of class\n");
798 799
	for (i = 0; i < LOCKHASH_SIZE; i++) {
		list_for_each_entry(st, &lockhash_table[i], hash_entry) {
800
			pr_info(" %p: %s\n", st->addr, st->name);
801 802 803 804
		}
	}
}

805 806 807 808 809 810 811 812 813 814
static void dump_info(void)
{
	if (info_threads)
		dump_threads();
	else if (info_map)
		dump_map();
	else
		die("Unknown type of information\n");
}

815
static int process_sample_event(struct perf_tool *tool __used,
816
				union perf_event *event,
817
				struct perf_sample *sample,
818
				struct perf_evsel *evsel,
819
				struct machine *machine)
820
{
821
	struct thread *thread = machine__findnew_thread(machine, sample->tid);
822 823 824

	if (thread == NULL) {
		pr_debug("problem processing %d event, skipping it.\n",
825
			event->header.type);
826 827 828
		return -1;
	}

829
	perf_evsel__process_lock_event(evsel, sample);
830 831 832
	return 0;
}

833
static struct perf_tool eops = {
834
	.sample			= process_sample_event,
835
	.comm			= perf_event__process_comm,
836
	.ordered_samples	= true,
837 838 839 840
};

static int read_events(void)
{
841
	session = perf_session__new(input_name, O_RDONLY, 0, false, &eops);
842 843 844 845 846 847 848 849 850 851 852 853 854 855 856 857 858 859
	if (!session)
		die("Initializing perf session failed\n");

	return perf_session__process_events(session, &eops);
}

static void sort_result(void)
{
	unsigned int i;
	struct lock_stat *st;

	for (i = 0; i < LOCKHASH_SIZE; i++) {
		list_for_each_entry(st, &lockhash_table[i], hash_entry) {
			insert_to_result(st, compare);
		}
	}
}

860
static void __cmd_report(void)
861 862 863 864 865 866 867 868
{
	setup_pager();
	select_key();
	read_events();
	sort_result();
	print_result();
}

869 870
static const char * const report_usage[] = {
	"perf lock report [<options>]",
871 872 873
	NULL
};

874
static const struct option report_options[] = {
875
	OPT_STRING('k', "key", &sort_key, "acquired",
876
		    "key for sorting (acquired / contended / wait_total / wait_max / wait_min)"),
877 878 879 880
	/* TODO: type */
	OPT_END()
};

881 882 883 884 885 886 887 888 889
static const char * const info_usage[] = {
	"perf lock info [<options>]",
	NULL
};

static const struct option info_options[] = {
	OPT_BOOLEAN('t', "threads", &info_threads,
		    "dump thread list in perf.data"),
	OPT_BOOLEAN('m', "map", &info_map,
890
		    "map of lock instances (address:name table)"),
891 892 893
	OPT_END()
};

894
static const char * const lock_usage[] = {
895
	"perf lock [<options>] {record|report|script|info}",
896 897 898 899
	NULL
};

static const struct option lock_options[] = {
900
	OPT_STRING('i', "input", &input_name, "file", "input file name"),
901
	OPT_INCR('v', "verbose", &verbose, "be more verbose (show symbol address, etc)"),
902
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, "dump raw trace in ASCII"),
903 904 905 906 907 908 909 910 911
	OPT_END()
};

static const char *record_args[] = {
	"record",
	"-R",
	"-f",
	"-m", "1024",
	"-c", "1",
912 913 914 915
	"-e", "lock:lock_acquire",
	"-e", "lock:lock_acquired",
	"-e", "lock:lock_contended",
	"-e", "lock:lock_release",
916 917 918 919 920 921 922 923 924 925
};

static int __cmd_record(int argc, const char **argv)
{
	unsigned int rec_argc, i, j;
	const char **rec_argv;

	rec_argc = ARRAY_SIZE(record_args) + argc - 1;
	rec_argv = calloc(rec_argc + 1, sizeof(char *));

926 927 928
	if (rec_argv == NULL)
		return -ENOMEM;

929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954
	for (i = 0; i < ARRAY_SIZE(record_args); i++)
		rec_argv[i] = strdup(record_args[i]);

	for (j = 1; j < (unsigned int)argc; j++, i++)
		rec_argv[i] = argv[j];

	BUG_ON(i != rec_argc);

	return cmd_record(i, rec_argv, NULL);
}

int cmd_lock(int argc, const char **argv, const char *prefix __used)
{
	unsigned int i;

	symbol__init();
	for (i = 0; i < LOCKHASH_SIZE; i++)
		INIT_LIST_HEAD(lockhash_table + i);

	argc = parse_options(argc, argv, lock_options, lock_usage,
			     PARSE_OPT_STOP_AT_NON_OPTION);
	if (!argc)
		usage_with_options(lock_usage, lock_options);

	if (!strncmp(argv[0], "rec", 3)) {
		return __cmd_record(argc, argv);
955 956
	} else if (!strncmp(argv[0], "report", 6)) {
		trace_handler = &report_lock_ops;
957 958
		if (argc) {
			argc = parse_options(argc, argv,
959
					     report_options, report_usage, 0);
960
			if (argc)
961
				usage_with_options(report_usage, report_options);
962
		}
963
		__cmd_report();
964 965 966
	} else if (!strcmp(argv[0], "script")) {
		/* Aliased to 'perf script' */
		return cmd_script(argc, argv, prefix);
967 968 969 970 971 972 973
	} else if (!strcmp(argv[0], "info")) {
		if (argc) {
			argc = parse_options(argc, argv,
					     info_options, info_usage, 0);
			if (argc)
				usage_with_options(info_usage, info_options);
		}
974 975
		/* recycling report_lock_ops */
		trace_handler = &report_lock_ops;
976 977
		setup_pager();
		read_events();
978
		dump_info();
979 980 981 982 983 984
	} else {
		usage_with_options(lock_usage, lock_options);
	}

	return 0;
}