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
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
