From: Samuel Thibault <samuel.thibault@ens-lyon.org>
To: Jan Kiszka <jan.kiszka@web.de>
Cc: kvm@vger.kernel.org, gleb@kernel.org, pbonzini@redhat.com
Subject: Re: nested KVM slower than QEMU with gnumach guest kernel
Date: Mon, 24 Nov 2014 01:42:51 +0100 [thread overview]
Message-ID: <20141124004251.GA2589@type> (raw)
In-Reply-To: <54699587.9040109@web.de>
Jan Kiszka, le Mon 17 Nov 2014 07:28:23 +0100, a écrit :
> I suppose this is a SMP host and guest? Does reducing CPUs to 1 change
> to picture?
Oddly enough, putting my host into UniProcessor mode is making L1
realmode simulation awfully slow. That also happens when binding kvm on
a single hardware thread like this:
hwloc-bind pu:0 kvm ...
but not when binding kvm on the two threads of the same core like this:
hwloc-bind core:0 kvm ...
...
> > Here is a sample of trace-cmd output dump: the same kind of pattern
> > repeats over and over, with EXTERNAL_INTERRUPT happening mostly
> > every other microsecond:
> >
> > qemu-system-x86-9752 [003] 4106.187755: kvm_exit: reason EXTERNAL_INTERRUPT rip 0xffffffffa02848b1 info 0 800000f6
> > qemu-system-x86-9752 [003] 4106.187756: kvm_entry: vcpu 0
> > qemu-system-x86-9752 [003] 4106.187757: kvm_exit: reason EXTERNAL_INTERRUPT rip 0xffffffffa02848b1 info 0 800000f6
> > qemu-system-x86-9752 [003] 4106.187758: kvm_entry: vcpu 0
> > qemu-system-x86-9752 [003] 4106.187759: kvm_exit: reason EXTERNAL_INTERRUPT rip 0xffffffffa02848b1 info 0 800000f6
> > qemu-system-x86-9752 [003] 4106.187760: kvm_entry: vcpu 0
Turning into UniProcessor mode however dropped them, but the slowness
is still there. So they are probably actually not the source of the
issue. I'm actually wondering whether they weren't simply coming
from the tracing engine itself: I see some irq_work_queue calls from
kernel/trace/ring_buffer.c and kernel/events/core.c.
> You may want to turn on more trace events, if not all, to possibly see
> what Linux does then.
With the EXTERNAL_INTERRUPT mostly away, I mostly get this over and over:
qemu-system-x86-2138 [000] 247.558705: kvm_exit: reason MSR_READ rip 0xffffffff81050a82 info 0 0
native_read_msr_safe
qemu-system-x86-2138 [000] 247.558705: kvm_msr: msr_read 1d9 = 0x0
qemu-system-x86-2138 [000] 247.558705: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558706: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558706: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558706: kvm_exit: reason VMRESUME rip 0xffffffffa03058ae info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558711: kvm_mmu_get_page: [FAILED TO PARSE] mmu_valid_gen=0x26 gfn=248173 role=114692 root_count=0 unsync=0 created=0
qemu-system-x86-2138 [000] 247.558712: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558712: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558712: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558712: kvm_exit: reason IO_INSTRUCTION rip 0xc0109769 info a10040 0
gnumach accesses the PIC
qemu-system-x86-2138 [000] 247.558713: kvm_nested_vmexit: rip: 0x00000000c0109769 reason: IO_INSTRUCTION ext_inf1: 0x0000000000a10040 ext_inf2: 0x0000000000000000 ext_int: 0x00000000 ext_int_err: 0x00000000
qemu-system-x86-2138 [000] 247.558713: kvm_nested_vmexit_inject: reason: IO_INSTRUCTION ext_inf1: 0x0000000000a10040 ext_inf2: 0x0000000000000000 ext_int: 0x00000000 ext_int_err: 0x00000000
qemu-system-x86-2138 [000] 247.558718: kvm_mmu_get_page: [FAILED TO PARSE] mmu_valid_gen=0x26 gfn=0 role=122884 root_count=0 unsync=0 created=0
qemu-system-x86-2138 [000] 247.558718: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558719: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558719: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558719: kvm_exit: reason VMREAD rip 0xffffffffa0305956 info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558720: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558720: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558720: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558721: kvm_exit: reason VMREAD rip 0xffffffffa030596f info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558721: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558721: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558721: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558722: kvm_exit: reason VMREAD rip 0xffffffffa02fb333 info 0 0
vmx_read_l1_tsc
qemu-system-x86-2138 [000] 247.558722: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558722: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558722: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558723: kvm_exit: reason VMREAD rip 0xffffffffa02fb54a info 0 0
vmx_handle_external_intr
qemu-system-x86-2138 [000] 247.558723: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558724: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558724: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558724: kvm_exit: reason VMREAD rip 0xffffffffa02ffe5f info 0 0
handle_io
qemu-system-x86-2138 [000] 247.558725: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558725: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558725: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558726: kvm_exit: reason VMREAD rip 0xffffffffa02fcce5 info 0 0
vmx_cache_reg
qemu-system-x86-2138 [000] 247.558726: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558726: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558726: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558727: kvm_exit: reason VMREAD rip 0xffffffffa02ffa2e info 0 0
skip_emulated_instruction
qemu-system-x86-2138 [000] 247.558727: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558727: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558727: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558728: kvm_exit: reason VMREAD rip 0xffffffffa02fb81a info 0 0
vmx_set_interrupt_shadow
qemu-system-x86-2138 [000] 247.558728: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558728: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558728: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558729: kvm_exit: reason VMREAD rip 0xffffffffa02fb270 info 0 0
vmx_get_rflags
qemu-system-x86-2138 [000] 247.558730: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558730: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558730: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558730: kvm_exit: reason VMREAD rip 0xffffffffa02fcbf5 info 0 0
vmx_interrupt_allowed
qemu-system-x86-2138 [000] 247.558731: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558731: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558731: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558734: kvm_exit: reason VMWRITE rip 0xffffffffa02fb7db info 0 0
vmx_get_cpl
qemu-system-x86-2138 [000] 247.558735: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558735: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558735: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558736: kvm_exit: reason VMWRITE rip 0xffffffffa02fb7db info 0 0
vmx_get_cpl
qemu-system-x86-2138 [000] 247.558736: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558736: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558736: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558737: kvm_exit: reason VMWRITE rip 0xffffffffa02fb7db info 0 0
vmx_get_cpl
qemu-system-x86-2138 [000] 247.558737: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558737: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558737: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558738: kvm_exit: reason VMWRITE rip 0xffffffffa02fb7db info 0 0
vmx_get_cpl
qemu-system-x86-2138 [000] 247.558738: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558738: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558739: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558739: kvm_exit: reason VMWRITE rip 0xffffffffa02fb7db info 0 0
vmx_get_cpl
qemu-system-x86-2138 [000] 247.558740: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558740: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558740: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558740: kvm_exit: reason MSR_READ rip 0xffffffff81050a82 info 0 0
native_read_msr_safe
qemu-system-x86-2138 [000] 247.558741: kvm_msr: msr_read 1d9 = 0x0
qemu-system-x86-2138 [000] 247.558741: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558741: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558741: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558741: kvm_exit: reason VMRESUME rip 0xffffffffa03058ae info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558746: kvm_mmu_get_page: [FAILED TO PARSE] mmu_valid_gen=0x26 gfn=248173 role=114692 root_count=0 unsync=0 created=0
qemu-system-x86-2138 [000] 247.558747: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558747: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558747: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558748: kvm_exit: reason IO_INSTRUCTION rip 0xc01095f5 info 210040 0
qemu-system-x86-2138 [000] 247.558748: kvm_nested_vmexit: rip: 0x00000000c01095f5 reason: IO_INSTRUCTION ext_inf1: 0x0000000000210040 ext_inf2: 0x0000000000000000 ext_int: 0x00000000 ext_int_err: 0x00000000
qemu-system-x86-2138 [000] 247.558749: kvm_nested_vmexit_inject: reason: IO_INSTRUCTION ext_inf1: 0x0000000000210040 ext_inf2: 0x0000000000000000 ext_int: 0x00000000 ext_int_err: 0x00000000
qemu-system-x86-2138 [000] 247.558753: kvm_mmu_get_page: [FAILED TO PARSE] mmu_valid_gen=0x26 gfn=0 role=122884 root_count=0 unsync=0 created=0
qemu-system-x86-2138 [000] 247.558754: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558754: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558754: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558755: kvm_exit: reason VMREAD rip 0xffffffffa0305956 info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558755: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558756: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558756: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558756: kvm_exit: reason VMREAD rip 0xffffffffa030596f info 0 0
vmx_vcpu_run
qemu-system-x86-2138 [000] 247.558757: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558757: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558757: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558757: kvm_exit: reason VMREAD rip 0xffffffffa02fb333 info 0 0
vmx_read_l1_tsc
qemu-system-x86-2138 [000] 247.558758: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558758: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558758: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558759: kvm_exit: reason VMREAD rip 0xffffffffa02fb54a info 0 0
vmx_handle_external_intr
qemu-system-x86-2138 [000] 247.558759: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558759: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558759: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558760: kvm_exit: reason VMREAD rip 0xffffffffa02ffe5f info 0 0
handle_io
qemu-system-x86-2138 [000] 247.558760: rcu_utilization: Start context switch
qemu-system-x86-2138 [000] 247.558760: rcu_utilization: End context switch
qemu-system-x86-2138 [000] 247.558760: kvm_entry: vcpu 0
qemu-system-x86-2138 [000] 247.558761: kvm_exit: reason VMREAD rip 0xffffffffa02fcce5 info 0 0
vmx_cache_reg
When running the same kind of operation with non-nested KVM, I get this
kind of trace:
qemu-system-x86-3667 [000] 1399.213498: kvm_exit: reason IO_INSTRUCTION rip 0x801090c8 info 210040 0
qemu-system-x86-3667 [000] 1399.213498: kvm_pio: pio_write at 0x21 size 1 count 1 val 0xff
qemu-system-x86-3667 [000] 1399.213499: rcu_utilization: Start context switch
qemu-system-x86-3667 [000] 1399.213499: rcu_utilization: End context switch
qemu-system-x86-3667 [000] 1399.213499: kvm_entry: vcpu 0
qemu-system-x86-3667 [000] 1399.213500: kvm_exit: reason IO_INSTRUCTION rip 0x801090d1 info a10040 0
qemu-system-x86-3667 [000] 1399.213500: kvm_pio: pio_write at 0xa1 size 1 count 1 val 0xff
qemu-system-x86-3667 [000] 1399.213500: rcu_utilization: Start context switch
qemu-system-x86-3667 [000] 1399.213501: rcu_utilization: End context switch
qemu-system-x86-3667 [000] 1399.213501: kvm_entry: vcpu 0
qemu-system-x86-3667 [000] 1399.213501: kvm_exit: reason IO_INSTRUCTION rip 0x80108f5d info 210040 0
qemu-system-x86-3667 [000] 1399.213501: kvm_pio: pio_write at 0x21 size 1 count 1 val 0x68
qemu-system-x86-3667 [000] 1399.213502: rcu_utilization: Start context switch
qemu-system-x86-3667 [000] 1399.213502: rcu_utilization: End context switch
qemu-system-x86-3667 [000] 1399.213502: kvm_entry: vcpu 0
i.e. just one kvm_exit per guest IO instruction, not 18 like above, are
those really expected?
Samuel
next prev parent reply other threads:[~2014-11-24 0:45 UTC|newest]
Thread overview: 16+ messages / expand[flat|nested] mbox.gz Atom feed top
2014-11-11 18:55 nested KVM slower than QEMU with gnumach guest kernel Samuel Thibault
2014-11-11 23:42 ` Jan Kiszka
2014-11-16 22:18 ` Samuel Thibault
2014-11-17 6:28 ` Jan Kiszka
2014-11-17 8:50 ` Samuel Thibault
2014-11-24 0:42 ` Samuel Thibault [this message]
2014-12-15 0:09 ` Samuel Thibault
2014-12-15 9:41 ` Paolo Bonzini
2014-11-17 8:58 ` Gleb Natapov
2014-11-17 9:03 ` Samuel Thibault
2014-11-17 9:04 ` Jan Kiszka
2014-11-17 9:10 ` Samuel Thibault
2014-11-17 9:21 ` Gleb Natapov
2014-11-17 9:37 ` Samuel Thibault
2014-11-17 9:38 ` Samuel Thibault
2014-11-23 21:50 ` Samuel Thibault
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20141124004251.GA2589@type \
--to=samuel.thibault@ens-lyon.org \
--cc=gleb@kernel.org \
--cc=jan.kiszka@web.de \
--cc=kvm@vger.kernel.org \
--cc=pbonzini@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox