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