trace_functions_graph.c 7.46 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
19
20
/* Spaces between function call and time duration */
#define TRACE_GRAPH_TIMESPACE_ENTRY	"                    "
/* Spaces between function call and closing braces */
#define TRACE_GRAPH_TIMESPACE_RET	"                               "
21
22
23
24
25
26
27
28
29
30
31
32
33

#define TRACE_GRAPH_PRINT_OVERRUN	0x1
static struct tracer_opt trace_opts[] = {
	/* Display overruns or not */
	{ TRACER_OPT(overrun, TRACE_GRAPH_PRINT_OVERRUN) },
	{ } /* Empty entry */
};

static struct tracer_flags tracer_flags = {
	.val = 0, /* Don't display overruns by default */
	.opts = trace_opts
};

34
/* pid on the last trace processed */
35
static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 };
36
37
38

static int graph_trace_init(struct trace_array *tr)
{
39
40
	int cpu, ret;

41
42
43
	for_each_online_cpu(cpu)
		tracing_reset(tr, cpu);

44
	ret = register_ftrace_graph(&trace_graph_return,
45
					&trace_graph_entry);
46
47
48
49
50
	if (ret)
		return ret;
	tracing_start_cmdline_record();

	return 0;
51
52
53
54
}

static void graph_trace_reset(struct trace_array *tr)
{
55
56
	tracing_stop_cmdline_record();
	unregister_ftrace_graph();
57
58
}

59
/* If the pid changed since the last trace, output this event */
60
static int verif_pid(struct trace_seq *s, pid_t pid, int cpu)
61
{
62
63
	char *comm;

64
	if (last_pid[cpu] != -1 && last_pid[cpu] == pid)
65
		return 1;
66

67
	last_pid[cpu] = pid;
68
69
	comm = trace_find_cmdline(pid);

70
	return trace_seq_printf(s, "\nCPU[%03d] "
71
				    " ------------8<---------- thread %s-%d"
72
				    " ------------8<----------\n\n",
73
				    cpu, comm, pid);
74
75
}

76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
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;

	event = ring_buffer_iter_peek(iter->buffer_iter[iter->cpu], NULL);

	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);
	return trace_seq_printf(s, "+ %llu.%lu us\n", duration, nsecs_rem);
}

/* 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 */
130
static enum print_line_t
131
132
print_graph_entry_leaf(struct trace_iterator *iter,
		struct ftrace_graph_ent_entry *entry, struct trace_seq *s)
133
{
134
135
136
137
138
	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;
139
	int i;
140
141
	int ret;

142
143
144
145
146
147
148
149
150
	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;

	/* Overhead */
	ret = print_graph_overhead(duration, s);
	if (!ret)
151
152
		return TRACE_TYPE_PARTIAL_LINE;

153
154
155
156
157
158
159
160
161
162
163
164
	/* 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;

	ret = trace_seq_printf(s, "();");
165
	if (!ret)
166
		return TRACE_TYPE_PARTIAL_LINE;
167

168
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
	/* Duration */
	ret = trace_seq_printf(s, TRACE_GRAPH_TIMESPACE_ENTRY);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	ret = print_graph_duration(duration, s);
	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 */
	ret = trace_seq_printf(s, "  ");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Function */
194
195
	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
196
197
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
198
199
200
201
202
203
	}

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

204
	ret = trace_seq_printf(s, "() {");
205
206
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
207
208
209
210
211
212

	/* No duration to print at this state */
	ret = trace_seq_printf(s, TRACE_GRAPH_TIMESPACE_ENTRY "-\n");
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

213
214
215
	return TRACE_TYPE_HANDLED;
}

216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
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;

	if (!verif_pid(s, ent->pid, cpu))
		return TRACE_TYPE_PARTIAL_LINE;

	ret = trace_seq_printf(s, "CPU[%03d] ", cpu);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

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

}

237
238
static enum print_line_t
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
239
		   struct trace_entry *ent, int cpu)
240
241
242
{
	int i;
	int ret;
243
	unsigned long long duration = trace->rettime - trace->calltime;
244

245
	/* Pid */
246
247
248
	if (!verif_pid(s, ent->pid, cpu))
		return TRACE_TYPE_PARTIAL_LINE;

249
	/* Cpu */
250
251
	ret = trace_seq_printf(s, "CPU[%03d] ", cpu);
	if (!ret)
252
		return TRACE_TYPE_PARTIAL_LINE;
253

254
255
256
257
258
259
	/* Overhead */
	ret = print_graph_overhead(duration, s);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	/* Closing brace */
260
261
	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
		ret = trace_seq_printf(s, " ");
262
263
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
264
265
266
267
268
	}

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

270
271
272
273
274
275
	/* Duration */
	ret = trace_seq_printf(s, TRACE_GRAPH_TIMESPACE_RET);
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;

	ret = print_graph_duration(duration, s);
276
277
	if (!ret)
		return TRACE_TYPE_PARTIAL_LINE;
278

279
	/* Overrun */
280
281
282
	if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
		ret = trace_seq_printf(s, " (Overruns: %lu)\n",
					trace->overrun);
283
284
		if (!ret)
			return TRACE_TYPE_PARTIAL_LINE;
285
286
287
288
289
290
291
292
293
	}
	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;
294

295
296
297
298
	switch (entry->type) {
	case TRACE_GRAPH_ENT: {
		struct ftrace_graph_ent_entry *field;
		trace_assign_type(field, entry);
299
		return print_graph_entry(field, s, iter,
300
					 iter->cpu);
301
302
303
304
	}
	case TRACE_GRAPH_RET: {
		struct ftrace_graph_ret_entry *field;
		trace_assign_type(field, entry);
305
		return print_graph_return(&field->ret, s, entry, iter->cpu);
306
307
308
	}
	default:
		return TRACE_TYPE_UNHANDLED;
309
310
311
312
	}
}

static struct tracer graph_trace __read_mostly = {
313
	.name	     = "function_graph",
314
315
316
317
318
319
320
321
322
323
324
325
	.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);