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