Date: Fri, 17 Jul 2015 10:32:15 -0400
From: Steven Rostedt <rostedt@goodmis.org>
To: He Kuang <hekuang@huawei.com>
Cc: <ast@plumgrid.com>, <masami.hiramatsu.pt@hitachi.com>, <acme@kernel.org>,
        <a.p.zijlstra@chello.nl>, <mingo@redhat.com>, <namhyung@kernel.org>,
        <jolsa@kernel.org>, <wangnan0@huawei.com>, <pi3orama@163.com>,
        <linux-kernel@vger.kernel.org>,
        Alex =?UTF-8?B?QmVu?= =?UTF-8?B?bsOpZQ==?= 
	<alex.bennee@linaro.org>
Subject: Re: [RFC PATCH v4 1/3] tracing/events: Fix wrong sample output by
 storing array length instead of size
Message-ID: <20150717103215.7d285953@gandalf.local.home>
In-Reply-To: <1436522587-136825-2-git-send-email-hekuang@huawei.com>
References: <1436522587-136825-1-git-send-email-hekuang@huawei.com>
	<1436522587-136825-2-git-send-email-hekuang@huawei.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Content-Length: 4083
Lines: 103

On Fri, 10 Jul 2015 10:03:05 +0000
He Kuang <hekuang@huawei.com> wrote:

> The output result of trace_foo_bar event in traceevent samples is
> wrong. This problem can be reproduced as following:
> 
>   (Build kernel with SAMPLE_TRACE_EVENTS=m)
> 
>   $ insmod trace-events-sample.ko
> 
>   $ echo 1 > /sys/kernel/debug/tracing/events/sample-trace/foo_bar/enable
> 
>   $ cat /sys/kernel/debug/tracing/trace
> 
>   event-sample-980 [000] ....  43.649559: foo_bar: foo hello 21 0x15
>   BIT1|BIT3|0x10 {0x1,0x6f6f6e53,0xff007970,0xffffffff} Snoopy
>                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>                  The array length is not right, should be {0x1}.
>   (ffffffff,ffffffff)
> 
>   event-sample-980 [000] ....  44.653827: foo_bar: foo hello 22 0x16
>   BIT2|BIT3|0x10
>   {0x1,0x2,0x646e6147,0x666c61,0xffffffff,0xffffffff,0x750aeffe,0x7}
>   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>                  The array length is not right, should be {0x1,0x2}.
>   Gandalf (ffffffff,ffffffff)
> 
> The event defined in samples/trace_events/trace-events-sample.h uses
> this helper function to output dynamic list:
> 
>    __print_array(__get_dynamic_array(list),
>                  __get_dynamic_array_len(list),
>                  sizeof(int))
> 
> Currently, __get_dynamic_array_len() returns the total size of the
> array instead of the number of items by referencing the high 16 bits
> of entry->data_loc_##item. The element size for calculating the number
> of items can not be fetched by referencing fields from __entry, so
> macro __get_dynamic_array_len can not return the expected value.
> 
> This patch stores array item number instead of the total size in
> entry->__data_loc_##item, and makes __get_dynamic_array_len get the
> right value directly. Because the function __get_bitmask() is affected
> by this change, __bitmask_size is assigned to the array len by
> multiplied bitmask type size.
> 
> After this patch:
> 
>   event-sample-993 [000] ....  692.348562: foo_bar: foo hello 201
>   0xc9 BIT1|BIT4|0xc0 {0x1} Snoopy (ffffffff,ffffffff)
>                       ^^^^^
>                       Array length fixed.
> 
>   event-sample-993 [000] ....  693.349276: foo_bar: foo hello 202
>   0xca BIT2|BIT4|0xc0 {0x1,0x2} Gandalf (ffffffff,ffffffff)
>                       ^^^^^^^^^
>                       Array length fixed.
> 
> Signed-off-by: He Kuang <hekuang@huawei.com>
> ---
>  include/trace/trace_events.h | 5 +++--
>  1 file changed, 3 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
> index 43be3b0..5abe027 100644
> --- a/include/trace/trace_events.h
> +++ b/include/trace/trace_events.h
> @@ -257,7 +257,8 @@ TRACE_MAKE_SYSTEM_STR();
>  	({								\
>  		void *__bitmask = __get_dynamic_array(field);		\
>  		unsigned int __bitmask_size;				\
> -		__bitmask_size = __get_dynamic_array_len(field);	\
> +		__bitmask_size = (__get_dynamic_array_len(field) *	\
> +				  sizeof(unsigned long));		\
>  		trace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
>  	})
>  
> @@ -453,7 +454,7 @@ trace_event_define_fields_##call(struct trace_event_call *event_call)	\
>  	__item_length = (len) * sizeof(type);				\
>  	__data_offsets->item = __data_size +				\
>  			       offsetof(typeof(*entry), __data);	\
> -	__data_offsets->item |= __item_length << 16;			\
> +	__data_offsets->item |= (len) << 16;				\

This change affects all callers of dymanic_array, not just bitmasks.

>  	__data_size += __item_length;
>  
>  #undef __string

BTW, if I revert commit ac01ce1410fc2 "tracing: Make
ftrace_print_array_seq compute buf_len" it works again.

I'm going to look into this some more, and maybe the answer is to go
back and just pass in buffer length here. I can't see what was broken
before that change.

-- Steve
--
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/