Re: [PATCH 3/5] ftrace: add ftrace_bprintk()

["Frédéric Weisbecker" <fweisbec@gmail.com>]

2009/3/2 Steven Rostedt <rostedt@goodmis.org>:
>
> On Sat, 28 Feb 2009, Frederic Weisbecker wrote:
>
>> From: Lai Jiangshan <laijs@cn.fujitsu.com>
>>
>> Impact: Add a generic printk() for ftrace, like ftrace_printk()
>>
>> ftrace_bprintk() use the infrastructure to record events on ring_buffer.
>>
>> [fweisbec@gmail.com: ported to latest -tip and made it work if !CONFIG_MODULES]
>>
>> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
>> Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
>> ---
>>  include/asm-generic/vmlinux.lds.h |    3 +
>>  include/linux/ftrace.h            |   21 ++++++
>>  include/linux/module.h            |    5 ++
>>  kernel/module.c                   |    6 ++
>>  kernel/trace/trace.c              |   15 ++++
>>  kernel/trace/trace_bprintk.c      |  132 ++++++++++++++++++++++++++++++++++++-
>>  6 files changed, 181 insertions(+), 1 deletions(-)
>>
>> diff --git a/include/asm-generic/vmlinux.lds.h b/include/asm-generic/vmlinux.lds.h
>> index 9d97491..13f20f4 100644
>> --- a/include/asm-generic/vmlinux.lds.h
>> +++ b/include/asm-generic/vmlinux.lds.h
>> @@ -100,6 +100,9 @@
>>               *(__vermagic)           /* Kernel version magic */      \
>>               *(__markers_strings)    /* Markers: strings */          \
>>               *(__tracepoints_strings)/* Tracepoints: strings */      \
>> +             VMLINUX_SYMBOL(__start___trace_bprintk_fmt) = .;        \
>> +             *(__trace_printk_fmt)   /* Trace_printk fmt' pointer */ \
>> +             VMLINUX_SYMBOL(__stop___trace_bprintk_fmt) = .;         \
>
> If this can only be done when tracing is enabled, I would wrap that up
> in a macro that is a nop when tracing is disabled.


Ah, good catch.


>>       }                                                               \
>>                                                                       \
>>       .rodata1          : AT(ADDR(.rodata1) - LOAD_OFFSET) {          \
>> diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
>> index 8ac2fac..f82b986 100644
>> --- a/include/linux/ftrace.h
>> +++ b/include/linux/ftrace.h
>> @@ -224,6 +224,27 @@ extern int ftrace_make_call(struct dyn_ftrace *rec, unsigned long addr);
>>
>>  #ifdef CONFIG_TRACE_BPRINTK
>>  extern int trace_vbprintk(unsigned long ip, const char *fmt, va_list args);
>> +extern int __ftrace_bprintk(unsigned long ip, const char *fmt, ...)
>> +             __attribute__ ((format (printf, 2, 3)));
>> +
>> +static inline void  ____ftrace_bprintk_check_format(const char *fmt, ...)
>> +             __attribute__ ((format (printf, 1, 2)));
>> +static inline void ____ftrace_bprintk_check_format(const char *fmt, ...) {}
>> +#define __ftrace_bprintk_check_format(fmt, args...)                  \
>> +do {                                                                 \
>> +     if (0)                                                          \
>> +             ____ftrace_bprintk_check_format(fmt, ##args);           \
>> +} while (0)
>> +
>> +#define ftrace_bprintk(fmt, args...)                                 \
>> +do {                                                                 \
>> +     static char *__attribute__((section("__trace_bprintk_fmt")))    \
>> +                     ftrace_bprintk_fmt = fmt;                       \
>> +     __ftrace_bprintk_check_format(fmt, ##args);                     \
>> +     __ftrace_bprintk(_THIS_IP_, ftrace_bprintk_fmt, ##args);        \
>> +} while (0)
>> +#else
>> +#define ftrace_bprintk ftrace_printk
>>  #endif
>>
>>  /* May be defined in arch */
>> diff --git a/include/linux/module.h b/include/linux/module.h
>> index 07b1cb4..c4f2845 100644
>> --- a/include/linux/module.h
>> +++ b/include/linux/module.h
>> @@ -347,6 +347,11 @@ struct module
>>       unsigned int num_tracepoints;
>>  #endif
>>
>> +#ifdef CONFIG_TRACE_BPRINTK
>> +     const char **trace_bprintk_fmt_start;
>> +     unsigned int num_trace_bprintk_fmt;
>> +#endif
>> +
>>  #ifdef CONFIG_MODULE_UNLOAD
>>       /* What modules depend on me? */
>>       struct list_head modules_which_use_me;
>> diff --git a/kernel/module.c b/kernel/module.c
>> index 90a6d63..fa96909 100644
>> --- a/kernel/module.c
>> +++ b/kernel/module.c
>> @@ -2192,6 +2192,12 @@ static noinline struct module *load_module(void __user *umod,
>>                                       &mod->num_tracepoints);
>>  #endif
>>
>> +#ifdef CONFIG_TRACE_BPRINTK
>> +     mod->trace_bprintk_fmt_start = section_objs(hdr, sechdrs, secstrings,
>> +                     "__trace_bprintk_fmt", sizeof(char *),
>> +                     &mod->num_trace_bprintk_fmt);
>> +#endif
>> +
>>  #ifdef CONFIG_MODVERSIONS
>>       if ((mod->num_syms && !mod->crcs)
>>           || (mod->num_gpl_syms && !mod->gpl_crcs)
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index 3a3ae19..0e30dce 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -3627,6 +3627,21 @@ out:
>>  }
>>  EXPORT_SYMBOL_GPL(trace_vbprintk);
>>
>> +int __ftrace_bprintk(unsigned long ip, const char *fmt, ...)
>> +{
>> +     int ret;
>> +     va_list ap;
>> +
>> +     if (!fmt)
>> +             return 0;
>> +
>> +     va_start(ap, fmt);
>> +     ret = trace_vbprintk(ip, fmt, ap);
>> +     va_end(ap);
>> +     return ret;
>> +}
>> +EXPORT_SYMBOL_GPL(__ftrace_bprintk);
>> +
>>  static int trace_panic_handler(struct notifier_block *this,
>>                              unsigned long event, void *unused)
>>  {
>> diff --git a/kernel/trace/trace_bprintk.c b/kernel/trace/trace_bprintk.c
>> index 1f8e532..28e6286 100644
>> --- a/kernel/trace/trace_bprintk.c
>> +++ b/kernel/trace/trace_bprintk.c
>> @@ -19,9 +19,23 @@
>>
>>  #include "trace.h"
>>
>> +#ifdef CONFIG_MODULE> +
>>  /* binary printk basic */
>>  static DEFINE_MUTEX(btrace_mutex);
>>  static int btrace_metadata_count;
>> +/*
>> + * modules ftrace_bprintk()'s formats are autosaved in struct trace_bprintk_fmt
>> + * which are queued on trace_bprintk_fmt_list.
>> + */
>> +static LIST_HEAD(trace_bprintk_fmt_list);
>> +
>> +struct trace_bprintk_fmt {
>> +     struct list_head list;
>> +     int count;
>> +     char fmt[0];
>> +};
>> +
>>
>>  static inline void lock_btrace(void)
>>  {
>> @@ -33,6 +47,93 @@ static inline void unlock_btrace(void)
>>       mutex_unlock(&btrace_mutex);
>>  }
>>
>> +/*
>> + * If trace_bprintk() is not active, we release the trace_bprintk's
>> + * formats that no modules has reference to.
>> + */
>> +static inline void shrink_trace_bprintk_fmt(void)
>> +{
>> +     struct trace_bprintk_fmt *pos, *next;
>> +     list_for_each_entry_safe(pos, next, &trace_bprintk_fmt_list, list) {
>> +             if (!pos->count) {
>> +                     list_del(&pos->list);
>> +                     kfree(pos);
>> +             }
>> +     }
>> +}
>> +
>> +static inline struct trace_bprintk_fmt *lookup_format(const char *fmt)
>> +{
>> +     struct trace_bprintk_fmt *pos;
>> +     list_for_each_entry(pos, &trace_bprintk_fmt_list, list) {
>> +             if (!strcmp(pos->fmt, fmt))
>> +                     return pos;
>> +     }
>> +     return NULL;
>> +}
>> +
>> +static
>> +void hold_module_trace_bprintk_format(const char **start, const char **end)
>> +{
>> +     const char **iter;
>> +     lock_btrace();
>> +     for (iter = start; iter < end; iter++) {
>> +             struct trace_bprintk_fmt *tb_fmt = lookup_format(*iter);
>> +             if (tb_fmt) {
>> +                     tb_fmt->count++;
>> +                     *iter = tb_fmt->fmt;
>> +                     continue;
>> +             }
>> +
>> +             tb_fmt = kmalloc(offsetof(struct trace_bprintk_fmt, fmt)
>> +                             + strlen(*iter) + 1, GFP_KERNEL);
>> +             if (tb_fmt) {
>> +                     list_add_tail(&tb_fmt->list, &trace_bprintk_fmt_list);
>> +                     tb_fmt->count = 1;
>> +                     strcpy(tb_fmt->fmt, *iter);
>> +                     *iter = tb_fmt->fmt;
>> +             } else
>> +                     *iter = NULL;
>> +     }
>> +     unlock_btrace();
>> +}
>> +
>> +static
>> +void release_module_trace_bprintk_format(const char **start, const char **end)
>> +{
>> +     const char **iter;
>> +     lock_btrace();
>> +     for (iter = start; iter < end; iter++) {
>> +             struct trace_bprintk_fmt *tb_fmt;
>> +             if (!*iter)
>> +                     continue;
>> +
>> +             tb_fmt = container_of(*iter, struct trace_bprintk_fmt, fmt[0]);
>> +             tb_fmt->count--;
>> +             if (!tb_fmt->count && !btrace_metadata_count) {
>> +                     list_del(&tb_fmt->list);
>> +                     kfree(tb_fmt);
>
> Shouldn't *iter get assigned to NULL somewhere here?
>
> -- Steve


Hm, why?

>
>> +             }
>> +     }
>> +     unlock_btrace();
>> +}
>> +
>> +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);
>> +             else if (val == MODULE_STATE_GOING)
>> +                     release_module_trace_bprintk_format(start, end);
>> +     }
>> +     return 0;
>> +}
>> +
>>  static void get_btrace_metadata(void)
>>  {
>>       lock_btrace();
>> @@ -44,9 +145,31 @@ static void put_btrace_metadata(void)
>>  {
>>       lock_btrace();
>>       btrace_metadata_count--;
>> +
>> +     if (!btrace_metadata_count) {
>> +             shrink_trace_bprintk_fmt();
>> +     }
>>       unlock_btrace();
>>  }
>>
>> +#else /* !CONFIG_MODULES */
>> +__init static int
>> +module_trace_bprintk_format_notify(struct notifier_block *self,
>> +             unsigned long val, void *data)
>> +{
>> +     return 0;
>> +}
>> +
>> +static inline void get_btrace_metadata(void) { }
>> +static inline void put_btrace_metadata(void) { }
>> +#endif /* CONFIG_MODULES */
>> +
>> +
>> +__initdata_or_module static
>> +struct notifier_block module_trace_bprintk_format_nb = {
>> +     .notifier_call = module_trace_bprintk_format_notify,
>> +};
>> +
>>  /* events tracer */
>>  int trace_bprintk_enable;
>>
>> @@ -81,7 +204,14 @@ static struct tracer bprintk_trace __read_mostly =
>>
>>  static __init int init_bprintk(void)
>>  {
>> -     return register_tracer(&bprintk_trace);
>> +     int ret = register_module_notifier(&module_trace_bprintk_format_nb);
>> +     if (ret)
>> +             return ret;
>> +
>> +     ret = register_tracer(&bprintk_trace);
>> +     if (ret)
>> +             unregister_module_notifier(&module_trace_bprintk_format_nb);
>> +     return ret;
>>  }
>>
>>  device_initcall(init_bprintk);
>> --
>> 1.6.1
>>
>>
>>
>