aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/trace/trace_functions_graph.c
diff options
context:
space:
mode:
authorLinus Torvalds <torvalds@linux-foundation.org>2009-04-05 14:04:19 -0400
committerLinus Torvalds <torvalds@linux-foundation.org>2009-04-05 14:04:19 -0400
commit714f83d5d9f7c785f622259dad1f4fad12d64664 (patch)
tree20563541ae438e11d686b4d629074eb002a481b7 /kernel/trace/trace_functions_graph.c
parent8901e7ffc2fa78ede7ce9826dbad68a3a25dc2dc (diff)
parent645dae969c3b8651c5bc7c54a1835ec03820f85f (diff)
Merge branch 'tracing-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
* 'tracing-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip: (413 commits) tracing, net: fix net tree and tracing tree merge interaction tracing, powerpc: fix powerpc tree and tracing tree interaction ring-buffer: do not remove reader page from list on ring buffer free function-graph: allow unregistering twice trace: make argument 'mem' of trace_seq_putmem() const tracing: add missing 'extern' keywords to trace_output.h tracing: provide trace_seq_reserve() blktrace: print out BLK_TN_MESSAGE properly blktrace: extract duplidate code blktrace: fix memory leak when freeing struct blk_io_trace blktrace: fix blk_probes_ref chaos blktrace: make classic output more classic blktrace: fix off-by-one bug blktrace: fix the original blktrace blktrace: fix a race when creating blk_tree_root in debugfs blktrace: fix timestamp in binary output tracing, Text Edit Lock: cleanup tracing: filter fix for TRACE_EVENT_FORMAT events ftrace: Using FTRACE_WARN_ON() to check "freed record" in ftrace_release() x86: kretprobe-booster interrupt emulation code fix ... Fix up trivial conflicts in arch/parisc/include/asm/ftrace.h include/linux/memory.h kernel/extable.c kernel/module.c
Diffstat (limited to 'kernel/trace/trace_functions_graph.c')
-rw-r--r--kernel/trace/trace_functions_graph.c570
1 files changed, 357 insertions, 213 deletions
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index dce71a5b51bc..d28687e7b3a7 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -1,7 +1,7 @@
1/* 1/*
2 * 2 *
3 * Function graph tracer. 3 * Function graph tracer.
4 * Copyright (c) 2008 Frederic Weisbecker <fweisbec@gmail.com> 4 * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
5 * Mostly borrowed from function tracer which 5 * Mostly borrowed from function tracer which
6 * is Copyright (c) Steven Rostedt <srostedt@redhat.com> 6 * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
7 * 7 *
@@ -12,6 +12,12 @@
12#include <linux/fs.h> 12#include <linux/fs.h>
13 13
14#include "trace.h" 14#include "trace.h"
15#include "trace_output.h"
16
17struct fgraph_data {
18 pid_t last_pid;
19 int depth;
20};
15 21
16#define TRACE_GRAPH_INDENT 2 22#define TRACE_GRAPH_INDENT 2
17 23
@@ -20,9 +26,11 @@
20#define TRACE_GRAPH_PRINT_CPU 0x2 26#define TRACE_GRAPH_PRINT_CPU 0x2
21#define TRACE_GRAPH_PRINT_OVERHEAD 0x4 27#define TRACE_GRAPH_PRINT_OVERHEAD 0x4
22#define TRACE_GRAPH_PRINT_PROC 0x8 28#define TRACE_GRAPH_PRINT_PROC 0x8
29#define TRACE_GRAPH_PRINT_DURATION 0x10
30#define TRACE_GRAPH_PRINT_ABS_TIME 0X20
23 31
24static struct tracer_opt trace_opts[] = { 32static struct tracer_opt trace_opts[] = {
25 /* Display overruns ? */ 33 /* Display overruns? (for self-debug purpose) */
26 { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) }, 34 { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
27 /* Display CPU ? */ 35 /* Display CPU ? */
28 { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) }, 36 { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
@@ -30,23 +38,28 @@ static struct tracer_opt trace_opts[] = {
30 { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) }, 38 { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
31 /* Display proc name/pid */ 39 /* Display proc name/pid */
32 { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) }, 40 { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
41 /* Display duration of execution */
42 { TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) },
43 /* Display absolute time of an entry */
44 { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) },
33 { } /* Empty entry */ 45 { } /* Empty entry */
34}; 46};
35 47
36static struct tracer_flags tracer_flags = { 48static struct tracer_flags tracer_flags = {
37 /* Don't display overruns and proc by default */ 49 /* Don't display overruns and proc by default */
38 .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD, 50 .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
51 TRACE_GRAPH_PRINT_DURATION,
39 .opts = trace_opts 52 .opts = trace_opts
40}; 53};
41 54
42/* pid on the last trace processed */ 55/* pid on the last trace processed */
43static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 }; 56
44 57
45/* Add a function return address to the trace stack on thread info.*/ 58/* Add a function return address to the trace stack on thread info.*/
46int 59int
47ftrace_push_return_trace(unsigned long ret, unsigned long long time, 60ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
48 unsigned long func, int *depth)
49{ 61{
62 unsigned long long calltime;
50 int index; 63 int index;
51 64
52 if (!current->ret_stack) 65 if (!current->ret_stack)
@@ -58,11 +71,13 @@ ftrace_push_return_trace(unsigned long ret, unsigned long long time,
58 return -EBUSY; 71 return -EBUSY;
59 } 72 }
60 73
74 calltime = trace_clock_local();
75
61 index = ++current->curr_ret_stack; 76 index = ++current->curr_ret_stack;
62 barrier(); 77 barrier();
63 current->ret_stack[index].ret = ret; 78 current->ret_stack[index].ret = ret;
64 current->ret_stack[index].func = func; 79 current->ret_stack[index].func = func;
65 current->ret_stack[index].calltime = time; 80 current->ret_stack[index].calltime = calltime;
66 *depth = index; 81 *depth = index;
67 82
68 return 0; 83 return 0;
@@ -104,7 +119,7 @@ unsigned long ftrace_return_to_handler(void)
104 unsigned long ret; 119 unsigned long ret;
105 120
106 ftrace_pop_return_trace(&trace, &ret); 121 ftrace_pop_return_trace(&trace, &ret);
107 trace.rettime = cpu_clock(raw_smp_processor_id()); 122 trace.rettime = trace_clock_local();
108 ftrace_graph_return(&trace); 123 ftrace_graph_return(&trace);
109 124
110 if (unlikely(!ret)) { 125 if (unlikely(!ret)) {
@@ -119,12 +134,7 @@ unsigned long ftrace_return_to_handler(void)
119 134
120static int graph_trace_init(struct trace_array *tr) 135static int graph_trace_init(struct trace_array *tr)
121{ 136{
122 int cpu, ret; 137 int ret = register_ftrace_graph(&trace_graph_return,
123
124 for_each_online_cpu(cpu)
125 tracing_reset(tr, cpu);
126
127 ret = register_ftrace_graph(&trace_graph_return,
128 &trace_graph_entry); 138 &trace_graph_entry);
129 if (ret) 139 if (ret)
130 return ret; 140 return ret;
@@ -187,15 +197,15 @@ print_graph_cpu(struct trace_seq *s, int cpu)
187static enum print_line_t 197static enum print_line_t
188print_graph_proc(struct trace_seq *s, pid_t pid) 198print_graph_proc(struct trace_seq *s, pid_t pid)
189{ 199{
190 int i; 200 char comm[TASK_COMM_LEN];
191 int ret;
192 int len;
193 char comm[8];
194 int spaces = 0;
195 /* sign + log10(MAX_INT) + '\0' */ 201 /* sign + log10(MAX_INT) + '\0' */
196 char pid_str[11]; 202 char pid_str[11];
203 int spaces = 0;
204 int ret;
205 int len;
206 int i;
197 207
198 strncpy(comm, trace_find_cmdline(pid), 7); 208 trace_find_cmdline(pid, comm);
199 comm[7] = '\0'; 209 comm[7] = '\0';
200 sprintf(pid_str, "%d", pid); 210 sprintf(pid_str, "%d", pid);
201 211
@@ -228,17 +238,25 @@ print_graph_proc(struct trace_seq *s, pid_t pid)
228 238
229/* If the pid changed since the last trace, output this event */ 239/* If the pid changed since the last trace, output this event */
230static enum print_line_t 240static enum print_line_t
231verif_pid(struct trace_seq *s, pid_t pid, int cpu) 241verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
232{ 242{
233 pid_t prev_pid; 243 pid_t prev_pid;
244 pid_t *last_pid;
234 int ret; 245 int ret;
235 246
236 if (last_pid[cpu] != -1 && last_pid[cpu] == pid) 247 if (!data)
248 return TRACE_TYPE_HANDLED;
249
250 last_pid = &(per_cpu_ptr(data, cpu)->last_pid);
251
252 if (*last_pid == pid)
237 return TRACE_TYPE_HANDLED; 253 return TRACE_TYPE_HANDLED;
238 254
239 prev_pid = last_pid[cpu]; 255 prev_pid = *last_pid;
240 last_pid[cpu] = pid; 256 *last_pid = pid;
241 257
258 if (prev_pid == -1)
259 return TRACE_TYPE_HANDLED;
242/* 260/*
243 * Context-switch trace line: 261 * Context-switch trace line:
244 262
@@ -250,34 +268,34 @@ verif_pid(struct trace_seq *s, pid_t pid, int cpu)
250 ret = trace_seq_printf(s, 268 ret = trace_seq_printf(s,
251 " ------------------------------------------\n"); 269 " ------------------------------------------\n");
252 if (!ret) 270 if (!ret)
253 TRACE_TYPE_PARTIAL_LINE; 271 return TRACE_TYPE_PARTIAL_LINE;
254 272
255 ret = print_graph_cpu(s, cpu); 273 ret = print_graph_cpu(s, cpu);
256 if (ret == TRACE_TYPE_PARTIAL_LINE) 274 if (ret == TRACE_TYPE_PARTIAL_LINE)
257 TRACE_TYPE_PARTIAL_LINE; 275 return TRACE_TYPE_PARTIAL_LINE;
258 276
259 ret = print_graph_proc(s, prev_pid); 277 ret = print_graph_proc(s, prev_pid);
260 if (ret == TRACE_TYPE_PARTIAL_LINE) 278 if (ret == TRACE_TYPE_PARTIAL_LINE)
261 TRACE_TYPE_PARTIAL_LINE; 279 return TRACE_TYPE_PARTIAL_LINE;
262 280
263 ret = trace_seq_printf(s, " => "); 281 ret = trace_seq_printf(s, " => ");
264 if (!ret) 282 if (!ret)
265 TRACE_TYPE_PARTIAL_LINE; 283 return TRACE_TYPE_PARTIAL_LINE;
266 284
267 ret = print_graph_proc(s, pid); 285 ret = print_graph_proc(s, pid);
268 if (ret == TRACE_TYPE_PARTIAL_LINE) 286 if (ret == TRACE_TYPE_PARTIAL_LINE)
269 TRACE_TYPE_PARTIAL_LINE; 287 return TRACE_TYPE_PARTIAL_LINE;
270 288
271 ret = trace_seq_printf(s, 289 ret = trace_seq_printf(s,
272 "\n ------------------------------------------\n\n"); 290 "\n ------------------------------------------\n\n");
273 if (!ret) 291 if (!ret)
274 TRACE_TYPE_PARTIAL_LINE; 292 return TRACE_TYPE_PARTIAL_LINE;
275 293
276 return ret; 294 return TRACE_TYPE_HANDLED;
277} 295}
278 296
279static bool 297static struct ftrace_graph_ret_entry *
280trace_branch_is_leaf(struct trace_iterator *iter, 298get_return_for_leaf(struct trace_iterator *iter,
281 struct ftrace_graph_ent_entry *curr) 299 struct ftrace_graph_ent_entry *curr)
282{ 300{
283 struct ring_buffer_iter *ring_iter; 301 struct ring_buffer_iter *ring_iter;
@@ -286,65 +304,123 @@ trace_branch_is_leaf(struct trace_iterator *iter,
286 304
287 ring_iter = iter->buffer_iter[iter->cpu]; 305 ring_iter = iter->buffer_iter[iter->cpu];
288 306
289 if (!ring_iter) 307 /* First peek to compare current entry and the next one */
290 return false; 308 if (ring_iter)
291 309 event = ring_buffer_iter_peek(ring_iter, NULL);
292 event = ring_buffer_iter_peek(ring_iter, NULL); 310 else {
311 /* We need to consume the current entry to see the next one */
312 ring_buffer_consume(iter->tr->buffer, iter->cpu, NULL);
313 event = ring_buffer_peek(iter->tr->buffer, iter->cpu,
314 NULL);
315 }
293 316
294 if (!event) 317 if (!event)
295 return false; 318 return NULL;
296 319
297 next = ring_buffer_event_data(event); 320 next = ring_buffer_event_data(event);
298 321
299 if (next->ent.type != TRACE_GRAPH_RET) 322 if (next->ent.type != TRACE_GRAPH_RET)
300 return false; 323 return NULL;
301 324
302 if (curr->ent.pid != next->ent.pid || 325 if (curr->ent.pid != next->ent.pid ||
303 curr->graph_ent.func != next->ret.func) 326 curr->graph_ent.func != next->ret.func)
304 return false; 327 return NULL;
328
329 /* this is a leaf, now advance the iterator */
330 if (ring_iter)
331 ring_buffer_read(ring_iter, NULL);
332
333 return next;
334}
335
336/* Signal a overhead of time execution to the output */
337static int
338print_graph_overhead(unsigned long long duration, struct trace_seq *s)
339{
340 /* If duration disappear, we don't need anything */
341 if (!(tracer_flags.val & TRACE_GRAPH_PRINT_DURATION))
342 return 1;
343
344 /* Non nested entry or return */
345 if (duration == -1)
346 return trace_seq_printf(s, " ");
347
348 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
349 /* Duration exceeded 100 msecs */
350 if (duration > 100000ULL)
351 return trace_seq_printf(s, "! ");
352
353 /* Duration exceeded 10 msecs */
354 if (duration > 10000ULL)
355 return trace_seq_printf(s, "+ ");
356 }
357
358 return trace_seq_printf(s, " ");
359}
360
361static int print_graph_abs_time(u64 t, struct trace_seq *s)
362{
363 unsigned long usecs_rem;
364
365 usecs_rem = do_div(t, NSEC_PER_SEC);
366 usecs_rem /= 1000;
305 367
306 return true; 368 return trace_seq_printf(s, "%5lu.%06lu | ",
369 (unsigned long)t, usecs_rem);
307} 370}
308 371
309static enum print_line_t 372static enum print_line_t
310print_graph_irq(struct trace_seq *s, unsigned long addr, 373print_graph_irq(struct trace_iterator *iter, unsigned long addr,
311 enum trace_type type, int cpu, pid_t pid) 374 enum trace_type type, int cpu, pid_t pid)
312{ 375{
313 int ret; 376 int ret;
377 struct trace_seq *s = &iter->seq;
314 378
315 if (addr < (unsigned long)__irqentry_text_start || 379 if (addr < (unsigned long)__irqentry_text_start ||
316 addr >= (unsigned long)__irqentry_text_end) 380 addr >= (unsigned long)__irqentry_text_end)
317 return TRACE_TYPE_UNHANDLED; 381 return TRACE_TYPE_UNHANDLED;
318 382
319 if (type == TRACE_GRAPH_ENT) { 383 /* Absolute time */
320 ret = trace_seq_printf(s, "==========> | "); 384 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
321 } else { 385 ret = print_graph_abs_time(iter->ts, s);
322 /* Cpu */ 386 if (!ret)
323 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) { 387 return TRACE_TYPE_PARTIAL_LINE;
324 ret = print_graph_cpu(s, cpu); 388 }
325 if (ret == TRACE_TYPE_PARTIAL_LINE)
326 return TRACE_TYPE_PARTIAL_LINE;
327 }
328 /* Proc */
329 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
330 ret = print_graph_proc(s, pid);
331 if (ret == TRACE_TYPE_PARTIAL_LINE)
332 return TRACE_TYPE_PARTIAL_LINE;
333 389
334 ret = trace_seq_printf(s, " | "); 390 /* Cpu */
335 if (!ret) 391 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
336 return TRACE_TYPE_PARTIAL_LINE; 392 ret = print_graph_cpu(s, cpu);
337 } 393 if (ret == TRACE_TYPE_PARTIAL_LINE)
394 return TRACE_TYPE_PARTIAL_LINE;
395 }
396 /* Proc */
397 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
398 ret = print_graph_proc(s, pid);
399 if (ret == TRACE_TYPE_PARTIAL_LINE)
400 return TRACE_TYPE_PARTIAL_LINE;
401 ret = trace_seq_printf(s, " | ");
402 if (!ret)
403 return TRACE_TYPE_PARTIAL_LINE;
404 }
338 405
339 /* No overhead */ 406 /* No overhead */
340 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 407 ret = print_graph_overhead(-1, s);
341 ret = trace_seq_printf(s, " "); 408 if (!ret)
342 if (!ret) 409 return TRACE_TYPE_PARTIAL_LINE;
343 return TRACE_TYPE_PARTIAL_LINE; 410
344 } 411 if (type == TRACE_GRAPH_ENT)
412 ret = trace_seq_printf(s, "==========>");
413 else
414 ret = trace_seq_printf(s, "<==========");
415
416 if (!ret)
417 return TRACE_TYPE_PARTIAL_LINE;
418
419 /* Don't close the duration column if haven't one */
420 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
421 trace_seq_printf(s, " |");
422 ret = trace_seq_printf(s, "\n");
345 423
346 ret = trace_seq_printf(s, "<========== |\n");
347 }
348 if (!ret) 424 if (!ret)
349 return TRACE_TYPE_PARTIAL_LINE; 425 return TRACE_TYPE_PARTIAL_LINE;
350 return TRACE_TYPE_HANDLED; 426 return TRACE_TYPE_HANDLED;
@@ -363,7 +439,7 @@ print_graph_duration(unsigned long long duration, struct trace_seq *s)
363 sprintf(msecs_str, "%lu", (unsigned long) duration); 439 sprintf(msecs_str, "%lu", (unsigned long) duration);
364 440
365 /* Print msecs */ 441 /* Print msecs */
366 ret = trace_seq_printf(s, msecs_str); 442 ret = trace_seq_printf(s, "%s", msecs_str);
367 if (!ret) 443 if (!ret)
368 return TRACE_TYPE_PARTIAL_LINE; 444 return TRACE_TYPE_PARTIAL_LINE;
369 445
@@ -396,52 +472,47 @@ print_graph_duration(unsigned long long duration, struct trace_seq *s)
396 472
397} 473}
398 474
399/* Signal a overhead of time execution to the output */
400static int
401print_graph_overhead(unsigned long long duration, struct trace_seq *s)
402{
403 /* Duration exceeded 100 msecs */
404 if (duration > 100000ULL)
405 return trace_seq_printf(s, "! ");
406
407 /* Duration exceeded 10 msecs */
408 if (duration > 10000ULL)
409 return trace_seq_printf(s, "+ ");
410
411 return trace_seq_printf(s, " ");
412}
413
414/* Case of a leaf function on its call entry */ 475/* Case of a leaf function on its call entry */
415static enum print_line_t 476static enum print_line_t
416print_graph_entry_leaf(struct trace_iterator *iter, 477print_graph_entry_leaf(struct trace_iterator *iter,
417 struct ftrace_graph_ent_entry *entry, struct trace_seq *s) 478 struct ftrace_graph_ent_entry *entry,
479 struct ftrace_graph_ret_entry *ret_entry, struct trace_seq *s)
418{ 480{
419 struct ftrace_graph_ret_entry *ret_entry; 481 struct fgraph_data *data = iter->private;
420 struct ftrace_graph_ret *graph_ret; 482 struct ftrace_graph_ret *graph_ret;
421 struct ring_buffer_event *event;
422 struct ftrace_graph_ent *call; 483 struct ftrace_graph_ent *call;
423 unsigned long long duration; 484 unsigned long long duration;
424 int ret; 485 int ret;
425 int i; 486 int i;
426 487
427 event = ring_buffer_read(iter->buffer_iter[iter->cpu], NULL);
428 ret_entry = ring_buffer_event_data(event);
429 graph_ret = &ret_entry->ret; 488 graph_ret = &ret_entry->ret;
430 call = &entry->graph_ent; 489 call = &entry->graph_ent;
431 duration = graph_ret->rettime - graph_ret->calltime; 490 duration = graph_ret->rettime - graph_ret->calltime;
432 491
433 /* Overhead */ 492 if (data) {
434 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 493 int cpu = iter->cpu;
435 ret = print_graph_overhead(duration, s); 494 int *depth = &(per_cpu_ptr(data, cpu)->depth);
436 if (!ret) 495
437 return TRACE_TYPE_PARTIAL_LINE; 496 /*
497 * Comments display at + 1 to depth. Since
498 * this is a leaf function, keep the comments
499 * equal to this depth.
500 */
501 *depth = call->depth - 1;
438 } 502 }
439 503
440 /* Duration */ 504 /* Overhead */
441 ret = print_graph_duration(duration, s); 505 ret = print_graph_overhead(duration, s);
442 if (ret == TRACE_TYPE_PARTIAL_LINE) 506 if (!ret)
443 return TRACE_TYPE_PARTIAL_LINE; 507 return TRACE_TYPE_PARTIAL_LINE;
444 508
509 /* Duration */
510 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
511 ret = print_graph_duration(duration, s);
512 if (ret == TRACE_TYPE_PARTIAL_LINE)
513 return TRACE_TYPE_PARTIAL_LINE;
514 }
515
445 /* Function */ 516 /* Function */
446 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) { 517 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
447 ret = trace_seq_printf(s, " "); 518 ret = trace_seq_printf(s, " ");
@@ -461,33 +532,34 @@ print_graph_entry_leaf(struct trace_iterator *iter,
461} 532}
462 533
463static enum print_line_t 534static enum print_line_t
464print_graph_entry_nested(struct ftrace_graph_ent_entry *entry, 535print_graph_entry_nested(struct trace_iterator *iter,
465 struct trace_seq *s, pid_t pid, int cpu) 536 struct ftrace_graph_ent_entry *entry,
537 struct trace_seq *s, int cpu)
466{ 538{
467 int i;
468 int ret;
469 struct ftrace_graph_ent *call = &entry->graph_ent; 539 struct ftrace_graph_ent *call = &entry->graph_ent;
540 struct fgraph_data *data = iter->private;
541 int ret;
542 int i;
470 543
471 /* No overhead */ 544 if (data) {
472 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 545 int cpu = iter->cpu;
473 ret = trace_seq_printf(s, " "); 546 int *depth = &(per_cpu_ptr(data, cpu)->depth);
474 if (!ret) 547
475 return TRACE_TYPE_PARTIAL_LINE; 548 *depth = call->depth;
476 } 549 }
477 550
478 /* Interrupt */ 551 /* No overhead */
479 ret = print_graph_irq(s, call->func, TRACE_GRAPH_ENT, cpu, pid); 552 ret = print_graph_overhead(-1, s);
480 if (ret == TRACE_TYPE_UNHANDLED) { 553 if (!ret)
481 /* No time */ 554 return TRACE_TYPE_PARTIAL_LINE;
555
556 /* No time */
557 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
482 ret = trace_seq_printf(s, " | "); 558 ret = trace_seq_printf(s, " | ");
483 if (!ret) 559 if (!ret)
484 return TRACE_TYPE_PARTIAL_LINE; 560 return TRACE_TYPE_PARTIAL_LINE;
485 } else {
486 if (ret == TRACE_TYPE_PARTIAL_LINE)
487 return TRACE_TYPE_PARTIAL_LINE;
488 } 561 }
489 562
490
491 /* Function */ 563 /* Function */
492 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) { 564 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
493 ret = trace_seq_printf(s, " "); 565 ret = trace_seq_printf(s, " ");
@@ -503,20 +575,40 @@ print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
503 if (!ret) 575 if (!ret)
504 return TRACE_TYPE_PARTIAL_LINE; 576 return TRACE_TYPE_PARTIAL_LINE;
505 577
506 return TRACE_TYPE_HANDLED; 578 /*
579 * we already consumed the current entry to check the next one
580 * and see if this is a leaf.
581 */
582 return TRACE_TYPE_NO_CONSUME;
507} 583}
508 584
509static enum print_line_t 585static enum print_line_t
510print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s, 586print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
511 struct trace_iterator *iter, int cpu) 587 int type, unsigned long addr)
512{ 588{
513 int ret; 589 struct fgraph_data *data = iter->private;
514 struct trace_entry *ent = iter->ent; 590 struct trace_entry *ent = iter->ent;
591 int cpu = iter->cpu;
592 int ret;
515 593
516 /* Pid */ 594 /* Pid */
517 if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE) 595 if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE)
518 return TRACE_TYPE_PARTIAL_LINE; 596 return TRACE_TYPE_PARTIAL_LINE;
519 597
598 if (type) {
599 /* Interrupt */
600 ret = print_graph_irq(iter, addr, type, cpu, ent->pid);
601 if (ret == TRACE_TYPE_PARTIAL_LINE)
602 return TRACE_TYPE_PARTIAL_LINE;
603 }
604
605 /* Absolute time */
606 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
607 ret = print_graph_abs_time(iter->ts, s);
608 if (!ret)
609 return TRACE_TYPE_PARTIAL_LINE;
610 }
611
520 /* Cpu */ 612 /* Cpu */
521 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) { 613 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
522 ret = print_graph_cpu(s, cpu); 614 ret = print_graph_cpu(s, cpu);
@@ -535,54 +627,65 @@ print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
535 return TRACE_TYPE_PARTIAL_LINE; 627 return TRACE_TYPE_PARTIAL_LINE;
536 } 628 }
537 629
538 if (trace_branch_is_leaf(iter, field)) 630 return 0;
539 return print_graph_entry_leaf(iter, field, s); 631}
632
633static enum print_line_t
634print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
635 struct trace_iterator *iter)
636{
637 int cpu = iter->cpu;
638 struct ftrace_graph_ent *call = &field->graph_ent;
639 struct ftrace_graph_ret_entry *leaf_ret;
640
641 if (print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func))
642 return TRACE_TYPE_PARTIAL_LINE;
643
644 leaf_ret = get_return_for_leaf(iter, field);
645 if (leaf_ret)
646 return print_graph_entry_leaf(iter, field, leaf_ret, s);
540 else 647 else
541 return print_graph_entry_nested(field, s, iter->ent->pid, cpu); 648 return print_graph_entry_nested(iter, field, s, cpu);
542 649
543} 650}
544 651
545static enum print_line_t 652static enum print_line_t
546print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s, 653print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
547 struct trace_entry *ent, int cpu) 654 struct trace_entry *ent, struct trace_iterator *iter)
548{ 655{
549 int i;
550 int ret;
551 unsigned long long duration = trace->rettime - trace->calltime; 656 unsigned long long duration = trace->rettime - trace->calltime;
657 struct fgraph_data *data = iter->private;
658 pid_t pid = ent->pid;
659 int cpu = iter->cpu;
660 int ret;
661 int i;
552 662
553 /* Pid */ 663 if (data) {
554 if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE) 664 int cpu = iter->cpu;
555 return TRACE_TYPE_PARTIAL_LINE; 665 int *depth = &(per_cpu_ptr(data, cpu)->depth);
556 666
557 /* Cpu */ 667 /*
558 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) { 668 * Comments display at + 1 to depth. This is the
559 ret = print_graph_cpu(s, cpu); 669 * return from a function, we now want the comments
560 if (ret == TRACE_TYPE_PARTIAL_LINE) 670 * to display at the same level of the bracket.
561 return TRACE_TYPE_PARTIAL_LINE; 671 */
672 *depth = trace->depth - 1;
562 } 673 }
563 674
564 /* Proc */ 675 if (print_graph_prologue(iter, s, 0, 0))
565 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) { 676 return TRACE_TYPE_PARTIAL_LINE;
566 ret = print_graph_proc(s, ent->pid);
567 if (ret == TRACE_TYPE_PARTIAL_LINE)
568 return TRACE_TYPE_PARTIAL_LINE;
569
570 ret = trace_seq_printf(s, " | ");
571 if (!ret)
572 return TRACE_TYPE_PARTIAL_LINE;
573 }
574 677
575 /* Overhead */ 678 /* Overhead */
576 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 679 ret = print_graph_overhead(duration, s);
577 ret = print_graph_overhead(duration, s); 680 if (!ret)
578 if (!ret) 681 return TRACE_TYPE_PARTIAL_LINE;
579 return TRACE_TYPE_PARTIAL_LINE;
580 }
581 682
582 /* Duration */ 683 /* Duration */
583 ret = print_graph_duration(duration, s); 684 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
584 if (ret == TRACE_TYPE_PARTIAL_LINE) 685 ret = print_graph_duration(duration, s);
585 return TRACE_TYPE_PARTIAL_LINE; 686 if (ret == TRACE_TYPE_PARTIAL_LINE)
687 return TRACE_TYPE_PARTIAL_LINE;
688 }
586 689
587 /* Closing brace */ 690 /* Closing brace */
588 for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) { 691 for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
@@ -603,7 +706,7 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
603 return TRACE_TYPE_PARTIAL_LINE; 706 return TRACE_TYPE_PARTIAL_LINE;
604 } 707 }
605 708
606 ret = print_graph_irq(s, trace->func, TRACE_GRAPH_RET, cpu, ent->pid); 709 ret = print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, cpu, pid);
607 if (ret == TRACE_TYPE_PARTIAL_LINE) 710 if (ret == TRACE_TYPE_PARTIAL_LINE)
608 return TRACE_TYPE_PARTIAL_LINE; 711 return TRACE_TYPE_PARTIAL_LINE;
609 712
@@ -611,61 +714,73 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
611} 714}
612 715
613static enum print_line_t 716static enum print_line_t
614print_graph_comment(struct print_entry *trace, struct trace_seq *s, 717print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
615 struct trace_entry *ent, struct trace_iterator *iter) 718 struct trace_iterator *iter)
616{ 719{
617 int i; 720 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
721 struct fgraph_data *data = iter->private;
722 struct trace_event *event;
723 int depth = 0;
618 int ret; 724 int ret;
725 int i;
619 726
620 /* Pid */ 727 if (data)
621 if (verif_pid(s, ent->pid, iter->cpu) == TRACE_TYPE_PARTIAL_LINE) 728 depth = per_cpu_ptr(data, iter->cpu)->depth;
622 return TRACE_TYPE_PARTIAL_LINE;
623
624 /* Cpu */
625 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
626 ret = print_graph_cpu(s, iter->cpu);
627 if (ret == TRACE_TYPE_PARTIAL_LINE)
628 return TRACE_TYPE_PARTIAL_LINE;
629 }
630
631 /* Proc */
632 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
633 ret = print_graph_proc(s, ent->pid);
634 if (ret == TRACE_TYPE_PARTIAL_LINE)
635 return TRACE_TYPE_PARTIAL_LINE;
636 729
637 ret = trace_seq_printf(s, " | "); 730 if (print_graph_prologue(iter, s, 0, 0))
638 if (!ret) 731 return TRACE_TYPE_PARTIAL_LINE;
639 return TRACE_TYPE_PARTIAL_LINE;
640 }
641 732
642 /* No overhead */ 733 /* No overhead */
643 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 734 ret = print_graph_overhead(-1, s);
644 ret = trace_seq_printf(s, " "); 735 if (!ret)
736 return TRACE_TYPE_PARTIAL_LINE;
737
738 /* No time */
739 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
740 ret = trace_seq_printf(s, " | ");
645 if (!ret) 741 if (!ret)
646 return TRACE_TYPE_PARTIAL_LINE; 742 return TRACE_TYPE_PARTIAL_LINE;
647 } 743 }
648 744
649 /* No time */
650 ret = trace_seq_printf(s, " | ");
651 if (!ret)
652 return TRACE_TYPE_PARTIAL_LINE;
653
654 /* Indentation */ 745 /* Indentation */
655 if (trace->depth > 0) 746 if (depth > 0)
656 for (i = 0; i < (trace->depth + 1) * TRACE_GRAPH_INDENT; i++) { 747 for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) {
657 ret = trace_seq_printf(s, " "); 748 ret = trace_seq_printf(s, " ");
658 if (!ret) 749 if (!ret)
659 return TRACE_TYPE_PARTIAL_LINE; 750 return TRACE_TYPE_PARTIAL_LINE;
660 } 751 }
661 752
662 /* The comment */ 753 /* The comment */
663 ret = trace_seq_printf(s, "/* %s", trace->buf); 754 ret = trace_seq_printf(s, "/* ");
664 if (!ret) 755 if (!ret)
665 return TRACE_TYPE_PARTIAL_LINE; 756 return TRACE_TYPE_PARTIAL_LINE;
666 757
667 if (ent->flags & TRACE_FLAG_CONT) 758 switch (iter->ent->type) {
668 trace_seq_print_cont(s, iter); 759 case TRACE_BPRINT:
760 ret = trace_print_bprintk_msg_only(iter);
761 if (ret != TRACE_TYPE_HANDLED)
762 return ret;
763 break;
764 case TRACE_PRINT:
765 ret = trace_print_printk_msg_only(iter);
766 if (ret != TRACE_TYPE_HANDLED)
767 return ret;
768 break;
769 default:
770 event = ftrace_find_event(ent->type);
771 if (!event)
772 return TRACE_TYPE_UNHANDLED;
773
774 ret = event->trace(iter, sym_flags);
775 if (ret != TRACE_TYPE_HANDLED)
776 return ret;
777 }
778
779 /* Strip ending newline */
780 if (s->buffer[s->len - 1] == '\n') {
781 s->buffer[s->len - 1] = '\0';
782 s->len--;
783 }
669 784
670 ret = trace_seq_printf(s, " */\n"); 785 ret = trace_seq_printf(s, " */\n");
671 if (!ret) 786 if (!ret)
@@ -678,62 +793,91 @@ print_graph_comment(struct print_entry *trace, struct trace_seq *s,
678enum print_line_t 793enum print_line_t
679print_graph_function(struct trace_iterator *iter) 794print_graph_function(struct trace_iterator *iter)
680{ 795{
681 struct trace_seq *s = &iter->seq;
682 struct trace_entry *entry = iter->ent; 796 struct trace_entry *entry = iter->ent;
797 struct trace_seq *s = &iter->seq;
683 798
684 switch (entry->type) { 799 switch (entry->type) {
685 case TRACE_GRAPH_ENT: { 800 case TRACE_GRAPH_ENT: {
686 struct ftrace_graph_ent_entry *field; 801 struct ftrace_graph_ent_entry *field;
687 trace_assign_type(field, entry); 802 trace_assign_type(field, entry);
688 return print_graph_entry(field, s, iter, 803 return print_graph_entry(field, s, iter);
689 iter->cpu);
690 } 804 }
691 case TRACE_GRAPH_RET: { 805 case TRACE_GRAPH_RET: {
692 struct ftrace_graph_ret_entry *field; 806 struct ftrace_graph_ret_entry *field;
693 trace_assign_type(field, entry); 807 trace_assign_type(field, entry);
694 return print_graph_return(&field->ret, s, entry, iter->cpu); 808 return print_graph_return(&field->ret, s, entry, iter);
695 }
696 case TRACE_PRINT: {
697 struct print_entry *field;
698 trace_assign_type(field, entry);
699 return print_graph_comment(field, s, entry, iter);
700 } 809 }
701 default: 810 default:
702 return TRACE_TYPE_UNHANDLED; 811 return print_graph_comment(s, entry, iter);
703 } 812 }
813
814 return TRACE_TYPE_HANDLED;
704} 815}
705 816
706static void print_graph_headers(struct seq_file *s) 817static void print_graph_headers(struct seq_file *s)
707{ 818{
708 /* 1st line */ 819 /* 1st line */
709 seq_printf(s, "# "); 820 seq_printf(s, "# ");
821 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
822 seq_printf(s, " TIME ");
710 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) 823 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
711 seq_printf(s, "CPU "); 824 seq_printf(s, "CPU");
712 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) 825 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
713 seq_printf(s, "TASK/PID "); 826 seq_printf(s, " TASK/PID ");
714 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) 827 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
715 seq_printf(s, "OVERHEAD/"); 828 seq_printf(s, " DURATION ");
716 seq_printf(s, "DURATION FUNCTION CALLS\n"); 829 seq_printf(s, " FUNCTION CALLS\n");
717 830
718 /* 2nd line */ 831 /* 2nd line */
719 seq_printf(s, "# "); 832 seq_printf(s, "# ");
833 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
834 seq_printf(s, " | ");
720 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) 835 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
721 seq_printf(s, "| "); 836 seq_printf(s, "| ");
722 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) 837 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
723 seq_printf(s, "| | "); 838 seq_printf(s, " | | ");
724 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 839 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
725 seq_printf(s, "| "); 840 seq_printf(s, " | | ");
726 seq_printf(s, "| | | | |\n"); 841 seq_printf(s, " | | | |\n");
727 } else 842}
728 seq_printf(s, " | | | | |\n"); 843
844static void graph_trace_open(struct trace_iterator *iter)
845{
846 /* pid and depth on the last trace processed */
847 struct fgraph_data *data = alloc_percpu(struct fgraph_data);
848 int cpu;
849
850 if (!data)
851 pr_warning("function graph tracer: not enough memory\n");
852 else
853 for_each_possible_cpu(cpu) {
854 pid_t *pid = &(per_cpu_ptr(data, cpu)->last_pid);
855 int *depth = &(per_cpu_ptr(data, cpu)->depth);
856 *pid = -1;
857 *depth = 0;
858 }
859
860 iter->private = data;
729} 861}
862
863static void graph_trace_close(struct trace_iterator *iter)
864{
865 free_percpu(iter->private);
866}
867
730static struct tracer graph_trace __read_mostly = { 868static struct tracer graph_trace __read_mostly = {
731 .name = "function_graph", 869 .name = "function_graph",
732 .init = graph_trace_init, 870 .open = graph_trace_open,
733 .reset = graph_trace_reset, 871 .close = graph_trace_close,
872 .wait_pipe = poll_wait_pipe,
873 .init = graph_trace_init,
874 .reset = graph_trace_reset,
734 .print_line = print_graph_function, 875 .print_line = print_graph_function,
735 .print_header = print_graph_headers, 876 .print_header = print_graph_headers,
736 .flags = &tracer_flags, 877 .flags = &tracer_flags,
878#ifdef CONFIG_FTRACE_SELFTEST
879 .selftest = trace_selftest_startup_function_graph,
880#endif
737}; 881};
738 882
739static __init int init_graph_trace(void) 883static __init int init_graph_trace(void)