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