I am new to kvm and trying to understand a profile collected with operf on a -smp 4 kvm machine. 1. on first look, why are there so many TIDs in Profile Dissect #1? I only have 2 vcpu emulated, should not i only see 4 threads. 2. opening qemu-system-x86_64 TID 7672 [TID 7672] (3838 ticks/37.74%) shows that this kvm cpu spent 54.48% of time in vmlinux (Profile Dissect #2). This is running the 429.mcf benchmark in spec2k6 which does not have a lot of IO. why is so much time spent in the vmlinux module. the profile of the vmlinux module is shown in Profile Dissect #3. 3. kvm.so is the module that emulates a small fraction of the X86 instructions as well as doing page walks, handling apic. kvm_arch_vcpu_ioctl_run takes the top spot, what does kvm_arch_vcpu_ioctl_run do ? 4. finally down to the kvm_intel.so module. vmx_vcpu_run takes the top spot accounting for just over one half of the total time in this module. The time spent in vmx_vcpu_run is the actual time spent in executing the spec2k6 mcf in the guest ? so does that mean execuing spec2k6 on mcf is only going to be a fraction of the speed of executing on bare metal because a significant percentage of the time is spent in the virtualization layer, e.g. vmlinux, kvm.so, etc Thank you, Gary Profile Dissect #1 Process > Thread > Module /ksmd [PID 44] (14970 ticks/27.13%) /.../operf [PID 8336] (13193 ticks/23.91%) /.../qemu-system-x86_64 [PID 7668] (10170 ticks/18.43%) /.../qemu-system-x86_64 TID 7672 [TID 7672] (3838 ticks/37.74%) /.../qemu-system-x86_64 TID 7673 [TID 7673] (3580 ticks/35.20%) /.../qemu-system-x86_64 TID 7670 [TID 7670] (1339 ticks/13.17%) /.../qemu-system-x86_64 TID 7671 [TID 7671] (858 ticks/8.44%) /.../qemu-system-x86_64 TID 7668 [TID 7668] (359 ticks/3.53%) /.../qemu-system-x86_64 TID 8338 [TID 8338] (138 ticks/1.36%) /.../qemu-system-x86_64 TID 8352 [TID 8352] (7 ticks/0.07%) /.../qemu-system-x86_64 TID 8354 [TID 8354] (7 ticks/0.07%) /.../qemu-system-x86_64 TID 8340 [TID 8340] (6 ticks/0.06%) /.../qemu-system-x86_64 TID 8357 [TID 8357] (5 ticks/0.05%) /.../qemu-system-x86_64 TID 8345 [TID 8345] (4 ticks/0.04%) /.../qemu-system-x86_64 TID 8346 [TID 8346] (4 ticks/0.04%) /.../qemu-system-x86_64 TID 8366 [TID 8366] (3 ticks/0.03%) /.../qemu-system-x86_64 TID 8368 [TID 8368] (3 ticks/0.03%) /.../qemu-system-x86_64 TID 0 [TID 0] (2 ticks/0.02%) /.../qemu-system-x86_64 TID 8337 [TID 8337] (2 ticks/0.02%) /.../qemu-system-x86_64 TID 8350 [TID 8350] (2 ticks/0.02%) /.../qemu-system-x86_64 TID 8355 [TID 8355] (2 ticks/0.02%) /.../qemu-system-x86_64 TID 8369 [TID 8369] (2 ticks/0.02%) Profile Dissect #2. /.../qemu-system-x86_64 TID 7672 [TID 7672] (3838 ticks/37.74%) /.../vmlinux (2091 ticks/54.48%) /kvm (921 ticks/24.00%) /kvm_intel (801 ticks/20.87%) /r8169 (12 ticks/0.31%) /.../qemu-system-x86_64 (7 ticks/0.18%) /e1000e (3 ticks/0.08%) /.../libglib-2.0.so.0.3200.4 (2 ticks/0.05%) /.../libc-2.15.so (1 ticks/0.03%) Profile Dissect #3 CPU_CLK_UNHALTED % Symbol/Functions 78 3.73 rcu_check_callbacks 74 3.54 timerqueue_add 71 3.40 update_cfs_rq_blocked_load 70 3.35 _raw_spin_lock 69 3.30 __srcu_read_lock 65 3.11 update_curr 57 2.73 lapic_next_deadline 54 2.58 task_tick_fair 54 2.58 do_timer 53 2.53 read_tsc 51 2.44 run_timer_softirq 42 2.01 hrtimer_interrupt 38 1.82 cpuacct_charge 36 1.72 __do_softirq 35 1.67 account_system_time 34 1.63 update_cfs_shares 30 1.43 __srcu_read_unlock 26 1.24 put_prev_task_fair 26 1.24 perf_event_task_tick 26 1.24 __schedule 25 1.20 irq_enter 23 1.10 _raw_spin_unlock_irqrestore 22 1.05 rb_insert_color 22 1.05 idle_cpu 22 1.05 enqueue_entity 21 1.00 math_state_restore Profile Dissect #4. CPU_CLK_UNHALTED % Symbol/Functions 193 20.96 kvm_arch_vcpu_ioctl_run 64 6.95 paging64_walk_addr_generic 55 5.97 x86_decode_insn 27 2.93 apic_update_ppr 24 2.61 x86_emulate_instruction 23 2.50 __apic_accept_irq 22 2.39 do_insn_fetch 21 2.28 kvm_load_guest_fpu 20 2.17 pvclock_gtod_notify 19 2.06 gfn_to_memslot 17 1.85 x86_emulate_insn 16 1.74 kvm_put_guest_fpu 15 1.63 kvm_set_shared_msr 15 1.63 apic_timer_fn 14 1.52 paging64_gva_to_gpa 14 1.52 kvm_ioapic_handles_vector 13 1.41 writeback 13 1.41 kvm_read_guest 13 1.41 init_emulate_ctxt 13 1.41 apic_has_pending_timer 12 1.30 kvm_get_apic_interrupt 12 1.30 kvm_apic_accept_pic_intr 12 1.30 decode_operand 11 1.19 emulator_read_write_onepage 11 1.19 em_mov 11 1.19 apic_set_eoi 10 1.09 kvm_lapic_get_cr8 10 1.09 kvm_fetch_guest_virt 9 0.98 kvm_arch_vcpu_load 9 0.98 kvm_apic_has_interrupt 9 0.98 gfn_to_hva_prot 8 0.87 writeback_registers 8 0.87 write_mmio 8 0.87 kvm_ioapic_send_eoi 8 0.87 kvm_apic_accept_events Profile Dissect #5. CPU_CLK_UNHALTED % Symbol/Functions 439 54.81 vmx_vcpu_run 80 9.99 vmx_handle_external_intr 47 5.87 __vmx_load_host_state.part.70 37 4.62 vmx_save_host_state 31 3.87 vmcs_writel 27 3.37 vmx_flush_tlb 15 1.87 vmx_handle_exit 10 1.25 clear_atomic_switch_msr 9 1.12 vmx_vcpu_load 9 1.12 handle_apic_access 8 1.00 vmx_decache_cr3 7 0.87 vmx_read_guest_seg_ar 7 0.87 vmx_get_cpl 6 0.75 vmx_vm_has_apicv 6 0.75 vmx_set_interrupt_shadow 6 0.75 vmx_get_interrupt_shadow 6 0.75 vmx_get_cs_db_l_bits 6 0.75 vmcs_clear_bits 5 0.62 vmx_inject_irq 5 0.62 vmx_get_rflags 4 0.50 vmx_vcpu_put 4 0.50 vmx_read_guest_seg_selector 4 0.50 vmx_interrupt_allowed 4 0.50 handle_exception 3 0.37 vmx_read_l1_tsc 3 0.37 update_cr8_intercept 3 0.37 handle_external_interrupt 2 0.25 vmx_sync_pir_to_irr_dummy 2 0.25 vmx_fpu_deactivate 2 0.25 vmx_fpu_activate 2 0.25 update_exception_bitmap 1 0.12 vmx_decache_cr0_guest_bits 1 0.12 skip_emulated_instruction -- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
