trace_functions_graph.c 14 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611
  1. /*
  2. *
  3. * Function graph tracer.
  4. * Copyright (c) 2008 Frederic Weisbecker <fweisbec@gmail.com>
  5. * Mostly borrowed from function tracer which
  6. * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
  7. *
  8. */
  9. #include <linux/debugfs.h>
  10. #include <linux/uaccess.h>
  11. #include <linux/ftrace.h>
  12. #include <linux/fs.h>
  13. #include "trace.h"
  14. #define TRACE_GRAPH_INDENT 2
  15. /* Flag options */
  16. #define TRACE_GRAPH_PRINT_OVERRUN 0x1
  17. #define TRACE_GRAPH_PRINT_CPU 0x2
  18. #define TRACE_GRAPH_PRINT_OVERHEAD 0x4
  19. #define TRACE_GRAPH_PRINT_PROC 0x8
  20. static struct tracer_opt trace_opts[] = {
  21. /* Display overruns ? */
  22. { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
  23. /* Display CPU ? */
  24. { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
  25. /* Display Overhead ? */
  26. { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
  27. /* Display proc name/pid */
  28. { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
  29. { } /* Empty entry */
  30. };
  31. static struct tracer_flags tracer_flags = {
  32. /* Don't display overruns and proc by default */
  33. .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD,
  34. .opts = trace_opts
  35. };
  36. /* pid on the last trace processed */
  37. static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 };
  38. static int graph_trace_init(struct trace_array *tr)
  39. {
  40. int cpu, ret;
  41. for_each_online_cpu(cpu)
  42. tracing_reset(tr, cpu);
  43. ret = register_ftrace_graph(&trace_graph_return,
  44. &trace_graph_entry);
  45. if (ret)
  46. return ret;
  47. tracing_start_cmdline_record();
  48. return 0;
  49. }
  50. static void graph_trace_reset(struct trace_array *tr)
  51. {
  52. tracing_stop_cmdline_record();
  53. unregister_ftrace_graph();
  54. }
  55. static inline int log10_cpu(int nb)
  56. {
  57. if (nb / 100)
  58. return 3;
  59. if (nb / 10)
  60. return 2;
  61. return 1;
  62. }
  63. static enum print_line_t
  64. print_graph_cpu(struct trace_seq *s, int cpu)
  65. {
  66. int i;
  67. int ret;
  68. int log10_this = log10_cpu(cpu);
  69. int log10_all = log10_cpu(cpus_weight_nr(cpu_online_map));
  70. /*
  71. * Start with a space character - to make it stand out
  72. * to the right a bit when trace output is pasted into
  73. * email:
  74. */
  75. ret = trace_seq_printf(s, " ");
  76. /*
  77. * Tricky - we space the CPU field according to the max
  78. * number of online CPUs. On a 2-cpu system it would take
  79. * a maximum of 1 digit - on a 128 cpu system it would
  80. * take up to 3 digits:
  81. */
  82. for (i = 0; i < log10_all - log10_this; i++) {
  83. ret = trace_seq_printf(s, " ");
  84. if (!ret)
  85. return TRACE_TYPE_PARTIAL_LINE;
  86. }
  87. ret = trace_seq_printf(s, "%d) ", cpu);
  88. if (!ret)
  89. return TRACE_TYPE_PARTIAL_LINE;
  90. return TRACE_TYPE_HANDLED;
  91. }
  92. #define TRACE_GRAPH_PROCINFO_LENGTH 14
  93. static enum print_line_t
  94. print_graph_proc(struct trace_seq *s, pid_t pid)
  95. {
  96. int i;
  97. int ret;
  98. int len;
  99. char comm[8];
  100. int spaces = 0;
  101. /* sign + log10(MAX_INT) + '\0' */
  102. char pid_str[11];
  103. strncpy(comm, trace_find_cmdline(pid), 7);
  104. comm[7] = '\0';
  105. sprintf(pid_str, "%d", pid);
  106. /* 1 stands for the "-" character */
  107. len = strlen(comm) + strlen(pid_str) + 1;
  108. if (len < TRACE_GRAPH_PROCINFO_LENGTH)
  109. spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
  110. /* First spaces to align center */
  111. for (i = 0; i < spaces / 2; i++) {
  112. ret = trace_seq_printf(s, " ");
  113. if (!ret)
  114. return TRACE_TYPE_PARTIAL_LINE;
  115. }
  116. ret = trace_seq_printf(s, "%s-%s", comm, pid_str);
  117. if (!ret)
  118. return TRACE_TYPE_PARTIAL_LINE;
  119. /* Last spaces to align center */
  120. for (i = 0; i < spaces - (spaces / 2); i++) {
  121. ret = trace_seq_printf(s, " ");
  122. if (!ret)
  123. return TRACE_TYPE_PARTIAL_LINE;
  124. }
  125. return TRACE_TYPE_HANDLED;
  126. }
  127. /* If the pid changed since the last trace, output this event */
  128. static enum print_line_t
  129. verif_pid(struct trace_seq *s, pid_t pid, int cpu)
  130. {
  131. pid_t prev_pid;
  132. int ret;
  133. if (last_pid[cpu] != -1 && last_pid[cpu] == pid)
  134. return TRACE_TYPE_HANDLED;
  135. prev_pid = last_pid[cpu];
  136. last_pid[cpu] = pid;
  137. /*
  138. * Context-switch trace line:
  139. ------------------------------------------
  140. | 1) migration/0--1 => sshd-1755
  141. ------------------------------------------
  142. */
  143. ret = trace_seq_printf(s,
  144. " ------------------------------------------\n");
  145. if (!ret)
  146. TRACE_TYPE_PARTIAL_LINE;
  147. ret = print_graph_cpu(s, cpu);
  148. if (ret == TRACE_TYPE_PARTIAL_LINE)
  149. TRACE_TYPE_PARTIAL_LINE;
  150. ret = print_graph_proc(s, prev_pid);
  151. if (ret == TRACE_TYPE_PARTIAL_LINE)
  152. TRACE_TYPE_PARTIAL_LINE;
  153. ret = trace_seq_printf(s, " => ");
  154. if (!ret)
  155. TRACE_TYPE_PARTIAL_LINE;
  156. ret = print_graph_proc(s, pid);
  157. if (ret == TRACE_TYPE_PARTIAL_LINE)
  158. TRACE_TYPE_PARTIAL_LINE;
  159. ret = trace_seq_printf(s,
  160. "\n ------------------------------------------\n\n");
  161. if (!ret)
  162. TRACE_TYPE_PARTIAL_LINE;
  163. return ret;
  164. }
  165. static bool
  166. trace_branch_is_leaf(struct trace_iterator *iter,
  167. struct ftrace_graph_ent_entry *curr)
  168. {
  169. struct ring_buffer_iter *ring_iter;
  170. struct ring_buffer_event *event;
  171. struct ftrace_graph_ret_entry *next;
  172. ring_iter = iter->buffer_iter[iter->cpu];
  173. if (!ring_iter)
  174. return false;
  175. event = ring_buffer_iter_peek(ring_iter, NULL);
  176. if (!event)
  177. return false;
  178. next = ring_buffer_event_data(event);
  179. if (next->ent.type != TRACE_GRAPH_RET)
  180. return false;
  181. if (curr->ent.pid != next->ent.pid ||
  182. curr->graph_ent.func != next->ret.func)
  183. return false;
  184. return true;
  185. }
  186. static enum print_line_t
  187. print_graph_duration(unsigned long long duration, struct trace_seq *s)
  188. {
  189. unsigned long nsecs_rem = do_div(duration, 1000);
  190. /* log10(ULONG_MAX) + '\0' */
  191. char msecs_str[21];
  192. char nsecs_str[5];
  193. int ret, len;
  194. int i;
  195. sprintf(msecs_str, "%lu", (unsigned long) duration);
  196. /* Print msecs */
  197. ret = trace_seq_printf(s, msecs_str);
  198. if (!ret)
  199. return TRACE_TYPE_PARTIAL_LINE;
  200. len = strlen(msecs_str);
  201. /* Print nsecs (we don't want to exceed 7 numbers) */
  202. if (len < 7) {
  203. snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem);
  204. ret = trace_seq_printf(s, ".%s", nsecs_str);
  205. if (!ret)
  206. return TRACE_TYPE_PARTIAL_LINE;
  207. len += strlen(nsecs_str);
  208. }
  209. ret = trace_seq_printf(s, " us ");
  210. if (!ret)
  211. return TRACE_TYPE_PARTIAL_LINE;
  212. /* Print remaining spaces to fit the row's width */
  213. for (i = len; i < 7; i++) {
  214. ret = trace_seq_printf(s, " ");
  215. if (!ret)
  216. return TRACE_TYPE_PARTIAL_LINE;
  217. }
  218. ret = trace_seq_printf(s, "| ");
  219. if (!ret)
  220. return TRACE_TYPE_PARTIAL_LINE;
  221. return TRACE_TYPE_HANDLED;
  222. }
  223. /* Signal a overhead of time execution to the output */
  224. static int
  225. print_graph_overhead(unsigned long long duration, struct trace_seq *s)
  226. {
  227. /* Duration exceeded 100 msecs */
  228. if (duration > 100000ULL)
  229. return trace_seq_printf(s, "! ");
  230. /* Duration exceeded 10 msecs */
  231. if (duration > 10000ULL)
  232. return trace_seq_printf(s, "+ ");
  233. return trace_seq_printf(s, " ");
  234. }
  235. /* Case of a leaf function on its call entry */
  236. static enum print_line_t
  237. print_graph_entry_leaf(struct trace_iterator *iter,
  238. struct ftrace_graph_ent_entry *entry, struct trace_seq *s)
  239. {
  240. struct ftrace_graph_ret_entry *ret_entry;
  241. struct ftrace_graph_ret *graph_ret;
  242. struct ring_buffer_event *event;
  243. struct ftrace_graph_ent *call;
  244. unsigned long long duration;
  245. int ret;
  246. int i;
  247. event = ring_buffer_read(iter->buffer_iter[iter->cpu], NULL);
  248. ret_entry = ring_buffer_event_data(event);
  249. graph_ret = &ret_entry->ret;
  250. call = &entry->graph_ent;
  251. duration = graph_ret->rettime - graph_ret->calltime;
  252. /* Overhead */
  253. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
  254. ret = print_graph_overhead(duration, s);
  255. if (!ret)
  256. return TRACE_TYPE_PARTIAL_LINE;
  257. }
  258. /* Duration */
  259. ret = print_graph_duration(duration, s);
  260. if (ret == TRACE_TYPE_PARTIAL_LINE)
  261. return TRACE_TYPE_PARTIAL_LINE;
  262. /* Function */
  263. for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
  264. ret = trace_seq_printf(s, " ");
  265. if (!ret)
  266. return TRACE_TYPE_PARTIAL_LINE;
  267. }
  268. ret = seq_print_ip_sym(s, call->func, 0);
  269. if (!ret)
  270. return TRACE_TYPE_PARTIAL_LINE;
  271. ret = trace_seq_printf(s, "();\n");
  272. if (!ret)
  273. return TRACE_TYPE_PARTIAL_LINE;
  274. return TRACE_TYPE_HANDLED;
  275. }
  276. static enum print_line_t
  277. print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
  278. struct trace_seq *s)
  279. {
  280. int i;
  281. int ret;
  282. struct ftrace_graph_ent *call = &entry->graph_ent;
  283. /* No overhead */
  284. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
  285. ret = trace_seq_printf(s, " ");
  286. if (!ret)
  287. return TRACE_TYPE_PARTIAL_LINE;
  288. }
  289. /* No time */
  290. ret = trace_seq_printf(s, " | ");
  291. /* Function */
  292. for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
  293. ret = trace_seq_printf(s, " ");
  294. if (!ret)
  295. return TRACE_TYPE_PARTIAL_LINE;
  296. }
  297. ret = seq_print_ip_sym(s, call->func, 0);
  298. if (!ret)
  299. return TRACE_TYPE_PARTIAL_LINE;
  300. ret = trace_seq_printf(s, "() {\n");
  301. if (!ret)
  302. return TRACE_TYPE_PARTIAL_LINE;
  303. return TRACE_TYPE_HANDLED;
  304. }
  305. static enum print_line_t
  306. print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
  307. struct trace_iterator *iter, int cpu)
  308. {
  309. int ret;
  310. struct trace_entry *ent = iter->ent;
  311. /* Pid */
  312. if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE)
  313. return TRACE_TYPE_PARTIAL_LINE;
  314. /* Cpu */
  315. if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
  316. ret = print_graph_cpu(s, cpu);
  317. if (ret == TRACE_TYPE_PARTIAL_LINE)
  318. return TRACE_TYPE_PARTIAL_LINE;
  319. }
  320. /* Proc */
  321. if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
  322. ret = print_graph_proc(s, ent->pid);
  323. if (ret == TRACE_TYPE_PARTIAL_LINE)
  324. return TRACE_TYPE_PARTIAL_LINE;
  325. ret = trace_seq_printf(s, " | ");
  326. if (!ret)
  327. return TRACE_TYPE_PARTIAL_LINE;
  328. }
  329. if (trace_branch_is_leaf(iter, field))
  330. return print_graph_entry_leaf(iter, field, s);
  331. else
  332. return print_graph_entry_nested(field, s);
  333. }
  334. static enum print_line_t
  335. print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
  336. struct trace_entry *ent, int cpu)
  337. {
  338. int i;
  339. int ret;
  340. unsigned long long duration = trace->rettime - trace->calltime;
  341. /* Pid */
  342. if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE)
  343. return TRACE_TYPE_PARTIAL_LINE;
  344. /* Cpu */
  345. if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
  346. ret = print_graph_cpu(s, cpu);
  347. if (ret == TRACE_TYPE_PARTIAL_LINE)
  348. return TRACE_TYPE_PARTIAL_LINE;
  349. }
  350. /* Proc */
  351. if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
  352. ret = print_graph_proc(s, ent->pid);
  353. if (ret == TRACE_TYPE_PARTIAL_LINE)
  354. return TRACE_TYPE_PARTIAL_LINE;
  355. ret = trace_seq_printf(s, " | ");
  356. if (!ret)
  357. return TRACE_TYPE_PARTIAL_LINE;
  358. }
  359. /* Overhead */
  360. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
  361. ret = print_graph_overhead(duration, s);
  362. if (!ret)
  363. return TRACE_TYPE_PARTIAL_LINE;
  364. }
  365. /* Duration */
  366. ret = print_graph_duration(duration, s);
  367. if (ret == TRACE_TYPE_PARTIAL_LINE)
  368. return TRACE_TYPE_PARTIAL_LINE;
  369. /* Closing brace */
  370. for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
  371. ret = trace_seq_printf(s, " ");
  372. if (!ret)
  373. return TRACE_TYPE_PARTIAL_LINE;
  374. }
  375. ret = trace_seq_printf(s, "}\n");
  376. if (!ret)
  377. return TRACE_TYPE_PARTIAL_LINE;
  378. /* Overrun */
  379. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
  380. ret = trace_seq_printf(s, " (Overruns: %lu)\n",
  381. trace->overrun);
  382. if (!ret)
  383. return TRACE_TYPE_PARTIAL_LINE;
  384. }
  385. return TRACE_TYPE_HANDLED;
  386. }
  387. static enum print_line_t
  388. print_graph_comment(struct print_entry *trace, struct trace_seq *s,
  389. struct trace_entry *ent, struct trace_iterator *iter)
  390. {
  391. int i;
  392. int ret;
  393. /* Pid */
  394. if (verif_pid(s, ent->pid, iter->cpu) == TRACE_TYPE_PARTIAL_LINE)
  395. return TRACE_TYPE_PARTIAL_LINE;
  396. /* Cpu */
  397. if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
  398. ret = print_graph_cpu(s, iter->cpu);
  399. if (ret == TRACE_TYPE_PARTIAL_LINE)
  400. return TRACE_TYPE_PARTIAL_LINE;
  401. }
  402. /* Proc */
  403. if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
  404. ret = print_graph_proc(s, ent->pid);
  405. if (ret == TRACE_TYPE_PARTIAL_LINE)
  406. return TRACE_TYPE_PARTIAL_LINE;
  407. ret = trace_seq_printf(s, " | ");
  408. if (!ret)
  409. return TRACE_TYPE_PARTIAL_LINE;
  410. }
  411. /* No overhead */
  412. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
  413. ret = trace_seq_printf(s, " ");
  414. if (!ret)
  415. return TRACE_TYPE_PARTIAL_LINE;
  416. }
  417. /* No time */
  418. ret = trace_seq_printf(s, " | ");
  419. if (!ret)
  420. return TRACE_TYPE_PARTIAL_LINE;
  421. /* Indentation */
  422. if (trace->depth > 0)
  423. for (i = 0; i < (trace->depth + 1) * TRACE_GRAPH_INDENT; i++) {
  424. ret = trace_seq_printf(s, " ");
  425. if (!ret)
  426. return TRACE_TYPE_PARTIAL_LINE;
  427. }
  428. /* The comment */
  429. ret = trace_seq_printf(s, "/* %s", trace->buf);
  430. if (!ret)
  431. return TRACE_TYPE_PARTIAL_LINE;
  432. if (ent->flags & TRACE_FLAG_CONT)
  433. trace_seq_print_cont(s, iter);
  434. ret = trace_seq_printf(s, " */\n");
  435. if (!ret)
  436. return TRACE_TYPE_PARTIAL_LINE;
  437. return TRACE_TYPE_HANDLED;
  438. }
  439. enum print_line_t
  440. print_graph_function(struct trace_iterator *iter)
  441. {
  442. struct trace_seq *s = &iter->seq;
  443. struct trace_entry *entry = iter->ent;
  444. switch (entry->type) {
  445. case TRACE_GRAPH_ENT: {
  446. struct ftrace_graph_ent_entry *field;
  447. trace_assign_type(field, entry);
  448. return print_graph_entry(field, s, iter,
  449. iter->cpu);
  450. }
  451. case TRACE_GRAPH_RET: {
  452. struct ftrace_graph_ret_entry *field;
  453. trace_assign_type(field, entry);
  454. return print_graph_return(&field->ret, s, entry, iter->cpu);
  455. }
  456. case TRACE_PRINT: {
  457. struct print_entry *field;
  458. trace_assign_type(field, entry);
  459. return print_graph_comment(field, s, entry, iter);
  460. }
  461. default:
  462. return TRACE_TYPE_UNHANDLED;
  463. }
  464. }
  465. static void print_graph_headers(struct seq_file *s)
  466. {
  467. /* 1st line */
  468. seq_printf(s, "# ");
  469. if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
  470. seq_printf(s, "CPU ");
  471. if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
  472. seq_printf(s, "TASK/PID ");
  473. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD)
  474. seq_printf(s, "OVERHEAD/");
  475. seq_printf(s, "DURATION FUNCTION CALLS\n");
  476. /* 2nd line */
  477. seq_printf(s, "# ");
  478. if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
  479. seq_printf(s, "| ");
  480. if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
  481. seq_printf(s, "| | ");
  482. if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
  483. seq_printf(s, "| ");
  484. seq_printf(s, "| | | | |\n");
  485. } else
  486. seq_printf(s, " | | | | |\n");
  487. }
  488. static struct tracer graph_trace __read_mostly = {
  489. .name = "function_graph",
  490. .init = graph_trace_init,
  491. .reset = graph_trace_reset,
  492. .print_line = print_graph_function,
  493. .print_header = print_graph_headers,
  494. .flags = &tracer_flags,
  495. };
  496. static __init int init_graph_trace(void)
  497. {
  498. return register_tracer(&graph_trace);
  499. }
  500. device_initcall(init_graph_trace);