[PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Namhyung Kim]

From: Namhyung Kim <namhyung.kim@lge.com>

The kvm_emulate_insn tracepoint used __print_insn()
for printing its instructions. However it makes the
format of the event hard to parse as it reveals TP
internals.

Fortunately, kernel provides __print_hex for almost
same purpose, we can use it instead of open coding
it. The user-space can be changed to parse it later.

That means raw kernel tracing will not be affected
by this change:

 # cd /sys/kernel/debug/tracing/
 # cat events/kvm/kvm_emulate_insn/format
 name: kvm_emulate_insn
 ID: 29
 format:
	...
 print fmt: "%x:%llx:%s (%s)%s", REC->csbase, REC->rip, __print_hex(REC->insn, REC->len), \
 __print_symbolic(REC->flags, { 0, "real" }, { (1 << 0) | (1 << 1), "vm16" }, \
 { (1 << 0), "prot16" }, { (1 << 0) | (1 << 2), "prot32" }, { (1 << 0) | (1 << 3), "prot64" }), \
 REC->failed ? " failed" : ""

 # echo 1 > events/kvm/kvm_emulate_insn/enable
 # cat trace
 # tracer: nop
 #
 # entries-in-buffer/entries-written: 2183/2183   #P:12
 #
 #                              _-----=> irqs-off
 #                             / _----=> need-resched
 #                            | / _---=> hardirq/softirq
 #                            || / _--=> preempt-depth
 #                            ||| /     delay
 #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
 #              | |       |   ||||       |         |
         qemu-kvm-1782  [002] ...1   140.931636: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)
         qemu-kvm-1781  [004] ...1   140.931637: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)

Cc: kvm@vger.kernel.org
Link: http://lkml.kernel.org/n/tip-wfw6y3b9ugtey8snaow9nmg5@git.kernel.org
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 arch/x86/kvm/trace.h   |   12 +-----------
 include/trace/ftrace.h |    1 +
 2 files changed, 2 insertions(+), 11 deletions(-)

diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 911d2641f14c..62d02e3c3ed6 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -710,16 +710,6 @@ TRACE_EVENT(kvm_skinit,
 		  __entry->rip, __entry->slb)
 );
 
-#define __print_insn(insn, ilen) ({		                 \
-	int i;							 \
-	const char *ret = p->buffer + p->len;			 \
-								 \
-	for (i = 0; i < ilen; ++i)				 \
-		trace_seq_printf(p, " %02x", insn[i]);		 \
-	trace_seq_printf(p, "%c", 0);				 \
-	ret;							 \
-	})
-
 #define KVM_EMUL_INSN_F_CR0_PE (1 << 0)
 #define KVM_EMUL_INSN_F_EFL_VM (1 << 1)
 #define KVM_EMUL_INSN_F_CS_D   (1 << 2)
@@ -786,7 +776,7 @@ TRACE_EVENT(kvm_emulate_insn,
 
 	TP_printk("%x:%llx:%s (%s)%s",
 		  __entry->csbase, __entry->rip,
-		  __print_insn(__entry->insn, __entry->len),
+		  __print_hex(__entry->insn, __entry->len),
 		  __print_symbolic(__entry->flags,
 				   kvm_trace_symbol_emul_flags),
 		  __entry->failed ? " failed" : ""
diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index 769724944fc6..c6bc2faaf261 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -571,6 +571,7 @@ static inline void ftrace_test_probe_##call(void)			\
 
 #undef __print_flags
 #undef __print_symbolic
+#undef __print_hex
 #undef __get_dynamic_array
 #undef __get_str
 
-- 
1.7.10.2

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Steven Rostedt]

[ Added Avi]

On Wed, 2012-06-27 at 09:41 +0900, Namhyung Kim wrote:
> From: Namhyung Kim <namhyung.kim@lge.com>
> 
> The kvm_emulate_insn tracepoint used __print_insn()
> for printing its instructions. However it makes the
> format of the event hard to parse as it reveals TP
> internals.
> 
> Fortunately, kernel provides __print_hex for almost
> same purpose, we can use it instead of open coding
> it. The user-space can be changed to parse it later.
> 
> That means raw kernel tracing will not be affected
> by this change:
> 
>  # cd /sys/kernel/debug/tracing/
>  # cat events/kvm/kvm_emulate_insn/format
>  name: kvm_emulate_insn
>  ID: 29
>  format:
> 	...
>  print fmt: "%x:%llx:%s (%s)%s", REC->csbase, REC->rip, __print_hex(REC->insn, REC->len), \
>  __print_symbolic(REC->flags, { 0, "real" }, { (1 << 0) | (1 << 1), "vm16" }, \
>  { (1 << 0), "prot16" }, { (1 << 0) | (1 << 2), "prot32" }, { (1 << 0) | (1 << 3), "prot64" }), \
>  REC->failed ? " failed" : ""
> 
>  # echo 1 > events/kvm/kvm_emulate_insn/enable
>  # cat trace
>  # tracer: nop
>  #
>  # entries-in-buffer/entries-written: 2183/2183   #P:12
>  #
>  #                              _-----=> irqs-off
>  #                             / _----=> need-resched
>  #                            | / _---=> hardirq/softirq
>  #                            || / _--=> preempt-depth
>  #                            ||| /     delay
>  #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
>  #              | |       |   ||||       |         |
>          qemu-kvm-1782  [002] ...1   140.931636: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)
>          qemu-kvm-1781  [004] ...1   140.931637: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)

Avi, can you give your Acked-by for this change?

-- Steve

> 
> Cc: kvm@vger.kernel.org
> Link: http://lkml.kernel.org/n/tip-wfw6y3b9ugtey8snaow9nmg5@git.kernel.org
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>  arch/x86/kvm/trace.h   |   12 +-----------
>  include/trace/ftrace.h |    1 +
>  2 files changed, 2 insertions(+), 11 deletions(-)
> 
> diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
> index 911d2641f14c..62d02e3c3ed6 100644
> --- a/arch/x86/kvm/trace.h
> +++ b/arch/x86/kvm/trace.h
> @@ -710,16 +710,6 @@ TRACE_EVENT(kvm_skinit,
>  		  __entry->rip, __entry->slb)
>  );
>  
> -#define __print_insn(insn, ilen) ({		                 \
> -	int i;							 \
> -	const char *ret = p->buffer + p->len;			 \
> -								 \
> -	for (i = 0; i < ilen; ++i)				 \
> -		trace_seq_printf(p, " %02x", insn[i]);		 \
> -	trace_seq_printf(p, "%c", 0);				 \
> -	ret;							 \
> -	})
> -
>  #define KVM_EMUL_INSN_F_CR0_PE (1 << 0)
>  #define KVM_EMUL_INSN_F_EFL_VM (1 << 1)
>  #define KVM_EMUL_INSN_F_CS_D   (1 << 2)
> @@ -786,7 +776,7 @@ TRACE_EVENT(kvm_emulate_insn,
>  
>  	TP_printk("%x:%llx:%s (%s)%s",
>  		  __entry->csbase, __entry->rip,
> -		  __print_insn(__entry->insn, __entry->len),
> +		  __print_hex(__entry->insn, __entry->len),
>  		  __print_symbolic(__entry->flags,
>  				   kvm_trace_symbol_emul_flags),
>  		  __entry->failed ? " failed" : ""
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 769724944fc6..c6bc2faaf261 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -571,6 +571,7 @@ static inline void ftrace_test_probe_##call(void)			\
>  
>  #undef __print_flags
>  #undef __print_symbolic
> +#undef __print_hex
>  #undef __get_dynamic_array
>  #undef __get_str
>  

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Avi Kivity]

On 06/27/2012 03:49 PM, Steven Rostedt wrote:
> [ Added Avi]
> 
> On Wed, 2012-06-27 at 09:41 +0900, Namhyung Kim wrote:
>> From: Namhyung Kim <namhyung.kim@lge.com>
>> 
>> The kvm_emulate_insn tracepoint used __print_insn()
>> for printing its instructions. However it makes the
>> format of the event hard to parse as it reveals TP
>> internals.
>> 
>> Fortunately, kernel provides __print_hex for almost
>> same purpose, we can use it instead of open coding
>> it. The user-space can be changed to parse it later.
>> 
>> That means raw kernel tracing will not be affected
>> by this change:
>> 
>>  # cd /sys/kernel/debug/tracing/
>>  # cat events/kvm/kvm_emulate_insn/format
>>  name: kvm_emulate_insn
>>  ID: 29
>>  format:
>> 	...
>>  print fmt: "%x:%llx:%s (%s)%s", REC->csbase, REC->rip, __print_hex(REC->insn, REC->len), \
>>  __print_symbolic(REC->flags, { 0, "real" }, { (1 << 0) | (1 << 1), "vm16" }, \
>>  { (1 << 0), "prot16" }, { (1 << 0) | (1 << 2), "prot32" }, { (1 << 0) | (1 << 3), "prot64" }), \
>>  REC->failed ? " failed" : ""
>> 
>>  # echo 1 > events/kvm/kvm_emulate_insn/enable
>>  # cat trace
>>  # tracer: nop
>>  #
>>  # entries-in-buffer/entries-written: 2183/2183   #P:12
>>  #
>>  #                              _-----=> irqs-off
>>  #                             / _----=> need-resched
>>  #                            | / _---=> hardirq/softirq
>>  #                            || / _--=> preempt-depth
>>  #                            ||| /     delay
>>  #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
>>  #              | |       |   ||||       |         |
>>          qemu-kvm-1782  [002] ...1   140.931636: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)
>>          qemu-kvm-1781  [004] ...1   140.931637: kvm_emulate_insn: 0:c102fa25:89 10 (prot32)
> 
> Avi, can you give your Acked-by for this change?

Acked-by: Avi Kivity <avi@redhat.com>

Some time ago we discussed moving the trace-cmd plugins to /lib/modules,
which would make this trace display as "mov %edx,(%eax)" instead of "89
10", even for non-trace-cmd users.  Was there any movement on this?

-- 
error compiling committee.c: too many arguments to function

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Steven Rostedt]

On Wed, 2012-06-27 at 15:54 +0300, Avi Kivity wrote:

> Acked-by: Avi Kivity <avi@redhat.com>

Thanks Avi!

> 
> Some time ago we discussed moving the trace-cmd plugins to /lib/modules,
> which would make this trace display as "mov %edx,(%eax)" instead of "89
> 10", even for non-trace-cmd users.  Was there any movement on this?
> 

As a matter of fact ;-)  The trace-cmd libparsevent library has now been
moved to tools/lib/libtraceevent, in which perf now uses. It is just a
matter of time till perf gets the use of the trace-cmd plugins. We just
need to figure out the logistics.

Maybe make a tools/event_plugins ?

Or something to that affect?

-- Steve

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Namhyung Kim]

[CC'ing David]

Hi, Steve

On Wed, 27 Jun 2012 09:20:24 -0400, Steven Rostedt wrote:
> On Wed, 2012-06-27 at 15:54 +0300, Avi Kivity wrote:
>
>> Acked-by: Avi Kivity <avi@redhat.com>
>
> Thanks Avi!
>

Can you give me your ack's too (for this and other ones in the series)?
And if you ok, I can route this and future changes (from anybody) on
libtraceevent through my tree.


>> 
>> Some time ago we discussed moving the trace-cmd plugins to /lib/modules,
>> which would make this trace display as "mov %edx,(%eax)" instead of "89
>> 10", even for non-trace-cmd users.  Was there any movement on this?
>> 
>
> As a matter of fact ;-)  The trace-cmd libparsevent library has now been
> moved to tools/lib/libtraceevent, in which perf now uses. It is just a
> matter of time till perf gets the use of the trace-cmd plugins. We just
> need to figure out the logistics.
>
> Maybe make a tools/event_plugins ?
>
> Or something to that affect?
>

tools/lib/traceevent/plugins ?

Thanks,
Namhyung

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Steven Rostedt]

On Thu, 2012-06-28 at 10:16 +0900, Namhyung Kim wrote:
> [CC'ing David]
> 
> Hi, Steve
> 
> On Wed, 27 Jun 2012 09:20:24 -0400, Steven Rostedt wrote:
> > On Wed, 2012-06-27 at 15:54 +0300, Avi Kivity wrote:
> >
> >> Acked-by: Avi Kivity <avi@redhat.com>
> >
> > Thanks Avi!
> >
> 
> Can you give me your ack's too (for this and other ones in the series)?
> And if you ok, I can route this and future changes (from anybody) on
> libtraceevent through my tree.
> 

Actually, as this patch touches x86 and ftrace, and does not truly
affect the tools directory, I've already added it into my queue for 3.6.

-- Steve

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Namhyung Kim]

On Wed, 27 Jun 2012 21:52:44 -0400, Steven Rostedt wrote:
> On Thu, 2012-06-28 at 10:16 +0900, Namhyung Kim wrote:
>> [CC'ing David]
>> 
>> Hi, Steve
>> 
>> On Wed, 27 Jun 2012 09:20:24 -0400, Steven Rostedt wrote:
>> > On Wed, 2012-06-27 at 15:54 +0300, Avi Kivity wrote:
>> >
>> >> Acked-by: Avi Kivity <avi@redhat.com>
>> >
>> > Thanks Avi!
>> >
>> 
>> Can you give me your ack's too (for this and other ones in the series)?
>> And if you ok, I can route this and future changes (from anybody) on
>> libtraceevent through my tree.
>> 
>
> Actually, as this patch touches x86 and ftrace, and does not truly
> affect the tools directory, I've already added it into my queue for 3.6.
>

Ok, thanks. But how about other ones? Did you add all of 4 into you
queue?

Thanks,
Namhyung

Re: [PATCH 2/4] KVM: Use __print_hex() for kvm_emulate_insn tracepoint

[Steven Rostedt]

On Thu, 2012-06-28 at 10:59 +0900, Namhyung Kim wrote:

> Ok, thanks. But how about other ones? Did you add all of 4 into you
> queue?

Ah, no I didn't. I actually would like Arnaldo to do that.

Arnaldo,

Can you pull patches 1,3 & 4 into your repo, and add my:

Acked-by: Steven Rostedt <rostedt@goodmis.org>

Thanks!

-- Steve