builtin-lock.c 23 KB

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