[PATCH 07/10] trace_syscalls: init print_fmt

[PATCH 07/10] trace_syscalls: init print_fmt

[Lai Jiangshan]

Init print_fmt for trace_syscalls.

But this field is still not used now,
the next patches will use it and replace the ->show_format().

It is preparing patch for new way of printing format files which
uses defined fields and a defined print_fmt to print formats.

How will the new way works(and how print_fmt will be used)?
print name
print ID
print string "format:"
use struct ftrace_event_call->fields to print fields
use struct ftrace_event_call->print_fmt to print "print fmt: XXXXXXXXXXX"

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---
diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index 75289f3..1352b0a 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -191,6 +191,67 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
 	return trace_seq_putc(s, '\n');
 }
 
+static
+int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
+{
+	int i;
+	int pos = 0;
+
+	/* When len=0, we just calculate the needed length */
+#define LEN_OR_ZERO (len ? len - pos : 0)
+
+	pos += snprintf(buf + pos, LEN_OR_ZERO, "\"");
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, LEN_OR_ZERO, "%s: 0x%%0%zulx%s",
+				entry->args[i], sizeof(unsigned long),
+				i == entry->nb_args - 1 ? "" : ", ");
+	}
+	pos += snprintf(buf + pos, LEN_OR_ZERO, "\"");
+
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, LEN_OR_ZERO,
+				", ((unsigned long)(REC->%s))", entry->args[i]);
+	}
+
+#undef LEN_OR_ZERO
+
+	/* return the length of print_fmt */
+	return pos;
+}
+
+static int set_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	char *print_fmt;
+	int len;
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event != call) {
+		call->print_fmt = "\"0x%lx\", REC->ret";
+		return 0;
+	}
+
+	/* First: called with 0 length to calculate the needed length */
+	len = __set_enter_print_fmt(entry, NULL, 0);
+
+	print_fmt = kmalloc(len + 1, GFP_KERNEL);
+	if (!print_fmt)
+		return -ENOMEM;
+
+	/* Second: actually write the @print_fmt */
+	__set_enter_print_fmt(entry, print_fmt, len + 1);
+	call->print_fmt = print_fmt;
+
+	return 0;
+}
+
+static void free_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event == call)
+		kfree(call->print_fmt);
+}
+
 int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
 {
 	int ret;
@@ -386,9 +447,14 @@ int init_syscall_trace(struct ftrace_event_call *call)
 {
 	int id;
 
+	if (set_syscall_print_fmt(call) < 0)
+		return -ENOMEM;
+
 	id = register_ftrace_event(call->event);
-	if (!id)
+	if (!id) {
+		free_syscall_print_fmt(call);
 		return -ENODEV;
+	}
 	call->id = id;
 	INIT_LIST_HEAD(&call->fields);
 	return 0;

[tip:tracing/core] tracing/syscalls: Init print_fmt for syscall events

[tip-bot for Lai Jiangshan]

Commit-ID:  50307a45f8515f6244e3b08e6b19824b9fbfe293
Gitweb:     http://git.kernel.org/tip/50307a45f8515f6244e3b08e6b19824b9fbfe293
Author:     Lai Jiangshan <laijs@cn.fujitsu.com>
AuthorDate: Tue, 15 Dec 2009 15:39:45 +0800
Committer:  Steven Rostedt <rostedt@goodmis.org>
CommitDate: Wed, 6 Jan 2010 11:58:32 -0500

tracing/syscalls: Init print_fmt for syscall events

This is part of a patch set that removes the show_format method
in the ftrace event macros.

Add the print_fmt initialization to the syscall events.
The print_fmt is still not used, but will be in the follow up
patches.

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
LKML-Reference: <4B273D41.609@cn.fujitsu.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_syscalls.c |   68 ++++++++++++++++++++++++++++++++++++++++-
 1 files changed, 67 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index 75289f3..1352b0a 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -191,6 +191,67 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
 	return trace_seq_putc(s, '\n');
 }
 
+static
+int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
+{
+	int i;
+	int pos = 0;
+
+	/* When len=0, we just calculate the needed length */
+#define LEN_OR_ZERO (len ? len - pos : 0)
+
+	pos += snprintf(buf + pos, LEN_OR_ZERO, "\"");
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, LEN_OR_ZERO, "%s: 0x%%0%zulx%s",
+				entry->args[i], sizeof(unsigned long),
+				i == entry->nb_args - 1 ? "" : ", ");
+	}
+	pos += snprintf(buf + pos, LEN_OR_ZERO, "\"");
+
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, LEN_OR_ZERO,
+				", ((unsigned long)(REC->%s))", entry->args[i]);
+	}
+
+#undef LEN_OR_ZERO
+
+	/* return the length of print_fmt */
+	return pos;
+}
+
+static int set_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	char *print_fmt;
+	int len;
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event != call) {
+		call->print_fmt = "\"0x%lx\", REC->ret";
+		return 0;
+	}
+
+	/* First: called with 0 length to calculate the needed length */
+	len = __set_enter_print_fmt(entry, NULL, 0);
+
+	print_fmt = kmalloc(len + 1, GFP_KERNEL);
+	if (!print_fmt)
+		return -ENOMEM;
+
+	/* Second: actually write the @print_fmt */
+	__set_enter_print_fmt(entry, print_fmt, len + 1);
+	call->print_fmt = print_fmt;
+
+	return 0;
+}
+
+static void free_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event == call)
+		kfree(call->print_fmt);
+}
+
 int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
 {
 	int ret;
@@ -386,9 +447,14 @@ int init_syscall_trace(struct ftrace_event_call *call)
 {
 	int id;
 
+	if (set_syscall_print_fmt(call) < 0)
+		return -ENOMEM;
+
 	id = register_ftrace_event(call->event);
-	if (!id)
+	if (!id) {
+		free_syscall_print_fmt(call);
 		return -ENODEV;
+	}
 	call->id = id;
 	INIT_LIST_HEAD(&call->fields);
 	return 0;

[PATCH 07/10] trace_syscalls: init print_fmt

[Lai Jiangshan]

Init print_fmt for trace_syscalls.
It will be used for replacing ->show_format().

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---
diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index 75289f3..dcd8699 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -191,6 +191,61 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
 	return trace_seq_putc(s, '\n');
 }
 
+static
+int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
+{
+	int i;
+	int pos = 0;
+
+	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
+				"%s: 0x%%0%zulx%s", entry->args[i],
+				sizeof(unsigned long),
+				i == entry->nb_args - 1 ? "" : ", ");
+	}
+	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
+
+	for (i = 0; i < entry->nb_args; i++) {
+		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
+				", ((unsigned long)(REC->%s))", entry->args[i]);
+	}
+
+	/* return the length of print_fmt */
+	return pos;
+}
+
+static int set_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	char *print_fmt;
+	int len;
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event != call) {
+		call->print_fmt = "\"0x%lx\", REC->ret";
+		return 0;
+	}
+
+	len = __set_enter_print_fmt(entry, NULL, 0);
+
+	print_fmt = kmalloc(len + 1, GFP_KERNEL);
+	if (!print_fmt)
+		return -ENOMEM;
+
+	__set_enter_print_fmt(entry, print_fmt, len + 1);
+	call->print_fmt = print_fmt;
+
+	return 0;
+}
+
+static void free_syscall_print_fmt(struct ftrace_event_call *call)
+{
+	struct syscall_metadata *entry = call->data;
+
+	if (entry->enter_event == call)
+		kfree(call->print_fmt);
+}
+
 int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
 {
 	int ret;
@@ -386,9 +441,14 @@ int init_syscall_trace(struct ftrace_event_call *call)
 {
 	int id;
 
+	if (set_syscall_print_fmt(call) < 0)
+		return -ENOMEM;
+
 	id = register_ftrace_event(call->event);
-	if (!id)
+	if (!id) {
+		free_syscall_print_fmt(call);
 		return -ENODEV;
+	}
 	call->id = id;
 	INIT_LIST_HEAD(&call->fields);
 	return 0;

Re: [PATCH 07/10] trace_syscalls: init print_fmt

[Steven Rostedt]

On Wed, 2009-12-09 at 15:15 +0800, Lai Jiangshan wrote:
> Init print_fmt for trace_syscalls.
> It will be used for replacing ->show_format().

This needs more explanation too.

> 
> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> ---
> diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> index 75289f3..dcd8699 100644
> --- a/kernel/trace/trace_syscalls.c
> +++ b/kernel/trace/trace_syscalls.c
> @@ -191,6 +191,61 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
>  	return trace_seq_putc(s, '\n');
>  }
>  
> +static
> +int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
> +{
> +	int i;
> +	int pos = 0;
> +
> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
> +	for (i = 0; i < entry->nb_args; i++) {
> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
> +				"%s: 0x%%0%zulx%s", entry->args[i],
> +				sizeof(unsigned long),
> +				i == entry->nb_args - 1 ? "" : ", ");
> +	}
> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
> +
> +	for (i = 0; i < entry->nb_args; i++) {
> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
> +				", ((unsigned long)(REC->%s))", entry->args[i]);

Yuck! 4 snprintf(buf + pos, len > pos ? len - pos: 0 ...

Please make a wrapper for that.

Actually, this could use the new trace_seq code if I separate the
buffer. You would just need to do:

	struct trace_seq s;

	trace_seq_init(&s, buf, len);

	trace_seq_putc(&s, '"');
	for (i = 0; i < entry->nb_args; i++)
		trace_seq_printf(&s, "%s: 0x%%0%zulx%s", entry->args[i],
				sizeof(unsigned long),
				i == entry->nb_args - 1 ? "" : ", ");

	trace_seq_putc(&s, '"');

	for (i = 0; i < entry->nb_args; i++)
		trace_seq_printf(&s, ", ((unsigned long)(REC->%s)",
				entry->args[i]);

	return s.len;


Looks much better, and less error prone.

-- Steve

> +	}
> +
> +	/* return the length of print_fmt */
> +	return pos;
> +}
> +
> +static int set_syscall_print_fmt(struct ftrace_event_call *call)
> +{
> +	char *print_fmt;
> +	int len;
> +	struct syscall_metadata *entry = call->data;
> +
> +	if (entry->enter_event != call) {
> +		call->print_fmt = "\"0x%lx\", REC->ret";
> +		return 0;
> +	}
> +
> +	len = __set_enter_print_fmt(entry, NULL, 0);
> +
> +	print_fmt = kmalloc(len + 1, GFP_KERNEL);
> +	if (!print_fmt)
> +		return -ENOMEM;
> +
> +	__set_enter_print_fmt(entry, print_fmt, len + 1);
> +	call->print_fmt = print_fmt;
> +
> +	return 0;
> +}
> +
> +static void free_syscall_print_fmt(struct ftrace_event_call *call)
> +{
> +	struct syscall_metadata *entry = call->data;
> +
> +	if (entry->enter_event == call)
> +		kfree(call->print_fmt);
> +}
> +
>  int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
>  {
>  	int ret;
> @@ -386,9 +441,14 @@ int init_syscall_trace(struct ftrace_event_call *call)
>  {
>  	int id;
>  
> +	if (set_syscall_print_fmt(call) < 0)
> +		return -ENOMEM;
> +
>  	id = register_ftrace_event(call->event);
> -	if (!id)
> +	if (!id) {
> +		free_syscall_print_fmt(call);
>  		return -ENODEV;
> +	}
>  	call->id = id;
>  	INIT_LIST_HEAD(&call->fields);
>  	return 0;
> 
> 

Re: [PATCH 07/10] trace_syscalls: init print_fmt

[Lai Jiangshan]

Steven Rostedt wrote:
> On Wed, 2009-12-09 at 15:15 +0800, Lai Jiangshan wrote:
>> Init print_fmt for trace_syscalls.
>> It will be used for replacing ->show_format().
> 
> This needs more explanation too.
> 
>> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
>> ---
>> diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
>> index 75289f3..dcd8699 100644
>> --- a/kernel/trace/trace_syscalls.c
>> +++ b/kernel/trace/trace_syscalls.c
>> @@ -191,6 +191,61 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
>>  	return trace_seq_putc(s, '\n');
>>  }
>>  
>> +static
>> +int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
>> +{
>> +	int i;
>> +	int pos = 0;
>> +
>> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
>> +	for (i = 0; i < entry->nb_args; i++) {
>> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
>> +				"%s: 0x%%0%zulx%s", entry->args[i],
>> +				sizeof(unsigned long),
>> +				i == entry->nb_args - 1 ? "" : ", ");
>> +	}
>> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
>> +
>> +	for (i = 0; i < entry->nb_args; i++) {
>> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
>> +				", ((unsigned long)(REC->%s))", entry->args[i]);
> 
> Yuck! 4 snprintf(buf + pos, len > pos ? len - pos: 0 ...
> 
> Please make a wrapper for that.

Do you mind if I use a macro?
Readability are still the same... 

static
int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
{
	int i;
	int pos = 0;

#define BUF_PRINTF(fmt...)						\
do {									\
	pos += snprintf(buf + pos, len > pos ? len - pos : 0, fmt);	\
} while (0)

	BUF_PRINTF("\"");
	for (i = 0; i < entry->nb_args; i++) {
		BUF_PRINTF("%s: 0x%%0%zulx%s", entry->args[i],
				sizeof(unsigned long),
				i == entry->nb_args - 1 ? "\"" : ", ");
	}

	for (i = 0; i < entry->nb_args; i++)
		BUF_PRINTF(", ((unsigned long)(REC->%s))", entry->args[i]);

#under BUF_PRINTF

	/* return the length of print_fmt */
	return pos;
}

> 
> Actually, this could use the new trace_seq code if I separate the
> buffer. You would just need to do:
> 
> 	struct trace_seq s;

I think trace_seq can not help.
__set_enter_print_fmt() is called twice.
We calculate the length at the first time(don't write any thing),
then allocate memory and then really "snprintf" string into the buffer.

-- Lai

> 
> 	trace_seq_init(&s, buf, len);
> 
> 	trace_seq_putc(&s, '"');
> 	for (i = 0; i < entry->nb_args; i++)
> 		trace_seq_printf(&s, "%s: 0x%%0%zulx%s", entry->args[i],
> 				sizeof(unsigned long),
> 				i == entry->nb_args - 1 ? "" : ", ");
> 
> 	trace_seq_putc(&s, '"');
> 
> 	for (i = 0; i < entry->nb_args; i++)
> 		trace_seq_printf(&s, ", ((unsigned long)(REC->%s)",
> 				entry->args[i]);
> 
> 	return s.len;
> 
> 
> Looks much better, and less error prone.
> 
> -- Steve
> 

Re: [PATCH 07/10] trace_syscalls: init print_fmt

[Steven Rostedt]

On Fri, 2009-12-11 at 10:41 +0800, Lai Jiangshan wrote:
> Steven Rostedt wrote:
> > On Wed, 2009-12-09 at 15:15 +0800, Lai Jiangshan wrote:
> >> Init print_fmt for trace_syscalls.
> >> It will be used for replacing ->show_format().
> > 
> > This needs more explanation too.
> > 
> >> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> >> ---
> >> diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> >> index 75289f3..dcd8699 100644
> >> --- a/kernel/trace/trace_syscalls.c
> >> +++ b/kernel/trace/trace_syscalls.c
> >> @@ -191,6 +191,61 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> >>  	return trace_seq_putc(s, '\n');
> >>  }
> >>  
> >> +static
> >> +int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
> >> +{
> >> +	int i;
> >> +	int pos = 0;
> >> +
> >> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
> >> +	for (i = 0; i < entry->nb_args; i++) {
> >> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
> >> +				"%s: 0x%%0%zulx%s", entry->args[i],
> >> +				sizeof(unsigned long),
> >> +				i == entry->nb_args - 1 ? "" : ", ");
> >> +	}
> >> +	pos += snprintf(buf + pos, len > pos ? len - pos : 0, "\"");
> >> +
> >> +	for (i = 0; i < entry->nb_args; i++) {
> >> +		pos += snprintf(buf + pos, len > pos ? len - pos : 0,
> >> +				", ((unsigned long)(REC->%s))", entry->args[i]);
> > 
> > Yuck! 4 snprintf(buf + pos, len > pos ? len - pos: 0 ...
> > 
> > Please make a wrapper for that.
> 
> Do you mind if I use a macro?
> Readability are still the same... 
> 
> static
> int  __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len)
> {
> 	int i;
> 	int pos = 0;
> 
> #define BUF_PRINTF(fmt...)						\
> do {									\
> 	pos += snprintf(buf + pos, len > pos ? len - pos : 0, fmt);	\
> } while (0)
> 
> 	BUF_PRINTF("\"");
> 	for (i = 0; i < entry->nb_args; i++) {
> 		BUF_PRINTF("%s: 0x%%0%zulx%s", entry->args[i],
> 				sizeof(unsigned long),
> 				i == entry->nb_args - 1 ? "\"" : ", ");
> 	}
> 
> 	for (i = 0; i < entry->nb_args; i++)
> 		BUF_PRINTF(", ((unsigned long)(REC->%s))", entry->args[i]);
> 
> #under BUF_PRINTF
> 
> 	/* return the length of print_fmt */
> 	return pos;
> }
> 
> > 
> > Actually, this could use the new trace_seq code if I separate the
> > buffer. You would just need to do:
> > 
> > 	struct trace_seq s;
> 
> I think trace_seq can not help.
> __set_enter_print_fmt() is called twice.
> We calculate the length at the first time(don't write any thing),
> then allocate memory and then really "snprintf" string into the buffer.
> 

Oh God, I see what you are doing. Too many side effects here.

This code needs major comments. Anyway, you already calculated the
length that is needed, you can just do "len ? len - pos : 0".

First, please comment what it is doing (that it gets called twice, once
with 0 length to calculate the needed length and once with the
calculated length).

Then just make the test a macro:

#define LEN_OR_ZERO (len ? len - pos : 0)

	pos += snprintf(buf + pos, LEN_OR_ZERO, fmt);

...

#undef LEN_OR_ZERO


With comments explaining what is happening and this macro, it can make
reading the code a bit easier to understand what is going on.

-- Steve




> -- Lai
> 
> > 
> > 	trace_seq_init(&s, buf, len);
> > 
> > 	trace_seq_putc(&s, '"');
> > 	for (i = 0; i < entry->nb_args; i++)
> > 		trace_seq_printf(&s, "%s: 0x%%0%zulx%s", entry->args[i],
> > 				sizeof(unsigned long),
> > 				i == entry->nb_args - 1 ? "" : ", ");
> > 
> > 	trace_seq_putc(&s, '"');
> > 
> > 	for (i = 0; i < entry->nb_args; i++)
> > 		trace_seq_printf(&s, ", ((unsigned long)(REC->%s)",
> > 				entry->args[i]);
> > 
> > 	return s.len;
> > 
> > 
> > Looks much better, and less error prone.
> > 
> > -- Steve
> >