[PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[Lai Jiangshan]

Impact: let user knows the format

Create a file on <debugfs-dir>/tracing/ to show ftrace_bprintk()'s formats.

This formats will help for these condition:
1) User get binary data from core file.(formats are backup before coredump)
2) User splice ring_buffer to a file.
User can use formats for parsing the binary data in userspace.

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---
 trace.c         |    8 +++++
 trace.h         |    1
 trace_bprintk.c |   79 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 88 insertions(+)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 61c9108..085cc8a 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -2944,6 +2944,14 @@ static __init int tracer_init_debugfs(void)
 		pr_warning("Could not create debugfs "
 			   "'trace_marker' entry\n");
 
+#ifdef CONFIG_TRACE_BPRINTK
+	entry = debugfs_create_file("trace_bprintk_formats", 0444, d_tracer,
+				    NULL, &trace_bprintk_fmt_fops);
+	if (!entry)
+		pr_warning("Could not create debugfs "
+			   "'trace_bprintk_formats' entry\n");
+#endif
+
 #ifdef CONFIG_DYNAMIC_FTRACE
 	entry = debugfs_create_file("dyn_ftrace_total_info", 0444, d_tracer,
 				    &ftrace_update_tot_cnt,
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 6885d13..c50826d 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -128,6 +128,7 @@ struct bprintk_entry {
 	u32 buf[];
 };
 #ifdef CONFIG_TRACE_BPRINTK
+extern struct file_operations trace_bprintk_fmt_fops;
 extern int trace_bprintk_enable;
 #endif
 
diff --git a/kernel/trace/trace_bprintk.c b/kernel/trace/trace_bprintk.c
index 84c7a9c..cbe89dd 100644
--- a/kernel/trace/trace_bprintk.c
+++ b/kernel/trace/trace_bprintk.c
@@ -156,6 +156,85 @@ static struct notifier_block module_trace_bprintk_format_nb = {
 	.notifier_call = module_trace_bprintk_format_notify,
 };
 
+/* shows ftrace_bprintk()'s format */
+extern char *__start___trace_bprintk_fmt[], *__stop___trace_bprintk_fmt[];
+
+static void *fmt_start(struct seq_file *m, loff_t *pos)
+{
+	loff_t tmp;
+	struct trace_bprintk_fmt *tb_fmt;
+
+	lock_btrace();
+	if (*pos < __stop___trace_bprintk_fmt - __start___trace_bprintk_fmt)
+		return __stop___trace_bprintk_fmt[*pos - 1];
+
+	tmp = __start___trace_bprintk_fmt + *pos - __stop___trace_bprintk_fmt;
+	list_for_each_entry(tb_fmt, &trace_bprintk_fmt_list, list) {
+		if (tmp-- == 0)
+			return tb_fmt->fmt;
+	}
+	return NULL;
+}
+
+static void *fmt_next(struct seq_file *m, void *p, loff_t *pos)
+{
+	char *fmt = p;
+	struct list_head *list;
+
+	++*pos;
+	if (*pos < __stop___trace_bprintk_fmt - __start___trace_bprintk_fmt)
+		return __stop___trace_bprintk_fmt[*pos - 1];
+
+	if (__start___trace_bprintk_fmt + *pos - __stop___trace_bprintk_fmt)
+		list = &container_of(fmt, struct trace_bprintk_fmt, fmt[0])
+				->list;
+	else
+		list = &trace_bprintk_fmt_list;
+
+	if (list->next != &trace_bprintk_fmt_list)
+		return list_entry(list->next, struct trace_bprintk_fmt, list)
+				->fmt;
+	return NULL;
+}
+
+static void fmt_stop(struct seq_file *m, void *p)
+{
+	unlock_btrace();
+}
+
+static int fmt_show(struct seq_file *m, void *p)
+{
+	seq_printf(m, "addr=%p fmt=%s\n", p, (char *)p);
+	return 0;
+}
+
+static struct seq_operations trace_bprintk_fmt_seq_ops = {
+	.start		= fmt_start,
+	.next		= fmt_next,
+	.stop		= fmt_stop,
+	.show		= fmt_show,
+};
+
+static int fmt_open(struct inode *inode, struct file *file)
+{
+	int ret = seq_open(file, &trace_bprintk_fmt_seq_ops);
+	if (!ret)
+		get_btrace_metadata();
+	return ret;
+}
+
+static int fmt_release(struct inode *inode, struct file *file)
+{
+	put_btrace_metadata();
+	return seq_release(inode, file);
+}
+
+struct file_operations trace_bprintk_fmt_fops = {
+	.open		= fmt_open,
+	.read		= seq_read,
+	.release	= fmt_release,
+};
+
 /* events tracer */
 int trace_bprintk_enable;
 

Re: [PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[Jason Baron]

On Wed, Dec 31, 2008 at 10:56:23AM +0800, Lai Jiangshan wrote:
> 
> Impact: let user knows the format
> 
> Create a file on <debugfs-dir>/tracing/ to show ftrace_bprintk()'s formats.
> 
> This formats will help for these condition:
> 1) User get binary data from core file.(formats are backup before coredump)
> 2) User splice ring_buffer to a file.
> User can use formats for parsing the binary data in userspace.
> 

When I 'cat' trace_bprintk_formats on my system the file is empty. This
seems to be b/c 'ftrace_bprintk' is not being used in this patchset. It
can't be used in patch #5 during marker register b/c the format wouldn't
be known at runtime. Thus, as it currently stands this patch, patch 4/5,
isn't adding much?

A thought on how this might be resolved would be to have the core marker
code pass us its address so this could be recorded in the trace buffer.
Then, also add some debug file that displays the markers and maps marker
addresses with format strings.

thanks,

-Jason

Re: [PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[Lai Jiangshan]

Jason Baron wrote:
> On Wed, Dec 31, 2008 at 10:56:23AM +0800, Lai Jiangshan wrote:
>> Impact: let user knows the format
>>
>> Create a file on <debugfs-dir>/tracing/ to show ftrace_bprintk()'s formats.
>>
>> This formats will help for these condition:
>> 1) User get binary data from core file.(formats are backup before coredump)
>> 2) User splice ring_buffer to a file.
>> User can use formats for parsing the binary data in userspace.
>>
> 
> When I 'cat' trace_bprintk_formats on my system the file is empty. This
> seems to be b/c 'ftrace_bprintk' is not being used in this patchset. It
> can't be used in patch #5 during marker register b/c the format wouldn't
> be known at runtime. Thus, as it currently stands this patch, patch 4/5,
> isn't adding much?

If you don't use ftrace_bprintk(), the file trace_bprintk_formats is empty.
This file record all formats which ftrace_bprintk() uses.

You can use ftrace_bprintk() everywhere as another printk().

Patch #5 enables binary printk for markers, this is another additional tool
for tracing markers.

> 
> A thought on how this might be resolved would be to have the core marker
> code pass us its address so this could be recorded in the trace buffer.
> Then, also add some debug file that displays the markers and maps marker
> addresses with format strings.
> 

Patch#5 does it as you said.

Re: [PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[Jason Baron]

On Wed, Jan 14, 2009 at 10:49:56AM +0800, Lai Jiangshan wrote:
> Jason Baron wrote:
> > On Wed, Dec 31, 2008 at 10:56:23AM +0800, Lai Jiangshan wrote:
> >> Impact: let user knows the format
> >>
> >> Create a file on <debugfs-dir>/tracing/ to show ftrace_bprintk()'s formats.
> >>
> >> This formats will help for these condition:
> >> 1) User get binary data from core file.(formats are backup before coredump)
> >> 2) User splice ring_buffer to a file.
> >> User can use formats for parsing the binary data in userspace.
> >>
> > 
> > When I 'cat' trace_bprintk_formats on my system the file is empty. This
> > seems to be b/c 'ftrace_bprintk' is not being used in this patchset. It
> > can't be used in patch #5 during marker register b/c the format wouldn't
> > be known at runtime. Thus, as it currently stands this patch, patch 4/5,
> > isn't adding much?
> 
> If you don't use ftrace_bprintk(), the file trace_bprintk_formats is empty.
> This file record all formats which ftrace_bprintk() uses.
> 
> You can use ftrace_bprintk() everywhere as another printk().
> 
> Patch #5 enables binary printk for markers, this is another additional tool
> for tracing markers.
> 
> > 
> > A thought on how this might be resolved would be to have the core marker
> > code pass us its address so this could be recorded in the trace buffer.
> > Then, also add some debug file that displays the markers and maps marker
> > addresses with format strings.
> > 
> 
> Patch#5 does it as you said.
> 
> 
> 

hmm...i'm still not clear on this. in patch #5 you have:


+static void marker_bprintk_probe(void *probe_private, void *call_private,
+		const char *fmt, va_list *args)
+{
+	struct marker_bprintk_struct *p = probe_private;
+
+	if (p->fmt_state == MARKER_FMT_LACK) {
+		int flen = strlen(fmt);
+		if (p->fmt - p->name + flen < MARKER_NAME_FMT_LEN) {
+			memcpy(p->fmt, fmt, flen + 1);
+			p->fmt_state = MARKER_FMT_OK;
+		} else
+			p->fmt_state = MARKER_FMT_INVALID;
+	}
+
+	if (p->fmt_state == MARKER_FMT_OK)
+		trace_vbprintk(0, p->name, *args);
+}
+

trace_vbprintk first argument is 'ip'. So I don't see how we are
associating instruction pointers with each 'ftrace' record? Aren't we
just recording each entry with '0' for the 'ip'?

thanks,

-Jason

Re: [PATCH 4/5] ftrace: show ftrace_bprintk()'s formats

[Lai Jiangshan]

Jason Baron wrote:
> On Wed, Jan 14, 2009 at 10:49:56AM +0800, Lai Jiangshan wrote:
>> Jason Baron wrote:
>>> On Wed, Dec 31, 2008 at 10:56:23AM +0800, Lai Jiangshan wrote:
>>>> Impact: let user knows the format
>>>>
>>>> Create a file on <debugfs-dir>/tracing/ to show ftrace_bprintk()'s formats.
>>>>
>>>> This formats will help for these condition:
>>>> 1) User get binary data from core file.(formats are backup before coredump)
>>>> 2) User splice ring_buffer to a file.
>>>> User can use formats for parsing the binary data in userspace.
>>>>
>>> When I 'cat' trace_bprintk_formats on my system the file is empty. This
>>> seems to be b/c 'ftrace_bprintk' is not being used in this patchset. It
>>> can't be used in patch #5 during marker register b/c the format wouldn't
>>> be known at runtime. Thus, as it currently stands this patch, patch 4/5,
>>> isn't adding much?
>> If you don't use ftrace_bprintk(), the file trace_bprintk_formats is empty.
>> This file record all formats which ftrace_bprintk() uses.
>>
>> You can use ftrace_bprintk() everywhere as another printk().
>>
>> Patch #5 enables binary printk for markers, this is another additional tool
>> for tracing markers.
>>
>>> A thought on how this might be resolved would be to have the core marker
>>> code pass us its address so this could be recorded in the trace buffer.
>>> Then, also add some debug file that displays the markers and maps marker
>>> addresses with format strings.
>>>
>> Patch#5 does it as you said.
>>
>>
>>
> 
> hmm...i'm still not clear on this. in patch #5 you have:
> 
> 
> +static void marker_bprintk_probe(void *probe_private, void *call_private,
> +		const char *fmt, va_list *args)
> +{
> +	struct marker_bprintk_struct *p = probe_private;
> +
> +	if (p->fmt_state == MARKER_FMT_LACK) {
> +		int flen = strlen(fmt);
> +		if (p->fmt - p->name + flen < MARKER_NAME_FMT_LEN) {
> +			memcpy(p->fmt, fmt, flen + 1);
> +			p->fmt_state = MARKER_FMT_OK;
> +		} else
> +			p->fmt_state = MARKER_FMT_INVALID;
> +	}
> +
> +	if (p->fmt_state == MARKER_FMT_OK)
> +		trace_vbprintk(0, p->name, *args);
> +}
> +
> 
> trace_vbprintk first argument is 'ip'. So I don't see how we are
> associating instruction pointers with each 'ftrace' record? Aren't we
> just recording each entry with '0' for the 'ip'?
> 
argument 'ip' is used for ftrace_bprintk(), the caller of ftrace_bprintk()
will be output in the message.

argument 'ip' is not used when trace markers.
we may can use:
trace_vbprintk(CALLER_ADDR2, p->name, *args);
but this cannot work for !CONFIG_FRAME_POINTER.

I will remove argument 'ip' in next version.(if users need know the call_addr
when he use ftrace_bprintk(), just use "%pS":
ftrace_bprintk("%pS: msgfmt example %d, %d", _THIS_IP_, msgarg1, msgarg2);)

Thanks for pointed it out.

Lai.