[PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[Zenghui Yu]

After enabling KVM event tracing, almost all of trace_kvm_exit()'s
printk shows

	"kvm_exit: IRQ: ..."

even if the actual exception_type is NOT IRQ.  More specifically,
trace_kvm_exit() is defined in virt/kvm/arm/trace.h by TRACE_EVENT.

This slight problem may have existed after commit e6753f23d961
("tracepoint: Make rcuidle tracepoint callers use SRCU"). There are
two variables in trace_kvm_exit() and __DO_TRACE() which have the
same name, *idx*. Thus the actual value of *idx* will be overwritten
when tracing. Fix it by adding a simple prefix.

Signed-off-by: Zenghui Yu <yuzenghui@huawei.com>
Cc: Joel Fernandes <joel@joelfernandes.org>
Cc: Wang Haibin <wanghaibin.wang@huawei.com>
Cc: linux-trace-devel@vger.kernel.org
---
 include/linux/tracepoint.h | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index 538ba1a..e9de8ad 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -166,7 +166,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
 		struct tracepoint_func *it_func_ptr;			\
 		void *it_func;						\
 		void *__data;						\
-		int __maybe_unused idx = 0;				\
+		int __maybe_unused __idx = 0;				\
 									\
 		if (!(cond))						\
 			return;						\
@@ -182,7 +182,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
 		 * doesn't work from the idle path.			\
 		 */							\
 		if (rcuidle) {						\
-			idx = srcu_read_lock_notrace(&tracepoint_srcu);	\
+			__idx = srcu_read_lock_notrace(&tracepoint_srcu);\
 			rcu_irq_enter_irqson();				\
 		}							\
 									\
@@ -198,7 +198,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
 									\
 		if (rcuidle) {						\
 			rcu_irq_exit_irqson();				\
-			srcu_read_unlock_notrace(&tracepoint_srcu, idx);\
+			srcu_read_unlock_notrace(&tracepoint_srcu, __idx);\
 		}							\
 									\
 		preempt_enable_notrace();				\
-- 
1.8.3.1

Re: [PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[Steven Rostedt]

On Wed, 28 Nov 2018 03:35:23 +0000
Zenghui Yu <yuzenghui@huawei.com> wrote:

> After enabling KVM event tracing, almost all of trace_kvm_exit()'s
> printk shows
> 
> 	"kvm_exit: IRQ: ..."
> 
> even if the actual exception_type is NOT IRQ.  More specifically,
> trace_kvm_exit() is defined in virt/kvm/arm/trace.h by TRACE_EVENT.
> 
> This slight problem may have existed after commit e6753f23d961
> ("tracepoint: Make rcuidle tracepoint callers use SRCU"). There are
> two variables in trace_kvm_exit() and __DO_TRACE() which have the
> same name, *idx*. Thus the actual value of *idx* will be overwritten
> when tracing. Fix it by adding a simple prefix.

Nice catch! I'll apply it tomorrow and start testing it then.

Thanks!

-- Steve

> 
> Signed-off-by: Zenghui Yu <yuzenghui@huawei.com>
> Cc: Joel Fernandes <joel@joelfernandes.org>
> Cc: Wang Haibin <wanghaibin.wang@huawei.com>
> Cc: linux-trace-devel@vger.kernel.org
> ---
>  include/linux/tracepoint.h | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
> index 538ba1a..e9de8ad 100644
> --- a/include/linux/tracepoint.h
> +++ b/include/linux/tracepoint.h
> @@ -166,7 +166,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>  		struct tracepoint_func *it_func_ptr;			\
>  		void *it_func;						\
>  		void *__data;						\
> -		int __maybe_unused idx = 0;				\
> +		int __maybe_unused __idx = 0;				\
>  									\
>  		if (!(cond))						\
>  			return;						\
> @@ -182,7 +182,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>  		 * doesn't work from the idle path.			\
>  		 */							\
>  		if (rcuidle) {						\
> -			idx = srcu_read_lock_notrace(&tracepoint_srcu);	\
> +			__idx = srcu_read_lock_notrace(&tracepoint_srcu);\
>  			rcu_irq_enter_irqson();				\
>  		}							\
>  									\
> @@ -198,7 +198,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>  									\
>  		if (rcuidle) {						\
>  			rcu_irq_exit_irqson();				\
> -			srcu_read_unlock_notrace(&tracepoint_srcu, idx);\
> +			srcu_read_unlock_notrace(&tracepoint_srcu, __idx);\
>  		}							\
>  									\
>  		preempt_enable_notrace();				\

Re: [PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[Zenghui Yu]

On 2018/11/28 11:54, Steven Rostedt wrote:
> On Wed, 28 Nov 2018 03:35:23 +0000
> Zenghui Yu <yuzenghui@huawei.com> wrote:
> 
>> After enabling KVM event tracing, almost all of trace_kvm_exit()'s
>> printk shows
>>
>> 	"kvm_exit: IRQ: ..."
>>
>> even if the actual exception_type is NOT IRQ.  More specifically,
>> trace_kvm_exit() is defined in virt/kvm/arm/trace.h by TRACE_EVENT.
>>
>> This slight problem may have existed after commit e6753f23d961
>> ("tracepoint: Make rcuidle tracepoint callers use SRCU"). There are
>> two variables in trace_kvm_exit() and __DO_TRACE() which have the
>> same name, *idx*. Thus the actual value of *idx* will be overwritten
>> when tracing. Fix it by adding a simple prefix.
> 
> Nice catch! I'll apply it tomorrow and start testing it then.

Thanks Steven!

Zenghui

> 
> Thanks!
> 
> -- Steve
> 
>>
>> Signed-off-by: Zenghui Yu <yuzenghui@huawei.com>
>> Cc: Joel Fernandes <joel@joelfernandes.org>
>> Cc: Wang Haibin <wanghaibin.wang@huawei.com>
>> Cc: linux-trace-devel@vger.kernel.org
>> ---
>>   include/linux/tracepoint.h | 6 +++---
>>   1 file changed, 3 insertions(+), 3 deletions(-)
>>
>> diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
>> index 538ba1a..e9de8ad 100644
>> --- a/include/linux/tracepoint.h
>> +++ b/include/linux/tracepoint.h
>> @@ -166,7 +166,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>>   		struct tracepoint_func *it_func_ptr;			\
>>   		void *it_func;						\
>>   		void *__data;						\
>> -		int __maybe_unused idx = 0;				\
>> +		int __maybe_unused __idx = 0;				\
>>   									\
>>   		if (!(cond))						\
>>   			return;						\
>> @@ -182,7 +182,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>>   		 * doesn't work from the idle path.			\
>>   		 */							\
>>   		if (rcuidle) {						\
>> -			idx = srcu_read_lock_notrace(&tracepoint_srcu);	\
>> +			__idx = srcu_read_lock_notrace(&tracepoint_srcu);\
>>   			rcu_irq_enter_irqson();				\
>>   		}							\
>>   									\
>> @@ -198,7 +198,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>>   									\
>>   		if (rcuidle) {						\
>>   			rcu_irq_exit_irqson();				\
>> -			srcu_read_unlock_notrace(&tracepoint_srcu, idx);\
>> +			srcu_read_unlock_notrace(&tracepoint_srcu, __idx);\
>>   		}							\
>>   									\
>>   		preempt_enable_notrace();				\
> 
> 
> .
> 

Re: [PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[Steven Rostedt]

On Thu, 29 Nov 2018 10:21:55 +0800
Zenghui Yu <yuzenghui@huawei.com> wrote:

> On 2018/11/28 11:54, Steven Rostedt wrote:
> > On Wed, 28 Nov 2018 03:35:23 +0000
> > Zenghui Yu <yuzenghui@huawei.com> wrote:
> >   
> >> After enabling KVM event tracing, almost all of trace_kvm_exit()'s
> >> printk shows
> >>
> >> 	"kvm_exit: IRQ: ..."
> >>
> >> even if the actual exception_type is NOT IRQ.  More specifically,
> >> trace_kvm_exit() is defined in virt/kvm/arm/trace.h by TRACE_EVENT.
> >>
> >> This slight problem may have existed after commit e6753f23d961
> >> ("tracepoint: Make rcuidle tracepoint callers use SRCU"). There are
> >> two variables in trace_kvm_exit() and __DO_TRACE() which have the
> >> same name, *idx*. Thus the actual value of *idx* will be overwritten
> >> when tracing. Fix it by adding a simple prefix.  
> > 
> > Nice catch! I'll apply it tomorrow and start testing it then.  
> 
> Thanks Steven!
> 

FYI, I renamed your subject to:

 tracepoint: Use __idx instead of idx in DO_TRACE macro to make it unique

to make the name more specific to the fix and not the symptom.

Thanks!

-- Steve

Re: [PATCH] tracepoint: fix bad trace value in trace_kvm_exit()

[Joel Fernandes]

On Wed, Nov 28, 2018 at 09:34:42PM -0500, Steven Rostedt wrote:
> On Thu, 29 Nov 2018 10:21:55 +0800
> Zenghui Yu <yuzenghui@huawei.com> wrote:
> 
> > On 2018/11/28 11:54, Steven Rostedt wrote:
> > > On Wed, 28 Nov 2018 03:35:23 +0000
> > > Zenghui Yu <yuzenghui@huawei.com> wrote:
> > >   
> > >> After enabling KVM event tracing, almost all of trace_kvm_exit()'s
> > >> printk shows
> > >>
> > >> 	"kvm_exit: IRQ: ..."
> > >>
> > >> even if the actual exception_type is NOT IRQ.  More specifically,
> > >> trace_kvm_exit() is defined in virt/kvm/arm/trace.h by TRACE_EVENT.
> > >>
> > >> This slight problem may have existed after commit e6753f23d961
> > >> ("tracepoint: Make rcuidle tracepoint callers use SRCU"). There are
> > >> two variables in trace_kvm_exit() and __DO_TRACE() which have the
> > >> same name, *idx*. Thus the actual value of *idx* will be overwritten
> > >> when tracing. Fix it by adding a simple prefix.  
> > > 
> > > Nice catch! I'll apply it tomorrow and start testing it then.  
> > 
> > Thanks Steven!
> > 
> 
> FYI, I renamed your subject to:
> 
>  tracepoint: Use __idx instead of idx in DO_TRACE macro to make it unique
> 
> to make the name more specific to the fix and not the symptom.
> 
> Thanks!

Thanks!

Reviewed-by: Joel Fernandes (Google) <joel@joelfernandes.org>

 - Joel