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