trace_functions_graph.c 24.3 KB
Newer Older
1 2 3
/*
 *
 * Function graph tracer.
4
 * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
5 6 7 8 9 10 11 12 13 14
 * Mostly borrowed from function tracer which
 * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
 *
 */
#include <linux/debugfs.h>
#include <linux/uaccess.h>
#include <linux/ftrace.h>
#include <linux/fs.h>

#include "trace.h"
15
#include "trace_output.h"
16

17 18 19 20 21
struct fgraph_data {
	pid_t		last_pid;
	int		depth;
};

22
#define TRACE_GRAPH_INDENT	2
23

24
/* Flag options */
25
#define TRACE_GRAPH_PRINT_OVERRUN	0x1
26 27
#define TRACE_GRAPH_PRINT_CPU		0x2
#define TRACE_GRAPH_PRINT_OVERHEAD	0x4
28
#define TRACE_GRAPH_PRINT_PROC		0x8
29 30
#define TRACE_GRAPH_PRINT_DURATION	0x10
#define TRACE_GRAPH_PRINT_ABS_TIME	0X20
31

32
static struct tracer_opt trace_opts[] = {
33
	/* Display overruns? (for self-debug purpose) */
34 35 36 37 38
	{ TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
	/* Display CPU ? */
	{ TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
	/* Display Overhead ? */
	{ TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
39 40
	/* Display proc name/pid */
	{ TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
41 42 43 44
	/* Display duration of execution */
	{ TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) },
	/* Display absolute time of an entry */
	{ TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) },
45 46 47 48
	{ } /* Empty entry */
};

static struct tracer_flags tracer_flags = {
49
	/* Don't display overruns and proc by default */
50 51
	.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
	       TRACE_GRAPH_PRINT_DURATION,
52 53 54
	.opts = trace_opts
};

55
static struct trace_array *graph_array;
56

57

58 59
/* Add a function return address to the trace stack on thread info.*/
int
60 61
ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
			 unsigned long frame_pointer)
62
{
63
	unsigned long long calltime;
64 65 66 67 68
	int index;

	if (!current->ret_stack)
		return -EBUSY;

69 70 71 72 73 74
	/*
	 * We must make sure the ret_stack is tested before we read
	 * anything else.
	 */
	smp_rmb();

75 76 77 78 79 80
	/* The return trace stack is full */
	if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {
		atomic_inc(&current->trace_overrun);
		return -EBUSY;
	}

81 82
	calltime = trace_clock_local();

83 84 85 86
	index = ++current->curr_ret_stack;
	barrier();
	current->ret_stack[index].ret = ret;
	current->ret_stack[index].func = func;
87
	current->ret_stack[index].calltime = calltime;
88
	current->ret_stack[index].subtime = 0;
89
	current->ret_stack[index].fp = frame_pointer;
90 91 92 93 94 95
	*depth = index;

	return 0;
}

/* Retrieve a function return address to the trace stack on thread info.*/
96
static void
97 98
ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
			unsigned long frame_pointer)
99 100 101 102 103 104 105 106 107 108 109 110 111
{
	int index;

	index = current->curr_ret_stack;

	if (unlikely(index < 0)) {
		ftrace_graph_stop();
		WARN_ON(1);
		/* Might as well panic, otherwise we have no where to go */
		*ret = (unsigned long)panic;
		return;
	}

112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136
#ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST
	/*
	 * The arch may choose to record the frame pointer used
	 * and check it here to make sure that it is what we expect it
	 * to be. If gcc does not set the place holder of the return
	 * address in the frame pointer, and does a copy instead, then
	 * the function graph trace will fail. This test detects this
	 * case.
	 *
	 * Currently, x86_32 with optimize for size (-Os) makes the latest
	 * gcc do the above.
	 */
	if (unlikely(current->ret_stack[index].fp != frame_pointer)) {
		ftrace_graph_stop();
		WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
		     "  from func %pF return to %lx\n",
		     current->ret_stack[index].fp,
		     frame_pointer,
		     (void *)current->ret_stack[index].func,
		     current->ret_stack[index].ret);
		*ret = (unsigned long)panic;
		return;
	}
#endif

137 138 139 140 141 142 143 144 145 146 147
	*ret = current->ret_stack[index].ret;
	trace->func = current->ret_stack[index].func;
	trace->calltime = current->ret_stack[index].calltime;
	trace->overrun = atomic_read(&current->trace_overrun);
	trace->depth = index;
}

/*
 * Send the trace to the ring-buffer.
 * @return the original return address.
 */
148
unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
149 150 151 152
{
	struct ftrace_graph_ret trace;
	unsigned long ret;

153
	ftrace_pop_return_trace(&trace, &ret, frame_pointer);
154
	trace.rettime = trace_clock_local();
155
	ftrace_graph_return(&trace);
156 157
	barrier();
	current->curr_ret_stack--;
158 159 160 161 162 163 164 165 166 167 168

	if (unlikely(!ret)) {
		ftrace_graph_stop();
		WARN_ON(1);
		/* Might as well panic. What else to do? */
		ret = (unsigned long)panic;
	}

	return ret;
}

169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276
static int __trace_graph_entry(struct trace_array *tr,
				struct ftrace_graph_ent *trace,
				unsigned long flags,
				int pc)
{
	struct ftrace_event_call *call = &event_funcgraph_entry;
	struct ring_buffer_event *event;
	struct ftrace_graph_ent_entry *entry;

	if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled))))
		return 0;

	event = trace_buffer_lock_reserve(tr, TRACE_GRAPH_ENT,
					  sizeof(*entry), flags, pc);
	if (!event)
		return 0;
	entry	= ring_buffer_event_data(event);
	entry->graph_ent			= *trace;
	if (!filter_current_check_discard(call, entry, event))
		ring_buffer_unlock_commit(tr->buffer, event);

	return 1;
}

int trace_graph_entry(struct ftrace_graph_ent *trace)
{
	struct trace_array *tr = graph_array;
	struct trace_array_cpu *data;
	unsigned long flags;
	long disabled;
	int ret;
	int cpu;
	int pc;

	if (unlikely(!tr))
		return 0;

	if (!ftrace_trace_task(current))
		return 0;

	if (!ftrace_graph_addr(trace->func))
		return 0;

	local_irq_save(flags);
	cpu = raw_smp_processor_id();
	data = tr->data[cpu];
	disabled = atomic_inc_return(&data->disabled);
	if (likely(disabled == 1)) {
		pc = preempt_count();
		ret = __trace_graph_entry(tr, trace, flags, pc);
	} else {
		ret = 0;
	}
	/* Only do the atomic if it is not already set */
	if (!test_tsk_trace_graph(current))
		set_tsk_trace_graph(current);

	atomic_dec(&data->disabled);
	local_irq_restore(flags);

	return ret;
}

static void __trace_graph_return(struct trace_array *tr,
				struct ftrace_graph_ret *trace,
				unsigned long flags,
				int pc)
{
	struct ftrace_event_call *call = &event_funcgraph_exit;
	struct ring_buffer_event *event;
	struct ftrace_graph_ret_entry *entry;

	if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled))))
		return;

	event = trace_buffer_lock_reserve(tr, TRACE_GRAPH_RET,
					  sizeof(*entry), flags, pc);
	if (!event)
		return;
	entry	= ring_buffer_event_data(event);
	entry->ret				= *trace;
	if (!filter_current_check_discard(call, entry, event))
		ring_buffer_unlock_commit(tr->buffer, event);
}

void trace_graph_return(struct ftrace_graph_ret *trace)
{
	struct trace_array *tr = graph_array;
	struct trace_array_cpu *data;
	unsigned long flags;
	long disabled;
	int cpu;
	int pc;

	local_irq_save(flags);
	cpu = raw_smp_processor_id();
	data = tr->data[cpu];
	disabled = atomic_inc_return(&data->disabled);
	if (likely(disabled == 1)) {
		pc = preempt_count();
		__trace_graph_return(tr, trace, flags, pc);
	}
	if (!trace->depth)
		clear_tsk_trace_graph(current);
	atomic_dec(&data->disabled);
	local_irq_restore(flags);
}

277 278
static int graph_trace_init(struct trace_array *tr)
{
279 280 281 282 283
	int ret;

	graph_array = tr;
	ret = register_ftrace_graph(&trace_graph_return,
				    &trace_graph_entry);
284 285 286 287 288
	if (ret)
		return ret;
	tracing_start_cmdline_record();

	return 0;
289 290
}

291 292 293 294 295
void set_graph_array(struct trace_array *tr)
{
	graph_array = tr;
}

296 297
static void graph_trace_reset(struct trace_array *tr)
{
298 299
	tracing_stop_cmdline_record();
	unregister_ftrace_graph();
300 301
}

302
static int max_bytes_for_cpu;
303 304 305 306 307 308

static enum print_line_t
print_graph_cpu(struct trace_seq *s, int cpu)
{
	int ret;

309 310 311 312 313
	/*
	 * Start with a space character - to make it stand out
	 * to the right a bit when trace output is pasted into
	 * email:
	 */
314
	ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
315
	if (!ret)
316 317
		return TRACE_TYPE_PARTIAL_LINE;

318 319 320
	return TRACE_TYPE_HANDLED;
}

321 322 323 324 325
#define TRACE_GRAPH_PROCINFO_LENGTH	14

static enum print_line_t
print_graph_proc(struct trace_seq *s, pid_t pid)
{
326
	char comm[TASK_COMM_LEN];
327 328
	/* sign + log10(MAX_INT) + '\0' */
	char pid_str[11];
329 330 331 332
	int spaces = 0;
	int ret;
	int len;
	int i;
333

334
	trace_find_cmdline(pid, comm);
335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363
	comm[7] = '\0';
	sprintf(pid_str, "%d", pid);

	/* 1 stands for the "-" character */
	len = strlen(comm) + strlen(pid_str) + 1;

	if (len < TRACE_GRAPH_PROCINFO_LENGTH)
		spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;

	/* First spaces to align center */
	for (i = 0; i < spaces / 2; i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	ret = trace_seq_printf(s, "%s-%s", comm, pid_str);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Last spaces to align center */
	for (i = 0; i < spaces - (spaces / 2); i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
	return TRACE_TYPE_HANDLED;
}

364

365
/* If the pid changed since the last trace, output this event */
366
static enum print_line_t
367
verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
368
{
369
	pid_t prev_pid;
370
	pid_t *last_pid;
371
	int ret;
372

373
	if (!data)
374 375
		return TRACE_TYPE_HANDLED;

376
	last_pid = &(per_cpu_ptr(data, cpu)->last_pid);
377 378

	if (*last_pid == pid)
379
		return TRACE_TYPE_HANDLED;
380

381 382
	prev_pid = *last_pid;
	*last_pid = pid;
383

384 385
	if (prev_pid == -1)
		return TRACE_TYPE_HANDLED;
386 387 388 389 390 391 392 393 394
/*
 * Context-switch trace line:

 ------------------------------------------
 | 1)  migration/0--1  =>  sshd-1755
 ------------------------------------------

 */
	ret = trace_seq_printf(s,
395
		" ------------------------------------------\n");
396
	if (!ret)
397
		return TRACE_TYPE_PARTIAL_LINE;
398 399 400

	ret = print_graph_cpu(s, cpu);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
401
		return TRACE_TYPE_PARTIAL_LINE;
402 403 404

	ret = print_graph_proc(s, prev_pid);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
405
		return TRACE_TYPE_PARTIAL_LINE;
406 407 408

	ret = trace_seq_printf(s, " => ");
	if (!ret)
409
		return TRACE_TYPE_PARTIAL_LINE;
410 411 412

	ret = print_graph_proc(s, pid);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
413
		return TRACE_TYPE_PARTIAL_LINE;
414 415 416 417

	ret = trace_seq_printf(s,
		"\n ------------------------------------------\n\n");
	if (!ret)
418
		return TRACE_TYPE_PARTIAL_LINE;
419

420
	return TRACE_TYPE_HANDLED;
421 422
}

423 424
static struct ftrace_graph_ret_entry *
get_return_for_leaf(struct trace_iterator *iter,
425 426 427 428 429 430 431 432
		struct ftrace_graph_ent_entry *curr)
{
	struct ring_buffer_iter *ring_iter;
	struct ring_buffer_event *event;
	struct ftrace_graph_ret_entry *next;

	ring_iter = iter->buffer_iter[iter->cpu];

433 434 435 436 437 438 439 440 441
	/* First peek to compare current entry and the next one */
	if (ring_iter)
		event = ring_buffer_iter_peek(ring_iter, NULL);
	else {
	/* We need to consume the current entry to see the next one */
		ring_buffer_consume(iter->tr->buffer, iter->cpu, NULL);
		event = ring_buffer_peek(iter->tr->buffer, iter->cpu,
					NULL);
	}
442 443

	if (!event)
444
		return NULL;
445 446 447 448

	next = ring_buffer_event_data(event);

	if (next->ent.type != TRACE_GRAPH_RET)
449
		return NULL;
450 451 452

	if (curr->ent.pid != next->ent.pid ||
			curr->graph_ent.func != next->ret.func)
453
		return NULL;
454

455 456 457 458 459
	/* this is a leaf, now advance the iterator */
	if (ring_iter)
		ring_buffer_read(ring_iter, NULL);

	return next;
460 461
}

462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477 478 479 480 481 482 483 484 485 486
/* Signal a overhead of time execution to the output */
static int
print_graph_overhead(unsigned long long duration, struct trace_seq *s)
{
	/* If duration disappear, we don't need anything */
	if (!(tracer_flags.val & TRACE_GRAPH_PRINT_DURATION))
		return 1;

	/* Non nested entry or return */
	if (duration == -1)
		return trace_seq_printf(s, "  ");

	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
		/* Duration exceeded 100 msecs */
		if (duration > 100000ULL)
			return trace_seq_printf(s, "! ");

		/* Duration exceeded 10 msecs */
		if (duration > 10000ULL)
			return trace_seq_printf(s, "+ ");
	}

	return trace_seq_printf(s, "  ");
}

487 488 489 490 491 492 493 494 495 496 497
static int print_graph_abs_time(u64 t, struct trace_seq *s)
{
	unsigned long usecs_rem;

	usecs_rem = do_div(t, NSEC_PER_SEC);
	usecs_rem /= 1000;

	return trace_seq_printf(s, "%5lu.%06lu |  ",
			(unsigned long)t, usecs_rem);
}

498
static enum print_line_t
499
print_graph_irq(struct trace_iterator *iter, unsigned long addr,
500
		enum trace_type type, int cpu, pid_t pid)
501 502
{
	int ret;
503
	struct trace_seq *s = &iter->seq;
504 505 506 507 508

	if (addr < (unsigned long)__irqentry_text_start ||
		addr >= (unsigned long)__irqentry_text_end)
		return TRACE_TYPE_UNHANDLED;

509 510 511 512 513 514 515
	/* Absolute time */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
		ret = print_graph_abs_time(iter->ts, s);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

516 517 518 519 520 521 522 523 524 525 526 527 528 529 530
	/* Cpu */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
		ret = print_graph_cpu(s, cpu);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}
	/* Proc */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
		ret = print_graph_proc(s, pid);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
		ret = trace_seq_printf(s, " | ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
531

532 533 534 535
	/* No overhead */
	ret = print_graph_overhead(-1, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
536

537 538 539 540 541 542 543 544 545 546 547 548
	if (type == TRACE_GRAPH_ENT)
		ret = trace_seq_printf(s, "==========>");
	else
		ret = trace_seq_printf(s, "<==========");

	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Don't close the duration column if haven't one */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
		trace_seq_printf(s, " |");
	ret = trace_seq_printf(s, "\n");
549 550 551 552 553

	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
	return TRACE_TYPE_HANDLED;
}
554

555 556
enum print_line_t
trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
557 558
{
	unsigned long nsecs_rem = do_div(duration, 1000);
559 560 561 562 563 564 565 566 567
	/* log10(ULONG_MAX) + '\0' */
	char msecs_str[21];
	char nsecs_str[5];
	int ret, len;
	int i;

	sprintf(msecs_str, "%lu", (unsigned long) duration);

	/* Print msecs */
568
	ret = trace_seq_printf(s, "%s", msecs_str);
569 570 571 572 573 574 575 576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	len = strlen(msecs_str);

	/* Print nsecs (we don't want to exceed 7 numbers) */
	if (len < 7) {
		snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem);
		ret = trace_seq_printf(s, ".%s", nsecs_str);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
		len += strlen(nsecs_str);
	}

	ret = trace_seq_printf(s, " us ");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Print remaining spaces to fit the row's width */
	for (i = len; i < 7; i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
593 594 595 596 597 598 599 600 601 602 603
	return TRACE_TYPE_HANDLED;
}

static enum print_line_t
print_graph_duration(unsigned long long duration, struct trace_seq *s)
{
	int ret;

	ret = trace_print_graph_duration(duration, s);
	if (ret != TRACE_TYPE_HANDLED)
		return ret;
604 605 606 607 608

	ret = trace_seq_printf(s, "|  ");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

609
	return TRACE_TYPE_HANDLED;
610 611 612
}

/* Case of a leaf function on its call entry */
613
static enum print_line_t
614
print_graph_entry_leaf(struct trace_iterator *iter,
615 616
		struct ftrace_graph_ent_entry *entry,
		struct ftrace_graph_ret_entry *ret_entry, struct trace_seq *s)
617
{
618
	struct fgraph_data *data = iter->private;
619 620 621
	struct ftrace_graph_ret *graph_ret;
	struct ftrace_graph_ent *call;
	unsigned long long duration;
622
	int ret;
623
	int i;
624

625 626 627 628
	graph_ret = &ret_entry->ret;
	call = &entry->graph_ent;
	duration = graph_ret->rettime - graph_ret->calltime;

629 630 631 632 633 634 635 636 637 638 639 640
	if (data) {
		int cpu = iter->cpu;
		int *depth = &(per_cpu_ptr(data, cpu)->depth);

		/*
		 * Comments display at + 1 to depth. Since
		 * this is a leaf function, keep the comments
		 * equal to this depth.
		 */
		*depth = call->depth - 1;
	}

641
	/* Overhead */
642 643 644
	ret = print_graph_overhead(duration, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
645 646

	/* Duration */
647 648 649 650 651
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
		ret = print_graph_duration(duration, s);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}
652

653 654 655 656 657 658 659
	/* Function */
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

660
	ret = trace_seq_printf(s, "%pf();\n", (void *)call->func);
661 662 663 664 665 666 667
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	return TRACE_TYPE_HANDLED;
}

static enum print_line_t
668 669 670
print_graph_entry_nested(struct trace_iterator *iter,
			 struct ftrace_graph_ent_entry *entry,
			 struct trace_seq *s, int cpu)
671 672
{
	struct ftrace_graph_ent *call = &entry->graph_ent;
673 674 675 676 677 678 679 680 681 682
	struct fgraph_data *data = iter->private;
	int ret;
	int i;

	if (data) {
		int cpu = iter->cpu;
		int *depth = &(per_cpu_ptr(data, cpu)->depth);

		*depth = call->depth;
	}
683 684

	/* No overhead */
685 686 687
	ret = print_graph_overhead(-1, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
688

689 690
	/* No time */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
691 692 693 694 695
		ret = trace_seq_printf(s, "            |  ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

696
	/* Function */
697 698
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
699 700
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
701 702
	}

703
	ret = trace_seq_printf(s, "%pf() {\n", (void *)call->func);
704 705 706
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

707 708 709 710 711
	/*
	 * we already consumed the current entry to check the next one
	 * and see if this is a leaf.
	 */
	return TRACE_TYPE_NO_CONSUME;
712 713
}

714
static enum print_line_t
715 716
print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
		     int type, unsigned long addr)
717
{
718
	struct fgraph_data *data = iter->private;
719
	struct trace_entry *ent = iter->ent;
720 721
	int cpu = iter->cpu;
	int ret;
722

723
	/* Pid */
724
	if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE)
725 726
		return TRACE_TYPE_PARTIAL_LINE;

727 728 729 730 731 732
	if (type) {
		/* Interrupt */
		ret = print_graph_irq(iter, addr, type, cpu, ent->pid);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}
733

734 735 736 737 738 739 740
	/* Absolute time */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
		ret = print_graph_abs_time(iter->ts, s);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

741 742 743
	/* Cpu */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
		ret = print_graph_cpu(s, cpu);
744 745 746 747 748 749
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Proc */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
750
		ret = print_graph_proc(s, ent->pid);
751 752 753 754
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;

		ret = trace_seq_printf(s, " | ");
755 756 757
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
758

759 760 761 762 763 764 765 766 767 768 769 770 771 772
	return 0;
}

static enum print_line_t
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
			struct trace_iterator *iter)
{
	int cpu = iter->cpu;
	struct ftrace_graph_ent *call = &field->graph_ent;
	struct ftrace_graph_ret_entry *leaf_ret;

	if (print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func))
		return TRACE_TYPE_PARTIAL_LINE;

773 774 775
	leaf_ret = get_return_for_leaf(iter, field);
	if (leaf_ret)
		return print_graph_entry_leaf(iter, field, leaf_ret, s);
776
	else
777
		return print_graph_entry_nested(iter, field, s, cpu);
778 779 780

}

781 782
static enum print_line_t
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
783
		   struct trace_entry *ent, struct trace_iterator *iter)
784
{
785
	unsigned long long duration = trace->rettime - trace->calltime;
786 787 788 789 790 791 792 793 794 795 796 797 798 799 800 801 802
	struct fgraph_data *data = iter->private;
	pid_t pid = ent->pid;
	int cpu = iter->cpu;
	int ret;
	int i;

	if (data) {
		int cpu = iter->cpu;
		int *depth = &(per_cpu_ptr(data, cpu)->depth);

		/*
		 * Comments display at + 1 to depth. This is the
		 * return from a function, we now want the comments
		 * to display at the same level of the bracket.
		 */
		*depth = trace->depth - 1;
	}
803

804
	if (print_graph_prologue(iter, s, 0, 0))
805 806
		return TRACE_TYPE_PARTIAL_LINE;

807
	/* Overhead */
808 809 810
	ret = print_graph_overhead(duration, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
811 812

	/* Duration */
813 814 815 816 817
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
		ret = print_graph_duration(duration, s);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}
818 819

	/* Closing brace */
820 821
	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
822 823
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
824 825
	}

826
	ret = trace_seq_printf(s, "}\n");
827 828
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
829

830
	/* Overrun */
831 832 833
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
		ret = trace_seq_printf(s, " (Overruns: %lu)\n",
					trace->overrun);
834 835
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
836
	}
837

838
	ret = print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, cpu, pid);
839 840 841
	if (ret == TRACE_TYPE_PARTIAL_LINE)
		return TRACE_TYPE_PARTIAL_LINE;

842 843 844
	return TRACE_TYPE_HANDLED;
}

845
static enum print_line_t
846 847
print_graph_comment(struct trace_seq *s,  struct trace_entry *ent,
		    struct trace_iterator *iter)
848
{
849
	unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
850
	struct fgraph_data *data = iter->private;
851
	struct trace_event *event;
852
	int depth = 0;
853
	int ret;
854 855 856 857
	int i;

	if (data)
		depth = per_cpu_ptr(data, iter->cpu)->depth;
858

859
	if (print_graph_prologue(iter, s, 0, 0))
860 861
		return TRACE_TYPE_PARTIAL_LINE;

862
	/* No overhead */
863 864 865 866 867 868 869
	ret = print_graph_overhead(-1, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* No time */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
		ret = trace_seq_printf(s, "            |  ");
870 871 872 873 874
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Indentation */
875 876
	if (depth > 0)
		for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) {
877 878 879 880 881 882
			ret = trace_seq_printf(s, " ");
			if (!ret)
				return TRACE_TYPE_PARTIAL_LINE;
		}

	/* The comment */
883 884 885 886
	ret = trace_seq_printf(s, "/* ");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905 906
	switch (iter->ent->type) {
	case TRACE_BPRINT:
		ret = trace_print_bprintk_msg_only(iter);
		if (ret != TRACE_TYPE_HANDLED)
			return ret;
		break;
	case TRACE_PRINT:
		ret = trace_print_printk_msg_only(iter);
		if (ret != TRACE_TYPE_HANDLED)
			return ret;
		break;
	default:
		event = ftrace_find_event(ent->type);
		if (!event)
			return TRACE_TYPE_UNHANDLED;

		ret = event->trace(iter, sym_flags);
		if (ret != TRACE_TYPE_HANDLED)
			return ret;
	}
907

908 909 910 911 912 913
	/* Strip ending newline */
	if (s->buffer[s->len - 1] == '\n') {
		s->buffer[s->len - 1] = '\0';
		s->len--;
	}

914 915 916 917 918 919 920 921
	ret = trace_seq_printf(s, " */\n");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	return TRACE_TYPE_HANDLED;
}


922 923 924 925
enum print_line_t
print_graph_function(struct trace_iterator *iter)
{
	struct trace_entry *entry = iter->ent;
926
	struct trace_seq *s = &iter->seq;
927

928 929
	switch (entry->type) {
	case TRACE_GRAPH_ENT: {
930 931 932 933 934 935 936
		/*
		 * print_graph_entry() may consume the current event,
		 * thus @field may become invalid, so we need to save it.
		 * sizeof(struct ftrace_graph_ent_entry) is very small,
		 * it can be safely saved at the stack.
		 */
		struct ftrace_graph_ent_entry *field, saved;
937
		trace_assign_type(field, entry);
938 939
		saved = *field;
		return print_graph_entry(&saved, s, iter);
940 941 942 943
	}
	case TRACE_GRAPH_RET: {
		struct ftrace_graph_ret_entry *field;
		trace_assign_type(field, entry);
944
		return print_graph_return(&field->ret, s, entry, iter);
945 946
	}
	default:
947
		return print_graph_comment(s, entry, iter);
948
	}
949 950

	return TRACE_TYPE_HANDLED;
951 952
}

953 954 955 956
static void print_graph_headers(struct seq_file *s)
{
	/* 1st line */
	seq_printf(s, "# ");
957 958
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
		seq_printf(s, "     TIME       ");
959
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
960
		seq_printf(s, "CPU");
961
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
962 963 964 965
		seq_printf(s, "  TASK/PID      ");
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
		seq_printf(s, "  DURATION   ");
	seq_printf(s, "               FUNCTION CALLS\n");
966 967 968

	/* 2nd line */
	seq_printf(s, "# ");
969 970
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
		seq_printf(s, "      |         ");
971
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
972
		seq_printf(s, "|  ");
973
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
974 975 976 977
		seq_printf(s, "  |    |        ");
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
		seq_printf(s, "   |   |      ");
	seq_printf(s, "               |   |   |   |\n");
978
}
979 980 981

static void graph_trace_open(struct trace_iterator *iter)
{
982 983
	/* pid and depth on the last trace processed */
	struct fgraph_data *data = alloc_percpu(struct fgraph_data);
984 985
	int cpu;

986
	if (!data)
987 988 989
		pr_warning("function graph tracer: not enough memory\n");
	else
		for_each_possible_cpu(cpu) {
990 991
			pid_t *pid = &(per_cpu_ptr(data, cpu)->last_pid);
			int *depth = &(per_cpu_ptr(data, cpu)->depth);
992
			*pid = -1;
993
			*depth = 0;
994 995
		}

996
	iter->private = data;
997 998 999 1000
}

static void graph_trace_close(struct trace_iterator *iter)
{
1001
	free_percpu(iter->private);
1002 1003
}

1004
static struct tracer graph_trace __read_mostly = {
1005
	.name		= "function_graph",
1006 1007
	.open		= graph_trace_open,
	.close		= graph_trace_close,
1008
	.wait_pipe	= poll_wait_pipe,
1009 1010
	.init		= graph_trace_init,
	.reset		= graph_trace_reset,
1011 1012
	.print_line	= print_graph_function,
	.print_header	= print_graph_headers,
1013
	.flags		= &tracer_flags,
1014 1015 1016
#ifdef CONFIG_FTRACE_SELFTEST
	.selftest	= trace_selftest_startup_function_graph,
#endif
1017 1018 1019 1020
};

static __init int init_graph_trace(void)
{
1021 1022
	max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1);

1023 1024 1025 1026
	return register_tracer(&graph_trace);
}

device_initcall(init_graph_trace);