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