[PATCH 0/1] KVM: x86: improve the usability of the 'kvm

public inbox for kvm@vger.kernel.org
 help / color / mirror / Atom feed

* [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
@ 2014-05-02 15:57 Ulrich Obergfell
  2014-05-02 15:57 ` [PATCH 1/1] " Ulrich Obergfell
  2014-05-05  7:10 ` [PATCH 0/1] " Xiao Guangrong
  0 siblings, 2 replies; 5+ messages in thread
From: Ulrich Obergfell @ 2014-05-02 15:57 UTC (permalink / raw)
  To: kvm; +Cc: uobergfe, pbonzini

The current implementation of the 'kvm_pio' tracepoint in emulator_pio_in_out()
only tells us that 'something' has been read from or written to an I/O port. To
improve the usability of the tracepoint, I propose to include the value/content
that has been read or written in the trace output. The proposed patch aims at
the more common case where a single 8-bit or 16-bit or 32-bit value has been
read or written -- it does not fully cover the case where 'count' is greater
than one.

This is an example of what the patch can do (trace of PCI config space access).

 - on the host

   # trace-cmd record -e kvm:kvm_pio -f "(port >= 0xcf8) && (port <= 0xcff)"
   /sys/kernel/debug/tracing/events/kvm/kvm_pio/filter
   Hit Ctrl^C to stop recording

 - in a Linux guest

   # dd if=/sys/bus/pci/devices/0000:00:06.0/config bs=2 count=4 | hexdump
   4+0 records in
   4+0 records out
   8 bytes (8 B) copied, 0.000114056 s, 70.1 kB/s
   0000000 1af4 1001 0507 0010                    
   0000008

 - on the host

   # trace-cmd report
   ...
           qemu-kvm-23216 [001] 15211.994089: kvm_pio:              pio_write
   at 0xcf8 size 4 count 1 val 0x80003000 
           qemu-kvm-23216 [001] 15211.994108: kvm_pio:              pio_read
   at 0xcfc size 2 count 1 val 0x1af4 
           qemu-kvm-23216 [001] 15211.994129: kvm_pio:              pio_write
   at 0xcf8 size 4 count 1 val 0x80003000 
           qemu-kvm-23216 [001] 15211.994136: kvm_pio:              pio_read
   at 0xcfe size 2 count 1 val 0x1001 
           qemu-kvm-23216 [001] 15211.994143: kvm_pio:              pio_write
   at 0xcf8 size 4 count 1 val 0x80003004 
           qemu-kvm-23216 [001] 15211.994150: kvm_pio:              pio_read
   at 0xcfc size 2 count 1 val 0x507 
           qemu-kvm-23216 [001] 15211.994155: kvm_pio:              pio_write
   at 0xcf8 size 4 count 1 val 0x80003004 
           qemu-kvm-23216 [001] 15211.994161: kvm_pio:              pio_read
   at 0xcfe size 2 count 1 val 0x10 


Ulrich Obergfell (1):
  improve the usability of the 'kvm_pio' tracepoint

 arch/x86/kvm/trace.h | 20 ++++++++++++++++----
 arch/x86/kvm/x86.c   |  4 ++--
 2 files changed, 18 insertions(+), 6 deletions(-)

-- 
1.7.11.7


^ permalink raw reply	[flat|nested] 5+ messages in thread

* [PATCH 1/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
  2014-05-02 15:57 [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint Ulrich Obergfell
@ 2014-05-02 15:57 ` Ulrich Obergfell
  2014-05-05 20:41   ` Paolo Bonzini
  2014-05-05  7:10 ` [PATCH 0/1] " Xiao Guangrong
  1 sibling, 1 reply; 5+ messages in thread
From: Ulrich Obergfell @ 2014-05-02 15:57 UTC (permalink / raw)
  To: kvm; +Cc: uobergfe, pbonzini

This patch moves the 'kvm_pio' tracepoint to emulator_pio_in_emulated()
and emulator_pio_out_emulated(), and it adds an argument (a pointer to
the 'pio_data'). A single 8-bit or 16-bit or 32-bit data item is fetched
from 'pio_data' (depending on 'size'), and the value is included in the
trace record ('val'). If 'count' is greater than one, this is indicated
by the string "(...)" in the trace output.

Signed-off-by: Ulrich Obergfell <uobergfe@redhat.com>
---
 arch/x86/kvm/trace.h | 20 ++++++++++++++++----
 arch/x86/kvm/x86.c   |  4 ++--
 2 files changed, 18 insertions(+), 6 deletions(-)

diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 545245d..33574c9 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -91,16 +91,21 @@ TRACE_EVENT(kvm_hv_hypercall,
 /*
  * Tracepoint for PIO.
  */
+
+#define KVM_PIO_IN   0
+#define KVM_PIO_OUT  1
+
 TRACE_EVENT(kvm_pio,
 	TP_PROTO(unsigned int rw, unsigned int port, unsigned int size,
-		 unsigned int count),
-	TP_ARGS(rw, port, size, count),
+		 unsigned int count, void *data),
+	TP_ARGS(rw, port, size, count, data),
 
 	TP_STRUCT__entry(
 		__field(	unsigned int, 	rw		)
 		__field(	unsigned int, 	port		)
 		__field(	unsigned int, 	size		)
 		__field(	unsigned int,	count		)
+		__field(	unsigned int,	val		)
 	),
 
 	TP_fast_assign(
@@ -108,11 +113,18 @@ TRACE_EVENT(kvm_pio,
 		__entry->port		= port;
 		__entry->size		= size;
 		__entry->count		= count;
+		if (size == 1)
+			__entry->val	= *(unsigned char *)data;
+		else if (size == 2)
+			__entry->val	= *(unsigned short *)data;
+		else
+			__entry->val	= *(unsigned int *)data;
 	),
 
-	TP_printk("pio_%s at 0x%x size %d count %d",
+	TP_printk("pio_%s at 0x%x size %d count %d val 0x%x %s",
 		  __entry->rw ? "write" : "read",
-		  __entry->port, __entry->size, __entry->count)
+		  __entry->port, __entry->size, __entry->count, __entry->val,
+		  __entry->count > 1 ? "(...)" : "")
 );
 
 /*
diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index 8b8fc0b..cd79707 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -4486,8 +4486,6 @@ static int emulator_pio_in_out(struct kvm_vcpu *vcpu, int size,
 			       unsigned short port, void *val,
 			       unsigned int count, bool in)
 {
-	trace_kvm_pio(!in, port, size, count);
-
 	vcpu->arch.pio.port = port;
 	vcpu->arch.pio.in = in;
 	vcpu->arch.pio.count  = count;
@@ -4522,6 +4520,7 @@ static int emulator_pio_in_emulated(struct x86_emulate_ctxt *ctxt,
 	if (ret) {
 data_avail:
 		memcpy(val, vcpu->arch.pio_data, size * count);
+		trace_kvm_pio(KVM_PIO_IN, port, size, count, vcpu->arch.pio_data);
 		vcpu->arch.pio.count = 0;
 		return 1;
 	}
@@ -4536,6 +4535,7 @@ static int emulator_pio_out_emulated(struct x86_emulate_ctxt *ctxt,
 	struct kvm_vcpu *vcpu = emul_to_vcpu(ctxt);
 
 	memcpy(vcpu->arch.pio_data, val, size * count);
+	trace_kvm_pio(KVM_PIO_OUT, port, size, count, vcpu->arch.pio_data);
 	return emulator_pio_in_out(vcpu, size, port, (void *)val, count, false);
 }
 
-- 
1.7.11.7


^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: [PATCH 1/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
  2014-05-02 15:57 ` [PATCH 1/1] " Ulrich Obergfell
@ 2014-05-05 20:41   ` Paolo Bonzini
  0 siblings, 0 replies; 5+ messages in thread
From: Paolo Bonzini @ 2014-05-05 20:41 UTC (permalink / raw)
  To: Ulrich Obergfell, kvm

Il 02/05/2014 17:57, Ulrich Obergfell ha scritto:
> This patch moves the 'kvm_pio' tracepoint to emulator_pio_in_emulated()
> and emulator_pio_out_emulated(), and it adds an argument (a pointer to
> the 'pio_data'). A single 8-bit or 16-bit or 32-bit data item is fetched
> from 'pio_data' (depending on 'size'), and the value is included in the
> trace record ('val'). If 'count' is greater than one, this is indicated
> by the string "(...)" in the trace output.

A difference is that the tracepoint will be reported after an exit to 
userspace in the case of "in", rather than before.

The improvement however is noticeable; especially for "out" it allows to 
obtain much more information about the state of a device from a long 
trace.  Applying to kvm/queue, thanks.

Paolo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
  2014-05-02 15:57 [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint Ulrich Obergfell
  2014-05-02 15:57 ` [PATCH 1/1] " Ulrich Obergfell
@ 2014-05-05  7:10 ` Xiao Guangrong
  2014-05-05 17:11   ` Ulrich Obergfell
  1 sibling, 1 reply; 5+ messages in thread
From: Xiao Guangrong @ 2014-05-05  7:10 UTC (permalink / raw)
  To: Ulrich Obergfell, kvm; +Cc: pbonzini

On 05/02/2014 11:57 PM, Ulrich Obergfell wrote:
> The current implementation of the 'kvm_pio' tracepoint in emulator_pio_in_out()
> only tells us that 'something' has been read from or written to an I/O port. To
> improve the usability of the tracepoint, I propose to include the value/content
> that has been read or written in the trace output. The proposed patch aims at
> the more common case where a single 8-bit or 16-bit or 32-bit value has been
> read or written -- it does not fully cover the case where 'count' is greater
> than one.
> 
> This is an example of what the patch can do (trace of PCI config space access).
> 
>  - on the host
> 
>    # trace-cmd record -e kvm:kvm_pio -f "(port >= 0xcf8) && (port <= 0xcff)"
>    /sys/kernel/debug/tracing/events/kvm/kvm_pio/filter
>    Hit Ctrl^C to stop recording
> 
>  - in a Linux guest
> 
>    # dd if=/sys/bus/pci/devices/0000:00:06.0/config bs=2 count=4 | hexdump
>    4+0 records in
>    4+0 records out
>    8 bytes (8 B) copied, 0.000114056 s, 70.1 kB/s
>    0000000 1af4 1001 0507 0010                    
>    0000008
> 
>  - on the host
> 
>    # trace-cmd report
>    ...
>            qemu-kvm-23216 [001] 15211.994089: kvm_pio:              pio_write
>    at 0xcf8 size 4 count 1 val 0x80003000 
>            qemu-kvm-23216 [001] 15211.994108: kvm_pio:              pio_read
>    at 0xcfc size 2 count 1 val 0x1af4 
>            qemu-kvm-23216 [001] 15211.994129: kvm_pio:              pio_write
>    at 0xcf8 size 4 count 1 val 0x80003000 
>            qemu-kvm-23216 [001] 15211.994136: kvm_pio:              pio_read
>    at 0xcfe size 2 count 1 val 0x1001 
>            qemu-kvm-23216 [001] 15211.994143: kvm_pio:              pio_write
>    at 0xcf8 size 4 count 1 val 0x80003004 
>            qemu-kvm-23216 [001] 15211.994150: kvm_pio:              pio_read
>    at 0xcfc size 2 count 1 val 0x507 
>            qemu-kvm-23216 [001] 15211.994155: kvm_pio:              pio_write
>    at 0xcf8 size 4 count 1 val 0x80003004 
>            qemu-kvm-23216 [001] 15211.994161: kvm_pio:              pio_read
>    at 0xcfe size 2 count 1 val 0x10 
> 

Nice.

Could please check "perf kvm stat" to see if "--event=ioport"
can work after your patch?

Reviewed-by: Xiao Guangrong <xiaoguangrong@linux.vnet.ibm.com>


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
  2014-05-05  7:10 ` [PATCH 0/1] " Xiao Guangrong
@ 2014-05-05 17:11   ` Ulrich Obergfell
  0 siblings, 0 replies; 5+ messages in thread
From: Ulrich Obergfell @ 2014-05-05 17:11 UTC (permalink / raw)
  To: Xiao Guangrong; +Cc: kvm, pbonzini

> From: "Xiao Guangrong" <xiaoguangrong@linux.vnet.ibm.com>
> To: "Ulrich Obergfell" <uobergfe@redhat.com>, kvm@vger.kernel.org
> Cc: pbonzini@redhat.com
> Sent: Monday, May 5, 2014 9:10:19 AM
> Subject: Re: [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint
>
> On 05/02/2014 11:57 PM, Ulrich Obergfell wrote:
>> The current implementation of the 'kvm_pio' tracepoint in emulator_pio_in_out()
>> only tells us that 'something' has been read from or written to an I/O port. To
>> improve the usability of the tracepoint, I propose to include the value/content
>> that has been read or written in the trace output. The proposed patch aims at
>> the more common case where a single 8-bit or 16-bit or 32-bit value has been
>> read or written -- it does not fully cover the case where 'count' is greater
>> than one.
>> 
>> This is an example of what the patch can do (trace of PCI config space access).
>> 
>>  - on the host
>> 
>>    # trace-cmd record -e kvm:kvm_pio -f "(port >= 0xcf8) && (port <= 0xcff)"
>>    /sys/kernel/debug/tracing/events/kvm/kvm_pio/filter
>>    Hit Ctrl^C to stop recording
>> 
>>  - in a Linux guest
>> 
>>    # dd if=/sys/bus/pci/devices/0000:00:06.0/config bs=2 count=4 | hexdump
>>    4+0 records in
>>    4+0 records out
>>    8 bytes (8 B) copied, 0.000114056 s, 70.1 kB/s
>>    0000000 1af4 1001 0507 0010                    
>>    0000008
>> 
>>  - on the host
>> 
>>    # trace-cmd report
>>    ...
>>            qemu-kvm-23216 [001] 15211.994089: kvm_pio:              pio_write
>>    at 0xcf8 size 4 count 1 val 0x80003000 
>>            qemu-kvm-23216 [001] 15211.994108: kvm_pio:              pio_read
>>    at 0xcfc size 2 count 1 val 0x1af4 
>>            qemu-kvm-23216 [001] 15211.994129: kvm_pio:              pio_write
>>    at 0xcf8 size 4 count 1 val 0x80003000 
>>            qemu-kvm-23216 [001] 15211.994136: kvm_pio:              pio_read
>>    at 0xcfe size 2 count 1 val 0x1001 
>>            qemu-kvm-23216 [001] 15211.994143: kvm_pio:              pio_write
>>    at 0xcf8 size 4 count 1 val 0x80003004 
>>            qemu-kvm-23216 [001] 15211.994150: kvm_pio:              pio_read
>>    at 0xcfc size 2 count 1 val 0x507 
>>            qemu-kvm-23216 [001] 15211.994155: kvm_pio:              pio_write
>>    at 0xcf8 size 4 count 1 val 0x80003004 
>>            qemu-kvm-23216 [001] 15211.994161: kvm_pio:              pio_read
>>    at 0xcfe size 2 count 1 val 0x10 
>> 
>
> Nice.
>
> Could please check "perf kvm stat" to see if "--event=ioport"
> can work after your patch?
>
> Reviewed-by: Xiao Guangrong <xiaoguangrong@linux.vnet.ibm.com>

I've run a quick test with a local kernel - built from 3.15.0-rc1 source,
including the proposed patch - in combination with the 'perf' package that
is installed on my test machine. I didn't build a new 'perf' binary from
3.15.0-rc1 source.

The following output of the 'perf kvm stat live --event=ioport -d 10' command
looks reasonable.


17:10:29.036811

Analyze events for all VMs, all VCPUs:

      IO Port Access    Samples  Samples%     Time%   Min Time   Max Time         Avg time 

           0x177:PIN         35    20.00%    15.40%        1us        3us      1.68us ( +-   8.63% )
           0x376:PIN         30    17.14%    16.37%        1us        6us      2.08us ( +-  17.15% )
          0x170:POUT         15     8.57%    18.99%        2us        9us      4.83us ( +-  14.34% )
         0xc0ea:POUT         10     5.71%     6.57%        2us        2us      2.51us ( +-   5.06% )
          0xc0ea:PIN         10     5.71%     6.21%        1us        6us      2.37us ( +-  23.18% )
          0x176:POUT         10     5.71%     6.69%        1us        3us      2.55us ( +-   7.59% )
           0x170:PIN          5     2.86%     3.36%        2us        2us      2.56us ( +-   1.17% )
           0x171:PIN          5     2.86%     1.47%        1us        1us      1.12us ( +-   0.37% )
          0x171:POUT          5     2.86%     3.26%        2us        2us      2.49us ( +-   2.25% )
           0x172:PIN          5     2.86%     1.45%        1us        1us      1.11us ( +-   0.24% )
          0x172:POUT          5     2.86%     2.67%        1us        2us      2.04us ( +-   3.00% )
           0x173:PIN          5     2.86%     1.46%        1us        1us      1.11us ( +-   0.29% )
          0x173:POUT          5     2.86%     2.60%        1us        2us      1.99us ( +-   2.96% )
           0x174:PIN          5     2.86%     1.45%        1us        1us      1.11us ( +-   0.16% )
          0x174:POUT          5     2.86%     2.60%        1us        2us      1.99us ( +-   3.13% )
           0x175:PIN          5     2.86%     1.46%        1us        1us      1.12us ( +-   0.15% )
          0x175:POUT          5     2.86%     2.60%        1us        2us      1.98us ( +-   3.04% )
           0x176:PIN          5     2.86%     1.45%        1us        1us      1.11us ( +-   0.23% )
          0x177:POUT          5     2.86%     3.94%        2us        3us      3.01us ( +-   2.06% )

Total Samples:175, Total events handled time:381.58us.

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2014-05-05 20:41 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-05-02 15:57 [PATCH 0/1] KVM: x86: improve the usability of the 'kvm_pio' tracepoint Ulrich Obergfell
2014-05-02 15:57 ` [PATCH 1/1] " Ulrich Obergfell
2014-05-05 20:41   ` Paolo Bonzini
2014-05-05  7:10 ` [PATCH 0/1] " Xiao Guangrong
2014-05-05 17:11   ` Ulrich Obergfell

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox