aboutsummaryrefslogtreecommitdiffstats
path: root/tools/perf/builtin-lock.c
diff options
context:
space:
mode:
Diffstat (limited to 'tools/perf/builtin-lock.c')
-rw-r--r--tools/perf/builtin-lock.c724
1 files changed, 724 insertions, 0 deletions
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
new file mode 100644
index 000000000000..2b5f88754c26
--- /dev/null
+++ b/tools/perf/builtin-lock.c
@@ -0,0 +1,724 @@
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#include <sys/prctl.h>
18#include <semaphore.h>
19#include <pthread.h>
20#include <math.h>
21#include <limits.h>
22
23#include <linux/list.h>
24#include <linux/hash.h>
25
26/* based on kernel/lockdep.c */
27#define LOCKHASH_BITS 12
28#define LOCKHASH_SIZE (1UL << LOCKHASH_BITS)
29
30static struct list_head lockhash_table[LOCKHASH_SIZE];
31
32#define __lockhashfn(key) hash_long((unsigned long)key, LOCKHASH_BITS)
33#define lockhashentry(key) (lockhash_table + __lockhashfn((key)))
34
35#define LOCK_STATE_UNLOCKED 0 /* initial state */
36#define LOCK_STATE_LOCKED 1
37
38struct lock_stat {
39 struct list_head hash_entry;
40 struct rb_node rb; /* used for sorting */
41
42 /* FIXME: raw_field_value() returns unsigned long long,
43 * so address of lockdep_map should be dealed as 64bit.
44 * Is there more better solution? */
45 void *addr; /* address of lockdep_map, used as ID */
46 char *name; /* for strcpy(), we cannot use const */
47 char *file;
48 unsigned int line;
49
50 int state;
51 u64 prev_event_time; /* timestamp of previous event */
52
53 unsigned int nr_acquired;
54 unsigned int nr_acquire;
55 unsigned int nr_contended;
56 unsigned int nr_release;
57
58 /* these times are in nano sec. */
59 u64 wait_time_total;
60 u64 wait_time_min;
61 u64 wait_time_max;
62};
63
64/* build simple key function one is bigger than two */
65#define SINGLE_KEY(member) \
66 static int lock_stat_key_ ## member(struct lock_stat *one, \
67 struct lock_stat *two) \
68 { \
69 return one->member > two->member; \
70 }
71
72SINGLE_KEY(nr_acquired)
73SINGLE_KEY(nr_contended)
74SINGLE_KEY(wait_time_total)
75SINGLE_KEY(wait_time_min)
76SINGLE_KEY(wait_time_max)
77
78struct lock_key {
79 /*
80 * name: the value for specify by user
81 * this should be simpler than raw name of member
82 * e.g. nr_acquired -> acquired, wait_time_total -> wait_total
83 */
84 const char *name;
85 int (*key)(struct lock_stat*, struct lock_stat*);
86};
87
88static const char *sort_key = "acquired";
89static int (*compare)(struct lock_stat *, struct lock_stat *);
90
91#define DEF_KEY_LOCK(name, fn_suffix) \
92 { #name, lock_stat_key_ ## fn_suffix }
93struct lock_key keys[] = {
94 DEF_KEY_LOCK(acquired, nr_acquired),
95 DEF_KEY_LOCK(contended, nr_contended),
96 DEF_KEY_LOCK(wait_total, wait_time_total),
97 DEF_KEY_LOCK(wait_min, wait_time_min),
98 DEF_KEY_LOCK(wait_max, wait_time_max),
99
100 /* extra comparisons much complicated should be here */
101
102 { NULL, NULL }
103};
104
105static void select_key(void)
106{
107 int i;
108
109 for (i = 0; keys[i].name; i++) {
110 if (!strcmp(keys[i].name, sort_key)) {
111 compare = keys[i].key;
112 return;
113 }
114 }
115
116 die("Unknown compare key:%s\n", sort_key);
117}
118
119static struct rb_root result; /* place to store sorted data */
120
121static void insert_to_result(struct lock_stat *st,
122 int (*bigger)(struct lock_stat *,
123 struct lock_stat *))
124{
125 struct rb_node **rb = &result.rb_node;
126 struct rb_node *parent = NULL;
127 struct lock_stat *p;
128
129 while (*rb) {
130 p = container_of(*rb, struct lock_stat, rb);
131 parent = *rb;
132
133 if (bigger(st, p))
134 rb = &(*rb)->rb_left;
135 else
136 rb = &(*rb)->rb_right;
137 }
138
139 rb_link_node(&st->rb, parent, rb);
140 rb_insert_color(&st->rb, &result);
141}
142
143/* returns left most element of result, and erase it */
144static struct lock_stat *pop_from_result(void)
145{
146 struct rb_node *node = result.rb_node;
147
148 if (!node)
149 return NULL;
150
151 while (node->rb_left)
152 node = node->rb_left;
153
154 rb_erase(node, &result);
155 return container_of(node, struct lock_stat, rb);
156}
157
158static struct lock_stat *lock_stat_findnew(void *addr, const char *name,
159 const char *file, unsigned int line)
160{
161 struct list_head *entry = lockhashentry(addr);
162 struct lock_stat *ret, *new;
163
164 list_for_each_entry(ret, entry, hash_entry) {
165 if (ret->addr == addr)
166 return ret;
167 }
168
169 new = zalloc(sizeof(struct lock_stat));
170 if (!new)
171 goto alloc_failed;
172
173 new->addr = addr;
174 new->name = zalloc(sizeof(char) * strlen(name) + 1);
175 if (!new->name)
176 goto alloc_failed;
177 strcpy(new->name, name);
178 new->file = zalloc(sizeof(char) * strlen(file) + 1);
179 if (!new->file)
180 goto alloc_failed;
181 strcpy(new->file, file);
182 new->line = line;
183
184 /* LOCK_STATE_UNLOCKED == 0 isn't guaranteed forever */
185 new->state = LOCK_STATE_UNLOCKED;
186 new->wait_time_min = ULLONG_MAX;
187
188 list_add(&new->hash_entry, entry);
189 return new;
190
191alloc_failed:
192 die("memory allocation failed\n");
193}
194
195static char const *input_name = "perf.data";
196
197static int profile_cpu = -1;
198
199struct raw_event_sample {
200 u32 size;
201 char data[0];
202};
203
204struct trace_acquire_event {
205 void *addr;
206 const char *name;
207 const char *file;
208 unsigned int line;
209};
210
211struct trace_acquired_event {
212 void *addr;
213 const char *name;
214 const char *file;
215 unsigned int line;
216};
217
218struct trace_contended_event {
219 void *addr;
220 const char *name;
221 const char *file;
222 unsigned int line;
223};
224
225struct trace_release_event {
226 void *addr;
227 const char *name;
228 const char *file;
229 unsigned int line;
230};
231
232struct trace_lock_handler {
233 void (*acquire_event)(struct trace_acquire_event *,
234 struct event *,
235 int cpu,
236 u64 timestamp,
237 struct thread *thread);
238
239 void (*acquired_event)(struct trace_acquired_event *,
240 struct event *,
241 int cpu,
242 u64 timestamp,
243 struct thread *thread);
244
245 void (*contended_event)(struct trace_contended_event *,
246 struct event *,
247 int cpu,
248 u64 timestamp,
249 struct thread *thread);
250
251 void (*release_event)(struct trace_release_event *,
252 struct event *,
253 int cpu,
254 u64 timestamp,
255 struct thread *thread);
256};
257
258static void prof_lock_acquire_event(struct trace_acquire_event *acquire_event,
259 struct event *__event __used,
260 int cpu __used,
261 u64 timestamp,
262 struct thread *thread __used)
263{
264 struct lock_stat *st;
265
266 st = lock_stat_findnew(acquire_event->addr, acquire_event->name,
267 acquire_event->file, acquire_event->line);
268
269 switch (st->state) {
270 case LOCK_STATE_UNLOCKED:
271 break;
272 case LOCK_STATE_LOCKED:
273 break;
274 default:
275 BUG_ON(1);
276 break;
277 }
278
279 st->prev_event_time = timestamp;
280}
281
282static void prof_lock_acquired_event(struct trace_acquired_event *acquired_event,
283 struct event *__event __used,
284 int cpu __used,
285 u64 timestamp,
286 struct thread *thread __used)
287{
288 struct lock_stat *st;
289
290 st = lock_stat_findnew(acquired_event->addr, acquired_event->name,
291 acquired_event->file, acquired_event->line);
292
293 switch (st->state) {
294 case LOCK_STATE_UNLOCKED:
295 st->state = LOCK_STATE_LOCKED;
296 st->nr_acquired++;
297 break;
298 case LOCK_STATE_LOCKED:
299 break;
300 default:
301 BUG_ON(1);
302 break;
303 }
304
305 st->prev_event_time = timestamp;
306}
307
308static void prof_lock_contended_event(struct trace_contended_event *contended_event,
309 struct event *__event __used,
310 int cpu __used,
311 u64 timestamp,
312 struct thread *thread __used)
313{
314 struct lock_stat *st;
315
316 st = lock_stat_findnew(contended_event->addr, contended_event->name,
317 contended_event->file, contended_event->line);
318
319 switch (st->state) {
320 case LOCK_STATE_UNLOCKED:
321 break;
322 case LOCK_STATE_LOCKED:
323 st->nr_contended++;
324 break;
325 default:
326 BUG_ON(1);
327 break;
328 }
329
330 st->prev_event_time = timestamp;
331}
332
333static void prof_lock_release_event(struct trace_release_event *release_event,
334 struct event *__event __used,
335 int cpu __used,
336 u64 timestamp,
337 struct thread *thread __used)
338{
339 struct lock_stat *st;
340 u64 hold_time;
341
342 st = lock_stat_findnew(release_event->addr, release_event->name,
343 release_event->file, release_event->line);
344
345 switch (st->state) {
346 case LOCK_STATE_UNLOCKED:
347 break;
348 case LOCK_STATE_LOCKED:
349 st->state = LOCK_STATE_UNLOCKED;
350 hold_time = timestamp - st->prev_event_time;
351
352 if (timestamp < st->prev_event_time) {
353 /* terribly, this can happen... */
354 goto end;
355 }
356
357 if (st->wait_time_min > hold_time)
358 st->wait_time_min = hold_time;
359 if (st->wait_time_max < hold_time)
360 st->wait_time_max = hold_time;
361 st->wait_time_total += hold_time;
362
363 st->nr_release++;
364 break;
365 default:
366 BUG_ON(1);
367 break;
368 }
369
370end:
371 st->prev_event_time = timestamp;
372}
373
374/* lock oriented handlers */
375/* TODO: handlers for CPU oriented, thread oriented */
376static struct trace_lock_handler prof_lock_ops = {
377 .acquire_event = prof_lock_acquire_event,
378 .acquired_event = prof_lock_acquired_event,
379 .contended_event = prof_lock_contended_event,
380 .release_event = prof_lock_release_event,
381};
382
383static struct trace_lock_handler *trace_handler;
384
385static void
386process_lock_acquire_event(void *data,
387 struct event *event __used,
388 int cpu __used,
389 u64 timestamp __used,
390 struct thread *thread __used)
391{
392 struct trace_acquire_event acquire_event;
393 u64 tmp; /* this is required for casting... */
394
395 tmp = raw_field_value(event, "lockdep_addr", data);
396 memcpy(&acquire_event.addr, &tmp, sizeof(void *));
397 acquire_event.name = (char *)raw_field_ptr(event, "name", data);
398 acquire_event.file = (char *)raw_field_ptr(event, "file", data);
399 acquire_event.line =
400 (unsigned int)raw_field_value(event, "line", data);
401
402 if (trace_handler->acquire_event) {
403 trace_handler->acquire_event(&acquire_event,
404 event, cpu, timestamp, thread);
405 }
406}
407
408static void
409process_lock_acquired_event(void *data,
410 struct event *event __used,
411 int cpu __used,
412 u64 timestamp __used,
413 struct thread *thread __used)
414{
415 struct trace_acquired_event acquired_event;
416 u64 tmp; /* this is required for casting... */
417
418 tmp = raw_field_value(event, "lockdep_addr", data);
419 memcpy(&acquired_event.addr, &tmp, sizeof(void *));
420 acquired_event.name = (char *)raw_field_ptr(event, "name", data);
421 acquired_event.file = (char *)raw_field_ptr(event, "file", data);
422 acquired_event.line =
423 (unsigned int)raw_field_value(event, "line", data);
424
425 if (trace_handler->acquire_event) {
426 trace_handler->acquired_event(&acquired_event,
427 event, cpu, timestamp, thread);
428 }
429}
430
431static void
432process_lock_contended_event(void *data,
433 struct event *event __used,
434 int cpu __used,
435 u64 timestamp __used,
436 struct thread *thread __used)
437{
438 struct trace_contended_event contended_event;
439 u64 tmp; /* this is required for casting... */
440
441 tmp = raw_field_value(event, "lockdep_addr", data);
442 memcpy(&contended_event.addr, &tmp, sizeof(void *));
443 contended_event.name = (char *)raw_field_ptr(event, "name", data);
444 contended_event.file = (char *)raw_field_ptr(event, "file", data);
445 contended_event.line =
446 (unsigned int)raw_field_value(event, "line", data);
447
448 if (trace_handler->acquire_event) {
449 trace_handler->contended_event(&contended_event,
450 event, cpu, timestamp, thread);
451 }
452}
453
454static void
455process_lock_release_event(void *data,
456 struct event *event __used,
457 int cpu __used,
458 u64 timestamp __used,
459 struct thread *thread __used)
460{
461 struct trace_release_event release_event;
462 u64 tmp; /* this is required for casting... */
463
464 tmp = raw_field_value(event, "lockdep_addr", data);
465 memcpy(&release_event.addr, &tmp, sizeof(void *));
466 release_event.name = (char *)raw_field_ptr(event, "name", data);
467 release_event.file = (char *)raw_field_ptr(event, "file", data);
468 release_event.line =
469 (unsigned int)raw_field_value(event, "line", data);
470
471 if (trace_handler->acquire_event) {
472 trace_handler->release_event(&release_event,
473 event, cpu, timestamp, thread);
474 }
475}
476
477static void
478process_raw_event(void *data, int cpu,
479 u64 timestamp, struct thread *thread)
480{
481 struct event *event;
482 int type;
483
484 type = trace_parse_common_type(data);
485 event = trace_find_event(type);
486
487 if (!strcmp(event->name, "lock_acquire"))
488 process_lock_acquire_event(data, event, cpu, timestamp, thread);
489 if (!strcmp(event->name, "lock_acquired"))
490 process_lock_acquired_event(data, event, cpu, timestamp, thread);
491 if (!strcmp(event->name, "lock_contended"))
492 process_lock_contended_event(data, event, cpu, timestamp, thread);
493 if (!strcmp(event->name, "lock_release"))
494 process_lock_release_event(data, event, cpu, timestamp, thread);
495}
496
497static int process_sample_event(event_t *event, struct perf_session *session)
498{
499 struct thread *thread;
500 struct sample_data data;
501
502 bzero(&data, sizeof(struct sample_data));
503 event__parse_sample(event, session->sample_type, &data);
504 thread = perf_session__findnew(session, data.pid);
505
506 /*
507 * FIXME: this causes warn on 32bit environment
508 * because of (void *)data.ip (type of data.ip is u64)
509 */
510/* dump_printf("(IP, %d): %d/%d: %p period: %llu\n", */
511/* event->header.misc, */
512/* data.pid, data.tid, (void *)data.ip, data.period); */
513
514 if (thread == NULL) {
515 pr_debug("problem processing %d event, skipping it.\n",
516 event->header.type);
517 return -1;
518 }
519
520 dump_printf(" ... thread: %s:%d\n", thread->comm, thread->pid);
521
522 if (profile_cpu != -1 && profile_cpu != (int) data.cpu)
523 return 0;
524
525 process_raw_event(data.raw_data, data.cpu, data.time, thread);
526
527 return 0;
528}
529
530/* TODO: various way to print, coloring, nano or milli sec */
531static void print_result(void)
532{
533 struct lock_stat *st;
534 char cut_name[20];
535
536 printf("%18s ", "ID");
537 printf("%20s ", "Name");
538 printf("%10s ", "acquired");
539 printf("%10s ", "contended");
540
541 printf("%15s ", "total wait (ns)");
542 printf("%15s ", "max wait (ns)");
543 printf("%15s ", "min wait (ns)");
544
545 printf("\n\n");
546
547 while ((st = pop_from_result())) {
548 bzero(cut_name, 20);
549
550 printf("%p ", st->addr);
551
552 if (strlen(st->name) < 16) {
553 /* output raw name */
554 printf("%20s ", st->name);
555 } else {
556 strncpy(cut_name, st->name, 16);
557 cut_name[16] = '.';
558 cut_name[17] = '.';
559 cut_name[18] = '.';
560 cut_name[19] = '\0';
561 /* cut off name for saving output style */
562 printf("%20s ", cut_name);
563 }
564
565 printf("%10u ", st->nr_acquired);
566 printf("%10u ", st->nr_contended);
567
568 printf("%15llu ", st->wait_time_total);
569 printf("%15llu ", st->wait_time_max);
570 printf("%15llu ", st->wait_time_min == ULLONG_MAX ?
571 0 : st->wait_time_min);
572 printf("\n");
573 }
574}
575
576static void dump_map(void)
577{
578 unsigned int i;
579 struct lock_stat *st;
580
581 for (i = 0; i < LOCKHASH_SIZE; i++) {
582 list_for_each_entry(st, &lockhash_table[i], hash_entry) {
583 printf("%p: %s (src: %s, line: %u)\n",
584 st->addr, st->name, st->file, st->line);
585 }
586 }
587}
588
589static struct perf_event_ops eops = {
590 .sample = process_sample_event,
591 .comm = event__process_comm,
592};
593
594static struct perf_session *session;
595
596static int read_events(void)
597{
598 session = perf_session__new(input_name, O_RDONLY, 0);
599 if (!session)
600 die("Initializing perf session failed\n");
601
602 return perf_session__process_events(session, &eops);
603}
604
605static void sort_result(void)
606{
607 unsigned int i;
608 struct lock_stat *st;
609
610 for (i = 0; i < LOCKHASH_SIZE; i++) {
611 list_for_each_entry(st, &lockhash_table[i], hash_entry) {
612 insert_to_result(st, compare);
613 }
614 }
615}
616
617static void __cmd_prof(void)
618{
619 setup_pager();
620 select_key();
621 read_events();
622 sort_result();
623 print_result();
624}
625
626static const char * const prof_usage[] = {
627 "perf sched prof [<options>]",
628 NULL
629};
630
631static const struct option prof_options[] = {
632 OPT_STRING('k', "key", &sort_key, "acquired",
633 "key for sorting"),
634 /* TODO: type */
635 OPT_END()
636};
637
638static const char * const lock_usage[] = {
639 "perf lock [<options>] {record|trace|prof}",
640 NULL
641};
642
643static const struct option lock_options[] = {
644 OPT_STRING('i', "input", &input_name, "file",
645 "input file name"),
646 OPT_BOOLEAN('v', "verbose", &verbose,
647 "be more verbose (show symbol address, etc)"),
648 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
649 "dump raw trace in ASCII"),
650 OPT_END()
651};
652
653static const char *record_args[] = {
654 "record",
655 "-a",
656 "-R",
657 "-M",
658 "-f",
659 "-m", "1024",
660 "-c", "1",
661 "-e", "lock:lock_acquire:r",
662 "-e", "lock:lock_acquired:r",
663 "-e", "lock:lock_contended:r",
664 "-e", "lock:lock_release:r",
665};
666
667static int __cmd_record(int argc, const char **argv)
668{
669 unsigned int rec_argc, i, j;
670 const char **rec_argv;
671
672 rec_argc = ARRAY_SIZE(record_args) + argc - 1;
673 rec_argv = calloc(rec_argc + 1, sizeof(char *));
674
675 for (i = 0; i < ARRAY_SIZE(record_args); i++)
676 rec_argv[i] = strdup(record_args[i]);
677
678 for (j = 1; j < (unsigned int)argc; j++, i++)
679 rec_argv[i] = argv[j];
680
681 BUG_ON(i != rec_argc);
682
683 return cmd_record(i, rec_argv, NULL);
684}
685
686int cmd_lock(int argc, const char **argv, const char *prefix __used)
687{
688 unsigned int i;
689
690 symbol__init();
691 for (i = 0; i < LOCKHASH_SIZE; i++)
692 INIT_LIST_HEAD(lockhash_table + i);
693
694 argc = parse_options(argc, argv, lock_options, lock_usage,
695 PARSE_OPT_STOP_AT_NON_OPTION);
696 if (!argc)
697 usage_with_options(lock_usage, lock_options);
698
699 if (!strncmp(argv[0], "rec", 3)) {
700 return __cmd_record(argc, argv);
701 } else if (!strncmp(argv[0], "prof", 4)) {
702 trace_handler = &prof_lock_ops;
703 if (argc) {
704 argc = parse_options(argc, argv,
705 prof_options, prof_usage, 0);
706 if (argc)
707 usage_with_options(prof_usage, prof_options);
708 }
709 __cmd_prof();
710 } else if (!strcmp(argv[0], "trace")) {
711 /* Aliased to 'perf trace' */
712 return cmd_trace(argc, argv, prefix);
713 } else if (!strcmp(argv[0], "map")) {
714 /* recycling prof_lock_ops */
715 trace_handler = &prof_lock_ops;
716 setup_pager();
717 read_events();
718 dump_map();
719 } else {
720 usage_with_options(lock_usage, lock_options);
721 }
722
723 return 0;
724}