940 lines · 22.2 KB · C
RawDownload
/* * * Function graph tracer. * Copyright (c) 2008-2009 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"#include "trace_output.h" struct fgraph_data {	pid_t		last_pid;	int		depth;}; #define TRACE_GRAPH_INDENT	2 /* Flag options */#define TRACE_GRAPH_PRINT_OVERRUN	0x1#define TRACE_GRAPH_PRINT_CPU		0x2#define TRACE_GRAPH_PRINT_OVERHEAD	0x4#define TRACE_GRAPH_PRINT_PROC		0x8#define TRACE_GRAPH_PRINT_DURATION	0x10#define TRACE_GRAPH_PRINT_ABS_TIME	0X20 static struct tracer_opt trace_opts[] = {	/* Display overruns? (for self-debug purpose) */	{ 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) },	/* Display proc name/pid */	{ TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },	/* 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) },	{ } /* Empty entry */}; static struct tracer_flags tracer_flags = {	/* Don't display overruns and proc by default */	.val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |	       TRACE_GRAPH_PRINT_DURATION,	.opts = trace_opts}; /* pid on the last trace processed */  /* Add a function return address to the trace stack on thread info.*/intftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,			 unsigned long frame_pointer){	unsigned long long calltime;	int index; 	if (!current->ret_stack)		return -EBUSY; 	/*	 * We must make sure the ret_stack is tested before we read	 * anything else.	 */	smp_rmb(); 	/* The return trace stack is full */	if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {		atomic_inc(&current->trace_overrun);		return -EBUSY;	} 	calltime = trace_clock_local(); 	index = ++current->curr_ret_stack;	barrier();	current->ret_stack[index].ret = ret;	current->ret_stack[index].func = func;	current->ret_stack[index].calltime = calltime;	current->ret_stack[index].subtime = 0;	current->ret_stack[index].fp = frame_pointer;	*depth = index; 	return 0;} /* Retrieve a function return address to the trace stack on thread info.*/static voidftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,			unsigned long frame_pointer){	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;	} #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 	*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. */unsigned long ftrace_return_to_handler(unsigned long frame_pointer){	struct ftrace_graph_ret trace;	unsigned long ret; 	ftrace_pop_return_trace(&trace, &ret, frame_pointer);	trace.rettime = trace_clock_local();	ftrace_graph_return(&trace);	barrier();	current->curr_ret_stack--; 	if (unlikely(!ret)) {		ftrace_graph_stop();		WARN_ON(1);		/* Might as well panic. What else to do? */		ret = (unsigned long)panic;	} 	return ret;} static int graph_trace_init(struct trace_array *tr){	int ret = register_ftrace_graph(&trace_graph_return,					&trace_graph_entry);	if (ret)		return ret;	tracing_start_cmdline_record(); 	return 0;} static void graph_trace_reset(struct trace_array *tr){	tracing_stop_cmdline_record();	unregister_ftrace_graph();} static inline int log10_cpu(int nb){	if (nb / 100)		return 3;	if (nb / 10)		return 2;	return 1;} static enum print_line_tprint_graph_cpu(struct trace_seq *s, int cpu){	int i;	int ret;	int log10_this = log10_cpu(cpu);	int log10_all = log10_cpu(cpumask_weight(cpu_online_mask));  	/*	 * 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:	 */	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)		return TRACE_TYPE_PARTIAL_LINE; 	return TRACE_TYPE_HANDLED;} #define TRACE_GRAPH_PROCINFO_LENGTH	14 static enum print_line_tprint_graph_proc(struct trace_seq *s, pid_t pid){	char comm[TASK_COMM_LEN];	/* sign + log10(MAX_INT) + '\0' */	char pid_str[11];	int spaces = 0;	int ret;	int len;	int i; 	trace_find_cmdline(pid, comm);	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;}  /* If the pid changed since the last trace, output this event */static enum print_line_tverif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data){	pid_t prev_pid;	pid_t *last_pid;	int ret; 	if (!data)		return TRACE_TYPE_HANDLED; 	last_pid = &(per_cpu_ptr(data, cpu)->last_pid); 	if (*last_pid == pid)		return TRACE_TYPE_HANDLED; 	prev_pid = *last_pid;	*last_pid = pid; 	if (prev_pid == -1)		return TRACE_TYPE_HANDLED;/* * Context-switch trace line:  ------------------------------------------ | 1)  migration/0--1  =>  sshd-1755 ------------------------------------------  */	ret = trace_seq_printf(s,		" ------------------------------------------\n");	if (!ret)		return TRACE_TYPE_PARTIAL_LINE; 	ret = print_graph_cpu(s, cpu);	if (ret == TRACE_TYPE_PARTIAL_LINE)		return TRACE_TYPE_PARTIAL_LINE; 	ret = print_graph_proc(s, prev_pid);	if (ret == TRACE_TYPE_PARTIAL_LINE)		return TRACE_TYPE_PARTIAL_LINE; 	ret = trace_seq_printf(s, " => ");	if (!ret)		return TRACE_TYPE_PARTIAL_LINE; 	ret = print_graph_proc(s, pid);	if (ret == TRACE_TYPE_PARTIAL_LINE)		return TRACE_TYPE_PARTIAL_LINE; 	ret = trace_seq_printf(s,		"\n ------------------------------------------\n\n");	if (!ret)		return TRACE_TYPE_PARTIAL_LINE; 	return TRACE_TYPE_HANDLED;} static struct ftrace_graph_ret_entry *get_return_for_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]; 	/* 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);	} 	if (!event)		return NULL; 	next = ring_buffer_event_data(event); 	if (next->ent.type != TRACE_GRAPH_RET)		return NULL; 	if (curr->ent.pid != next->ent.pid ||			curr->graph_ent.func != next->ret.func)		return NULL; 	/* this is a leaf, now advance the iterator */	if (ring_iter)		ring_buffer_read(ring_iter, NULL); 	return next;} /* Signal a overhead of time execution to the output */static intprint_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, "  ");} 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);} static enum print_line_tprint_graph_irq(struct trace_iterator *iter, unsigned long addr,		enum trace_type type, int cpu, pid_t pid){	int ret;	struct trace_seq *s = &iter->seq; 	if (addr < (unsigned long)__irqentry_text_start ||		addr >= (unsigned long)__irqentry_text_end)		return TRACE_TYPE_UNHANDLED; 	/* 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;	} 	/* 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;	} 	/* No overhead */	ret = print_graph_overhead(-1, s);	if (!ret)		return TRACE_TYPE_PARTIAL_LINE; 	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"); 	if (!ret)		return TRACE_TYPE_PARTIAL_LINE;	return TRACE_TYPE_HANDLED;} enum print_line_ttrace_print_graph_duration(unsigned long long duration, struct trace_seq *s){	unsigned long nsecs_rem = do_div(duration, 1000);	/* 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 */	ret = trace_seq_printf(s, "%s", msecs_str);	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;	}

Lines 1–500 of 940.