perf trace: Fix array handling & value truncation

perf trace: Fix array handling & value truncation

[Ian Munsie]

This patch series fixes several issues with perf trace relating to the size of a long.

The first issue fixed by patch #2 is an assumption that tracepoints with arrays
as part of their output (for instance, raw_syscalls:sys_enter) that the size of
each element within the array is a long size. Due to further problems fixed by
patches #3 through #5, the long_size was not even being set in the
trace-event-parse.c file, and as a result the code was previously treating the
array elements as 0 size.

Patch #6 fixes issues where printing the values of pointers and longs from
64bit kernels were being truncated if perf was compiled as 32bit. This
obviously effects tracepoints with a "%p" or "%ld" in their output format, but
also affects the printout of the location of kprobes.

Patches #1 and #7 apply good software engineering practice to help spot future
regressions of these issues.

Thanks,
-Ian

[PATCH 1/7] perf trace: Defensive programming

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

This patch makes the failure case where the size that read_size is
passed is invalid kill perf immediately rather than silently failing, so
that further bugs or regressions using read_size can be found more
easily and squashed early.

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |    3 +--
 1 files changed, 1 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 73a0222..8f470f6 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -1912,8 +1912,7 @@ unsigned long long read_size(void *ptr, int size)
 	case 8:
 		return data2host8(ptr);
 	default:
-		/* BUG! */
-		return 0;
+		die("read_size BUG: Invalid size %d", size);
 	}
 }
 
-- 
1.7.1

[PATCH 2/7] perf trace: Correctly handle arrays

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

Previously, perf was assuming that an array from an ftrace event was an
array of longs, which will not always be the case. Additionally,
long_size is not even being initialised, so it would fail to read the
data and would erroneously report that the array was filled with zeroes.

This patch adds two extra entries into the field structure - arraylen
and elementsize, so that the code can easily look them up instead of
assuming that the elements are long_size. The element size is currently
derived by the size of the entire array and the number of elements
within the array.

This problem can be demonstrated with:
perf record -e raw_syscalls:sys_enter -a sleep 0.1
perf trace

Without this patch, output similar to the following is produced:
 perf-4355  [004]  1871.504685: sys_enter: NR 319 (0, 0, 0, 0, 0, 0)
 perf-4355  [004]  1871.504723: sys_enter: NR 3 (0, 0, 0, 0, 0, 0)
 perf-4355  [004]  1871.504733: sys_enter: NR 204 (0, 0, 0, 0, 0, 0)

After applying this patch, the output looks like:
 perf-4355  [004]  1871.504685: sys_enter: NR 319 (10247ac0, ffffffff, 5, ffffffff, 0, 107a80d8)
 perf-4355  [004]  1871.504723: sys_enter: NR 3 (a, ffb6fcf0, 20, ffffffff, 0, 10112c20)
 perf-4355  [004]  1871.504733: sys_enter: NR 204 (a, 4, 800, 6, 0, 10112c20)

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |   11 ++++++++++-
 tools/perf/util/trace-event.h       |    2 ++
 2 files changed, 12 insertions(+), 1 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 8f470f6..f360f75 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -852,6 +852,9 @@ static int event_read_fields(struct event *event, struct format_field **fields)
 			field->flags |= FIELD_IS_ARRAY;
 
 			type = read_token(&token);
+			if (test_type(type, EVENT_ITEM))
+				goto fail;
+			field->arraylen = strtoul(token, NULL, 0);
 		        while (strcmp(token, "]") != 0) {
 				if (last_type == EVENT_ITEM &&
 				    type == EVENT_ITEM)
@@ -971,6 +974,11 @@ static int event_read_fields(struct event *event, struct format_field **fields)
 
 		free_token(token);
 
+		if (field->flags & FIELD_IS_ARRAY)
+			field->elementsize = field->size / field->arraylen;
+		else
+			field->elementsize = field->size;
+
 		*fields = field;
 		fields = &field->next;
 
@@ -2101,7 +2109,8 @@ static unsigned long long eval_num_arg(void *data, int size,
 			}
 			right = eval_num_arg(data, size, event, arg->op.right);
 			val = read_size(data + larg->field.field->offset +
-					right * long_size, long_size);
+					right * larg->field.field->elementsize,
+					larg->field.field->elementsize);
 			break;
 		}
  default_op:
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 406d452..cc58a19 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -40,6 +40,8 @@ struct format_field {
 	char			*name;
 	int			offset;
 	int			size;
+	unsigned int		arraylen;
+	unsigned int		elementsize;
 	unsigned long		flags;
 };
 
-- 
1.7.1

Re: [PATCH 2/7] perf trace: Correctly handle arrays

[Steven Rostedt]

On Thu, 2010-05-13 at 16:03 +1000, Ian Munsie wrote:
> From: Ian Munsie <imunsie@au1.ibm.com>
> 
> Previously, perf was assuming that an array from an ftrace event was an
> array of longs, which will not always be the case. Additionally,
> long_size is not even being initialised, so it would fail to read the
> data and would erroneously report that the array was filled with zeroes.
> 
> This patch adds two extra entries into the field structure - arraylen
> and elementsize, so that the code can easily look them up instead of
> assuming that the elements are long_size. The element size is currently
> derived by the size of the entire array and the number of elements
> within the array.
> 
> This problem can be demonstrated with:
> perf record -e raw_syscalls:sys_enter -a sleep 0.1
> perf trace
> 

I'm added this to trace-cmd too.

> Without this patch, output similar to the following is produced:
>  perf-4355  [004]  1871.504685: sys_enter: NR 319 (0, 0, 0, 0, 0, 0)
>  perf-4355  [004]  1871.504723: sys_enter: NR 3 (0, 0, 0, 0, 0, 0)
>  perf-4355  [004]  1871.504733: sys_enter: NR 204 (0, 0, 0, 0, 0, 0)
> 
> After applying this patch, the output looks like:
>  perf-4355  [004]  1871.504685: sys_enter: NR 319 (10247ac0, ffffffff, 5, ffffffff, 0, 107a80d8)
>  perf-4355  [004]  1871.504723: sys_enter: NR 3 (a, ffb6fcf0, 20, ffffffff, 0, 10112c20)
>  perf-4355  [004]  1871.504733: sys_enter: NR 204 (a, 4, 800, 6, 0, 10112c20)
> 
> Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
> ---
>  tools/perf/util/trace-event-parse.c |   11 ++++++++++-
>  tools/perf/util/trace-event.h       |    2 ++
>  2 files changed, 12 insertions(+), 1 deletions(-)
> 
> diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> index 8f470f6..f360f75 100644
> --- a/tools/perf/util/trace-event-parse.c
> +++ b/tools/perf/util/trace-event-parse.c
> @@ -852,6 +852,9 @@ static int event_read_fields(struct event *event, struct format_field **fields)
>  			field->flags |= FIELD_IS_ARRAY;
>  
>  			type = read_token(&token);
> +			if (test_type(type, EVENT_ITEM))
> +				goto fail;

Note this will incorrectly fail on:

	field:__data_loc char[] name;

-- Steve

> +			field->arraylen = strtoul(token, NULL, 0);
>  		        while (strcmp(token, "]") != 0) {
>  				if (last_type == EVENT_ITEM &&
>  				    type == EVENT_ITEM)
> @@ -971,6 +974,11 @@ static int event_read_fields(struct event *event, struct format_field **fields)
>  
>  		free_token(token);
>  
> +		if (field->flags & FIELD_IS_ARRAY)
> +			field->elementsize = field->size / field->arraylen;
> +		else
> +			field->elementsize = field->size;
> +
>  		*fields = field;
>  		fields = &field->next;
>  
> @@ -2101,7 +2109,8 @@ static unsigned long long eval_num_arg(void *data, int size,
>  			}
>  			right = eval_num_arg(data, size, event, arg->op.right);
>  			val = read_size(data + larg->field.field->offset +
> -					right * long_size, long_size);
> +					right * larg->field.field->elementsize,
> +					larg->field.field->elementsize);
>  			break;
>  		}
>   default_op:
> diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> index 406d452..cc58a19 100644
> --- a/tools/perf/util/trace-event.h
> +++ b/tools/perf/util/trace-event.h
> @@ -40,6 +40,8 @@ struct format_field {
>  	char			*name;
>  	int			offset;
>  	int			size;
> +	unsigned int		arraylen;
> +	unsigned int		elementsize;
>  	unsigned long		flags;
>  };
>  

Re: [PATCH 2/7] perf trace: Correctly handle arrays

[Frederic Weisbecker]

On Thu, May 13, 2010 at 12:29:05PM -0400, Steven Rostedt wrote:
> On Thu, 2010-05-13 at 16:03 +1000, Ian Munsie wrote:
> > From: Ian Munsie <imunsie@au1.ibm.com>
> > 
> > Previously, perf was assuming that an array from an ftrace event was an
> > array of longs, which will not always be the case. Additionally,
> > long_size is not even being initialised, so it would fail to read the
> > data and would erroneously report that the array was filled with zeroes.
> > 
> > This patch adds two extra entries into the field structure - arraylen
> > and elementsize, so that the code can easily look them up instead of
> > assuming that the elements are long_size. The element size is currently
> > derived by the size of the entire array and the number of elements
> > within the array.
> > 
> > This problem can be demonstrated with:
> > perf record -e raw_syscalls:sys_enter -a sleep 0.1
> > perf trace
> > 
> 
> I'm added this to trace-cmd too.
> 
> > Without this patch, output similar to the following is produced:
> >  perf-4355  [004]  1871.504685: sys_enter: NR 319 (0, 0, 0, 0, 0, 0)
> >  perf-4355  [004]  1871.504723: sys_enter: NR 3 (0, 0, 0, 0, 0, 0)
> >  perf-4355  [004]  1871.504733: sys_enter: NR 204 (0, 0, 0, 0, 0, 0)
> > 
> > After applying this patch, the output looks like:
> >  perf-4355  [004]  1871.504685: sys_enter: NR 319 (10247ac0, ffffffff, 5, ffffffff, 0, 107a80d8)
> >  perf-4355  [004]  1871.504723: sys_enter: NR 3 (a, ffb6fcf0, 20, ffffffff, 0, 10112c20)
> >  perf-4355  [004]  1871.504733: sys_enter: NR 204 (a, 4, 800, 6, 0, 10112c20)
> > 
> > Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
> > ---
> >  tools/perf/util/trace-event-parse.c |   11 ++++++++++-
> >  tools/perf/util/trace-event.h       |    2 ++
> >  2 files changed, 12 insertions(+), 1 deletions(-)
> > 
> > diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> > index 8f470f6..f360f75 100644
> > --- a/tools/perf/util/trace-event-parse.c
> > +++ b/tools/perf/util/trace-event-parse.c
> > @@ -852,6 +852,9 @@ static int event_read_fields(struct event *event, struct format_field **fields)
> >  			field->flags |= FIELD_IS_ARRAY;
> >  
> >  			type = read_token(&token);
> > +			if (test_type(type, EVENT_ITEM))
> > +				goto fail;
> 
> Note this will incorrectly fail on:
> 
> 	field:__data_loc char[] name;
> 
> -- Steve



Nice patch, but indeed this part needs to be fixed.

Thanks.

Re: [PATCH 2/7] perf trace: Correctly handle arrays

[Steven Rostedt]

On Thu, 2010-05-13 at 16:03 +1000, Ian Munsie wrote:
> From: Ian Munsie <imunsie@au1.ibm.com>
> 
> Previously, perf was assuming that an array from an ftrace event was an
> array of longs, which will not always be the case. Additionally,
> long_size is not even being initialised, so it would fail to read the
> data and would erroneously report that the array was filled with zeroes.
> 
> This patch adds two extra entries into the field structure - arraylen
> and elementsize, so that the code can easily look them up instead of
> assuming that the elements are long_size. The element size is currently
> derived by the size of the entire array and the number of elements
> within the array.
> 
> This problem can be demonstrated with:
> perf record -e raw_syscalls:sys_enter -a sleep 0.1
> perf trace
> 
> Without this patch, output similar to the following is produced:
>  perf-4355  [004]  1871.504685: sys_enter: NR 319 (0, 0, 0, 0, 0, 0)
>  perf-4355  [004]  1871.504723: sys_enter: NR 3 (0, 0, 0, 0, 0, 0)
>  perf-4355  [004]  1871.504733: sys_enter: NR 204 (0, 0, 0, 0, 0, 0)
> 
> After applying this patch, the output looks like:
>  perf-4355  [004]  1871.504685: sys_enter: NR 319 (10247ac0, ffffffff, 5, ffffffff, 0, 107a80d8)
>  perf-4355  [004]  1871.504723: sys_enter: NR 3 (a, ffb6fcf0, 20, ffffffff, 0, 10112c20)
>  perf-4355  [004]  1871.504733: sys_enter: NR 204 (a, 4, 800, 6, 0, 10112c20)
> 
> Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
> ---
>  tools/perf/util/trace-event-parse.c |   11 ++++++++++-
>  tools/perf/util/trace-event.h       |    2 ++
>  2 files changed, 12 insertions(+), 1 deletions(-)
> 
> diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> index 8f470f6..f360f75 100644
> --- a/tools/perf/util/trace-event-parse.c
> +++ b/tools/perf/util/trace-event-parse.c
> @@ -852,6 +852,9 @@ static int event_read_fields(struct event *event, struct format_field **fields)
>  			field->flags |= FIELD_IS_ARRAY;
>  
>  			type = read_token(&token);
> +			if (test_type(type, EVENT_ITEM))
> +				goto fail;
> +			field->arraylen = strtoul(token, NULL, 0);
>  		        while (strcmp(token, "]") != 0) {
>  				if (last_type == EVENT_ITEM &&
>  				    type == EVENT_ITEM)
> @@ -971,6 +974,11 @@ static int event_read_fields(struct event *event, struct format_field **fields)
>  
>  		free_token(token);
>  
> +		if (field->flags & FIELD_IS_ARRAY)
> +			field->elementsize = field->size / field->arraylen;

Note, if an array also has something like [TASK_COMM_LEN] then arraylen
will be zero, causing a divide by zero exception above.

-- Steve

> +		else
> +			field->elementsize = field->size;
> +
>  		*fields = field;
>  		fields = &field->next;
>  
> @@ -2101,7 +2109,8 @@ static unsigned long long eval_num_arg(void *data, int size,
>  			}
>  			right = eval_num_arg(data, size, event, arg->op.right);
>  			val = read_size(data + larg->field.field->offset +
> -					right * long_size, long_size);
> +					right * larg->field.field->elementsize,
> +					larg->field.field->elementsize);
>  			break;
>  		}
>   default_op:
> diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> index 406d452..cc58a19 100644
> --- a/tools/perf/util/trace-event.h
> +++ b/tools/perf/util/trace-event.h
> @@ -40,6 +40,8 @@ struct format_field {
>  	char			*name;
>  	int			offset;
>  	int			size;
> +	unsigned int		arraylen;
> +	unsigned int		elementsize;
>  	unsigned long		flags;
>  };
>  

Re: [PATCH 2/7] perf trace: Correctly handle arrays

[Peter Zijlstra]

On Thu, 2010-05-13 at 12:32 -0400, Steven Rostedt wrote:
> 
> -- Steve
> 
> > +             else
> > +                     field->elementsize = field->size;
> > +
> >               *fields = field;
> >               fields = &field->next;
> >  
> > @@ -2101,7 +2109,8 @@ static unsigned long long eval_num_arg(void *data, int size,
> >                       }
> >                       right = eval_num_arg(data, size, event, arg->op.right);
> >                       val = read_size(data + larg->field.field->offset +
> > -                                     right * long_size, long_size);
> > +                                     right * larg->field.field->elementsize,
> > +                                     larg->field.field->elementsize);
> >                       break;
> >               }
> >   default_op:
> > diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> > index 406d452..cc58a19 100644
> > --- a/tools/perf/util/trace-event.h
> > +++ b/tools/perf/util/trace-event.h
> > @@ -40,6 +40,8 @@ struct format_field {
> >       char                    *name;
> >       int                     offset;
> >       int                     size;
> > +     unsigned int            arraylen;
> > +     unsigned int            elementsize;
> >       unsigned long           flags;
> >  };
> >  

What's with this new fad of not trimming emails?

Re: [PATCH 2/7] perf trace: Correctly handle arrays

[Steven Rostedt]

On Fri, 2010-05-14 at 12:39 +0200, Peter Zijlstra wrote:
> On Thu, 2010-05-13 at 12:32 -0400, Steven Rostedt wrote:
> > 
> > -- Steve
> > 
> > > +             else
> > > +                     field->elementsize = field->size;
> > > +
> > >               *fields = field;
> > >               fields = &field->next;
> > >  
> > > @@ -2101,7 +2109,8 @@ static unsigned long long eval_num_arg(void *data, int size,
> > >                       }
> > >                       right = eval_num_arg(data, size, event, arg->op.right);
> > >                       val = read_size(data + larg->field.field->offset +
> > > -                                     right * long_size, long_size);
> > > +                                     right * larg->field.field->elementsize,
> > > +                                     larg->field.field->elementsize);
> > >                       break;
> > >               }
> > >   default_op:
> > > diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> > > index 406d452..cc58a19 100644
> > > --- a/tools/perf/util/trace-event.h
> > > +++ b/tools/perf/util/trace-event.h
> > > @@ -40,6 +40,8 @@ struct format_field {
> > >       char                    *name;
> > >       int                     offset;
> > >       int                     size;
> > > +     unsigned int            arraylen;
> > > +     unsigned int            elementsize;
> > >       unsigned long           flags;
> > >  };
> > >  
> 
> What's with this new fad of not trimming emails?
> 

I usually do, but if it isn't that big I don't. But my rule (and I
suspect it with others too) is that I end my comments with my sig 
(-- Steve). After that, I have no more comments so you do not need to
look further. When I see someone's sig in the mail, I stop reading
further.

-- Steve

[PATCH 3/7] Revert "perf: Fix warning while reading ring buffer headers"

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

This reverts commit d00a47cce569a3e660a8c9de5d57af28d6a9f0f7.
    "perf: Fix warning while reading ring buffer headers"

The reverted patch removed the processing of the header_page, skipping
over it instead on the assumption that perf was not using any of the
data from that header. The patch neglected to remove the header_page_
variables which were initialised in the removed code, nor did it fix any
code that was using those variables.

In particular, long_size was set based on one of those variables
(header_page_size_size) to learn the size of a long from the kernel,
which is necessary to correctly print out some of the trace information
in some circumstances. For instance, the size of a long in a 64 bit
kernel would differ from the size of a long in perf if it was compiled
for a 32 bit userspace. Perf trace needs to know the size of a long in
the kernel so that it can print out the correct value without
truncation.

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |   89 +++++++++++++++++++++++++++++++++++
 tools/perf/util/trace-event-read.c  |   12 ++---
 tools/perf/util/trace-event.h       |    1 +
 3 files changed, 95 insertions(+), 7 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index f360f75..9717f7a 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -691,6 +691,11 @@ static int __read_expected(enum event_type expect, const char *str,
 	return ret;
 }
 
+static int read_expected_warn(enum event_type expect, const char *str, bool warn)
+{
+	return __read_expected(expect, str, 1, warn);
+}
+
 static int read_expected(enum event_type expect, const char *str)
 {
 	return __read_expected(expect, str, 1, true);
@@ -3107,6 +3112,90 @@ static void print_args(struct print_arg *args)
 	}
 }
 
+static void parse_header_field(const char *field,
+			       int *offset, int *size, bool warn)
+{
+	char *token;
+	int type;
+
+	if (read_expected(EVENT_ITEM, "field") < 0)
+		return;
+	if (read_expected(EVENT_OP, ":") < 0)
+		return;
+
+	/* type */
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto fail;
+	free_token(token);
+
+	if (read_expected_warn(EVENT_ITEM, field, warn) < 0)
+		return;
+	if (read_expected(EVENT_OP, ";") < 0)
+		return;
+	if (read_expected(EVENT_ITEM, "offset") < 0)
+		return;
+	if (read_expected(EVENT_OP, ":") < 0)
+		return;
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto fail;
+	*offset = atoi(token);
+	free_token(token);
+	if (read_expected(EVENT_OP, ";") < 0)
+		return;
+	if (read_expected(EVENT_ITEM, "size") < 0)
+		return;
+	if (read_expected(EVENT_OP, ":") < 0)
+		return;
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto fail;
+	*size = atoi(token);
+	free_token(token);
+	if (read_expected(EVENT_OP, ";") < 0)
+		return;
+	type = read_token(&token);
+	if (type != EVENT_NEWLINE) {
+		/* newer versions of the kernel have a "signed" type */
+		if (type != EVENT_ITEM)
+			goto fail;
+
+		if (strcmp(token, "signed") != 0)
+			goto fail;
+
+		free_token(token);
+
+		if (read_expected(EVENT_OP, ":") < 0)
+			return;
+
+		if (read_expect_type(EVENT_ITEM, &token))
+			goto fail;
+
+		free_token(token);
+		if (read_expected(EVENT_OP, ";") < 0)
+			return;
+
+		if (read_expect_type(EVENT_NEWLINE, &token))
+			goto fail;
+	}
+ fail:
+	free_token(token);
+}
+
+int parse_header_page(char *buf, unsigned long size)
+{
+	init_input_buf(buf, size);
+
+	parse_header_field("timestamp", &header_page_ts_offset,
+			   &header_page_ts_size, true);
+	parse_header_field("commit", &header_page_size_offset,
+			   &header_page_size_size, true);
+	parse_header_field("overwrite", &header_page_overwrite_offset,
+			   &header_page_overwrite_size, false);
+	parse_header_field("data", &header_page_data_offset,
+			   &header_page_data_size, true);
+
+	return 0;
+}
+
 int parse_ftrace_file(char *buf, unsigned long size)
 {
 	struct format_field *field;
diff --git a/tools/perf/util/trace-event-read.c b/tools/perf/util/trace-event-read.c
index cb54cd0..43f19c1 100644
--- a/tools/perf/util/trace-event-read.c
+++ b/tools/perf/util/trace-event-read.c
@@ -53,12 +53,6 @@ static unsigned long	page_size;
 static ssize_t calc_data_size;
 static bool repipe;
 
-/* If it fails, the next read will report it */
-static void skip(int size)
-{
-	lseek(input_fd, size, SEEK_CUR);
-}
-
 static int do_read(int fd, void *buf, int size)
 {
 	int rsize = size;
@@ -190,6 +184,7 @@ static void read_ftrace_printk(void)
 static void read_header_files(void)
 {
 	unsigned long long size;
+	char *header_page;
 	char *header_event;
 	char buf[BUFSIZ];
 
@@ -199,7 +194,10 @@ static void read_header_files(void)
 		die("did not read header page");
 
 	size = read8();
-	skip(size);
+	header_page = malloc_or_die(size);
+	read_or_die(header_page, size);
+	parse_header_page(header_page, size);
+	free(header_page);
 
 	/*
 	 * The size field in the page is of type long,
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index cc58a19..5fa3c5a 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -246,6 +246,7 @@ extern int header_page_data_size;
 
 extern bool latency_format;
 
+int parse_header_page(char *buf, unsigned long size);
 int trace_parse_common_type(void *data);
 int trace_parse_common_pid(void *data);
 int parse_common_pc(void *data);
-- 
1.7.1

Re: [PATCH 3/7] Revert "perf: Fix warning while reading ring buffer headers"

[Frederic Weisbecker]

On Thu, May 13, 2010 at 04:03:48PM +1000, Ian Munsie wrote:
> From: Ian Munsie <imunsie@au1.ibm.com>
> 
> This reverts commit d00a47cce569a3e660a8c9de5d57af28d6a9f0f7.
>     "perf: Fix warning while reading ring buffer headers"
> 
> The reverted patch removed the processing of the header_page, skipping
> over it instead on the assumption that perf was not using any of the
> data from that header. The patch neglected to remove the header_page_
> variables which were initialised in the removed code, nor did it fix any
> code that was using those variables.
> 
> In particular, long_size was set based on one of those variables
> (header_page_size_size) to learn the size of a long from the kernel,
> which is necessary to correctly print out some of the trace information
> in some circumstances. For instance, the size of a long in a 64 bit
> kernel would differ from the size of a long in perf if it was compiled
> for a 32 bit userspace. Perf trace needs to know the size of a long in
> the kernel so that it can print out the correct value without
> truncation.



I don't understand.
In the format file we have the size of the fields beside their type name,
so why do we need this?

Thanks.

[PATCH 4/7] perf trace: Rewind pointer in case field in header_page is missing

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

This patch rewinds the input pointer in the event that parsing one of
the fields in the header_page fails (which can happen if a field is
missing, such as the overwrite field), allowing the next field to be
parsed.

This patch fixes an issue from e9e94e3bd862d31777335722e747e97d9821bc1d
"perf trace: Ignore "overwrite" field if present in /events/header_page"
which ignored the field mismatch warning, but left the pointer in at
invalid position, resulting in this warning when the next field was
processed:

    	Warning: Error: expected type 6 but read 4

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |   35 +++++++++++++++++++++++------------
 1 files changed, 23 insertions(+), 12 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 9717f7a..950c757 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -29,6 +29,7 @@
 #include <errno.h>
 
 #undef _GNU_SOURCE
+#include <linux/kernel.h>
 #include "../perf.h"
 #include "util.h"
 #include "trace-event.h"
@@ -37,6 +38,8 @@ int header_page_ts_offset;
 int header_page_ts_size;
 int header_page_size_offset;
 int header_page_size_size;
+/* NOTE: the overwrite field may not be present on all systems so, check if
+ * header_page_overwrite_size > 0 before use */
 int header_page_overwrite_offset;
 int header_page_overwrite_size;
 int header_page_data_offset;
@@ -3117,11 +3120,12 @@ static void parse_header_field(const char *field,
 {
 	char *token;
 	int type;
+	unsigned long long input_buf_ptr_sav = input_buf_ptr;
 
 	if (read_expected(EVENT_ITEM, "field") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_OP, ":") < 0)
-		return;
+		goto tokenlessfail;
 
 	/* type */
 	if (read_expect_type(EVENT_ITEM, &token) < 0)
@@ -3129,29 +3133,29 @@ static void parse_header_field(const char *field,
 	free_token(token);
 
 	if (read_expected_warn(EVENT_ITEM, field, warn) < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_OP, ";") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_ITEM, "offset") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_OP, ":") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expect_type(EVENT_ITEM, &token) < 0)
 		goto fail;
 	*offset = atoi(token);
 	free_token(token);
 	if (read_expected(EVENT_OP, ";") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_ITEM, "size") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expected(EVENT_OP, ":") < 0)
-		return;
+		goto tokenlessfail;
 	if (read_expect_type(EVENT_ITEM, &token) < 0)
 		goto fail;
 	*size = atoi(token);
 	free_token(token);
 	if (read_expected(EVENT_OP, ";") < 0)
-		return;
+		goto tokenlessfail;
 	type = read_token(&token);
 	if (type != EVENT_NEWLINE) {
 		/* newer versions of the kernel have a "signed" type */
@@ -3164,20 +3168,27 @@ static void parse_header_field(const char *field,
 		free_token(token);
 
 		if (read_expected(EVENT_OP, ":") < 0)
-			return;
+			goto tokenlessfail;
 
 		if (read_expect_type(EVENT_ITEM, &token))
 			goto fail;
 
 		free_token(token);
 		if (read_expected(EVENT_OP, ";") < 0)
-			return;
+			goto tokenlessfail;
 
 		if (read_expect_type(EVENT_NEWLINE, &token))
 			goto fail;
 	}
+	free_token(token);
+	return;
+
  fail:
 	free_token(token);
+ tokenlessfail:
+	input_buf_ptr = input_buf_ptr_sav;
+	if (warn)
+		pr_warning("Failed to parse %s field of header_page\n", field);
 }
 
 int parse_header_page(char *buf, unsigned long size)
-- 
1.7.1

[PATCH 5/7] perf trace: use long_size from trace-event-read

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

long_size was not being initialised in trace-event-parse, which caused a
few bugs. This patch makes it use the long_size from trace-event-read.

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |    2 +-
 tools/perf/util/trace-event-read.c  |    2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 950c757..f9f80be 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -52,7 +52,7 @@ static unsigned long long input_buf_ptr;
 static unsigned long long input_buf_siz;
 
 static int cpus;
-static int long_size;
+extern int long_size;
 static int is_flag_field;
 static int is_symbolic_field;
 
diff --git a/tools/perf/util/trace-event-read.c b/tools/perf/util/trace-event-read.c
index 43f19c1..de30159 100644
--- a/tools/perf/util/trace-event-read.c
+++ b/tools/perf/util/trace-event-read.c
@@ -46,7 +46,7 @@ static int read_page;
 
 int file_bigendian;
 int host_bigendian;
-static int long_size;
+int long_size;
 
 static unsigned long	page_size;
 
-- 
1.7.1

[PATCH 6/7] perf trace: Fix value truncation with 64bit kernel and 32bit userspace

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

On systems with a 64bit kernel and 32bit userspace, perf trace would
truncate pointers and longs down to 32 bits when displaying them. This
was due to calling printf("%p", (long long)val); or printf("%ld",
(long)val); which both would truncate the long to the size of a
userspace long in perf.

This patch adds a final parse of the format string in the event that the
size of a long in the kernel does not match the size of a long in
userspace (both 32bit => 64bit and vice versa. "%p" is explicitly
converted to "0x%llx" for 64=>32, or "0x%x" for 32=>64. "%l*" is
similarly converted to "%ll*" for 64=>32 or "%*" for 32=>64.

Running perf trace without the patch on a PPC machine with a 64bit
kernel and 32bit userspace produces output similar to the following
recording the timer:timer_start tracepoint:
  swapper-0     [000]  6420.045520: timer_start: timer=0xc0000000 function=sync_supers_timer_fn expires=612604 [timeout=600]
 events/0-27    [000]  6420.045547: timer_start: timer=0xc0000000 function=delayed_work_timer_fn expires=612104 [timeout=100]
  swapper-0     [000]  6420.135502: timer_start: timer=0xc0000000 function=neigh_timer_handler expires=613547 [timeout=1534]

With the patch, the timer value is no longer truncated:
  swapper-0     [000]  6420.045520: timer_start: timer=0xc000000000caffe8 function=sync_supers_timer_fn expires=612604 [timeout=600]
 events/0-27    [000]  6420.045547: timer_start: timer=0xc000000000e052f0 function=delayed_work_timer_fn expires=612104 [timeout=100]
  swapper-0     [000]  6420.135502: timer_start: timer=0xc0000000bce1e698 function=neigh_timer_handler expires=613547 [timeout=1534]

Similarly, running perf trace without the patch on a x86_64 kernel and
32bit perf recording a simple probe placed on schedule:
        events/0-7     [000] 24070.926153: schedule: (8159886b)

With the patch, the location of the probe is no longer truncated and
matches the location of schedule from kallsyms:
        events/0-7     [000] 24070.926153: schedule: (ffffffff8159886b)

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/util/trace-event-parse.c |   68 ++++++++++++++++++++++++++++++++--
 1 files changed, 64 insertions(+), 4 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index f9f80be..f74abdb 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2475,6 +2475,67 @@ static char *get_bprint_format(void *data, int size __unused, struct event *even
 	return format;
 }
 
+static void convert_kernel_host_format(char *kernel_format, int *ls)
+{
+	char user_format[32];
+	char *kptr = kernel_format;
+	char *uptr = user_format;
+	const char *newfmt;
+	int len;
+
+	if (sizeof(long) == long_size)
+		return;
+	if (long_size != 4 && long_size != 8) {
+		pr_warning("Invalid kernel long size %d, data may be truncated\n", long_size);
+		return;
+	}
+
+	while (*kptr) {
+		newfmt = NULL;
+		if (!strncmp(kptr, "%p", 2)) {
+			/* printf("%p") will treat pointer as userspace size */
+			if (long_size == 8) {
+				/* 64bit kernel => 32bit userspace, convert pointer => long long */
+				newfmt = "0x%llx";
+				*ls += 1;
+			} else {
+				/* 32bit kernel => 64bit userspace, convert pointer => int */
+				newfmt = "0x%x";
+			}
+			kptr += 2;
+		} else if (!strncmp(kptr, "%l", 2) && strncmp(kptr, "%ll", 3)) {
+			assert(*ls >= 1);
+			if (long_size == 8) {
+				/* 64bit kernel => 32bit userspace, convert long => long long */
+				newfmt = "%ll";
+				*ls += 1;
+			} else {
+				/* 32bit kernel => 64bit userspace, convert long => int */
+				newfmt = "%";
+				*ls -= 1;
+			}
+			kptr += 2;
+		}
+
+		if (newfmt) {
+			len = strlen(newfmt);
+			if (uptr - user_format + len + 1 >= 32)
+				/* should never happen */
+				die("overflow while converting long");
+			memcpy(uptr, newfmt, len);
+			uptr += len;
+		} else {
+			if (uptr - user_format + 1 >= 32)
+				/* should never happen */
+				die("overflow while converting long");
+			*uptr++ = *kptr++;
+		}
+	}
+	assert(uptr - user_format < 32);
+	*uptr++ = 0;
+	memcpy(kernel_format, user_format, uptr - user_format);
+}
+
 static void pretty_print(void *data, int size, struct event *event)
 {
 	struct print_fmt *print_fmt = &event->print_fmt;
@@ -2542,10 +2603,7 @@ static void pretty_print(void *data, int size, struct event *event)
 			case '0' ... '9':
 				goto cont_process;
 			case 'p':
-				if (long_size == 4)
-					ls = 1;
-				else
-					ls = 2;
+				ls = 1;
 
 				if (*(ptr+1) == 'F' ||
 				    *(ptr+1) == 'f') {
@@ -2572,6 +2630,8 @@ static void pretty_print(void *data, int size, struct event *event)
 				memcpy(format, saveptr, len);
 				format[len] = 0;
 
+				convert_kernel_host_format(format, &ls);
+
 				val = eval_num_arg(data, size, event, arg);
 				arg = arg->next;
 
-- 
1.7.1

[PATCH 7/7] perf trace test: Test cases for kernel->host format string conversion

[Ian Munsie]

From: Ian Munsie <imunsie@au1.ibm.com>

This patch adds some test cases to be run with perf test to verify the
correct operation of the convert_kernel_host_format function.

Signed-off-by: Ian Munsie <imunsie@au1.ibm.com>
---
 tools/perf/builtin-test.c           |   36 ++++++++++++++++++++++++++++++
 tools/perf/util/test-cases.h        |    8 ++++++
 tools/perf/util/trace-event-parse.c |   41 +++++++++++++++++++++++++++++++++++
 3 files changed, 85 insertions(+), 0 deletions(-)
 create mode 100644 tools/perf/util/test-cases.h

diff --git a/tools/perf/builtin-test.c b/tools/perf/builtin-test.c
index 0339612..d1c6179 100644
--- a/tools/perf/builtin-test.c
+++ b/tools/perf/builtin-test.c
@@ -11,6 +11,19 @@
 #include "util/session.h"
 #include "util/symbol.h"
 #include "util/thread.h"
+#include "util/test-cases.h"
+
+#define INIT_TEST_CASES \
+	int test_case_err = 0; \
+	int test_case_num = 0;
+
+#define TEST_CASE(fn) \
+	pr_debug("--- test case #%d start ---\n", ++test_case_num); \
+	test_case_err += fn; \
+	pr_debug("--- test case #%d end ---\n", test_case_num); \
+
+#define TEST_CASES_ERR test_case_err
+
 
 static long page_size;
 
@@ -219,6 +232,25 @@ out:
 	return err;
 }
 
+static int test__convert_kernel_host_format(void)
+{
+	INIT_TEST_CASES
+
+	TEST_CASE(test_case__convert_kernel_host_format(4, "0x44444444", 1, "%p", 0x44444444UL))
+	TEST_CASE(test_case__convert_kernel_host_format(8, "0x88888888", 1, "%p", 0x88888888UL))
+	TEST_CASE(test_case__convert_kernel_host_format(8, "0x12345678abcdef00", 1, "%p", 0x12345678abcdef00ULL))
+
+	TEST_CASE(test_case__convert_kernel_host_format(4, "9223372036854775807", 2, "%lld", 9223372036854775807LL))
+	TEST_CASE(test_case__convert_kernel_host_format(8, "9223372036854775807", 2, "%lld", 9223372036854775807LL))
+
+	TEST_CASE(test_case__convert_kernel_host_format(4, "2147483647", 1, "%ld", 2147483647))
+	TEST_CASE(test_case__convert_kernel_host_format(8, "2147483647", 1, "%ld", 2147483647))
+	TEST_CASE(test_case__convert_kernel_host_format(8, "9223372036854775807", 1, "%ld", 9223372036854775807LL))
+
+	return TEST_CASES_ERR;
+}
+
+
 static struct test {
 	const char *desc;
 	int (*func)(void);
@@ -228,6 +260,10 @@ static struct test {
 		.func = test__vmlinux_matches_kallsyms,
 	},
 	{
+		.desc = "trace handles printing values from kernels with differing long size",
+		.func = test__convert_kernel_host_format,
+	},
+	{
 		.func = NULL,
 	},
 };
diff --git a/tools/perf/util/test-cases.h b/tools/perf/util/test-cases.h
new file mode 100644
index 0000000..be1da92
--- /dev/null
+++ b/tools/perf/util/test-cases.h
@@ -0,0 +1,8 @@
+#ifndef PERF_TEST_CASES_H_
+#define PERF_TEST_CASES_H_
+
+int test_case__convert_kernel_host_format(const int kern_long_size,
+		const char *expected_out, const int ls,
+		const char *kern_format, const unsigned long long val);
+
+#endif
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index f74abdb..ac3d0b7 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -33,6 +33,7 @@
 #include "../perf.h"
 #include "util.h"
 #include "trace-event.h"
+#include "test-cases.h"
 
 int header_page_ts_offset;
 int header_page_ts_size;
@@ -2536,6 +2537,46 @@ static void convert_kernel_host_format(char *kernel_format, int *ls)
 	memcpy(kernel_format, user_format, uptr - user_format);
 }
 
+int test_case__convert_kernel_host_format(const int kern_long_size,
+		const char *expected_out, const int ls,
+		const char *kern_format, const unsigned long long val)
+{
+	char test_fmt[32];
+	char test_out[32];
+	int test_ls = ls;
+	int err = 0;
+
+	assert(strlen(expected_out) < 32);
+	assert(strlen(kern_format) < 32);
+
+	long_size = kern_long_size;
+	memcpy(test_fmt, kern_format, 32);
+
+	convert_kernel_host_format(test_fmt, &test_ls);
+	switch (test_ls) {
+	case 0:
+		snprintf(test_out, 32, test_fmt, (int)val);
+		break;
+	case 1:
+		snprintf(test_out, 32, test_fmt, (long)val);
+		break;
+	case 2:
+		snprintf(test_out, 32, test_fmt, (long long)val);
+		break;
+	default:
+		err = -1;
+		pr_info("Invalid ls (%d)\n", test_ls);
+	}
+
+	if (strncmp(test_out, expected_out, 32)) {
+		err = -1;
+		pr_info("FAIL: Expected string: %s\n"
+			"      Returned string: %s\n",
+			expected_out, test_out);
+	}
+	return err;
+}
+
 static void pretty_print(void *data, int size, struct event *event)
 {
 	struct print_fmt *print_fmt = &event->print_fmt;
-- 
1.7.1