trace_functions_graph.c 9 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
/*
 *
 * Function graph tracer.
 * Copyright (c) 2008 Frederic Weisbecker <fweisbec@gmail.com>
 * 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"

16
#define TRACE_GRAPH_INDENT	2
17

18
/* Flag options */
19
#define TRACE_GRAPH_PRINT_OVERRUN	0x1
20
21
22
#define TRACE_GRAPH_PRINT_CPU		0x2
#define TRACE_GRAPH_PRINT_OVERHEAD	0x4

23
static struct tracer_opt trace_opts[] = {
24
25
26
27
28
29
	/* Display overruns ? */
	{ 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) },
30
31
32
33
	{ } /* Empty entry */
};

static struct tracer_flags tracer_flags = {
34
35
	/* Don't display overruns by default */
	.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD,
36
37
38
	.opts = trace_opts
};

39
/* pid on the last trace processed */
40
static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 };
41
42
43

static int graph_trace_init(struct trace_array *tr)
{
44
45
	int cpu, ret;

46
47
48
	for_each_online_cpu(cpu)
		tracing_reset(tr, cpu);

49
	ret = register_ftrace_graph(&trace_graph_return,
50
					&trace_graph_entry);
51
52
53
54
55
	if (ret)
		return ret;
	tracing_start_cmdline_record();

	return 0;
56
57
58
59
}

static void graph_trace_reset(struct trace_array *tr)
{
60
61
	tracing_stop_cmdline_record();
	unregister_ftrace_graph();
62
63
}

64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
static inline int log10_cpu(int nb)
{
	if (nb / 100)
		return 3;
	if (nb / 10)
		return 2;
	return 1;
}

static enum print_line_t
print_graph_cpu(struct trace_seq *s, int cpu)
{
	int i;
	int ret;
	int log10_this = log10_cpu(cpu);
	int log10_all = log10_cpu(cpus_weight_nr(cpu_online_map));


82
83
84
85
86
87
88
89
90
91
92
93
94
	/*
	 * Start with a space character - to make it stand out
	 * to the right a bit when trace output is pasted into
	 * email:
	 */
	ret = trace_seq_printf(s, " ");

	/*
	 * Tricky - we space the CPU field according to the max
	 * number of online CPUs. On a 2-cpu system it would take
	 * a maximum of 1 digit - on a 128 cpu system it would
	 * take up to 3 digits:
	 */
95
96
97
98
99
100
101
	for (i = 0; i < log10_all - log10_this; i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
	ret = trace_seq_printf(s, "%d) ", cpu);
	if (!ret)
102
103
		return TRACE_TYPE_PARTIAL_LINE;

104
105
106
107
	return TRACE_TYPE_HANDLED;
}


108
/* If the pid changed since the last trace, output this event */
109
static int verif_pid(struct trace_seq *s, pid_t pid, int cpu)
110
{
111
112
113
	char *comm, *prev_comm;
	pid_t prev_pid;
	int ret;
114

115
	if (last_pid[cpu] != -1 && last_pid[cpu] == pid)
116
		return 1;
117

118
	prev_pid = last_pid[cpu];
119
	last_pid[cpu] = pid;
120

121
	comm = trace_find_cmdline(pid);
122
	prev_comm = trace_find_cmdline(prev_pid);
123

124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
/*
 * Context-switch trace line:

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

 */
	ret = trace_seq_printf(s,
		" ------------------------------------------\n");
	ret += trace_seq_printf(s, " | %d)  %s-%d  =>  %s-%d\n",
				  cpu, prev_comm, prev_pid, comm, pid);
	ret += trace_seq_printf(s,
		" ------------------------------------------\n\n");
	return ret;
139
140
}

141
142
143
144
145
146
147
148
149
150
151
152
153
static bool
trace_branch_is_leaf(struct trace_iterator *iter,
		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];

	if (!ring_iter)
		return false;

154
	event = ring_buffer_iter_peek(ring_iter, NULL);
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175

	if (!event)
		return false;

	next = ring_buffer_event_data(event);

	if (next->ent.type != TRACE_GRAPH_RET)
		return false;

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

	return true;
}


static inline int
print_graph_duration(unsigned long long duration, struct trace_seq *s)
{
	unsigned long nsecs_rem = do_div(duration, 1000);
176
	return trace_seq_printf(s, "%4llu.%3lu us |  ", duration, nsecs_rem);
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
}

/* Signal a overhead of time execution to the output */
static int
print_graph_overhead(unsigned long long duration, struct trace_seq *s)
{
	/* 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, "  ");
}

/* Case of a leaf function on its call entry */
195
static enum print_line_t
196
197
print_graph_entry_leaf(struct trace_iterator *iter,
		struct ftrace_graph_ent_entry *entry, struct trace_seq *s)
198
{
199
200
201
202
203
	struct ftrace_graph_ret_entry *ret_entry;
	struct ftrace_graph_ret *graph_ret;
	struct ring_buffer_event *event;
	struct ftrace_graph_ent *call;
	unsigned long long duration;
204
	int ret;
205
	int i;
206

207
208
209
210
211
212
	event = ring_buffer_read(iter->buffer_iter[iter->cpu], NULL);
	ret_entry = ring_buffer_event_data(event);
	graph_ret = &ret_entry->ret;
	call = &entry->graph_ent;
	duration = graph_ret->rettime - graph_ret->calltime;

213
214
215
216
	/* Must not exceed 8 characters: 9999.999 us */
	if (duration > 10000000ULL)
		duration = 9999999ULL;

217
	/* Overhead */
218
219
220
221
222
223
224
225
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
		ret = print_graph_overhead(duration, s);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Duration */
	ret = print_graph_duration(duration, s);
226
	if (!ret)
227
228
		return TRACE_TYPE_PARTIAL_LINE;

229
230
231
232
233
234
235
236
237
238
239
	/* Function */
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	ret = seq_print_ip_sym(s, call->func, 0);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

240
	ret = trace_seq_printf(s, "();\n");
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	return TRACE_TYPE_HANDLED;
}

static enum print_line_t
print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
			struct trace_seq *s)
{
	int i;
	int ret;
	struct ftrace_graph_ent *call = &entry->graph_ent;

	/* No overhead */
256
257
258
259
260
261
262
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
		ret = trace_seq_printf(s, "  ");
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* No time */
263
	ret = trace_seq_printf(s, "            |  ");
264
265

	/* Function */
266
267
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
268
269
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
270
271
272
273
274
275
	}

	ret = seq_print_ip_sym(s, call->func, 0);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

276
	ret = trace_seq_printf(s, "() {\n");
277
278
279
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

280
281
282
	return TRACE_TYPE_HANDLED;
}

283
284
285
286
287
288
289
static enum print_line_t
print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
			struct trace_iterator *iter, int cpu)
{
	int ret;
	struct trace_entry *ent = iter->ent;

290
	/* Pid */
291
292
293
	if (!verif_pid(s, ent->pid, cpu))
		return TRACE_TYPE_PARTIAL_LINE;

294
295
296
297
298
299
	/* Cpu */
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
		ret = print_graph_cpu(s, cpu);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
300
301
302
303
304
305
306
307

	if (trace_branch_is_leaf(iter, field))
		return print_graph_entry_leaf(iter, field, s);
	else
		return print_graph_entry_nested(field, s);

}

308
309
static enum print_line_t
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
310
		   struct trace_entry *ent, int cpu)
311
312
313
{
	int i;
	int ret;
314
	unsigned long long duration = trace->rettime - trace->calltime;
315

316
317
318
319
	/* Must not exceed 8 characters: xxxx.yyy us */
	if (duration > 10000000ULL)
		duration = 9999999ULL;

320
	/* Pid */
321
322
323
	if (!verif_pid(s, ent->pid, cpu))
		return TRACE_TYPE_PARTIAL_LINE;

324
	/* Cpu */
325
326
327
328
329
	if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
		ret = print_graph_cpu(s, cpu);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}
330

331
	/* Overhead */
332
333
334
335
336
337
338
339
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
		ret = print_graph_overhead(duration, s);
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
	}

	/* Duration */
	ret = print_graph_duration(duration, s);
340
341
342
343
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Closing brace */
344
345
	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
346
347
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
348
349
	}

350
	ret = trace_seq_printf(s, "}\n");
351
352
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
353

354
	/* Overrun */
355
356
357
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
		ret = trace_seq_printf(s, " (Overruns: %lu)\n",
					trace->overrun);
358
359
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
360
361
362
363
364
365
366
367
368
	}
	return TRACE_TYPE_HANDLED;
}

enum print_line_t
print_graph_function(struct trace_iterator *iter)
{
	struct trace_seq *s = &iter->seq;
	struct trace_entry *entry = iter->ent;
369

370
371
372
373
	switch (entry->type) {
	case TRACE_GRAPH_ENT: {
		struct ftrace_graph_ent_entry *field;
		trace_assign_type(field, entry);
374
		return print_graph_entry(field, s, iter,
375
					 iter->cpu);
376
377
378
379
	}
	case TRACE_GRAPH_RET: {
		struct ftrace_graph_ret_entry *field;
		trace_assign_type(field, entry);
380
		return print_graph_return(&field->ret, s, entry, iter->cpu);
381
382
383
	}
	default:
		return TRACE_TYPE_UNHANDLED;
384
385
386
387
	}
}

static struct tracer graph_trace __read_mostly = {
388
	.name	     = "function_graph",
389
390
391
392
393
394
395
396
397
398
399
400
	.init	     = graph_trace_init,
	.reset	     = graph_trace_reset,
	.print_line = print_graph_function,
	.flags		= &tracer_flags,
};

static __init int init_graph_trace(void)
{
	return register_tracer(&graph_trace);
}

device_initcall(init_graph_trace);