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