builtin-lock.c 49.2 KB
Newer Older
1
// SPDX-License-Identifier: GPL-2.0
2
#include <errno.h>
3
#include <inttypes.h>
4 5 6
#include "builtin.h"
#include "perf.h"

7
#include "util/evlist.h" // for struct evsel_str_handler
8
#include "util/evsel.h"
9 10 11
#include "util/symbol.h"
#include "util/thread.h"
#include "util/header.h"
12
#include "util/target.h"
13
#include "util/callchain.h"
14
#include "util/lock-contention.h"
15
#include "util/bpf_skel/lock_data.h"
16

17
#include <subcmd/pager.h>
18
#include <subcmd/parse-options.h>
19
#include "util/trace-event.h"
20
#include "util/tracepoint.h"
21 22 23

#include "util/debug.h"
#include "util/session.h"
24
#include "util/tool.h"
25
#include "util/data.h"
26
#include "util/string2.h"
27
#include "util/map.h"
28
#include "util/util.h"
29 30 31 32 33 34 35 36 37

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

#include <linux/list.h>
#include <linux/hash.h>
38
#include <linux/kernel.h>
39
#include <linux/zalloc.h>
40
#include <linux/err.h>
41
#include <linux/stringify.h>
42

43
static struct perf_session *session;
44
static struct target target;
45

46 47 48 49
/* based on kernel/lockdep.c */
#define LOCKHASH_BITS		12
#define LOCKHASH_SIZE		(1UL << LOCKHASH_BITS)

50
static struct hlist_head lockhash_table[LOCKHASH_SIZE];
51 52 53 54

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

55 56
static struct rb_root		thread_stats;

57
static bool combine_locks;
58
static bool show_thread_stats;
59
static bool show_lock_addrs;
60
static bool use_bpf;
61
static unsigned long bpf_map_entries = 10240;
62 63
static int max_stack_depth = CONTENTION_STACK_DEPTH;
static int stack_skip = CONTENTION_STACK_SKIP;
64
static int print_nr_entries = INT_MAX / 2;
65

66 67
static struct lock_filter filters;

68
static enum lock_aggr_mode aggr_mode = LOCK_AGGR_ADDR;
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 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119
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));
120 121 122 123
	if (!st) {
		pr_err("memory allocation failed\n");
		return NULL;
	}
124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141

	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));
142 143 144 145
	if (!st) {
		pr_err("memory allocation failed\n");
		return NULL;
	}
146 147 148 149 150 151 152 153 154 155
	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;
}

156
/* build simple key function one is bigger than two */
157
#define SINGLE_KEY(member)						\
158 159 160 161 162 163 164 165
	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)
166
SINGLE_KEY(avg_wait_time)
167 168 169
SINGLE_KEY(wait_time_total)
SINGLE_KEY(wait_time_max)

170 171 172 173 174 175 176 177 178 179 180 181
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;
}

182 183 184 185 186 187
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
	 */
188
	const char		*name;
189 190 191 192 193
	/* header: the string printed on the header line */
	const char		*header;
	/* len: the printing width of the field */
	int			len;
	/* key: a pointer to function to compare two lock stats for sorting */
194
	int			(*key)(struct lock_stat*, struct lock_stat*);
195 196 197 198
	/* print: a pointer to function to print a given lock stats */
	void			(*print)(struct lock_key*, struct lock_stat*);
	/* list: list entry to link this */
	struct list_head	list;
199 200
};

201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225
static void lock_stat_key_print_time(unsigned long long nsec, int len)
{
	static const struct {
		float base;
		const char *unit;
	} table[] = {
		{ 1e9 * 3600, "h " },
		{ 1e9 * 60, "m " },
		{ 1e9, "s " },
		{ 1e6, "ms" },
		{ 1e3, "us" },
		{ 0, NULL },
	};

	for (int i = 0; table[i].unit; i++) {
		if (nsec < table[i].base)
			continue;

		pr_info("%*.2f %s", len - 3, nsec / table[i].base, table[i].unit);
		return;
	}

	pr_info("%*llu %s", len - 3, nsec, "ns");
}

226 227 228 229 230 231 232
#define PRINT_KEY(member)						\
static void lock_stat_key_print_ ## member(struct lock_key *key,	\
					   struct lock_stat *ls)	\
{									\
	pr_info("%*llu", key->len, (unsigned long long)ls->member);	\
}

233 234 235 236 237 238 239
#define PRINT_TIME(member)						\
static void lock_stat_key_print_ ## member(struct lock_key *key,	\
					   struct lock_stat *ls)	\
{									\
	lock_stat_key_print_time((unsigned long long)ls->member, key->len);	\
}

240 241
PRINT_KEY(nr_acquired)
PRINT_KEY(nr_contended)
242 243 244
PRINT_TIME(avg_wait_time)
PRINT_TIME(wait_time_total)
PRINT_TIME(wait_time_max)
245 246 247 248 249 250 251 252 253

static void lock_stat_key_print_wait_time_min(struct lock_key *key,
					      struct lock_stat *ls)
{
	u64 wait_time = ls->wait_time_min;

	if (wait_time == ULLONG_MAX)
		wait_time = 0;

254
	lock_stat_key_print_time(wait_time, key->len);
255 256 257
}


258 259 260 261
static const char		*sort_key = "acquired";

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

262
static struct rb_root		sorted; /* place to store intermediate data */
263
static struct rb_root		result;	/* place to store sorted data */
264

265
static LIST_HEAD(lock_keys);
266
static const char		*output_fields;
267 268 269

#define DEF_KEY_LOCK(name, header, fn_suffix, len)			\
	{ #name, header, len, lock_stat_key_ ## fn_suffix, lock_stat_key_print_ ## fn_suffix, {} }
270
static struct lock_key report_keys[] = {
271 272
	DEF_KEY_LOCK(acquired, "acquired", nr_acquired, 10),
	DEF_KEY_LOCK(contended, "contended", nr_contended, 10),
273 274 275 276
	DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12),
	DEF_KEY_LOCK(wait_total, "total wait", wait_time_total, 12),
	DEF_KEY_LOCK(wait_max, "max wait", wait_time_max, 12),
	DEF_KEY_LOCK(wait_min, "min wait", wait_time_min, 12),
277 278

	/* extra comparisons much complicated should be here */
279
	{ }
280 281
};

282 283 284 285 286 287 288 289 290 291 292 293
static struct lock_key contention_keys[] = {
	DEF_KEY_LOCK(contended, "contended", nr_contended, 10),
	DEF_KEY_LOCK(wait_total, "total wait", wait_time_total, 12),
	DEF_KEY_LOCK(wait_max, "max wait", wait_time_max, 12),
	DEF_KEY_LOCK(wait_min, "min wait", wait_time_min, 12),
	DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12),

	/* extra comparisons much complicated should be here */
	{ }
};

static int select_key(bool contention)
294 295
{
	int i;
296 297 298 299
	struct lock_key *keys = report_keys;

	if (contention)
		keys = contention_keys;
300 301 302 303

	for (i = 0; keys[i].name; i++) {
		if (!strcmp(keys[i].name, sort_key)) {
			compare = keys[i].key;
304 305 306 307 308

			/* selected key should be in the output fields */
			if (list_empty(&keys[i].list))
				list_add_tail(&keys[i].list, &lock_keys);

309
			return 0;
310 311 312
		}
	}

313 314
	pr_err("Unknown compare key: %s\n", sort_key);
	return -1;
315 316
}

317
static int add_output_field(bool contention, char *name)
318 319
{
	int i;
320 321 322 323
	struct lock_key *keys = report_keys;

	if (contention)
		keys = contention_keys;
324

325 326 327 328 329 330
	for (i = 0; keys[i].name; i++) {
		if (strcmp(keys[i].name, name))
			continue;

		/* prevent double link */
		if (list_empty(&keys[i].list))
331
			list_add_tail(&keys[i].list, &lock_keys);
332 333 334 335 336 337 338 339

		return 0;
	}

	pr_err("Unknown output field: %s\n", name);
	return -1;
}

340
static int setup_output_field(bool contention, const char *str)
341 342 343
{
	char *tok, *tmp, *orig;
	int i, ret = 0;
344 345 346 347
	struct lock_key *keys = report_keys;

	if (contention)
		keys = contention_keys;
348 349 350 351 352 353 354 355

	/* no output field given: use all of them */
	if (str == NULL) {
		for (i = 0; keys[i].name; i++)
			list_add_tail(&keys[i].list, &lock_keys);
		return 0;
	}

356
	for (i = 0; keys[i].name; i++)
357
		INIT_LIST_HEAD(&keys[i].list);
358

359 360 361 362 363
	orig = tmp = strdup(str);
	if (orig == NULL)
		return -ENOMEM;

	while ((tok = strsep(&tmp, ",")) != NULL){
364
		ret = add_output_field(contention, tok);
365 366 367 368 369 370
		if (ret < 0)
			break;
	}
	free(orig);

	return ret;
371 372
}

373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401
static void combine_lock_stats(struct lock_stat *st)
{
	struct rb_node **rb = &sorted.rb_node;
	struct rb_node *parent = NULL;
	struct lock_stat *p;
	int ret;

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

		if (st->name && p->name)
			ret = strcmp(st->name, p->name);
		else
			ret = !!st->name - !!p->name;

		if (ret == 0) {
			p->nr_acquired += st->nr_acquired;
			p->nr_contended += st->nr_contended;
			p->wait_time_total += st->wait_time_total;

			if (p->nr_contended)
				p->avg_wait_time = p->wait_time_total / p->nr_contended;

			if (p->wait_time_min > st->wait_time_min)
				p->wait_time_min = st->wait_time_min;
			if (p->wait_time_max < st->wait_time_max)
				p->wait_time_max = st->wait_time_max;

402
			p->broken |= st->broken;
403 404 405 406 407 408 409 410 411 412 413 414 415 416
			st->combined = 1;
			return;
		}

		if (ret < 0)
			rb = &(*rb)->rb_left;
		else
			rb = &(*rb)->rb_right;
	}

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

417
static void insert_to_result(struct lock_stat *st,
418
			     int (*bigger)(struct lock_stat *, struct lock_stat *))
419 420 421 422 423
{
	struct rb_node **rb = &result.rb_node;
	struct rb_node *parent = NULL;
	struct lock_stat *p;

424 425 426
	if (combine_locks && st->combined)
		return;

427 428 429 430 431 432 433 434 435 436 437 438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455
	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);
}

456 457 458 459 460 461 462 463 464 465 466 467
static struct lock_stat *lock_stat_find(u64 addr)
{
	struct hlist_head *entry = lockhashentry(addr);
	struct lock_stat *ret;

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

468
static struct lock_stat *lock_stat_findnew(u64 addr, const char *name, int flags)
469
{
470
	struct hlist_head *entry = lockhashentry(addr);
471 472
	struct lock_stat *ret, *new;

473
	hlist_for_each_entry(ret, entry, hash_entry) {
474 475 476 477 478 479 480 481 482
		if (ret->addr == addr)
			return ret;
	}

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

	new->addr = addr;
483
	new->name = strdup(name);
484 485
	if (!new->name) {
		free(new);
486
		goto alloc_failed;
487
	}
488

489
	new->flags = flags;
490 491
	new->wait_time_min = ULLONG_MAX;

492
	hlist_add_head(&new->hash_entry, entry);
493 494 495
	return new;

alloc_failed:
496 497
	pr_err("memory allocation failed\n");
	return NULL;
498 499 500
}

struct trace_lock_handler {
501
	/* it's used on CONFIG_LOCKDEP */
502
	int (*acquire_event)(struct evsel *evsel,
503
			     struct perf_sample *sample);
504

505
	/* it's used on CONFIG_LOCKDEP && CONFIG_LOCK_STAT */
506
	int (*acquired_event)(struct evsel *evsel,
507
			      struct perf_sample *sample);
508

509
	/* it's used on CONFIG_LOCKDEP && CONFIG_LOCK_STAT */
510
	int (*contended_event)(struct evsel *evsel,
511
			       struct perf_sample *sample);
512

513
	/* it's used on CONFIG_LOCKDEP */
514
	int (*release_event)(struct evsel *evsel,
515
			     struct perf_sample *sample);
516 517 518 519 520 521 522 523

	/* it's used when CONFIG_LOCKDEP is off */
	int (*contention_begin_event)(struct evsel *evsel,
				      struct perf_sample *sample);

	/* it's used when CONFIG_LOCKDEP is off */
	int (*contention_end_event)(struct evsel *evsel,
				    struct perf_sample *sample);
524 525
};

526
static struct lock_seq_stat *get_seq(struct thread_stat *ts, u64 addr)
527 528 529 530 531 532 533 534 535
{
	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));
536 537 538 539
	if (!seq) {
		pr_err("memory allocation failed\n");
		return NULL;
	}
540 541 542 543 544 545 546
	seq->state = SEQ_STATE_UNINITIALIZED;
	seq->addr = addr;

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

547 548 549 550 551 552 553 554 555
enum broken_state {
	BROKEN_ACQUIRE,
	BROKEN_ACQUIRED,
	BROKEN_CONTENDED,
	BROKEN_RELEASE,
	BROKEN_MAX,
};

static int bad_hist[BROKEN_MAX];
556

557 558 559 560 561
enum acquire_flags {
	TRY_LOCK = 1,
	READ_LOCK = 2,
};

562
static int get_key_by_aggr_mode_simple(u64 *key, u64 addr, u32 tid)
563
{
564 565
	switch (aggr_mode) {
	case LOCK_AGGR_ADDR:
566
		*key = addr;
567 568
		break;
	case LOCK_AGGR_TASK:
569
		*key = tid;
570 571 572 573 574 575
		break;
	case LOCK_AGGR_CALLER:
	default:
		pr_err("Invalid aggregation mode: %d\n", aggr_mode);
		return -EINVAL;
	}
576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602 603 604 605
	return 0;
}

static u64 callchain_id(struct evsel *evsel, struct perf_sample *sample);

static int get_key_by_aggr_mode(u64 *key, u64 addr, struct evsel *evsel,
				 struct perf_sample *sample)
{
	if (aggr_mode == LOCK_AGGR_CALLER) {
		*key = callchain_id(evsel, sample);
		return 0;
	}
	return get_key_by_aggr_mode_simple(key, addr, sample->tid);
}

static int report_lock_acquire_event(struct evsel *evsel,
				     struct perf_sample *sample)
{
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
	const char *name = evsel__strval(evsel, sample, "name");
	u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
	int flag = evsel__intval(evsel, sample, "flags");
	u64 key;
	int ret;

	ret = get_key_by_aggr_mode_simple(&key, addr, sample->tid);
	if (ret < 0)
		return ret;
606

607
	ls = lock_stat_findnew(key, name, 0);
608
	if (!ls)
609
		return -ENOMEM;
610

611
	ts = thread_stat_findnew(sample->tid);
612
	if (!ts)
613
		return -ENOMEM;
614

615
	seq = get_seq(ts, addr);
616
	if (!seq)
617
		return -ENOMEM;
618

619 620 621
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
	case SEQ_STATE_RELEASED:
622
		if (!flag) {
623 624
			seq->state = SEQ_STATE_ACQUIRING;
		} else {
625
			if (flag & TRY_LOCK)
626
				ls->nr_trylock++;
627
			if (flag & READ_LOCK)
628 629 630 631 632 633 634
				ls->nr_readlock++;
			seq->state = SEQ_STATE_READ_ACQUIRED;
			seq->read_count = 1;
			ls->nr_acquired++;
		}
		break;
	case SEQ_STATE_READ_ACQUIRED:
635
		if (flag & READ_LOCK) {
636 637 638 639 640 641
			seq->read_count++;
			ls->nr_acquired++;
			goto end;
		} else {
			goto broken;
		}
642
		break;
643 644 645 646
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_CONTENDED:
broken:
647 648 649 650 651
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_ACQUIRE]++;
		}
652
		list_del_init(&seq->list);
653 654
		free(seq);
		goto end;
655
	default:
656
		BUG_ON("Unknown state of lock sequence found!\n");
657 658 659
		break;
	}

660
	ls->nr_acquire++;
661
	seq->prev_event_time = sample->time;
662
end:
663
	return 0;
664 665
}

666
static int report_lock_acquired_event(struct evsel *evsel,
667
				      struct perf_sample *sample)
668
{
669 670 671 672
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
	u64 contended_term;
673
	const char *name = evsel__strval(evsel, sample, "name");
674
	u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
675
	u64 key;
676
	int ret;
677

678 679 680
	ret = get_key_by_aggr_mode_simple(&key, addr, sample->tid);
	if (ret < 0)
		return ret;
681

682
	ls = lock_stat_findnew(key, name, 0);
683
	if (!ls)
684
		return -ENOMEM;
685

686
	ts = thread_stat_findnew(sample->tid);
687
	if (!ts)
688
		return -ENOMEM;
689

690
	seq = get_seq(ts, addr);
691
	if (!seq)
692
		return -ENOMEM;
693

694 695 696
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		/* orphan event, do nothing */
697
		return 0;
698
	case SEQ_STATE_ACQUIRING:
699
		break;
700
	case SEQ_STATE_CONTENDED:
701
		contended_term = sample->time - seq->prev_event_time;
702 703 704
		ls->wait_time_total += contended_term;
		if (contended_term < ls->wait_time_min)
			ls->wait_time_min = contended_term;
705
		if (ls->wait_time_max < contended_term)
706
			ls->wait_time_max = contended_term;
707
		break;
708 709 710
	case SEQ_STATE_RELEASED:
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_READ_ACQUIRED:
711 712 713 714 715
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_ACQUIRED]++;
		}
716
		list_del_init(&seq->list);
717 718
		free(seq);
		goto end;
719
	default:
720
		BUG_ON("Unknown state of lock sequence found!\n");
721 722 723
		break;
	}

724 725
	seq->state = SEQ_STATE_ACQUIRED;
	ls->nr_acquired++;
726
	ls->avg_wait_time = ls->nr_contended ? ls->wait_time_total/ls->nr_contended : 0;
727
	seq->prev_event_time = sample->time;
728
end:
729
	return 0;
730 731
}

732
static int report_lock_contended_event(struct evsel *evsel,
733
				       struct perf_sample *sample)
734
{
735 736 737
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
738
	const char *name = evsel__strval(evsel, sample, "name");
739
	u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
740
	u64 key;
741
	int ret;
742

743 744 745
	ret = get_key_by_aggr_mode_simple(&key, addr, sample->tid);
	if (ret < 0)
		return ret;
746

747
	ls = lock_stat_findnew(key, name, 0);
748
	if (!ls)
749
		return -ENOMEM;
750

751
	ts = thread_stat_findnew(sample->tid);
752
	if (!ts)
753
		return -ENOMEM;
754

755
	seq = get_seq(ts, addr);
756
	if (!seq)
757
		return -ENOMEM;
758

759 760 761
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		/* orphan event, do nothing */
762
		return 0;
763
	case SEQ_STATE_ACQUIRING:
764
		break;
765 766 767 768
	case SEQ_STATE_RELEASED:
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_READ_ACQUIRED:
	case SEQ_STATE_CONTENDED:
769 770 771 772 773
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_CONTENDED]++;
		}
774
		list_del_init(&seq->list);
775 776
		free(seq);
		goto end;
777
	default:
778
		BUG_ON("Unknown state of lock sequence found!\n");
779 780 781
		break;
	}

782 783
	seq->state = SEQ_STATE_CONTENDED;
	ls->nr_contended++;
784
	ls->avg_wait_time = ls->wait_time_total/ls->nr_contended;
785
	seq->prev_event_time = sample->time;
786
end:
787
	return 0;
788 789
}

790
static int report_lock_release_event(struct evsel *evsel,
791
				     struct perf_sample *sample)
792
{
793 794 795
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
796
	const char *name = evsel__strval(evsel, sample, "name");
797
	u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
798
	u64 key;
799
	int ret;
800

801 802 803
	ret = get_key_by_aggr_mode_simple(&key, addr, sample->tid);
	if (ret < 0)
		return ret;
804

805
	ls = lock_stat_findnew(key, name, 0);
806
	if (!ls)
807
		return -ENOMEM;
808

809
	ts = thread_stat_findnew(sample->tid);
810
	if (!ts)
811
		return -ENOMEM;
812

813
	seq = get_seq(ts, addr);
814
	if (!seq)
815
		return -ENOMEM;
816

817 818 819 820 821 822 823 824
	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		goto end;
	case SEQ_STATE_ACQUIRED:
		break;
	case SEQ_STATE_READ_ACQUIRED:
		seq->read_count--;
		BUG_ON(seq->read_count < 0);
825
		if (seq->read_count) {
826
			ls->nr_release++;
827 828
			goto end;
		}
829 830 831 832
		break;
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_CONTENDED:
	case SEQ_STATE_RELEASED:
833 834 835 836 837
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_RELEASE]++;
		}
838
		goto free_seq;
839
	default:
840
		BUG_ON("Unknown state of lock sequence found!\n");
841 842 843
		break;
	}

844 845
	ls->nr_release++;
free_seq:
846
	list_del_init(&seq->list);
847
	free(seq);
848
end:
849
	return 0;
850 851
}

852 853 854 855 856 857 858 859 860 861 862 863 864 865 866 867 868
static int get_symbol_name_offset(struct map *map, struct symbol *sym, u64 ip,
				  char *buf, int size)
{
	u64 offset;

	if (map == NULL || sym == NULL) {
		buf[0] = '\0';
		return 0;
	}

	offset = map->map_ip(map, ip) - sym->start;

	if (offset)
		return scnprintf(buf, size, "%s+%#lx", sym->name, offset);
	else
		return strlcpy(buf, sym->name, size);
}
869 870 871 872 873
static int lock_contention_caller(struct evsel *evsel, struct perf_sample *sample,
				  char *buf, int size)
{
	struct thread *thread;
	struct callchain_cursor *cursor = &callchain_cursor;
874
	struct machine *machine = &session->machines.host;
875 876 877 878 879 880 881 882
	struct symbol *sym;
	int skip = 0;
	int ret;

	/* lock names will be replaced to task name later */
	if (show_thread_stats)
		return -1;

883
	thread = machine__findnew_thread(machine, -1, sample->pid);
884 885 886 887 888
	if (thread == NULL)
		return -1;

	/* use caller function name from the callchain */
	ret = thread__resolve_callchain(thread, cursor, evsel, sample,
889
					NULL, NULL, max_stack_depth);
890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905
	if (ret != 0) {
		thread__put(thread);
		return -1;
	}

	callchain_cursor_commit(cursor);
	thread__put(thread);

	while (true) {
		struct callchain_cursor_node *node;

		node = callchain_cursor_current(cursor);
		if (node == NULL)
			break;

		/* skip first few entries - for lock functions */
906
		if (++skip <= stack_skip)
907 908 909
			goto next;

		sym = node->ms.sym;
910
		if (sym && !machine__is_lock_function(machine, node->ip)) {
911 912
			get_symbol_name_offset(node->ms.map, sym, node->ip,
					       buf, size);
913 914 915 916 917 918 919 920 921
			return 0;
		}

next:
		callchain_cursor_advance(cursor);
	}
	return -1;
}

922 923 924
static u64 callchain_id(struct evsel *evsel, struct perf_sample *sample)
{
	struct callchain_cursor *cursor = &callchain_cursor;
925
	struct machine *machine = &session->machines.host;
926 927 928 929 930
	struct thread *thread;
	u64 hash = 0;
	int skip = 0;
	int ret;

931
	thread = machine__findnew_thread(machine, -1, sample->pid);
932 933 934 935 936
	if (thread == NULL)
		return -1;

	/* use caller function name from the callchain */
	ret = thread__resolve_callchain(thread, cursor, evsel, sample,
937
					NULL, NULL, max_stack_depth);
938 939 940 941 942 943 944 945 946 947 948 949 950 951 952
	thread__put(thread);

	if (ret != 0)
		return -1;

	callchain_cursor_commit(cursor);

	while (true) {
		struct callchain_cursor_node *node;

		node = callchain_cursor_current(cursor);
		if (node == NULL)
			break;

		/* skip first few entries - for lock functions */
953
		if (++skip <= stack_skip)
954 955
			goto next;

956
		if (node->ms.sym && machine__is_lock_function(machine, node->ip))
957 958 959 960 961 962 963 964 965 966
			goto next;

		hash ^= hash_long((unsigned long)node->ip, 64);

next:
		callchain_cursor_advance(cursor);
	}
	return hash;
}

967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987
static u64 *get_callstack(struct perf_sample *sample, int max_stack)
{
	u64 *callstack;
	u64 i;
	int c;

	callstack = calloc(max_stack, sizeof(*callstack));
	if (callstack == NULL)
		return NULL;

	for (i = 0, c = 0; i < sample->callchain->nr && c < max_stack; i++) {
		u64 ip = sample->callchain->ips[i];

		if (ip >= PERF_CONTEXT_MAX)
			continue;

		callstack[c++] = ip;
	}
	return callstack;
}

988 989 990 991 992 993 994
static int report_lock_contention_begin_event(struct evsel *evsel,
					      struct perf_sample *sample)
{
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
	u64 addr = evsel__intval(evsel, sample, "lock_addr");
995
	unsigned int flags = evsel__intval(evsel, sample, "flags");
996
	u64 key;
997
	int i, ret;
998

999 1000 1001
	ret = get_key_by_aggr_mode(&key, addr, evsel, sample);
	if (ret < 0)
		return ret;
1002

1003
	ls = lock_stat_find(key);
1004 1005
	if (!ls) {
		char buf[128];
1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028
		const char *name = "";
		struct machine *machine = &session->machines.host;
		struct map *kmap;
		struct symbol *sym;

		switch (aggr_mode) {
		case LOCK_AGGR_ADDR:
			/* make sure it loads the kernel map to find lock symbols */
			map__load(machine__kernel_map(machine));

			sym = machine__find_kernel_symbol(machine, key, &kmap);
			if (sym)
				name = sym->name;
			break;
		case LOCK_AGGR_CALLER:
			name = buf;
			if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0)
				name = "Unknown";
			break;
		case LOCK_AGGR_TASK:
		default:
			break;
		}
1029

1030
		ls = lock_stat_findnew(key, name, flags);
1031 1032
		if (!ls)
			return -ENOMEM;
1033

1034
		if (aggr_mode == LOCK_AGGR_CALLER && verbose > 0) {
1035
			ls->callstack = get_callstack(sample, max_stack_depth);
1036 1037 1038
			if (ls->callstack == NULL)
				return -ENOMEM;
		}
1039
	}
1040

1041 1042 1043 1044 1045 1046 1047 1048 1049 1050 1051 1052 1053 1054
	if (filters.nr_types) {
		bool found = false;

		for (i = 0; i < filters.nr_types; i++) {
			if (flags == filters.types[i]) {
				found = true;
				break;
			}
		}

		if (!found)
			return 0;
	}

1055 1056 1057 1058 1059 1060 1061 1062 1063 1064 1065 1066 1067 1068 1069 1070 1071 1072 1073 1074 1075 1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101 1102 1103 1104 1105 1106
	ts = thread_stat_findnew(sample->tid);
	if (!ts)
		return -ENOMEM;

	seq = get_seq(ts, addr);
	if (!seq)
		return -ENOMEM;

	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
	case SEQ_STATE_ACQUIRED:
		break;
	case SEQ_STATE_CONTENDED:
		/*
		 * It can have nested contention begin with mutex spinning,
		 * then we would use the original contention begin event and
		 * ignore the second one.
		 */
		goto end;
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_READ_ACQUIRED:
	case SEQ_STATE_RELEASED:
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_CONTENDED]++;
		}
		list_del_init(&seq->list);
		free(seq);
		goto end;
	default:
		BUG_ON("Unknown state of lock sequence found!\n");
		break;
	}

	if (seq->state != SEQ_STATE_CONTENDED) {
		seq->state = SEQ_STATE_CONTENDED;
		seq->prev_event_time = sample->time;
		ls->nr_contended++;
	}
end:
	return 0;
}

static int report_lock_contention_end_event(struct evsel *evsel,
					    struct perf_sample *sample)
{
	struct lock_stat *ls;
	struct thread_stat *ts;
	struct lock_seq_stat *seq;
	u64 contended_term;
	u64 addr = evsel__intval(evsel, sample, "lock_addr");
1107
	u64 key;
1108
	int ret;
1109

1110 1111 1112
	ret = get_key_by_aggr_mode(&key, addr, evsel, sample);
	if (ret < 0)
		return ret;
1113

1114
	ls = lock_stat_find(key);
1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133 1134 1135 1136 1137 1138 1139 1140 1141 1142 1143 1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159 1160
	if (!ls)
		return 0;

	ts = thread_stat_find(sample->tid);
	if (!ts)
		return 0;

	seq = get_seq(ts, addr);
	if (!seq)
		return -ENOMEM;

	switch (seq->state) {
	case SEQ_STATE_UNINITIALIZED:
		goto end;
	case SEQ_STATE_CONTENDED:
		contended_term = sample->time - seq->prev_event_time;
		ls->wait_time_total += contended_term;
		if (contended_term < ls->wait_time_min)
			ls->wait_time_min = contended_term;
		if (ls->wait_time_max < contended_term)
			ls->wait_time_max = contended_term;
		break;
	case SEQ_STATE_ACQUIRING:
	case SEQ_STATE_ACQUIRED:
	case SEQ_STATE_READ_ACQUIRED:
	case SEQ_STATE_RELEASED:
		/* broken lock sequence */
		if (!ls->broken) {
			ls->broken = 1;
			bad_hist[BROKEN_ACQUIRED]++;
		}
		list_del_init(&seq->list);
		free(seq);
		goto end;
	default:
		BUG_ON("Unknown state of lock sequence found!\n");
		break;
	}

	seq->state = SEQ_STATE_ACQUIRED;
	ls->nr_acquired++;
	ls->avg_wait_time = ls->wait_time_total/ls->nr_acquired;
end:
	return 0;
}

1161 1162
/* lock oriented handlers */
/* TODO: handlers for CPU oriented, thread oriented */
1163 1164 1165 1166 1167
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,
1168 1169
	.contention_begin_event	= report_lock_contention_begin_event,
	.contention_end_event	= report_lock_contention_end_event,
1170 1171
};

1172 1173 1174 1175 1176 1177
static struct trace_lock_handler contention_lock_ops  = {
	.contention_begin_event	= report_lock_contention_begin_event,
	.contention_end_event	= report_lock_contention_end_event,
};


1178 1179
static struct trace_lock_handler *trace_handler;

1180
static int evsel__process_lock_acquire(struct evsel *evsel, struct perf_sample *sample)
1181
{
1182
	if (trace_handler->acquire_event)
1183 1184
		return trace_handler->acquire_event(evsel, sample);
	return 0;
1185 1186
}

1187
static int evsel__process_lock_acquired(struct evsel *evsel, struct perf_sample *sample)
1188
{
1189
	if (trace_handler->acquired_event)
1190 1191
		return trace_handler->acquired_event(evsel, sample);
	return 0;
1192 1193
}

1194
static int evsel__process_lock_contended(struct evsel *evsel, struct perf_sample *sample)
1195
{
1196
	if (trace_handler->contended_event)
1197 1198
		return trace_handler->contended_event(evsel, sample);
	return 0;
1199 1200
}

1201
static int evsel__process_lock_release(struct evsel *evsel, struct perf_sample *sample)
1202
{
1203
	if (trace_handler->release_event)
1204 1205
		return trace_handler->release_event(evsel, sample);
	return 0;
1206 1207
}

1208 1209 1210 1211 1212 1213 1214 1215 1216 1217 1218 1219 1220 1221
static int evsel__process_contention_begin(struct evsel *evsel, struct perf_sample *sample)
{
	if (trace_handler->contention_begin_event)
		return trace_handler->contention_begin_event(evsel, sample);
	return 0;
}

static int evsel__process_contention_end(struct evsel *evsel, struct perf_sample *sample)
{
	if (trace_handler->contention_end_event)
		return trace_handler->contention_end_event(evsel, sample);
	return 0;
}

1222 1223 1224 1225
static void print_bad_events(int bad, int total)
{
	/* Output for debug, this have to be removed */
	int i;
1226
	int broken = 0;
1227 1228 1229
	const char *name[4] =
		{ "acquire", "acquired", "contended", "release" };

1230 1231 1232
	for (i = 0; i < BROKEN_MAX; i++)
		broken += bad_hist[i];

1233
	if (quiet || (broken == 0 && verbose <= 0))
1234 1235
		return;

1236
	pr_info("\n=== output for debug===\n\n");
1237
	pr_info("bad: %d, total: %d\n", bad, total);
1238
	pr_info("bad rate: %.2f %%\n", (double)bad / (double)total * 100);
1239 1240 1241 1242 1243
	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]);
}

1244 1245 1246 1247
/* TODO: various way to print, coloring, nano or milli sec */
static void print_result(void)
{
	struct lock_stat *st;
1248
	struct lock_key *key;
1249
	char cut_name[20];
1250
	int bad, total, printed;
1251

1252 1253 1254 1255 1256 1257
	if (!quiet) {
		pr_info("%20s ", "Name");
		list_for_each_entry(key, &lock_keys, list)
			pr_info("%*s ", key->len, key->header);
		pr_info("\n\n");
	}
1258

1259
	bad = total = printed = 0;
1260
	while ((st = pop_from_result())) {
1261
		total++;
1262
		if (st->broken)
1263
			bad++;
1264
		if (!st->nr_acquired)
1265
			continue;
1266

1267 1268
		bzero(cut_name, 20);

1269
		if (strlen(st->name) < 20) {
1270
			/* output raw name */
1271 1272 1273 1274 1275 1276 1277 1278 1279 1280 1281
			const char *name = st->name;

			if (show_thread_stats) {
				struct thread *t;

				/* st->addr contains tid of thread */
				t = perf_session__findnew(session, st->addr);
				name = thread__comm_str(t);
			}

			pr_info("%20s ", name);
1282 1283 1284 1285 1286 1287 1288
		} 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 */
1289
			pr_info("%20s ", cut_name);
1290 1291
		}

1292 1293 1294 1295
		list_for_each_entry(key, &lock_keys, list) {
			key->print(key, st);
			pr_info(" ");
		}
1296
		pr_info("\n");
1297 1298 1299

		if (++printed >= print_nr_entries)
			break;
1300
	}
1301

1302
	print_bad_events(bad, total);
1303 1304
}

1305
static bool info_threads, info_map;
1306 1307 1308 1309 1310 1311 1312 1313 1314 1315 1316 1317 1318

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);
1319
		pr_info("%10d: %s\n", st->tid, thread__comm_str(t));
1320
		node = rb_next(node);
1321
		thread__put(t);
1322
	}
1323 1324
}

1325 1326 1327 1328 1329 1330 1331 1332 1333 1334 1335 1336 1337 1338 1339
static int compare_maps(struct lock_stat *a, struct lock_stat *b)
{
	int ret;

	if (a->name && b->name)
		ret = strcmp(a->name, b->name);
	else
		ret = !!a->name - !!b->name;

	if (!ret)
		return a->addr < b->addr;
	else
		return ret < 0;
}

1340 1341 1342 1343 1344
static void dump_map(void)
{
	unsigned int i;
	struct lock_stat *st;

1345
	pr_info("Address of instance: name of class\n");
1346
	for (i = 0; i < LOCKHASH_SIZE; i++) {
1347
		hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
1348
			insert_to_result(st, compare_maps);
1349 1350
		}
	}
1351 1352 1353

	while ((st = pop_from_result()))
		pr_info(" %#llx: %s\n", (unsigned long long)st->addr, st->name);
1354 1355
}

1356
static int dump_info(void)
1357
{
1358 1359
	int rc = 0;

1360 1361 1362 1363
	if (info_threads)
		dump_threads();
	else if (info_map)
		dump_map();
1364 1365 1366 1367 1368 1369
	else {
		rc = -1;
		pr_err("Unknown type of information\n");
	}

	return rc;
1370 1371
}

1372 1373 1374 1375 1376 1377 1378 1379 1380 1381 1382 1383 1384 1385 1386 1387 1388 1389 1390 1391 1392 1393 1394 1395 1396 1397 1398 1399
static const struct evsel_str_handler lock_tracepoints[] = {
	{ "lock:lock_acquire",	 evsel__process_lock_acquire,   }, /* CONFIG_LOCKDEP */
	{ "lock:lock_acquired",	 evsel__process_lock_acquired,  }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
	{ "lock:lock_contended", evsel__process_lock_contended, }, /* CONFIG_LOCKDEP, CONFIG_LOCK_STAT */
	{ "lock:lock_release",	 evsel__process_lock_release,   }, /* CONFIG_LOCKDEP */
};

static const struct evsel_str_handler contention_tracepoints[] = {
	{ "lock:contention_begin", evsel__process_contention_begin, },
	{ "lock:contention_end",   evsel__process_contention_end,   },
};

static int process_event_update(struct perf_tool *tool,
				union perf_event *event,
				struct evlist **pevlist)
{
	int ret;

	ret = perf_event__process_event_update(tool, event, pevlist);
	if (ret < 0)
		return ret;

	/* this can return -EEXIST since we call it for each evsel */
	perf_session__set_tracepoints_handlers(session, lock_tracepoints);
	perf_session__set_tracepoints_handlers(session, contention_tracepoints);
	return 0;
}

1400
typedef int (*tracepoint_handler)(struct evsel *evsel,
1401 1402
				  struct perf_sample *sample);

1403
static int process_sample_event(struct perf_tool *tool __maybe_unused,
1404
				union perf_event *event,
1405
				struct perf_sample *sample,
1406
				struct evsel *evsel,
1407
				struct machine *machine)
1408
{
1409
	int err = 0;
1410 1411
	struct thread *thread = machine__findnew_thread(machine, sample->pid,
							sample->tid);
1412 1413 1414

	if (thread == NULL) {
		pr_debug("problem processing %d event, skipping it.\n",
1415
			event->header.type);
1416 1417 1418
		return -1;
	}

1419 1420
	if (evsel->handler != NULL) {
		tracepoint_handler f = evsel->handler;
1421
		err = f(evsel, sample);
1422 1423
	}

1424 1425 1426
	thread__put(thread);

	return err;
1427 1428
}

1429 1430 1431 1432 1433 1434 1435 1436 1437 1438 1439 1440 1441 1442 1443
static void combine_result(void)
{
	unsigned int i;
	struct lock_stat *st;

	if (!combine_locks)
		return;

	for (i = 0; i < LOCKHASH_SIZE; i++) {
		hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
			combine_lock_stats(st);
		}
	}
}

1444 1445 1446 1447 1448 1449
static void sort_result(void)
{
	unsigned int i;
	struct lock_stat *st;

	for (i = 0; i < LOCKHASH_SIZE; i++) {
1450
		hlist_for_each_entry(st, &lockhash_table[i], hash_entry) {
1451 1452 1453 1454 1455
			insert_to_result(st, compare);
		}
	}
}

1456 1457 1458 1459 1460 1461 1462 1463 1464 1465 1466 1467 1468 1469 1470 1471 1472
static const struct {
	unsigned int flags;
	const char *name;
} lock_type_table[] = {
	{ 0,				"semaphore" },
	{ LCB_F_SPIN,			"spinlock" },
	{ LCB_F_SPIN | LCB_F_READ,	"rwlock:R" },
	{ LCB_F_SPIN | LCB_F_WRITE,	"rwlock:W"},
	{ LCB_F_READ,			"rwsem:R" },
	{ LCB_F_WRITE,			"rwsem:W" },
	{ LCB_F_RT,			"rtmutex" },
	{ LCB_F_RT | LCB_F_READ,	"rwlock-rt:R" },
	{ LCB_F_RT | LCB_F_WRITE,	"rwlock-rt:W"},
	{ LCB_F_PERCPU | LCB_F_READ,	"pcpu-sem:R" },
	{ LCB_F_PERCPU | LCB_F_WRITE,	"pcpu-sem:W" },
	{ LCB_F_MUTEX,			"mutex" },
	{ LCB_F_MUTEX | LCB_F_SPIN,	"mutex" },
1473 1474
	/* alias for get_type_flag() */
	{ LCB_F_MUTEX | LCB_F_SPIN,	"mutex-spin" },
1475
};
1476

1477 1478 1479 1480 1481
static const char *get_type_str(unsigned int flags)
{
	for (unsigned int i = 0; i < ARRAY_SIZE(lock_type_table); i++) {
		if (lock_type_table[i].flags == flags)
			return lock_type_table[i].name;
1482 1483 1484 1485
	}
	return "unknown";
}

1486 1487 1488 1489 1490 1491 1492 1493 1494 1495 1496 1497 1498 1499 1500
static unsigned int get_type_flag(const char *str)
{
	for (unsigned int i = 0; i < ARRAY_SIZE(lock_type_table); i++) {
		if (!strcmp(lock_type_table[i].name, str))
			return lock_type_table[i].flags;
	}
	return UINT_MAX;
}

static void lock_filter_finish(void)
{
	zfree(&filters.types);
	filters.nr_types = 0;
}

1501 1502 1503 1504 1505
static void sort_contention_result(void)
{
	sort_result();
}

1506
static void print_contention_result(struct lock_contention *con)
1507 1508 1509
{
	struct lock_stat *st;
	struct lock_key *key;
1510
	int bad, total, printed;
1511

1512 1513 1514
	if (!quiet) {
		list_for_each_entry(key, &lock_keys, list)
			pr_info("%*s ", key->len, key->header);
1515

1516 1517
		switch (aggr_mode) {
		case LOCK_AGGR_TASK:
1518
			pr_info("  %10s   %s\n\n", "pid", "comm");
1519 1520
			break;
		case LOCK_AGGR_CALLER:
1521
			pr_info("  %10s   %s\n\n", "type", "caller");
1522 1523 1524 1525 1526 1527 1528
			break;
		case LOCK_AGGR_ADDR:
			pr_info("  %16s   %s\n\n", "address", "symbol");
			break;
		default:
			break;
		}
1529
	}
1530

1531
	bad = total = printed = 0;
1532 1533 1534
	if (use_bpf)
		bad = bad_hist[BROKEN_CONTENDED];

1535
	while ((st = pop_from_result())) {
1536 1537 1538
		struct thread *t;
		int pid;

1539
		total += use_bpf ? st->nr_contended : 1;
1540 1541 1542
		if (st->broken)
			bad++;

1543 1544 1545
		if (!st->wait_time_total)
			continue;

1546 1547 1548 1549 1550
		list_for_each_entry(key, &lock_keys, list) {
			key->print(key, st);
			pr_info(" ");
		}

1551 1552
		switch (aggr_mode) {
		case LOCK_AGGR_CALLER:
1553
			pr_info("  %10s   %s\n", get_type_str(st->flags), st->name);
1554 1555 1556
			break;
		case LOCK_AGGR_TASK:
			pid = st->addr;
1557 1558
			t = perf_session__findnew(session, pid);
			pr_info("  %10d   %s\n", pid, thread__comm_str(t));
1559 1560 1561 1562 1563 1564 1565
			break;
		case LOCK_AGGR_ADDR:
			pr_info("  %016llx   %s\n", (unsigned long long)st->addr,
				st->name ? : "");
			break;
		default:
			break;
1566 1567
		}

1568
		if (aggr_mode == LOCK_AGGR_CALLER && verbose > 0) {
1569 1570 1571 1572 1573
			struct map *kmap;
			struct symbol *sym;
			char buf[128];
			u64 ip;

1574
			for (int i = 0; i < max_stack_depth; i++) {
1575 1576 1577 1578 1579 1580 1581 1582 1583
				if (!st->callstack || !st->callstack[i])
					break;

				ip = st->callstack[i];
				sym = machine__find_kernel_symbol(con->machine, ip, &kmap);
				get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf));
				pr_info("\t\t\t%#lx  %s\n", (unsigned long)ip, buf);
			}
		}
1584 1585 1586

		if (++printed >= print_nr_entries)
			break;
1587 1588 1589 1590 1591
	}

	print_bad_events(bad, total);
}

1592 1593
static bool force;

1594
static int __cmd_report(bool display_info)
1595
{
1596
	int err = -EINVAL;
1597
	struct perf_tool eops = {
1598 1599
		.attr		 = perf_event__process_attr,
		.event_update	 = process_event_update,
1600 1601
		.sample		 = process_sample_event,
		.comm		 = perf_event__process_comm,
1602
		.mmap		 = perf_event__process_mmap,
1603
		.namespaces	 = perf_event__process_namespaces,
1604
		.tracing_data	 = perf_event__process_tracing_data,
1605
		.ordered_events	 = true,
1606
	};
1607
	struct perf_data data = {
1608 1609 1610
		.path  = input_name,
		.mode  = PERF_DATA_MODE_READ,
		.force = force,
1611
	};
1612

1613
	session = perf_session__new(&data, &eops);
1614
	if (IS_ERR(session)) {
1615
		pr_err("Initializing perf session failed\n");
1616
		return PTR_ERR(session);
1617
	}
1618

1619 1620
	/* for lock function check */
	symbol_conf.sort_by_name = true;
1621
	symbol__init(&session->header.env);
1622

1623 1624 1625
	if (!data.is_pipe) {
		if (!perf_session__has_traces(session, "lock record"))
			goto out_delete;
1626

1627 1628 1629 1630
		if (perf_session__set_tracepoints_handlers(session, lock_tracepoints)) {
			pr_err("Initializing perf session tracepoint handlers failed\n");
			goto out_delete;
		}
1631

1632 1633 1634 1635
		if (perf_session__set_tracepoints_handlers(session, contention_tracepoints)) {
			pr_err("Initializing perf session tracepoint handlers failed\n");
			goto out_delete;
		}
1636 1637
	}

1638
	if (setup_output_field(false, output_fields))
1639 1640
		goto out_delete;

1641
	if (select_key(false))
1642
		goto out_delete;
1643

1644 1645 1646
	if (show_thread_stats)
		aggr_mode = LOCK_AGGR_TASK;

1647
	err = perf_session__process_events(session);
1648 1649
	if (err)
		goto out_delete;
1650 1651

	setup_pager();
1652 1653 1654
	if (display_info) /* used for info subcommand */
		err = dump_info();
	else {
1655
		combine_result();
1656 1657 1658
		sort_result();
		print_result();
	}
1659

1660 1661 1662
out_delete:
	perf_session__delete(session);
	return err;
1663 1664
}

1665 1666 1667 1668
static void sighandler(int sig __maybe_unused)
{
}

1669
static int __cmd_contention(int argc, const char **argv)
1670 1671 1672
{
	int err = -EINVAL;
	struct perf_tool eops = {
1673 1674
		.attr		 = perf_event__process_attr,
		.event_update	 = process_event_update,
1675 1676 1677
		.sample		 = process_sample_event,
		.comm		 = perf_event__process_comm,
		.mmap		 = perf_event__process_mmap,
1678
		.tracing_data	 = perf_event__process_tracing_data,
1679 1680 1681 1682 1683 1684 1685
		.ordered_events	 = true,
	};
	struct perf_data data = {
		.path  = input_name,
		.mode  = PERF_DATA_MODE_READ,
		.force = force,
	};
1686 1687 1688
	struct lock_contention con = {
		.target = &target,
		.result = &lockhash_table[0],
1689
		.map_nr_entries = bpf_map_entries,
1690 1691
		.max_stack = max_stack_depth,
		.stack_skip = stack_skip,
1692
	};
1693

1694
	session = perf_session__new(use_bpf ? NULL : &data, &eops);
1695 1696 1697 1698 1699
	if (IS_ERR(session)) {
		pr_err("Initializing perf session failed\n");
		return PTR_ERR(session);
	}

1700 1701
	con.machine = &session->machines.host;

1702 1703 1704
	con.aggr_mode = aggr_mode = show_thread_stats ? LOCK_AGGR_TASK :
		show_lock_addrs ? LOCK_AGGR_ADDR : LOCK_AGGR_CALLER;

1705 1706 1707 1708
	/* for lock function check */
	symbol_conf.sort_by_name = true;
	symbol__init(&session->header.env);

1709
	if (use_bpf) {
1710 1711 1712 1713 1714 1715 1716
		err = target__validate(&target);
		if (err) {
			char errbuf[512];

			target__strerror(&target, err, errbuf, 512);
			pr_err("%s\n", errbuf);
			goto out_delete;
1717
		}
1718

1719 1720 1721
		signal(SIGINT, sighandler);
		signal(SIGCHLD, sighandler);
		signal(SIGTERM, sighandler);
1722

1723 1724
		con.evlist = evlist__new();
		if (con.evlist == NULL) {
1725 1726 1727 1728
			err = -ENOMEM;
			goto out_delete;
		}

1729
		err = evlist__create_maps(con.evlist, &target);
1730 1731 1732 1733
		if (err < 0)
			goto out_delete;

		if (argc) {
1734
			err = evlist__prepare_workload(con.evlist, &target,
1735 1736 1737 1738 1739
						       argv, false, NULL);
			if (err < 0)
				goto out_delete;
		}

1740
		if (lock_contention_prepare(&con) < 0) {
1741 1742 1743
			pr_err("lock contention BPF setup failed\n");
			goto out_delete;
		}
1744
	} else if (!data.is_pipe) {
1745 1746
		if (!perf_session__has_traces(session, "lock record"))
			goto out_delete;
1747

1748 1749 1750 1751 1752 1753 1754 1755 1756 1757 1758
		if (!evlist__find_evsel_by_str(session->evlist,
					       "lock:contention_begin")) {
			pr_err("lock contention evsel not found\n");
			goto out_delete;
		}

		if (perf_session__set_tracepoints_handlers(session,
						contention_tracepoints)) {
			pr_err("Initializing perf session tracepoint handlers failed\n");
			goto out_delete;
		}
1759 1760
	}

1761
	if (setup_output_field(true, output_fields))
1762 1763
		goto out_delete;

1764
	if (select_key(true))
1765 1766
		goto out_delete;

1767 1768
	if (use_bpf) {
		lock_contention_start();
1769
		if (argc)
1770
			evlist__start_workload(con.evlist);
1771 1772 1773 1774 1775

		/* wait for signal */
		pause();

		lock_contention_stop();
1776
		lock_contention_read(&con);
1777 1778 1779

		/* abuse bad hist stats for lost entries */
		bad_hist[BROKEN_CONTENDED] = con.lost;
1780 1781 1782 1783 1784
	} else {
		err = perf_session__process_events(session);
		if (err)
			goto out_delete;
	}
1785 1786 1787 1788

	setup_pager();

	sort_contention_result();
1789
	print_contention_result(&con);
1790 1791

out_delete:
1792
	lock_filter_finish();
1793
	evlist__delete(con.evlist);
1794
	lock_contention_finish();
1795 1796 1797 1798 1799
	perf_session__delete(session);
	return err;
}


1800 1801
static int __cmd_record(int argc, const char **argv)
{
1802
	const char *record_args[] = {
1803
		"record", "-R", "-m", "1024", "-c", "1", "--synth", "task",
1804
	};
1805 1806 1807
	const char *callgraph_args[] = {
		"--call-graph", "fp," __stringify(CONTENTION_STACK_DEPTH),
	};
1808
	unsigned int rec_argc, i, j, ret;
1809
	unsigned int nr_tracepoints;
1810
	unsigned int nr_callgraph_args = 0;
1811
	const char **rec_argv;
1812
	bool has_lock_stat = true;
1813

1814
	for (i = 0; i < ARRAY_SIZE(lock_tracepoints); i++) {
1815
		if (!is_valid_tracepoint(lock_tracepoints[i].name)) {
1816 1817 1818 1819 1820 1821 1822 1823 1824 1825 1826 1827 1828 1829 1830 1831
			pr_debug("tracepoint %s is not enabled. "
				 "Are CONFIG_LOCKDEP and CONFIG_LOCK_STAT enabled?\n",
				 lock_tracepoints[i].name);
			has_lock_stat = false;
			break;
		}
	}

	if (has_lock_stat)
		goto setup_args;

	for (i = 0; i < ARRAY_SIZE(contention_tracepoints); i++) {
		if (!is_valid_tracepoint(contention_tracepoints[i].name)) {
			pr_err("tracepoint %s is not enabled.\n",
			       contention_tracepoints[i].name);
			return 1;
1832 1833 1834
		}
	}

1835 1836
	nr_callgraph_args = ARRAY_SIZE(callgraph_args);

1837
setup_args:
1838
	rec_argc = ARRAY_SIZE(record_args) + nr_callgraph_args + argc - 1;
1839 1840 1841 1842 1843 1844

	if (has_lock_stat)
		nr_tracepoints = ARRAY_SIZE(lock_tracepoints);
	else
		nr_tracepoints = ARRAY_SIZE(contention_tracepoints);

1845
	/* factor of 2 is for -e in front of each tracepoint */
1846
	rec_argc += 2 * nr_tracepoints;
1847

1848
	rec_argv = calloc(rec_argc + 1, sizeof(char *));
1849
	if (!rec_argv)
1850 1851
		return -ENOMEM;

1852 1853 1854
	for (i = 0; i < ARRAY_SIZE(record_args); i++)
		rec_argv[i] = strdup(record_args[i]);

1855 1856 1857 1858 1859 1860 1861 1862 1863 1864 1865
	for (j = 0; j < nr_tracepoints; j++) {
		const char *ev_name;

		if (has_lock_stat)
			ev_name = strdup(lock_tracepoints[j].name);
		else
			ev_name = strdup(contention_tracepoints[j].name);

		if (!ev_name)
			return -ENOMEM;

1866
		rec_argv[i++] = "-e";
1867
		rec_argv[i++] = ev_name;
1868 1869
	}

1870 1871 1872
	for (j = 0; j < nr_callgraph_args; j++, i++)
		rec_argv[i] = callgraph_args[j];

1873 1874 1875 1876 1877
	for (j = 1; j < (unsigned int)argc; j++, i++)
		rec_argv[i] = argv[j];

	BUG_ON(i != rec_argc);

1878
	ret = cmd_record(i, rec_argv);
1879 1880
	free(rec_argv);
	return ret;
1881 1882
}

1883 1884 1885 1886 1887 1888 1889 1890 1891 1892 1893 1894 1895 1896 1897 1898 1899 1900
static int parse_map_entry(const struct option *opt, const char *str,
			    int unset __maybe_unused)
{
	unsigned long *len = (unsigned long *)opt->value;
	unsigned long val;
	char *endptr;

	errno = 0;
	val = strtoul(str, &endptr, 0);
	if (*endptr != '\0' || errno != 0) {
		pr_err("invalid BPF map length: %s\n", str);
		return -1;
	}

	*len = val;
	return 0;
}

1901 1902 1903 1904 1905 1906 1907 1908 1909 1910 1911 1912 1913 1914 1915 1916 1917 1918 1919 1920 1921 1922 1923
static int parse_max_stack(const struct option *opt, const char *str,
			   int unset __maybe_unused)
{
	unsigned long *len = (unsigned long *)opt->value;
	long val;
	char *endptr;

	errno = 0;
	val = strtol(str, &endptr, 0);
	if (*endptr != '\0' || errno != 0) {
		pr_err("invalid max stack depth: %s\n", str);
		return -1;
	}

	if (val < 0 || val > sysctl__max_stack()) {
		pr_err("invalid max stack depth: %ld\n", val);
		return -1;
	}

	*len = val;
	return 0;
}

1924 1925 1926 1927 1928 1929 1930 1931 1932 1933 1934 1935 1936 1937 1938 1939 1940 1941 1942 1943 1944 1945 1946 1947 1948 1949 1950 1951 1952 1953 1954 1955 1956 1957 1958 1959 1960 1961 1962 1963 1964 1965 1966 1967 1968 1969 1970 1971 1972 1973 1974 1975 1976 1977 1978 1979 1980 1981 1982 1983 1984 1985 1986 1987 1988 1989 1990 1991 1992 1993 1994 1995 1996
static bool add_lock_type(unsigned int flags)
{
	unsigned int *tmp;

	tmp = realloc(filters.types, (filters.nr_types + 1) * sizeof(*filters.types));
	if (tmp == NULL)
		return false;

	tmp[filters.nr_types++] = flags;
	filters.types = tmp;
	return true;
}

static int parse_lock_type(const struct option *opt __maybe_unused, const char *str,
			   int unset __maybe_unused)
{
	char *s, *tmp, *tok;
	int ret = 0;

	s = strdup(str);
	if (s == NULL)
		return -1;

	for (tok = strtok_r(s, ", ", &tmp); tok; tok = strtok_r(NULL, ", ", &tmp)) {
		unsigned int flags = get_type_flag(tok);

		if (flags == -1U) {
			char buf[32];

			if (strchr(tok, ':'))
			    continue;

			/* try :R and :W suffixes for rwlock, rwsem, ... */
			scnprintf(buf, sizeof(buf), "%s:R", tok);
			flags = get_type_flag(buf);
			if (flags != UINT_MAX) {
				if (!add_lock_type(flags)) {
					ret = -1;
					break;
				}
			}

			scnprintf(buf, sizeof(buf), "%s:W", tok);
			flags = get_type_flag(buf);
			if (flags != UINT_MAX) {
				if (!add_lock_type(flags)) {
					ret = -1;
					break;
				}
			}
			continue;
		}

		if (!add_lock_type(flags)) {
			ret = -1;
			break;
		}

		if (!strcmp(tok, "mutex")) {
			flags = get_type_flag("mutex-spin");
			if (flags != UINT_MAX) {
				if (!add_lock_type(flags)) {
					ret = -1;
					break;
				}
			}
		}
	}

	free(s);
	return ret;
}

1997
int cmd_lock(int argc, const char **argv)
1998
{
1999 2000 2001 2002
	const struct option lock_options[] = {
	OPT_STRING('i', "input", &input_name, "file", "input file name"),
	OPT_INCR('v', "verbose", &verbose, "be more verbose (show symbol address, etc)"),
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, "dump raw trace in ASCII"),
2003
	OPT_BOOLEAN('f', "force", &force, "don't complain, do it"),
2004 2005 2006 2007
	OPT_STRING(0, "vmlinux", &symbol_conf.vmlinux_name,
		   "file", "vmlinux pathname"),
	OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name,
		   "file", "kallsyms pathname"),
2008
	OPT_BOOLEAN('q', "quiet", &quiet, "Do not show any warnings or messages"),
2009 2010 2011
	OPT_END()
	};

2012 2013 2014 2015 2016
	const struct option info_options[] = {
	OPT_BOOLEAN('t', "threads", &info_threads,
		    "dump thread list in perf.data"),
	OPT_BOOLEAN('m', "map", &info_map,
		    "map of lock instances (address:name table)"),
2017
	OPT_PARENT(lock_options)
2018
	};
2019

2020 2021
	const struct option report_options[] = {
	OPT_STRING('k', "key", &sort_key, "acquired",
2022
		    "key for sorting (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"),
2023 2024
	OPT_STRING('F', "field", &output_fields, NULL,
		    "output fields (acquired / contended / avg_wait / wait_total / wait_max / wait_min)"),
2025
	/* TODO: type */
2026 2027
	OPT_BOOLEAN('c', "combine-locks", &combine_locks,
		    "combine locks in the same class"),
2028 2029
	OPT_BOOLEAN('t', "threads", &show_thread_stats,
		    "show per-thread lock stats"),
2030
	OPT_INTEGER('E', "entries", &print_nr_entries, "display this many functions"),
2031
	OPT_PARENT(lock_options)
2032
	};
2033

2034
	struct option contention_options[] = {
2035 2036 2037 2038
	OPT_STRING('k', "key", &sort_key, "wait_total",
		    "key for sorting (contended / wait_total / wait_max / wait_min / avg_wait)"),
	OPT_STRING('F', "field", &output_fields, "contended,wait_total,wait_max,avg_wait",
		    "output fields (contended / wait_total / wait_max / wait_min / avg_wait)"),
2039 2040
	OPT_BOOLEAN('t', "threads", &show_thread_stats,
		    "show per-thread lock stats"),
2041
	OPT_BOOLEAN('b', "use-bpf", &use_bpf, "use BPF program to collect lock contention stats"),
2042 2043 2044 2045 2046 2047 2048 2049
	OPT_BOOLEAN('a', "all-cpus", &target.system_wide,
		    "System-wide collection from all CPUs"),
	OPT_STRING('C', "cpu", &target.cpu_list, "cpu",
		    "List of cpus to monitor"),
	OPT_STRING('p', "pid", &target.pid, "pid",
		   "Trace on existing process id"),
	OPT_STRING(0, "tid", &target.tid, "tid",
		   "Trace on existing thread id (exclusive to --pid)"),
2050 2051
	OPT_CALLBACK(0, "map-nr-entries", &bpf_map_entries, "num",
		     "Max number of BPF map entries", parse_map_entry),
2052 2053 2054
	OPT_CALLBACK(0, "max-stack", &max_stack_depth, "num",
		     "Set the maximum stack depth when collecting lopck contention, "
		     "Default: " __stringify(CONTENTION_STACK_DEPTH), parse_max_stack),
2055 2056 2057
	OPT_INTEGER(0, "stack-skip", &stack_skip,
		    "Set the number of stack depth to skip when finding a lock caller, "
		    "Default: " __stringify(CONTENTION_STACK_SKIP)),
2058
	OPT_INTEGER('E', "entries", &print_nr_entries, "display this many functions"),
2059
	OPT_BOOLEAN('l', "lock-addr", &show_lock_addrs, "show lock stats by address"),
2060 2061
	OPT_CALLBACK('Y', "type-filter", NULL, "FLAGS",
		     "Filter specific type of locks", parse_lock_type),
2062 2063 2064
	OPT_PARENT(lock_options)
	};

2065 2066 2067 2068
	const char * const info_usage[] = {
		"perf lock info [<options>]",
		NULL
	};
2069
	const char *const lock_subcommands[] = { "record", "report", "script",
2070
						 "info", "contention", NULL };
2071 2072
	const char *lock_usage[] = {
		NULL,
2073 2074 2075 2076 2077 2078
		NULL
	};
	const char * const report_usage[] = {
		"perf lock report [<options>]",
		NULL
	};
2079 2080 2081 2082
	const char * const contention_usage[] = {
		"perf lock contention [<options>]",
		NULL
	};
2083
	unsigned int i;
2084
	int rc = 0;
2085 2086

	for (i = 0; i < LOCKHASH_SIZE; i++)
2087
		INIT_HLIST_HEAD(lockhash_table + i);
2088

2089 2090
	argc = parse_options_subcommand(argc, argv, lock_options, lock_subcommands,
					lock_usage, PARSE_OPT_STOP_AT_NON_OPTION);
2091 2092 2093
	if (!argc)
		usage_with_options(lock_usage, lock_options);

2094
	if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) {
2095
		return __cmd_record(argc, argv);
2096
	} else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) {
2097
		trace_handler = &report_lock_ops;
2098 2099
		if (argc) {
			argc = parse_options(argc, argv,
2100
					     report_options, report_usage, 0);
2101
			if (argc)
2102
				usage_with_options(report_usage, report_options);
2103
		}
2104
		rc = __cmd_report(false);
2105 2106
	} else if (!strcmp(argv[0], "script")) {
		/* Aliased to 'perf script' */
2107
		return cmd_script(argc, argv);
2108 2109 2110 2111 2112 2113 2114
	} 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);
		}
2115 2116
		/* recycling report_lock_ops */
		trace_handler = &report_lock_ops;
2117
		rc = __cmd_report(true);
2118 2119
	} else if (strlen(argv[0]) > 2 && strstarts("contention", argv[0])) {
		trace_handler = &contention_lock_ops;
2120 2121 2122
		sort_key = "wait_total";
		output_fields = "contended,wait_total,wait_max,avg_wait";

2123 2124 2125 2126
#ifndef HAVE_BPF_SKEL
		set_option_nobuild(contention_options, 'b', "use-bpf",
				   "no BUILD_BPF_SKEL=1", false);
#endif
2127 2128 2129 2130
		if (argc) {
			argc = parse_options(argc, argv, contention_options,
					     contention_usage, 0);
		}
2131 2132 2133 2134 2135 2136 2137 2138 2139 2140

		if (show_thread_stats && show_lock_addrs) {
			pr_err("Cannot use thread and addr mode together\n");
			parse_options_usage(contention_usage, contention_options,
					    "threads", 0);
			parse_options_usage(NULL, contention_options,
					    "lock-addr", 0);
			return -1;
		}

2141
		rc = __cmd_contention(argc, argv);
2142 2143 2144 2145
	} else {
		usage_with_options(lock_usage, lock_options);
	}

2146
	return rc;
2147
}