trace_functions_graph.c 27.8 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
struct fgraph_cpu_data {
18
19
	pid_t		last_pid;
	int		depth;
20
21
22
23
24
25
26
27
28
29
30
	int		ignore;
};

struct fgraph_data {
	struct fgraph_cpu_data		*cpu_data;

	/* Place to preserve last processed entry. */
	struct ftrace_graph_ent_entry	ent;
	struct ftrace_graph_ret_entry	ret;
	int				failed;
	int				cpu;
31
32
};

33
#define TRACE_GRAPH_INDENT	2
34

35
/* Flag options */
36
#define TRACE_GRAPH_PRINT_OVERRUN	0x1
37
38
#define TRACE_GRAPH_PRINT_CPU		0x2
#define TRACE_GRAPH_PRINT_OVERHEAD	0x4
39
#define TRACE_GRAPH_PRINT_PROC		0x8
40
41
#define TRACE_GRAPH_PRINT_DURATION	0x10
#define TRACE_GRAPH_PRINT_ABS_TIME	0X20
42

43
static struct tracer_opt trace_opts[] = {
44
	/* Display overruns? (for self-debug purpose) */
45
46
47
48
49
	{ 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) },
50
51
	/* Display proc name/pid */
	{ TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
52
53
54
55
	/* 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) },
56
57
58
59
	{ } /* Empty entry */
};

static struct tracer_flags tracer_flags = {
60
	/* Don't display overruns and proc by default */
61
62
	.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
	       TRACE_GRAPH_PRINT_DURATION,
63
64
65
	.opts = trace_opts
};

66
static struct trace_array *graph_array;
67

68

69
70
/* Add a function return address to the trace stack on thread info.*/
int
71
72
ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
			 unsigned long frame_pointer)
73
{
74
	unsigned long long calltime;
75
76
77
78
79
	int index;

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

80
81
82
83
84
85
	/*
	 * We must make sure the ret_stack is tested before we read
	 * anything else.
	 */
	smp_rmb();

86
87
88
89
90
91
	/* The return trace stack is full */
	if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {
		atomic_inc(&current->trace_overrun);
		return -EBUSY;
	}

92
93
	calltime = trace_clock_local();

94
95
96
97
	index = ++current->curr_ret_stack;
	barrier();
	current->ret_stack[index].ret = ret;
	current->ret_stack[index].func = func;
98
	current->ret_stack[index].calltime = calltime;
99
	current->ret_stack[index].subtime = 0;
100
	current->ret_stack[index].fp = frame_pointer;
101
102
103
104
105
106
	*depth = index;

	return 0;
}

/* Retrieve a function return address to the trace stack on thread info.*/
107
static void
108
109
ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
			unsigned long frame_pointer)
110
111
112
113
114
115
116
117
118
119
120
121
122
{
	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;
	}

123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
#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"
138
		     "  from func %ps return to %lx\n",
139
140
141
142
143
144
145
146
147
		     current->ret_stack[index].fp,
		     frame_pointer,
		     (void *)current->ret_stack[index].func,
		     current->ret_stack[index].ret);
		*ret = (unsigned long)panic;
		return;
	}
#endif

148
149
150
151
152
153
154
155
156
157
158
	*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.
 */
159
unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
160
161
162
163
{
	struct ftrace_graph_ret trace;
	unsigned long ret;

164
	ftrace_pop_return_trace(&trace, &ret, frame_pointer);
165
	trace.rettime = trace_clock_local();
166
	ftrace_graph_return(&trace);
167
168
	barrier();
	current->curr_ret_stack--;
169
170
171
172
173
174
175
176
177
178
179

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

	return ret;
}

180
181
182
183
184
185
186
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;
187
	struct ring_buffer *buffer = tr->buffer;
188
189
	struct ftrace_graph_ent_entry *entry;

190
	if (unlikely(__this_cpu_read(per_cpu_var(ftrace_cpu_disabled))))
191
192
		return 0;

193
	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
194
195
196
197
198
					  sizeof(*entry), flags, pc);
	if (!event)
		return 0;
	entry	= ring_buffer_event_data(event);
	entry->graph_ent			= *trace;
199
200
	if (!filter_current_check_discard(buffer, call, entry, event))
		ring_buffer_unlock_commit(buffer, event);
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

	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;
251
	struct ring_buffer *buffer = tr->buffer;
252
253
	struct ftrace_graph_ret_entry *entry;

254
	if (unlikely(__this_cpu_read(per_cpu_var(ftrace_cpu_disabled))))
255
256
		return;

257
	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET,
258
259
260
261
262
					  sizeof(*entry), flags, pc);
	if (!event)
		return;
	entry	= ring_buffer_event_data(event);
	entry->ret				= *trace;
263
264
	if (!filter_current_check_discard(buffer, call, entry, event))
		ring_buffer_unlock_commit(buffer, event);
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
}

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);
}

290
291
static int graph_trace_init(struct trace_array *tr)
{
292
293
294
295
296
	int ret;

	graph_array = tr;
	ret = register_ftrace_graph(&trace_graph_return,
				    &trace_graph_entry);
297
298
299
300
301
	if (ret)
		return ret;
	tracing_start_cmdline_record();

	return 0;
302
303
}

304
305
306
307
308
void set_graph_array(struct trace_array *tr)
{
	graph_array = tr;
}

309
310
static void graph_trace_reset(struct trace_array *tr)
{
311
312
	tracing_stop_cmdline_record();
	unregister_ftrace_graph();
313
314
}

315
static int max_bytes_for_cpu;
316
317
318
319
320
321

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

322
323
324
325
326
	/*
	 * Start with a space character - to make it stand out
	 * to the right a bit when trace output is pasted into
	 * email:
	 */
327
	ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
328
	if (!ret)
329
330
		return TRACE_TYPE_PARTIAL_LINE;

331
332
333
	return TRACE_TYPE_HANDLED;
}

334
335
336
337
338
#define TRACE_GRAPH_PROCINFO_LENGTH	14

static enum print_line_t
print_graph_proc(struct trace_seq *s, pid_t pid)
{
339
	char comm[TASK_COMM_LEN];
340
341
	/* sign + log10(MAX_INT) + '\0' */
	char pid_str[11];
342
343
344
345
	int spaces = 0;
	int ret;
	int len;
	int i;
346

347
	trace_find_cmdline(pid, comm);
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
	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;
}

377

378
379
380
static enum print_line_t
print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
{
381
	if (!trace_seq_putc(s, ' '))
382
383
		return 0;

384
	return trace_print_lat_fmt(s, entry);
385
386
}

387
/* If the pid changed since the last trace, output this event */
388
static enum print_line_t
389
verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
390
{
391
	pid_t prev_pid;
392
	pid_t *last_pid;
393
	int ret;
394

395
	if (!data)
396
397
		return TRACE_TYPE_HANDLED;

398
	last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
399
400

	if (*last_pid == pid)
401
		return TRACE_TYPE_HANDLED;
402

403
404
	prev_pid = *last_pid;
	*last_pid = pid;
405

406
407
	if (prev_pid == -1)
		return TRACE_TYPE_HANDLED;
408
409
410
411
412
413
414
415
416
/*
 * Context-switch trace line:

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

 */
	ret = trace_seq_printf(s,
417
		" ------------------------------------------\n");
418
	if (!ret)
419
		return TRACE_TYPE_PARTIAL_LINE;
420
421
422

	ret = print_graph_cpu(s, cpu);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
423
		return TRACE_TYPE_PARTIAL_LINE;
424
425
426

	ret = print_graph_proc(s, prev_pid);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
427
		return TRACE_TYPE_PARTIAL_LINE;
428
429
430

	ret = trace_seq_printf(s, " => ");
	if (!ret)
431
		return TRACE_TYPE_PARTIAL_LINE;
432
433
434

	ret = print_graph_proc(s, pid);
	if (ret == TRACE_TYPE_PARTIAL_LINE)
435
		return TRACE_TYPE_PARTIAL_LINE;
436
437
438
439

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

442
	return TRACE_TYPE_HANDLED;
443
444
}

445
446
static struct ftrace_graph_ret_entry *
get_return_for_leaf(struct trace_iterator *iter,
447
448
		struct ftrace_graph_ent_entry *curr)
{
449
450
	struct fgraph_data *data = iter->private;
	struct ring_buffer_iter *ring_iter = NULL;
451
452
453
	struct ring_buffer_event *event;
	struct ftrace_graph_ret_entry *next;

454
455
456
457
458
459
460
461
	/*
	 * If the previous output failed to write to the seq buffer,
	 * then we just reuse the data from before.
	 */
	if (data && data->failed) {
		curr = &data->ent;
		next = &data->ret;
	} else {
462

463
464
465
466
467
468
469
470
471
472
473
474
475
476
		ring_iter = iter->buffer_iter[iter->cpu];

		/* 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);
		}
477

478
479
480
481
		if (!event)
			return NULL;

		next = ring_buffer_event_data(event);
482

483
484
485
486
487
488
489
490
491
		if (data) {
			/*
			 * Save current and next entries for later reference
			 * if the output fails.
			 */
			data->ent = *curr;
			data->ret = *next;
		}
	}
492
493

	if (next->ent.type != TRACE_GRAPH_RET)
494
		return NULL;
495
496
497

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

500
501
502
503
504
	/* this is a leaf, now advance the iterator */
	if (ring_iter)
		ring_buffer_read(ring_iter, NULL);

	return next;
505
506
}

507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
/* 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, "  ");
}

532
533
534
535
536
537
538
539
540
541
542
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);
}

543
static enum print_line_t
544
print_graph_irq(struct trace_iterator *iter, unsigned long addr,
545
		enum trace_type type, int cpu, pid_t pid)
546
547
{
	int ret;
548
	struct trace_seq *s = &iter->seq;
549
550
551
552
553

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

554
555
556
557
558
559
560
	/* 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;
	}

561
562
563
564
565
566
	/* 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;
	}
567

568
569
570
571
572
573
574
575
576
	/* 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;
	}
577

578
579
580
581
	/* No overhead */
	ret = print_graph_overhead(-1, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
582

583
584
585
586
587
588
589
590
591
592
593
594
	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");
595
596
597
598
599

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

601
602
enum print_line_t
trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
603
604
{
	unsigned long nsecs_rem = do_div(duration, 1000);
605
606
607
608
609
610
611
612
613
	/* 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 */
614
	ret = trace_seq_printf(s, "%s", msecs_str);
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
	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;
	}
639
640
641
642
643
644
645
646
647
648
649
	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;
650
651
652
653
654

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

655
	return TRACE_TYPE_HANDLED;
656
657
658
}

/* Case of a leaf function on its call entry */
659
static enum print_line_t
660
print_graph_entry_leaf(struct trace_iterator *iter,
661
662
		struct ftrace_graph_ent_entry *entry,
		struct ftrace_graph_ret_entry *ret_entry, struct trace_seq *s)
663
{
664
	struct fgraph_data *data = iter->private;
665
666
667
	struct ftrace_graph_ret *graph_ret;
	struct ftrace_graph_ent *call;
	unsigned long long duration;
668
	int ret;
669
	int i;
670

671
672
673
674
	graph_ret = &ret_entry->ret;
	call = &entry->graph_ent;
	duration = graph_ret->rettime - graph_ret->calltime;

675
676
	if (data) {
		int cpu = iter->cpu;
677
		int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
678
679
680
681
682
683
684
685
686

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

687
	/* Overhead */
688
689
690
	ret = print_graph_overhead(duration, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
691
692

	/* Duration */
693
694
695
696
697
	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;
	}
698

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

706
	ret = trace_seq_printf(s, "%ps();\n", (void *)call->func);
707
708
709
710
711
712
713
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	return TRACE_TYPE_HANDLED;
}

static enum print_line_t
714
715
716
print_graph_entry_nested(struct trace_iterator *iter,
			 struct ftrace_graph_ent_entry *entry,
			 struct trace_seq *s, int cpu)
717
718
{
	struct ftrace_graph_ent *call = &entry->graph_ent;
719
720
721
722
723
724
	struct fgraph_data *data = iter->private;
	int ret;
	int i;

	if (data) {
		int cpu = iter->cpu;
725
		int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
726
727
728

		*depth = call->depth;
	}
729
730

	/* No overhead */
731
732
733
	ret = print_graph_overhead(-1, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
734

735
736
	/* No time */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) {
737
738
739
740
741
		ret = trace_seq_printf(s, "            |  ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

742
	/* Function */
743
744
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
745
746
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
747
748
	}

749
	ret = trace_seq_printf(s, "%ps() {\n", (void *)call->func);
750
751
752
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

753
754
755
756
757
	/*
	 * we already consumed the current entry to check the next one
	 * and see if this is a leaf.
	 */
	return TRACE_TYPE_NO_CONSUME;
758
759
}

760
static enum print_line_t
761
762
print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
		     int type, unsigned long addr)
763
{
764
	struct fgraph_data *data = iter->private;
765
	struct trace_entry *ent = iter->ent;
766
767
	int cpu = iter->cpu;
	int ret;
768

769
	/* Pid */
770
	if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE)
771
772
		return TRACE_TYPE_PARTIAL_LINE;

773
774
775
776
777
778
	if (type) {
		/* Interrupt */
		ret = print_graph_irq(iter, addr, type, cpu, ent->pid);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}
779

780
781
782
783
784
785
786
	/* 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;
	}

787
788
789
	/* Cpu */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
		ret = print_graph_cpu(s, cpu);
790
791
792
793
794
795
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Proc */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
796
		ret = print_graph_proc(s, ent->pid);
797
798
799
800
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;

		ret = trace_seq_printf(s, " | ");
801
802
803
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
804

805
806
807
808
809
810
811
	/* Latency format */
	if (trace_flags & TRACE_ITER_LATENCY_FMT) {
		ret = print_graph_lat_fmt(s, ent);
		if (ret == TRACE_TYPE_PARTIAL_LINE)
			return TRACE_TYPE_PARTIAL_LINE;
	}

812
813
814
815
816
817
818
	return 0;
}

static enum print_line_t
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
			struct trace_iterator *iter)
{
819
	struct fgraph_data *data = iter->private;
820
821
	struct ftrace_graph_ent *call = &field->graph_ent;
	struct ftrace_graph_ret_entry *leaf_ret;
822
823
	static enum print_line_t ret;
	int cpu = iter->cpu;
824
825
826
827

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

828
829
	leaf_ret = get_return_for_leaf(iter, field);
	if (leaf_ret)
830
		ret = print_graph_entry_leaf(iter, field, leaf_ret, s);
831
	else
832
		ret = print_graph_entry_nested(iter, field, s, cpu);
833

834
835
836
837
838
839
840
841
842
843
844
845
846
	if (data) {
		/*
		 * If we failed to write our output, then we need to make
		 * note of it. Because we already consumed our entry.
		 */
		if (s->full) {
			data->failed = 1;
			data->cpu = cpu;
		} else
			data->failed = 0;
	}

	return ret;
847
848
}

849
850
static enum print_line_t
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
851
		   struct trace_entry *ent, struct trace_iterator *iter)
852
{
853
	unsigned long long duration = trace->rettime - trace->calltime;
854
855
856
857
858
859
860
861
	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;
862
		int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
863
864
865
866
867
868
869
870

		/*
		 * 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;
	}
871

872
	if (print_graph_prologue(iter, s, 0, 0))
873
874
		return TRACE_TYPE_PARTIAL_LINE;

875
	/* Overhead */
876
877
878
	ret = print_graph_overhead(duration, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
879
880

	/* Duration */
881
882
883
884
885
	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;
	}
886
887

	/* Closing brace */
888
889
	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
890
891
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
892
893
	}

894
	ret = trace_seq_printf(s, "}\n");
895
896
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
897

898
	/* Overrun */
899
900
901
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
		ret = trace_seq_printf(s, " (Overruns: %lu)\n",
					trace->overrun);
902
903
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
904
	}
905

906
	ret = print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, cpu, pid);
907
908
909
	if (ret == TRACE_TYPE_PARTIAL_LINE)
		return TRACE_TYPE_PARTIAL_LINE;

910
911
912
	return TRACE_TYPE_HANDLED;
}

913
static enum print_line_t
914
915
print_graph_comment(struct trace_seq *s,  struct trace_entry *ent,
		    struct trace_iterator *iter)
916
{
917
	unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
918
	struct fgraph_data *data = iter->private;
919
	struct trace_event *event;
920
	int depth = 0;
921
	int ret;
922
923
924
	int i;

	if (data)
925
		depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
926

927
	if (print_graph_prologue(iter, s, 0, 0))
928
929
		return TRACE_TYPE_PARTIAL_LINE;

930
	/* No overhead */
931
932
933
934
935
936
937
	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, "            |  ");
938
939
940
941
942
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Indentation */
943
944
	if (depth > 0)
		for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) {
945
946
947
948
949
950
			ret = trace_seq_printf(s, " ");
			if (!ret)
				return TRACE_TYPE_PARTIAL_LINE;
		}

	/* The comment */
951
952
953
954
	ret = trace_seq_printf(s, "/* ");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

955
956
957
958
959
960
961
962
963
964
965
966
967
968
969
970
971
972
973
974
	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;
	}
975

976
977
978
979
980
981
	/* Strip ending newline */
	if (s->buffer[s->len - 1] == '\n') {
		s->buffer[s->len - 1] = '\0';
		s->len--;
	}

982
983
984
985
986
987
988
989
	ret = trace_seq_printf(s, " */\n");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	return TRACE_TYPE_HANDLED;
}


990
991
992
enum print_line_t
print_graph_function(struct trace_iterator *iter)
{
993
994
	struct ftrace_graph_ent_entry *field;
	struct fgraph_data *data = iter->private;
995
	struct trace_entry *entry = iter->ent;
996
	struct trace_seq *s = &iter->seq;
997
998
999
1000
1001
1002
1003
1004
1005
1006
1007
1008
1009
1010
1011
1012
1013
1014
1015
1016
1017
1018
1019
	int cpu = iter->cpu;
	int ret;

	if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) {
		per_cpu_ptr(data->cpu_data, cpu)->ignore = 0;
		return TRACE_TYPE_HANDLED;
	}

	/*
	 * If the last output failed, there's a possibility we need
	 * to print out the missing entry which would never go out.
	 */
	if (data && data->failed) {
		field = &data->ent;
		iter->cpu = data->cpu;
		ret = print_graph_entry(field, s, iter);
		if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
			per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
			ret = TRACE_TYPE_NO_CONSUME;
		}
		iter->cpu = cpu;
		return ret;
	}
1020

1021
1022
	switch (entry->type) {
	case TRACE_GRAPH_ENT: {
1023
1024
1025
1026
1027
1028
		/*
		 * 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.
		 */
1029
		struct ftrace_graph_ent_entry saved;
1030
		trace_assign_type(field, entry);
1031
1032
		saved = *field;
		return print_graph_entry(&saved, s, iter);
1033
1034
1035
1036
	}
	case TRACE_GRAPH_RET: {
		struct ftrace_graph_ret_entry *field;
		trace_assign_type(field, entry);
1037
		return print_graph_return(&field->ret, s, entry, iter);
1038
1039
	}
	default:
1040
		return print_graph_comment(s, entry, iter);
1041
	}
1042
1043

	return TRACE_TYPE_HANDLED;
1044
1045
}

1046
1047
1048
1049
1050
1051
1052
1053
1054
1055
1056
1057
1058
1059
1060
1061
1062
1063
static void print_lat_header(struct seq_file *s)
{
	static const char spaces[] = "                "	/* 16 spaces */
		"    "					/* 4 spaces */
		"                 ";			/* 17 spaces */
	int size = 0;

	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
		size += 16;
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
		size += 4;
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
		size += 17;

	seq_printf(s, "#%.*s  _-----=> irqs-off        \n", size, spaces);
	seq_printf(s, "#%.*s / _----=> need-resched    \n", size, spaces);
	seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
	seq_printf(s, "#%.*s|| / _--=> preempt-depth   \n", size, spaces);
1064
1065
	seq_printf(s, "#%.*s||| / _-=> lock-depth      \n", size, spaces);
	seq_printf(s, "#%.*s|||| /                     \n", size, spaces);
1066
1067
}

1068
1069
static void print_graph_headers(struct seq_file *s)
{
1070
1071
1072
1073
1074
	int lat = trace_flags & TRACE_ITER_LATENCY_FMT;

	if (lat)
		print_lat_header(s);

1075
	/* 1st line */
1076
	seq_printf(s, "#");
1077
1078
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
		seq_printf(s, "     TIME       ");
1079
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
1080
		seq_printf(s, " CPU");
1081
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
1082
1083
		seq_printf(s, "  TASK/PID       ");
	if (lat)
1084
		seq_printf(s, "|||||");
1085
1086
1087
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
		seq_printf(s, "  DURATION   ");
	seq_printf(s, "               FUNCTION CALLS\n");
1088
1089

	/* 2nd line */
1090
	seq_printf(s, "#");
1091
1092
	if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
		seq_printf(s, "      |         ");
1093
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
1094
		seq_printf(s, " |  ");
1095
	if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
1096
1097
		seq_printf(s, "   |    |        ");
	if (lat)
1098
		seq_printf(s, "|||||");
1099
1100
1101
	if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
		seq_printf(s, "   |   |      ");
	seq_printf(s, "               |   |   |   |\n");
1102
}
1103
1104
1105

static void graph_trace_open(struct trace_iterator *iter)
{
1106
	/* pid and depth on the last trace processed */
1107
	struct fgraph_data *data;
1108
1109
	int cpu;

1110
1111
1112
	iter->private = NULL;

	data = kzalloc(sizeof(*data), GFP_KERNEL);
1113
	if (!data)
1114
1115
1116
1117
1118
1119
1120
1121
1122
1123
1124
1125
1126
1127
		goto out_err;

	data->cpu_data = alloc_percpu(struct fgraph_cpu_data);
	if (!data->cpu_data)
		goto out_err_free;

	for_each_possible_cpu(cpu) {
		pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
		int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
		int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore);
		*pid = -1;
		*depth = 0;
		*ignore = 0;
	}
1128

1129
	iter->private = data;
1130
1131
1132
1133
1134
1135
1136

	return;

 out_err_free:
	kfree(data);
 out_err:
	pr_warning("function graph tracer: not enough memory\n");
1137
1138
1139
1140
}

static void graph_trace_close(struct trace_iterator *iter)
{
1141
1142
1143
1144
1145
1146
	struct fgraph_data *data = iter->private;

	if (data) {
		free_percpu(data->cpu_data);
		kfree(data);
	}
1147
1148
}

1149
static struct tracer graph_trace __read_mostly = {
1150
	.name		= "function_graph",
1151
	.open		= graph_trace_open,
1152
	.pipe_open	= graph_trace_open,
1153
	.close		= graph_trace_close,
1154
	.pipe_close	= graph_trace_close,
1155
	.wait_pipe	= poll_wait_pipe,
1156
1157
	.init		= graph_trace_init,
	.reset		= graph_trace_reset,
1158
1159
	.print_line	= print_graph_function,
	.print_header	= print_graph_headers,
1160
	.flags		= &tracer_flags,
1161
1162
1163
#ifdef CONFIG_FTRACE_SELFTEST
	.selftest	= trace_selftest_startup_function_graph,
#endif
1164
1165
1166
1167
};

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

1170
1171
1172
1173
	return register_tracer(&graph_trace);
}

device_initcall(init_graph_trace);