2009-03-06 09:21:47 -07:00
|
|
|
/*
|
|
|
|
* trace binary printk
|
|
|
|
*
|
|
|
|
* Copyright (C) 2008 Lai Jiangshan <laijs@cn.fujitsu.com>
|
|
|
|
*
|
|
|
|
*/
|
2009-03-12 12:23:17 -06:00
|
|
|
#include <linux/seq_file.h>
|
|
|
|
#include <linux/debugfs.h>
|
|
|
|
#include <linux/uaccess.h>
|
2009-03-06 09:21:47 -07:00
|
|
|
#include <linux/kernel.h>
|
|
|
|
#include <linux/ftrace.h>
|
|
|
|
#include <linux/string.h>
|
2009-03-12 12:23:17 -06:00
|
|
|
#include <linux/module.h>
|
|
|
|
#include <linux/mutex.h>
|
2009-03-06 09:21:47 -07:00
|
|
|
#include <linux/ctype.h>
|
|
|
|
#include <linux/list.h>
|
|
|
|
#include <linux/slab.h>
|
|
|
|
#include <linux/fs.h>
|
|
|
|
|
|
|
|
#include "trace.h"
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
#ifdef CONFIG_MODULES
|
|
|
|
|
|
|
|
/*
|
2009-03-06 09:21:49 -07:00
|
|
|
* modules trace_printk()'s formats are autosaved in struct trace_bprintk_fmt
|
2009-03-06 09:21:48 -07:00
|
|
|
* which are queued on trace_bprintk_fmt_list.
|
|
|
|
*/
|
|
|
|
static LIST_HEAD(trace_bprintk_fmt_list);
|
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
/* serialize accesses to trace_bprintk_fmt_list */
|
|
|
|
static DEFINE_MUTEX(btrace_mutex);
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
struct trace_bprintk_fmt {
|
|
|
|
struct list_head list;
|
2011-03-21 20:59:21 -06:00
|
|
|
const char *fmt;
|
2009-03-06 09:21:48 -07:00
|
|
|
};
|
|
|
|
|
|
|
|
static inline struct trace_bprintk_fmt *lookup_format(const char *fmt)
|
2009-03-06 09:21:47 -07:00
|
|
|
{
|
2009-03-06 09:21:48 -07:00
|
|
|
struct trace_bprintk_fmt *pos;
|
|
|
|
list_for_each_entry(pos, &trace_bprintk_fmt_list, list) {
|
|
|
|
if (!strcmp(pos->fmt, fmt))
|
|
|
|
return pos;
|
|
|
|
}
|
|
|
|
return NULL;
|
2009-03-06 09:21:47 -07:00
|
|
|
}
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
static
|
|
|
|
void hold_module_trace_bprintk_format(const char **start, const char **end)
|
2009-03-06 09:21:47 -07:00
|
|
|
{
|
2009-03-06 09:21:48 -07:00
|
|
|
const char **iter;
|
2011-03-21 20:59:21 -06:00
|
|
|
char *fmt;
|
2009-03-06 09:21:49 -07:00
|
|
|
|
tracing: Add percpu buffers for trace_printk()
Currently, trace_printk() uses a single buffer to write into
to calculate the size and format needed to save the trace. To
do this safely in an SMP environment, a spin_lock() is taken
to only allow one writer at a time to the buffer. But this could
also affect what is being traced, and add synchronization that
would not be there otherwise.
Ideally, using percpu buffers would be useful, but since trace_printk()
is only used in development, having per cpu buffers for something
never used is a waste of space. Thus, the use of the trace_bprintk()
format section is changed to be used for static fmts as well as dynamic ones.
Then at boot up, we can check if the section that holds the trace_printk
formats is non-empty, and if it does contain something, then we
know a trace_printk() has been added to the kernel. At this time
the trace_printk per cpu buffers are allocated. A check is also
done at module load time in case a module is added that contains a
trace_printk().
Once the buffers are allocated, they are never freed. If you use
a trace_printk() then you should know what you are doing.
A buffer is made for each type of context:
normal
softirq
irq
nmi
The context is checked and the appropriate buffer is used.
This allows for totally lockless usage of trace_printk(),
and they no longer even disable interrupts.
Requested-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
2011-09-22 12:01:55 -06:00
|
|
|
/* allocate the trace_printk per cpu buffers */
|
|
|
|
if (start != end)
|
|
|
|
trace_printk_init_buffers();
|
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
mutex_lock(&btrace_mutex);
|
2009-03-06 09:21:48 -07:00
|
|
|
for (iter = start; iter < end; iter++) {
|
|
|
|
struct trace_bprintk_fmt *tb_fmt = lookup_format(*iter);
|
|
|
|
if (tb_fmt) {
|
|
|
|
*iter = tb_fmt->fmt;
|
|
|
|
continue;
|
|
|
|
}
|
|
|
|
|
2011-08-08 19:39:39 -06:00
|
|
|
fmt = NULL;
|
2011-03-21 20:59:21 -06:00
|
|
|
tb_fmt = kmalloc(sizeof(*tb_fmt), GFP_KERNEL);
|
2011-08-08 19:39:39 -06:00
|
|
|
if (tb_fmt) {
|
2011-03-21 20:59:21 -06:00
|
|
|
fmt = kmalloc(strlen(*iter) + 1, GFP_KERNEL);
|
2011-08-08 19:39:39 -06:00
|
|
|
if (fmt) {
|
|
|
|
list_add_tail(&tb_fmt->list, &trace_bprintk_fmt_list);
|
|
|
|
strcpy(fmt, *iter);
|
|
|
|
tb_fmt->fmt = fmt;
|
|
|
|
} else
|
|
|
|
kfree(tb_fmt);
|
2011-03-21 20:59:21 -06:00
|
|
|
}
|
2011-08-08 19:39:39 -06:00
|
|
|
*iter = fmt;
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
}
|
2009-03-06 09:21:49 -07:00
|
|
|
mutex_unlock(&btrace_mutex);
|
2009-03-06 09:21:47 -07:00
|
|
|
}
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
static int module_trace_bprintk_format_notify(struct notifier_block *self,
|
|
|
|
unsigned long val, void *data)
|
|
|
|
{
|
|
|
|
struct module *mod = data;
|
|
|
|
if (mod->num_trace_bprintk_fmt) {
|
|
|
|
const char **start = mod->trace_bprintk_fmt_start;
|
|
|
|
const char **end = start + mod->num_trace_bprintk_fmt;
|
|
|
|
|
|
|
|
if (val == MODULE_STATE_COMING)
|
|
|
|
hold_module_trace_bprintk_format(start, end);
|
|
|
|
}
|
|
|
|
return 0;
|
|
|
|
}
|
|
|
|
|
2011-03-21 21:36:31 -06:00
|
|
|
/*
|
|
|
|
* The debugfs/tracing/printk_formats file maps the addresses with
|
|
|
|
* the ASCII formats that are used in the bprintk events in the
|
|
|
|
* buffer. For userspace tools to be able to decode the events from
|
|
|
|
* the buffer, they need to be able to map the address with the format.
|
|
|
|
*
|
|
|
|
* The addresses of the bprintk formats are in their own section
|
|
|
|
* __trace_printk_fmt. But for modules we copy them into a link list.
|
|
|
|
* The code to print the formats and their addresses passes around the
|
|
|
|
* address of the fmt string. If the fmt address passed into the seq
|
|
|
|
* functions is within the kernel core __trace_printk_fmt section, then
|
|
|
|
* it simply uses the next pointer in the list.
|
|
|
|
*
|
|
|
|
* When the fmt pointer is outside the kernel core __trace_printk_fmt
|
|
|
|
* section, then we need to read the link list pointers. The trick is
|
|
|
|
* we pass the address of the string to the seq function just like
|
|
|
|
* we do for the kernel core formats. To get back the structure that
|
|
|
|
* holds the format, we simply use containerof() and then go to the
|
|
|
|
* next format in the list.
|
|
|
|
*/
|
|
|
|
static const char **
|
|
|
|
find_next_mod_format(int start_index, void *v, const char **fmt, loff_t *pos)
|
|
|
|
{
|
|
|
|
struct trace_bprintk_fmt *mod_fmt;
|
|
|
|
|
|
|
|
if (list_empty(&trace_bprintk_fmt_list))
|
|
|
|
return NULL;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* v will point to the address of the fmt record from t_next
|
|
|
|
* v will be NULL from t_start.
|
|
|
|
* If this is the first pointer or called from start
|
|
|
|
* then we need to walk the list.
|
|
|
|
*/
|
|
|
|
if (!v || start_index == *pos) {
|
|
|
|
struct trace_bprintk_fmt *p;
|
|
|
|
|
|
|
|
/* search the module list */
|
|
|
|
list_for_each_entry(p, &trace_bprintk_fmt_list, list) {
|
|
|
|
if (start_index == *pos)
|
|
|
|
return &p->fmt;
|
|
|
|
start_index++;
|
|
|
|
}
|
|
|
|
/* pos > index */
|
|
|
|
return NULL;
|
|
|
|
}
|
|
|
|
|
|
|
|
/*
|
|
|
|
* v points to the address of the fmt field in the mod list
|
|
|
|
* structure that holds the module print format.
|
|
|
|
*/
|
|
|
|
mod_fmt = container_of(v, typeof(*mod_fmt), fmt);
|
|
|
|
if (mod_fmt->list.next == &trace_bprintk_fmt_list)
|
|
|
|
return NULL;
|
|
|
|
|
|
|
|
mod_fmt = container_of(mod_fmt->list.next, typeof(*mod_fmt), list);
|
|
|
|
|
|
|
|
return &mod_fmt->fmt;
|
|
|
|
}
|
|
|
|
|
|
|
|
static void format_mod_start(void)
|
|
|
|
{
|
|
|
|
mutex_lock(&btrace_mutex);
|
|
|
|
}
|
|
|
|
|
|
|
|
static void format_mod_stop(void)
|
|
|
|
{
|
|
|
|
mutex_unlock(&btrace_mutex);
|
|
|
|
}
|
|
|
|
|
2009-03-06 09:21:48 -07:00
|
|
|
#else /* !CONFIG_MODULES */
|
|
|
|
__init static int
|
|
|
|
module_trace_bprintk_format_notify(struct notifier_block *self,
|
|
|
|
unsigned long val, void *data)
|
|
|
|
{
|
|
|
|
return 0;
|
|
|
|
}
|
2011-03-21 21:36:31 -06:00
|
|
|
static inline const char **
|
|
|
|
find_next_mod_format(int start_index, void *v, const char **fmt, loff_t *pos)
|
|
|
|
{
|
|
|
|
return NULL;
|
|
|
|
}
|
|
|
|
static inline void format_mod_start(void) { }
|
|
|
|
static inline void format_mod_stop(void) { }
|
2009-03-06 09:21:48 -07:00
|
|
|
#endif /* CONFIG_MODULES */
|
|
|
|
|
|
|
|
|
|
|
|
__initdata_or_module static
|
|
|
|
struct notifier_block module_trace_bprintk_format_nb = {
|
|
|
|
.notifier_call = module_trace_bprintk_format_notify,
|
|
|
|
};
|
|
|
|
|
2009-03-12 11:24:49 -06:00
|
|
|
int __trace_bprintk(unsigned long ip, const char *fmt, ...)
|
2009-03-06 09:21:49 -07:00
|
|
|
{
|
|
|
|
int ret;
|
|
|
|
va_list ap;
|
2009-03-06 09:21:47 -07:00
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
if (unlikely(!fmt))
|
|
|
|
return 0;
|
2009-03-06 09:21:47 -07:00
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
if (!(trace_flags & TRACE_ITER_PRINTK))
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
va_start(ap, fmt);
|
2009-03-19 12:03:53 -06:00
|
|
|
ret = trace_vbprintk(ip, fmt, ap);
|
2009-03-06 09:21:49 -07:00
|
|
|
va_end(ap);
|
|
|
|
return ret;
|
2009-03-06 09:21:47 -07:00
|
|
|
}
|
2009-03-12 11:24:49 -06:00
|
|
|
EXPORT_SYMBOL_GPL(__trace_bprintk);
|
2009-03-06 09:21:47 -07:00
|
|
|
|
2009-03-12 11:24:49 -06:00
|
|
|
int __ftrace_vbprintk(unsigned long ip, const char *fmt, va_list ap)
|
2009-03-06 09:21:49 -07:00
|
|
|
{
|
|
|
|
if (unlikely(!fmt))
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
if (!(trace_flags & TRACE_ITER_PRINTK))
|
|
|
|
return 0;
|
|
|
|
|
2009-03-19 12:03:53 -06:00
|
|
|
return trace_vbprintk(ip, fmt, ap);
|
2009-03-12 11:24:49 -06:00
|
|
|
}
|
|
|
|
EXPORT_SYMBOL_GPL(__ftrace_vbprintk);
|
|
|
|
|
|
|
|
int __trace_printk(unsigned long ip, const char *fmt, ...)
|
|
|
|
{
|
|
|
|
int ret;
|
|
|
|
va_list ap;
|
|
|
|
|
|
|
|
if (!(trace_flags & TRACE_ITER_PRINTK))
|
|
|
|
return 0;
|
|
|
|
|
|
|
|
va_start(ap, fmt);
|
2009-03-19 12:03:53 -06:00
|
|
|
ret = trace_vprintk(ip, fmt, ap);
|
2009-03-12 11:24:49 -06:00
|
|
|
va_end(ap);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
EXPORT_SYMBOL_GPL(__trace_printk);
|
|
|
|
|
|
|
|
int __ftrace_vprintk(unsigned long ip, const char *fmt, va_list ap)
|
|
|
|
{
|
|
|
|
if (!(trace_flags & TRACE_ITER_PRINTK))
|
|
|
|
return 0;
|
|
|
|
|
2009-03-19 12:03:53 -06:00
|
|
|
return trace_vprintk(ip, fmt, ap);
|
2009-03-06 09:21:47 -07:00
|
|
|
}
|
2009-03-06 09:21:49 -07:00
|
|
|
EXPORT_SYMBOL_GPL(__ftrace_vprintk);
|
2009-03-06 09:21:47 -07:00
|
|
|
|
2011-03-21 21:36:31 -06:00
|
|
|
static const char **find_next(void *v, loff_t *pos)
|
|
|
|
{
|
|
|
|
const char **fmt = v;
|
|
|
|
int start_index;
|
|
|
|
|
|
|
|
start_index = __stop___trace_bprintk_fmt - __start___trace_bprintk_fmt;
|
|
|
|
|
|
|
|
if (*pos < start_index)
|
2011-06-09 06:40:59 -06:00
|
|
|
return __start___trace_bprintk_fmt + *pos;
|
2011-03-21 21:36:31 -06:00
|
|
|
|
|
|
|
return find_next_mod_format(start_index, v, fmt, pos);
|
|
|
|
}
|
|
|
|
|
2009-03-12 12:23:17 -06:00
|
|
|
static void *
|
2009-06-23 19:52:58 -06:00
|
|
|
t_start(struct seq_file *m, loff_t *pos)
|
2009-03-12 12:23:17 -06:00
|
|
|
{
|
2011-03-21 21:36:31 -06:00
|
|
|
format_mod_start();
|
|
|
|
return find_next(NULL, pos);
|
2009-03-12 12:23:17 -06:00
|
|
|
}
|
|
|
|
|
2009-06-23 19:52:58 -06:00
|
|
|
static void *t_next(struct seq_file *m, void * v, loff_t *pos)
|
2009-03-12 12:23:17 -06:00
|
|
|
{
|
2009-06-23 19:52:58 -06:00
|
|
|
(*pos)++;
|
2011-03-21 21:36:31 -06:00
|
|
|
return find_next(v, pos);
|
2009-03-12 12:23:17 -06:00
|
|
|
}
|
|
|
|
|
|
|
|
static int t_show(struct seq_file *m, void *v)
|
|
|
|
{
|
|
|
|
const char **fmt = v;
|
|
|
|
const char *str = *fmt;
|
|
|
|
int i;
|
|
|
|
|
2009-07-22 21:11:03 -06:00
|
|
|
seq_printf(m, "0x%lx : \"", *(unsigned long *)fmt);
|
2009-03-12 12:23:17 -06:00
|
|
|
|
|
|
|
/*
|
|
|
|
* Tabs and new lines need to be converted.
|
|
|
|
*/
|
|
|
|
for (i = 0; str[i]; i++) {
|
|
|
|
switch (str[i]) {
|
|
|
|
case '\n':
|
|
|
|
seq_puts(m, "\\n");
|
|
|
|
break;
|
|
|
|
case '\t':
|
|
|
|
seq_puts(m, "\\t");
|
|
|
|
break;
|
|
|
|
case '\\':
|
|
|
|
seq_puts(m, "\\");
|
|
|
|
break;
|
|
|
|
case '"':
|
|
|
|
seq_puts(m, "\\\"");
|
|
|
|
break;
|
|
|
|
default:
|
|
|
|
seq_putc(m, str[i]);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
seq_puts(m, "\"\n");
|
|
|
|
|
|
|
|
return 0;
|
|
|
|
}
|
|
|
|
|
|
|
|
static void t_stop(struct seq_file *m, void *p)
|
|
|
|
{
|
2011-03-21 21:36:31 -06:00
|
|
|
format_mod_stop();
|
2009-03-12 12:23:17 -06:00
|
|
|
}
|
|
|
|
|
|
|
|
static const struct seq_operations show_format_seq_ops = {
|
|
|
|
.start = t_start,
|
|
|
|
.next = t_next,
|
|
|
|
.show = t_show,
|
|
|
|
.stop = t_stop,
|
|
|
|
};
|
|
|
|
|
|
|
|
static int
|
|
|
|
ftrace_formats_open(struct inode *inode, struct file *file)
|
|
|
|
{
|
2009-06-23 19:52:58 -06:00
|
|
|
return seq_open(file, &show_format_seq_ops);
|
2009-03-12 12:23:17 -06:00
|
|
|
}
|
|
|
|
|
|
|
|
static const struct file_operations ftrace_formats_fops = {
|
|
|
|
.open = ftrace_formats_open,
|
|
|
|
.read = seq_read,
|
|
|
|
.llseek = seq_lseek,
|
|
|
|
.release = seq_release,
|
|
|
|
};
|
|
|
|
|
|
|
|
static __init int init_trace_printk_function_export(void)
|
|
|
|
{
|
|
|
|
struct dentry *d_tracer;
|
|
|
|
|
|
|
|
d_tracer = tracing_init_dentry();
|
|
|
|
if (!d_tracer)
|
|
|
|
return 0;
|
|
|
|
|
2009-03-26 17:25:38 -06:00
|
|
|
trace_create_file("printk_formats", 0444, d_tracer,
|
2009-03-12 12:23:17 -06:00
|
|
|
NULL, &ftrace_formats_fops);
|
|
|
|
|
|
|
|
return 0;
|
|
|
|
}
|
|
|
|
|
|
|
|
fs_initcall(init_trace_printk_function_export);
|
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
static __init int init_trace_printk(void)
|
2009-03-06 09:21:47 -07:00
|
|
|
{
|
2009-03-06 09:21:49 -07:00
|
|
|
return register_module_notifier(&module_trace_bprintk_format_nb);
|
2009-03-06 09:21:47 -07:00
|
|
|
}
|
|
|
|
|
2009-03-06 09:21:49 -07:00
|
|
|
early_initcall(init_trace_printk);
|