lkml.org 
[lkml]   [2008]   [Aug]   [27]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [Patch] Tracing/ftrace: Adds a marker to allow user comments
2008/8/24 Frédéric Weisbecker <fweisbec@gmail.com>:
> The documentation of mmiotrace describes an unimplemented feature which allows the user
> to write any comments on his trace by writing on a tracing/marker file.
> Here is an implementation of this idea.
>
> It applies on last version of tip tree.
>
> Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
> ---
> kernel/trace/trace.c | 264 ++++++++++++++++++++++++++++++++++++--------------
> kernel/trace/trace.h | 5 +
> 2 files changed, 198 insertions(+), 71 deletions(-)
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 1801900..ee06849 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -955,6 +955,121 @@ __trace_special(void *__tr, void *__data,
> trace_wake_up();
> }
>
> +/* Add a message provided by the user (TRACE_MARK) or by __ftrace_printk */
> +
> +void trace_print(char *buf, int len, struct trace_entry *tmp_ent,
> + struct trace_array *tr, struct trace_array_cpu *data,
> + unsigned long flags)
> +{
> + struct trace_entry *entry;
> + int write, written = 0;
> +
> + __raw_spin_lock(&data->lock);
> + entry = tracing_get_trace_entry(tr, data);
> + tracing_generic_entry_update(entry, flags);
> + entry->type = tmp_ent->type;
> +
> + if (entry->type == TRACE_PRINT)
> + entry->field.print.ip = tmp_ent->field.print.ip;
> +
> + write = min(len, (int)(TRACE_PRINT_BUF_SIZE-1));
> + memcpy(&entry->field.print.buf, buf, write);
> + entry->field.print.buf[write] = 0;
> +
> + written = write;
> +
> + if (written != len)
> + entry->field.flags |= TRACE_FLAG_CONT;
> +
> + while (written != len) {
> + entry = tracing_get_trace_entry(tr, data);
> +
> + entry->type = TRACE_CONT;
> + write = min(len - written, (int)(TRACE_CONT_BUF_SIZE-1));
> + memcpy(&entry->cont.buf, buf+written, write);
> + entry->cont.buf[write] = 0;
> + written += write;
> + }
> + __raw_spin_unlock(&data->lock);
> +}
> +
> +/* Add a message provided by the user towards the tracing_mark file */
> +int tracing_mark(char *buf, int size)
> +{
> + struct trace_array *tr = &global_trace;
> + struct trace_array_cpu *data;
> + struct trace_entry tmp_ent;
> + unsigned long flags;
> + long disabled;
> + int cpu;
> +
> + local_irq_save(flags);
> + cpu = raw_smp_processor_id();
> + data = tr->data[cpu];
> + disabled = atomic_inc_return(&data->disabled);
> +
> + if (unlikely(disabled != 1))
> + goto out;
> +
> + size = min(size, TRACE_BUF_SIZE - 1);
> + tmp_ent.type = TRACE_MARK;
> + buf[size - 1] = 0;
> +
> + trace_print(buf, size, &tmp_ent, tr, data, flags);
> +
> +out:
> + atomic_dec(&data->disabled);
> + local_irq_restore(flags);
> + return size;
> +}
> +
> +
> +int __ftrace_printk(unsigned long ip, const char *fmt, ...)
> +{
> + struct trace_array *tr = &global_trace;
> + static DEFINE_SPINLOCK(trace_buf_lock);
> + static char trace_buf[TRACE_BUF_SIZE];
> + struct trace_array_cpu *data;
> + struct trace_entry tmp_ent;
> + unsigned long flags;
> + long disabled;
> + va_list ap;
> + int cpu, len = 0;
> +
> + if (likely(!ftrace_function_enabled))
> + return 0;
> +
> + local_irq_save(flags);
> + cpu = raw_smp_processor_id();
> + data = tr->data[cpu];
> + disabled = atomic_inc_return(&data->disabled);
> +
> + if (unlikely(disabled != 1 || !ftrace_function_enabled))
> + goto out;
> +
> + tmp_ent.type = TRACE_PRINT;
> + tmp_ent.field.print.ip = ip;
> +
> + spin_lock(&trace_buf_lock);
> + va_start(ap, fmt);
> + len = vsnprintf(trace_buf, TRACE_BUF_SIZE, fmt, ap);
> + va_end(ap);
> +
> + len = min(len, TRACE_BUF_SIZE-1);
> + trace_buf[len] = 0;
> +
> + trace_print(trace_buf, len, &tmp_ent, tr, data, flags);
> +
> + spin_unlock(&trace_buf_lock);
> +
> + out:
> + atomic_dec(&data->disabled);
> + local_irq_restore(flags);
> +
> + return len;
> +}
> +EXPORT_SYMBOL_GPL(__ftrace_printk);
> +
> void
> tracing_sched_switch_trace(struct trace_array *tr,
> struct trace_array_cpu *data,
> @@ -1943,6 +2058,26 @@ static int print_bin_fmt(struct trace_iterator *iter)
> return 1;
> }
>
> +/* Add the user message on the pipe */
> +static int print_mark(struct trace_iterator *iter)
> +{
> + struct trace_seq *s = &iter->seq;
> + struct trace_entry *entry = iter->ent;
> + struct trace_field *field = &entry->field;
> +
> + int ret;
> +
> + ret = trace_seq_printf(s, field->print.buf);
> + if (field->flags && TRACE_FLAG_CONT)
> + trace_seq_print_cont(s, iter);
> + trace_seq_printf(s, "\n");
> +
> + if (ret)
> + return 1;
> + return 0;
> +}
> +
> +
> static int trace_empty(struct trace_iterator *iter)
> {
> struct trace_array_cpu *data;
> @@ -1961,6 +2096,9 @@ static int trace_empty(struct trace_iterator *iter)
>
> static int print_trace_line(struct trace_iterator *iter)
> {
> + if (iter->ent->type == TRACE_MARK)
> + return print_mark(iter);
> +
> if (iter->trace && iter->trace->print_line)
> return iter->trace->print_line(iter);
>
> @@ -2918,6 +3056,49 @@ tracing_entries_write(struct file *filp, const char __user *ubuf,
> return cnt;
> }
>
> +static int tracing_open_mark(struct inode *inode, struct file *filp)
> +{
> + int ret;
> +
> + ret = tracing_open_generic(inode, filp);
> + if (ret)
> + return ret;
> +
> + if (current_trace == &no_tracer)
> + return -ENODEV;
> +
> + return 0;
> +}
> +
> +
> +static ssize_t
> +tracing_mark_write(struct file *filp, const char __user *ubuf,
> + size_t cnt, loff_t *fpos)
> +{
> + char *buf;
> +
> + if (cnt > TRACE_BUF_SIZE)
> + cnt = TRACE_BUF_SIZE;
> +
> + buf = kmalloc(cnt, GFP_KERNEL);
> +
> + if (buf == NULL)
> + return -ENOMEM;
> +
> + if (copy_from_user(buf, ubuf, cnt)) {
> + kfree(buf);
> + return -EFAULT;
> + }
> +
> + cnt = tracing_mark(buf, cnt);
> + kfree(buf);
> + *fpos += cnt;
> +
> + return cnt;
> +}
> +
> +
> +
> static struct file_operations tracing_max_lat_fops = {
> .open = tracing_open_generic,
> .read = tracing_max_lat_read,
> @@ -2949,6 +3130,11 @@ static struct file_operations tracing_entries_fops = {
> .write = tracing_entries_write,
> };
>
> +static struct file_operations tracing_mark_fops = {
> + .open = tracing_open_mark,
> + .write = tracing_mark_write,
> +};
> +
> #ifdef CONFIG_DYNAMIC_FTRACE
>
> static ssize_t
> @@ -3066,6 +3252,13 @@ static __init void tracer_init_debugfs(void)
> pr_warning("Could not create debugfs "
> "'trace_entries' entry\n");
>
> + entry = debugfs_create_file("trace_marker", 0220, d_tracer,
> + NULL, &tracing_mark_fops);
> +
> + if (!entry)
> + pr_warning("Could not create debugfs "
> + "'trace_marker' entry\n");
> +
> #ifdef CONFIG_DYNAMIC_FTRACE
> entry = debugfs_create_file("dyn_ftrace_total_info", 0444, d_tracer,
> &ftrace_update_tot_cnt,
> @@ -3079,77 +3272,6 @@ static __init void tracer_init_debugfs(void)
> #endif
> }
>
> -#define TRACE_BUF_SIZE 1024
> -#define TRACE_PRINT_BUF_SIZE \
> - (sizeof(struct trace_field) - offsetof(struct trace_field, print.buf))
> -#define TRACE_CONT_BUF_SIZE sizeof(struct trace_field)
> -
> -int __ftrace_printk(unsigned long ip, const char *fmt, ...)
> -{
> - struct trace_array *tr = &global_trace;
> - static DEFINE_SPINLOCK(trace_buf_lock);
> - static char trace_buf[TRACE_BUF_SIZE];
> - struct trace_array_cpu *data;
> - struct trace_entry *entry;
> - unsigned long flags;
> - long disabled;
> - va_list ap;
> - int cpu, len = 0, write, written = 0;
> -
> - if (likely(!ftrace_function_enabled))
> - return 0;
> -
> - local_irq_save(flags);
> - cpu = raw_smp_processor_id();
> - data = tr->data[cpu];
> - disabled = atomic_inc_return(&data->disabled);
> -
> - if (unlikely(disabled != 1 || !ftrace_function_enabled))
> - goto out;
> -
> - spin_lock(&trace_buf_lock);
> - va_start(ap, fmt);
> - len = vsnprintf(trace_buf, TRACE_BUF_SIZE, fmt, ap);
> - va_end(ap);
> -
> - len = min(len, TRACE_BUF_SIZE-1);
> - trace_buf[len] = 0;
> -
> - __raw_spin_lock(&data->lock);
> - entry = tracing_get_trace_entry(tr, data);
> - tracing_generic_entry_update(entry, flags);
> - entry->type = TRACE_PRINT;
> - entry->field.print.ip = ip;
> -
> - write = min(len, (int)(TRACE_PRINT_BUF_SIZE-1));
> -
> - memcpy(&entry->field.print.buf, trace_buf, write);
> - entry->field.print.buf[write] = 0;
> - written = write;
> -
> - if (written != len)
> - entry->field.flags |= TRACE_FLAG_CONT;
> -
> - while (written != len) {
> - entry = tracing_get_trace_entry(tr, data);
> -
> - entry->type = TRACE_CONT;
> - write = min(len - written, (int)(TRACE_CONT_BUF_SIZE-1));
> - memcpy(&entry->cont.buf, trace_buf+written, write);
> - entry->cont.buf[write] = 0;
> - written += write;
> - }
> - __raw_spin_unlock(&data->lock);
> -
> - spin_unlock(&trace_buf_lock);
> -
> - out:
> - atomic_dec(&data->disabled);
> - local_irq_restore(flags);
> -
> - return len;
> -}
> -EXPORT_SYMBOL_GPL(__ftrace_printk);
>
> static int trace_panic_handler(struct notifier_block *this,
> unsigned long event, void *unused)
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 50b6d7a..ccc245c 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -14,6 +14,7 @@ enum trace_type {
> TRACE_CTX,
> TRACE_WAKE,
> TRACE_CONT,
> + TRACE_MARK,
> TRACE_STACK,
> TRACE_PRINT,
> TRACE_SPECIAL,
> @@ -106,6 +107,10 @@ struct trace_entry {
> };
>
> #define TRACE_ENTRY_SIZE sizeof(struct trace_entry)
> +#define TRACE_BUF_SIZE 1024
> +#define TRACE_PRINT_BUF_SIZE \
> + (sizeof(struct trace_field) - offsetof(struct trace_field, print.buf))
> +#define TRACE_CONT_BUF_SIZE sizeof(struct trace_field)
>
> /*
> * The CPU trace array - it consists of thousands of trace entries
>

Do you think I should modify something or use a way to make it better?
(Added Pekka Paalanen in Cc since it concerns an idea from his
mmiotrace's documentation)...
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

\
 
 \ /
  Last update: 2008-08-27 12:01    [W:0.147 / U:4.916 seconds]
©2003-2018 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site