high host load from vmx_set_supported_cpuid call?

Hi,

while trying to find source of KVM guest slowness, I noticed following in perf top:

              326.00 19.6% vmx_set_supported_cpuid                        /lib/modules/3.0.53lb6.02/kernel/arch/x86/kvm/kvm-intel.ko    

              108.00  6.5% kvm_arch_dev_ioctl                             /lib/modules/3.0.53lb6.02/kernel/arch/x86/kvm/kvm.ko          
              100.00  6.0% tick_dev_program_event                         [kernel.kallsyms]                                             
               78.00  4.7% __remove_hrtimer                               [kernel.kallsyms]                                             
               52.00  3.1% acpi_processor_reevaluate_tstate               /lib/modules/3.0.53lb6.02/kernel/drivers/acpi/processor.ko    
               45.00  2.7% find_busiest_group                             [kernel.kallsyms]                                             
               43.00  2.6% do_raw_spin_lock                               [kernel.kallsyms]                                             

my question is, is this normal? I tried googling for vmx_set_supported_cpuid but am not really clever about it...

here's snippet from trace-cmd:

version = 6
CPU 11 is empty
cpus=12

        qemu-kvm-7766  [000] 235066.551604: kvm_msi_set_irq:      dst 1 vec 51 (LowPrio|logical|edge|rh)
        qemu-kvm-7766  [000] 235066.551606: kvm_apic_accept_irq:  apicid 0 vec 81 (LowPrio|edge)
        qemu-kvm-7767  [001] 235066.551618: kvm_inj_virq:         irq 81
        qemu-kvm-7767  [001] 235066.551620: kvm_entry:            vcpu 0
        qemu-kvm-7767  [001] 235066.551625: kvm_exit:             reason EPT_MISCONFIG rip 0xffffffff81023d96 info 0 0
        qemu-kvm-7767  [001] 235066.551630: kvm_emulate_insn:     [FAILED TO PARSE] rip=18446744071578992022 csbase=0 len=2 insn=ARRAY[8b, 00, c9, 89, c0, c3,
 0f, 1f, 40, 00, 55, 48, 89, e5, 0f] flags=9 failed=0
        qemu-kvm-7767  [001] 235066.551631: vcpu_match_mmio:      gva 0xffffc900000040f0 gpa 0xfed000f0 Read GPA
        qemu-kvm-7767  [001] 235066.551632: kvm_mmio:             mmio unsatisfied-read len 4 gpa 0xfed000f0 val 0x0
        qemu-kvm-7767  [001] 235066.551634: kvm_userspace_exit:   reason KVM_EXIT_MMIO (6)
        qemu-kvm-7767  [001] 235066.551648: kvm_mmio:             mmio read len 4 gpa 0xfed000f0 val 0xfed25f11
        qemu-kvm-7767  [001] 235066.551649: kvm_entry:            vcpu 0
        qemu-kvm-7767  [001] 235066.551650: kvm_exit:             reason EPT_MISCONFIG rip 0xffffffff81023d96 info 0 0
        qemu-kvm-7767  [001] 235066.551652: kvm_emulate_insn:     [FAILED TO PARSE] rip=18446744071578992022 csbase=0 len=2 insn=ARRAY[8b, 00, c9, 89, c0, c3,
 0f, 1f, 40, 00, 55, 48, 89, e5, 0f] flags=9 failed=0
        qemu-kvm-7767  [001] 235066.551652: vcpu_match_mmio:      gva 0xffffc900000040f0 gpa 0xfed000f0 Read GPA
        qemu-kvm-7767  [001] 235066.551653: kvm_mmio:             mmio unsatisfied-read len 4 gpa 0xfed000f0 val 0x0
        qemu-kvm-7767  [001] 235066.551653: kvm_userspace_exit:   reason KVM_EXIT_MMIO (6)
        qemu-kvm-7767  [001] 235066.551656: kvm_mmio:             mmio read len 4 gpa 0xfed000f0 val 0xfed26450
        qemu-kvm-7767  [001] 235066.551657: kvm_entry:            vcpu 0
        qemu-kvm-7767  [001] 235066.551659: kvm_exit:             reason EPT_MISCONFIG rip 0xffffffff81023d96 info 0 0
        qemu-kvm-7767  [001] 235066.551660: kvm_emulate_insn:     [FAILED TO PARSE] rip=18446744071578992022 csbase=0 len=2 insn=ARRAY[8b, 00, c9, 89, c0, c3,
 0f, 1f, 40, 00, 55, 48, 89, e5, 0f] flags=9 failed=0
        qemu-kvm-7767  [001] 235066.551660: vcpu_match_mmio:      gva 0xffffc900000040f0 gpa 0xfed000f0 Read GPA
        qemu-kvm-7767  [001] 235066.551660: kvm_mmio:             mmio unsatisfied-read len 4 gpa 0xfed000f0 val 0x0
        qemu-kvm-7767  [001] 235066.551661: kvm_userspace_exit:   reason KVM_EXIT_MMIO (6)
        qemu-kvm-7767  [001] 235066.551663: kvm_mmio:             mmio read len 4 gpa 0xfed000f0 val 0xfed2672b
        qemu-kvm-7767  [001] 235066.551664: kvm_entry:            vcpu 0
        qemu-kvm-7767  [001] 235066.551667: kvm_exit:             reason APIC_ACCESS rip 0xffffffff810219eb info 10b0 0
        qemu-kvm-7767  [001] 235066.551667: kvm_apic:             apic_write APIC_EOI = 0x0
        qemu-kvm-7767  [001] 235066.551668: kvm_eoi:              apicid 0 vector 81
        qemu-kvm-7767  [001] 235066.551668: kvm_entry:            vcpu 0
        qemu-kvm-7767  [001] 235066.551681: kvm_exit:             reason EPT_MISCONFIG rip 0xffffffff81023d96 info 0 0
        qemu-kvm-7767  [001] 235066.551682: kvm_emulate_insn:     [FAILED TO PARSE] rip=18446744071578992022 csbase=0 len=2 insn=ARRAY[8b, 00, c9, 89, c0, c3,
 0f, 1f, 40, 00, 55, 48, 89, e5, 0f] flags=9 failed=0
        qemu-kvm-7767  [001] 235066.551683: vcpu_match_mmio:      gva 0xffffc900000040f0 gpa 0xfed000f0 Read GPA
        qemu-kvm-7767  [001] 235066.551683: kvm_mmio:             mmio unsatisfied-read len 4 gpa 0xfed000f0 val 0x0
        qemu-kvm-7767  [001] 235066.551684: kvm_userspace_exit:   reason KVM_EXIT_MMIO (6)

(I can store trace-cmd file somewhere if it can help).

This host is x86_64 centos6, running kernel 3.0.53 with kvm-kmod-3.6 and qemu-kvm-1.2.0

If I could provide more information, I'll be happy to do so..

BR

nik

Signature · 14 lines

-------------------------------------
Ing. Nikola CIPRICH
LinuxBox.cz, s.r.o.
28. rijna 168, 709 00 Ostrava

tel.:   +420 591 166 214
fax:    +420 596 621 273
mobil:  +420 777 093 799

www.linuxbox.cz

mobil servis: +420 737 238 656
email servis: [email protected]
-------------------------------------

Something wrong with your symbols. This function cannot take that much. It is three and a half instruction long and should be called only once during vm startup.

Hi Gleb,

Quoted 3 lines

Something wrong with your symbols. This function cannot take that much. It is three and a half instruction long and should be called only once during vm startup.

well, it didn't make any sense to me, glad I wasn't that wrong :) how could that be? I guess it could be perf/kernel mismatch right? I'll try to fix that and see if it helps..

More like loaded modules/installed modules mismatch.

Quoted 1 line

More like loaded modules/installed modules mismatch.

I see, the problem is, that I've got kvm-kmod compiled separately! thus kvm*.ko symboles don't match!
I see that kvm-kmod build produces System.map file, I guess I need to merge it with kernel's System.map?

I think you need to copy them over old modules in /lib/modules.

--
Gleb.

hmm, that should be OK, new kvm*.ko modules are part of kernel rpm package, there's no old module there. (I checked by both inspecting kernel pkg and using modinfo)... Could it be something else?

Quoted 6 lines

--
Gleb.

Signature · 14 lines

-------------------------------------
Ing. Nikola CIPRICH
LinuxBox.cz, s.r.o.
28. rijna 168, 709 00 Ostrava

tel.:   +420 591 166 214
fax:    +420 596 621 273
mobil:  +420 777 093 799

www.linuxbox.cz

mobil servis: +420 737 238 656
email servis: [email protected]
-------------------------------------

Quoted 3 lines

hmm, that should be OK, new kvm*.ko modules are part of kernel rpm package, there's no old module there. (I checked by both inspecting kernel pkg and using modinfo)... Could it be something else?

hmm, I can reply to myself this time - perf seems to get the symbols using /proc/kallsyms and there apparently are symbols from inkernel KVM modules, not the externally built. I guess the problem with my kernel package is I build both kernel and external KVM modules and then replace kernel ones causing kallsyms mismatch..
I'll have to fix this first, reboot host and then see...

Quoted 1 line

I think you need to copy them over old modules in /lib/modules.

hmm, that should be OK, new kvm*.ko modules are part of kernel rpm package, there's no old module there. (I checked by both inspecting kernel pkg and using modinfo)... Could it be something else?