• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 
thread_stat_find(u32 tid)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 
thread_stat_insert(struct thread_stat * new)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 
thread_stat_findnew_after_first(u32 tid)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 
thread_stat_findnew_first(u32 tid)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)
SINGLE_KEY(nr_contended)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 
select_key(void)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 
insert_to_result(struct lock_stat * st,int (* bigger)(struct lock_stat *,struct lock_stat *))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 */
pop_from_result(void)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 
lock_stat_findnew(void * addr,const char * name)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 
get_seq(struct thread_stat * ts,void * addr)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
report_lock_acquire_event(struct trace_acquire_event * acquire_event,struct event * __event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
report_lock_acquired_event(struct trace_acquired_event * acquired_event,struct event * __event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
report_lock_contended_event(struct trace_contended_event * contended_event,struct event * __event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
report_lock_release_event(struct trace_release_event * release_event,struct event * __event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
process_lock_acquire_event(void * data,struct event * event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
process_lock_acquired_event(void * data,struct event * event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
process_lock_contended_event(void * data,struct event * event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
process_lock_release_event(void * data,struct event * event __used,int cpu __used,u64 timestamp __used,struct thread * thread __used)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
process_raw_event(void * data,int cpu,u64 timestamp,struct thread * thread)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 
print_bad_events(int bad,int total)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 */
print_result(void)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 
dump_threads(void)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 
dump_map(void)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 
dump_info(void)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 
process_sample_event(union perf_event * event,struct perf_sample * sample,struct perf_evsel * evsel __used,struct perf_session * s)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 
read_events(void)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 
sort_result(void)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 
__cmd_report(void)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 
__cmd_record(int argc,const char ** argv)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 
cmd_lock(int argc,const char ** argv,const char * prefix __used)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