trace.c

Kernel code of linux kernel

/*
 * ring buffer based function tracer
 *
 * Copyright (C) 2007-2008 Steven Rostedt <[e-mail]>
 * Copyright (C) 2008 Ingo Molnar <[e-mail]>
 *
 * Originally taken from the RT patch by:
 *    Arnaldo Carvalho de Melo <[e-mail]>
 *
 * Based on code from the latency_tracer, that is:
 *  Copyright (C) 2004-2006 Ingo Molnar
 *  Copyright (C) 2004 William Lee Irwin III
 */
#include <linux/utsrelease.h>
#include <linux/kallsyms.h>
#include <linux/seq_file.h>
#include <linux/debugfs.h>
#include <linux/pagemap.h>
#include <linux/hardirq.h>
#include <linux/linkage.h>
#include <linux/uaccess.h>
#include <linux/ftrace.h>
#include <linux/module.h>
#include <linux/percpu.h>
#include <linux/ctype.h>
#include <linux/init.h>
#include <linux/poll.h>
#include <linux/gfp.h>
#include <linux/fs.h>
#include <linux/kprobes.h>
#include <linux/writeback.h>

#include <linux/stacktrace.h>

#include "trace.h"

unsigned long __read_mostly	tracing_max_latency = (cycle_t)ULONG_MAX;
unsigned long __read_mostly	tracing_thresh;

static unsigned long __read_mostly	tracing_nr_buffers;
static cpumask_t __read_mostly		tracing_buffer_mask;

#define for_each_tracing_cpu(cpu)	\
	for_each_cpu_mask(cpu, tracing_buffer_mask)

static int trace_alloc_page(void);
static int trace_free_page(void);

static int tracing_disabled = 1;

static unsigned long tracing_pages_allocated;

long
ns2usecs(cycle_t nsec)
{
	nsec += 500;
	do_div(nsec, 1000);
	return nsec;
}

cycle_t ftrace_now(int cpu)
{
	return cpu_clock(cpu);
}

/*
 * The global_trace is the descriptor that holds the tracing
 * buffers for the live tracing. For each CPU, it contains
 * a link list of pages that will store trace entries. The
 * page descriptor of the pages in the memory is used to hold
 * the link list by linking the lru item in the page descriptor
 * to each of the pages in the buffer per CPU.
 *
 * For each active CPU there is a data field that holds the
 * pages for the buffer for that CPU. Each CPU has the same number
 * of pages allocated for its buffer.
 */
static struct trace_array	global_trace;

static DEFINE_PER_CPU(struct trace_array_cpu, global_trace_cpu);

/*
 * The max_tr is used to snapshot the global_trace when a maximum
 * latency is reached. Some tracers will use this to store a maximum
 * trace while it continues examining live traces.
 *
 * The buffers for the max_tr are set up the same as the global_trace.
 * When a snapshot is taken, the link list of the max_tr is swapped
 * with the link list of the global_trace and the buffers are reset for
 * the global_trace so the tracing can continue.
 */
static struct trace_array	max_tr;

static DEFINE_PER_CPU(struct trace_array_cpu, max_data);

/* tracer_enabled is used to toggle activation of a tracer */
static int			tracer_enabled = 1;

/* function tracing enabled */
int				ftrace_function_enabled;

/*
 * trace_nr_entries is the number of entries that is allocated
 * for a buffer. Note, the number of entries is always rounded
 * to ENTRIES_PER_PAGE.
 */
static unsigned long		trace_nr_entries = 65536UL;

/* trace_types holds a link list of available tracers. */
static struct tracer		*trace_types __read_mostly;

/* current_trace points to the tracer that is currently active */
static struct tracer		*current_trace __read_mostly;

/*
 * max_tracer_type_len is used to simplify the allocating of
 * buffers to read userspace tracer names. We keep track of
 * the longest tracer name registered.
 */
static int			max_tracer_type_len;

/*
 * trace_types_lock is used to protect the trace_types list.
 * This lock is also used to keep user access serialized.
 * Accesses from userspace will grab this lock while userspace
 * activities happen inside the kernel.
 */
static DEFINE_MUTEX(trace_types_lock);

/* trace_wait is a waitqueue for tasks blocked on trace_poll */
static DECLARE_WAIT_QUEUE_HEAD(trace_wait);

/* trace_flags holds iter_ctrl options */
unsigned long trace_flags = TRACE_ITER_PRINT_PARENT;

static notrace void no_trace_init(struct trace_array *tr)
{
	int cpu;

	ftrace_function_enabled = 0;
	if(tr->ctrl)
		for_each_online_cpu(cpu)
			tracing_reset(tr->data[cpu]);
	tracer_enabled = 0;
}

/* dummy trace to disable tracing */
static struct tracer no_tracer __read_mostly = {
	.name		= "none",
	.init		= no_trace_init
};


/**
 * trace_wake_up - wake up tasks waiting for trace input
 *
 * Simply wakes up any task that is blocked on the trace_wait
 * queue. These is used with trace_poll for tasks polling the trace.
 */
void trace_wake_up(void)
{
	/*
	 * The runqueue_is_locked() can fail, but this is the best we
	 * have for now:
	 */
	if (!(trace_flags & TRACE_ITER_BLOCK) && !runqueue_is_locked())
		wake_up(&trace_wait);
}

#define ENTRIES_PER_PAGE (PAGE_SIZE / sizeof(struct trace_entry))

static int __init set_nr_entries(char *str)
{
	unsigned long nr_entries;
	int ret;

	if (!str)
		return 0;
	ret = strict_strtoul(str, 0, &nr_entries);
	/* nr_entries can not be zero */
	if (ret < 0 || nr_entries == 0)
		return 0;
	trace_nr_entries = nr_entries;
	return 1;
}
__setup("trace_entries=", set_nr_entries);

unsigned long nsecs_to_usecs(unsigned long nsecs)
{
	return nsecs / 1000;
}

/*
 * trace_flag_type is an enumeration that holds different
 * states when a trace occurs. These are:
 *  IRQS_OFF	- interrupts were disabled
 *  NEED_RESCED - reschedule is requested
 *  HARDIRQ	- inside an interrupt handler
 *  SOFTIRQ	- inside a softirq handler
 */
enum trace_flag_type {
	TRACE_FLAG_IRQS_OFF		= 0x01,
	TRACE_FLAG_NEED_RESCHED		= 0x02,
	TRACE_FLAG_HARDIRQ		= 0x04,
	TRACE_FLAG_SOFTIRQ		= 0x08,
};

/*
 * TRACE_ITER_SYM_MASK masks the options in trace_flags that
 * control the output of kernel symbols.
 */
#define TRACE_ITER_SYM_MASK \
	(TRACE_ITER_PRINT_PARENT|TRACE_ITER_SYM_OFFSET|TRACE_ITER_SYM_ADDR)

/* These must match the bit postions in trace_iterator_flags */
static const char *trace_options[] = {
	"print-parent",
	"sym-offset",
	"sym-addr",
	"verbose",
	"raw",
	"hex",
	"bin",
	"block",
	"stacktrace",
	"sched-tree",
	NULL
};

/*
 * ftrace_max_lock is used to protect the swapping of buffers
 * when taking a max snapshot. The buffers themselves are
 * protected by per_cpu spinlocks. But the action of the swap
 * needs its own lock.
 *
 * This is defined as a raw_spinlock_t in order to help
 * with performance when lockdep debugging is enabled.
 */
static raw_spinlock_t ftrace_max_lock =
	(raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;

/*
 * Copy the new maximum trace into the separate maximum-trace
 * structure. (this way the maximum trace is permanently saved,
 * for later retrieval via /debugfs/tracing/latency_trace)
 */
static void
__update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu)
{
	struct trace_array_cpu *data = tr->data[cpu];

	max_tr.cpu = cpu;
	max_tr.time_start = data->preempt_timestamp;

	data = max_tr.data[cpu];
	data->saved_latency = tracing_max_latency;

	memcpy(data->comm, tsk->comm, TASK_COMM_LEN);
	data->pid = tsk->pid;
	data->uid = tsk->uid;
	data->nice = tsk->static_prio - 20 - MAX_RT_PRIO;
	data->policy = tsk->policy;
	data->rt_priority = tsk->rt_priority;

	/* record this tasks comm */
	tracing_record_cmdline(current);
}

#define CHECK_COND(cond)			\
	if (unlikely(cond)) {			\
		tracing_disabled = 1;		\
		WARN_ON(1);			\
		return -1;			\
	}

/**
 * check_pages - integrity check of trace buffers
 *
 * As a safty measure we check to make sure the data pages have not
 * been corrupted.
 */
int check_pages(struct trace_array_cpu *data)
{
	struct page *page, *tmp;

	CHECK_COND(data->trace_pages.next->prev != &data->trace_pages);
	CHECK_COND(data->trace_pages.prev->next != &data->trace_pages);

	list_for_each_entry_safe(page, tmp, &data->trace_pages, lru) {
		CHECK_COND(page->lru.next->prev != &page->lru);
		CHECK_COND(page->lru.prev->next != &page->lru);
	}

	return 0;
}

/**
 * head_page - page address of the first page in per_cpu buffer.
 *
 * head_page returns the page address of the first page in
 * a per_cpu buffer. This also preforms various consistency
 * checks to make sure the buffer has not been corrupted.
 */
void *head_page(struct trace_array_cpu *data)
{
	struct page *page;

	if (list_empty(&data->trace_pages))
		return NULL;

	page = list_entry(data->trace_pages.next, struct page, lru);
	BUG_ON(&page->lru == &data->trace_pages);

	return page_address(page);
}

/**
 * trace_seq_printf - sequence printing of trace information
 * @s: trace sequence descriptor
 * @fmt: printf format string
 *
 * The tracer may use either sequence operations or its own
 * copy to user routines. To simplify formating of a trace
 * trace_seq_printf is used to store strings into a special
 * buffer (@s). Then the output may be either used by
 * the sequencer or pulled into another buffer.
 */
int
trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
{
	int len = (PAGE_SIZE - 1) - s->len;
	va_list ap;
	int ret;

	if (!len)
		return 0;

	va_start(ap, fmt);
	ret = vsnprintf(s->buffer + s->len, len, fmt, ap);
	va_end(ap);

	/* If we can't write it all, don't bother writing anything */
	if (ret >= len)
		return 0;

	s->len += ret;

	return len;
}

/**
 * trace_seq_puts - trace sequence printing of simple string
 * @s: trace sequence descriptor
 * @str: simple string to record
 *
 * The tracer may use either the sequence operations or its own
 * copy to user routines. This function records a simple string
 * into a special buffer (@s) for later retrieval by a sequencer
 * or other mechanism.
 */
static int
trace_seq_puts(struct trace_seq *s, const char *str)
{
	int len = strlen(str);

	if (len > ((PAGE_SIZE - 1) - s->len))
		return 0;

	memcpy(s->buffer + s->len, str, len);
	s->len += len;

	return len;
}

static int
trace_seq_putc(struct trace_seq *s, unsigned char c)
{
	if (s->len >= (PAGE_SIZE - 1))
		return 0;

	s->buffer[s->len++] = c;

	return 1;
}

static int
trace_seq_putmem(struct trace_seq *s, void *mem, size_t len)
{
	if (len > ((PAGE_SIZE - 1) - s->len))
		return 0;

	memcpy(s->buffer + s->len, mem, len);
	s->len += len;

	return len;
}

#define HEX_CHARS 17
static const char hex2asc[] = "0123456789abcdef";

static int
trace_seq_putmem_hex(struct trace_seq *s, void *mem, size_t len)
{
	unsigned char hex[HEX_CHARS];
	unsigned char *data = mem;
	unsigned char byte;
	int i, j;

	BUG_ON(len >= HEX_CHARS);

#ifdef __BIG_ENDIAN
	for (i = 0, j = 0; i < len; i++) {
#else
	for (i = len-1, j = 0; i >= 0; i--) {
#endif
		byte = data[i];

		hex[j++] = hex2asc[byte & 0x0f];
		hex[j++] = hex2asc[byte >> 4];
	}
	hex[j++] = ' ';

	return trace_seq_putmem(s, hex, j);
}

static void
trace_seq_reset(struct trace_seq *s)
{
	s->len = 0;
	s->readpos = 0;
}

ssize_t trace_seq_to_user(struct trace_seq *s, char __user *ubuf, size_t cnt)
{
	int len;
	int ret;

	if (s->len <= s->readpos)
		return -EBUSY;

	len = s->len - s->readpos;
	if (cnt > len)
		cnt = len;
	ret = copy_to_user(ubuf, s->buffer + s->readpos, cnt);
	if (ret)
		return -EFAULT;

	s->readpos += len;
	return cnt;
}

static void
trace_print_seq(struct seq_file *m, struct trace_seq *s)
{
	int len = s->len >= PAGE_SIZE ? PAGE_SIZE - 1 : s->len;

	s->buffer[len] = 0;
	seq_puts(m, s->buffer);

	trace_seq_reset(s);
}

/*
 * flip the trace buffers between two trace descriptors.
 * This usually is the buffers between the global_trace and
 * the max_tr to record a snapshot of a current trace.
 *
 * The ftrace_max_lock must be held.
 */
static void
flip_trace(struct trace_array_cpu *tr1, struct trace_array_cpu *tr2)
{
	struct list_head flip_pages;

	INIT_LIST_HEAD(&flip_pages);

	memcpy(&tr1->trace_head_idx, &tr2->trace_head_idx,
		sizeof(struct trace_array_cpu) -
		offsetof(struct trace_array_cpu, trace_head_idx));

	check_pages(tr1);
	check_pages(tr2);
	list_splice_init(&tr1->trace_pages, &flip_pages);
	list_splice_init(&tr2->trace_pages, &tr1->trace_pages);
	list_splice_init(&flip_pages, &tr2->trace_pages);
	BUG_ON(!list_empty(&flip_pages));
	check_pages(tr1);
	check_pages(tr2);
}

/**
 * update_max_tr - snapshot all trace buffers from global_trace to max_tr
 * @tr: tracer
 * @tsk: the task with the latency
 * @cpu: The cpu that initiated the trace.
 *
 * Flip the buffers between the @tr and the max_tr and record information
 * about which task was the cause of this latency.
 */
void
update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu)
{
	struct trace_array_cpu *data;
	int i;

	WARN_ON_ONCE(!irqs_disabled());
	__raw_spin_lock(&ftrace_max_lock);
	/* clear out all the previous traces */
	for_each_tracing_cpu(i) {
		data = tr->data[i];
		flip_trace(max_tr.data[i], data);
		tracing_reset(data);
	}

	__update_max_tr(tr, tsk, cpu);
	__raw_spin_unlock(&ftrace_max_lock);
}

/**
 * update_max_tr_single - only copy one trace over, and reset the rest
 * @tr - tracer
 * @tsk - task with the latency
 * @cpu - the cpu of the buffer to copy.
 *
 * Flip the trace of a single CPU buffer between the @tr and the max_tr.
 */
void
update_max_tr_single(struct trace_array *tr, struct task_struct *tsk, int cpu)
{
	struct trace_array_cpu *data = tr->data[cpu];
	int i;

	WARN_ON_ONCE(!irqs_disabled());
	__raw_spin_lock(&ftrace_max_lock);
	for_each_tracing_cpu(i)
		tracing_reset(max_tr.data[i]);

	flip_trace(max_tr.data[cpu], data);
	tracing_reset(data);

	__update_max_tr(tr, tsk, cpu);
	__raw_spin_unlock(&ftrace_max_lock);
}

/**
 * register_tracer - register a tracer with the ftrace system.
 * @type - the plugin for the tracer
 *
 * Register a new plugin tracer.
 */
int register_tracer(struct tracer *type)
{
	struct tracer *t;
	int len;
	int ret = 0;

	if (!type->name) {
		pr_info("Tracer must have a name\n");
		return -1;
	}

	mutex_lock(&trace_types_lock);
	for (t = trace_types; t; t = t->next) {
		if (strcmp(type->name, t->name) == 0) {
			/* already found */
			pr_info("Trace %s already registered\n",
				type->name);
			ret = -1;
			goto out;
		}
	}

#ifdef CONFIG_FTRACE_STARTUP_TEST
	if (type->selftest) {