[question] lots of interrupts injected to vm when pressing some key w/o releasing

[question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

Hi all,

If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
bringing very bad experience. But the other keys are okay.
And, linux guest has no this problem.

If I remove the commit of 0bc830b05c667218d703f2026ec866c49df974fc, then the
problem disappeared, but win7 guest got stuck at booting stage.
And so strange that If the vm has only one vcpu, then the problem also disappeared.

Any ideas?

Thanks,
Zhang Haoyu

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 20/11/2014 03:20, Zhang Haoyu wrote:
> Hi all,
> 
> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
> bringing very bad experience. But the other keys are okay.
> And, linux guest has no this problem.

Do you have a trace for this?  What version of QEMU and what UI backend?

Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Zhang Haoyu]

>On 20/11/2014 03:20, Zhang Haoyu wrote:
>> Hi all,
>> 
>> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
>> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
>> bringing very bad experience. But the other keys are okay.
>> And, linux guest has no this problem.
>
>Do you have a trace for this?  What version of QEMU and what UI backend?
>
Sorry for forgetting to mention test environment from the start.
Host: rhel7 with kernel-3.10.0-121
QEMU: qemu-2.0.2
Guest: win7(bad),win2008(bad),linux-kernel-3.10.0-121(good)

No UI backend, directly start the VM via qemu command.

perf top data when above problem happening: 
   PerfTop:    8710 irqs/sec  kernel:69.5%  exact:  0.0% [4000Hz cycles],  (target_pid: 22382)
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

    15.04%  [kernel]                 [k] read_hpet                                  
    11.69%  [kvm_intel]              [k] vmx_vcpu_run                               
     6.99%  [kvm]                    [k] vcpu_enter_guest                           
     5.22%  [kvm]                    [k] kvm_vcpu_on_spin                           
     4.76%  [kernel]                 [k] __srcu_read_lock                           
     4.31%  libglib-2.0.so.0.3200.4  [.] g_hash_table_lookup                        
     3.21%  [kvm_intel]              [k] __vmx_load_host_state                      
     2.60%  libglib-2.0.so.0.3200.4  [.] g_str_hash                                 
     2.49%  [kvm_intel]              [k] vmx_save_host_state                        
     2.07%  qemu-system-x86_64       [.] e1000_txmmio_poll                          
     1.36%  [kernel]                 [k] __srcu_read_unlock                         
     1.24%  libc-2.13.so             [.] 0x00000000000e7582                         
     1.05%  qemu-system-x86_64       [.] start_xmit                                 
     1.04%  [kvm]                    [k] kvm_fast_pio_in_complete_emulated_pio      
     1.04%  [kvm_intel]              [k] vmcs_writel                                
     1.02%  qemu-system-x86_64       [.] vnc_refresh_server_surface                 
     0.99%  [vdso]                   [.] 0x0000000000000847                         
     0.98%  [kernel]                 [k] native_read_tsc                            
     0.93%  [kernel]                 [k] fget_light                                 
     0.85%  [kvm]                    [k] kvm_arch_vcpu_load                         
     0.83%  [kvm_intel]              [k] vmx_cache_reg                              
     0.79%  [kvm]                    [k] kvm_arch_vcpu_ioctl_run                    
     0.73%  qemu-system-x86_64       [.] object_class_dynamic_cast                  
     0.72%  libpthread-2.13.so       [.] pthread_mutex_lock                         
     0.68%  [kvm_intel]              [k] add_atomic_switch_msr                      
     0.63%  [kvm]                    [k] emulator_pio_in_out.isra.101               
     0.62%  [kernel]                 [k] recalc_sigpending                          
     0.61%  qemu-system-x86_64       [.] kvm_cpu_exec                               
     0.59%  qemu-system-x86_64       [.] kvm_arch_post_run                          
     0.58%  [kernel]                 [k] _raw_spin_lock_irq                         
7716 unprocessable samples recorded.

Thanks,
Zhang Haoyu
>Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Gleb Natapov]

On Thu, Nov 20, 2014 at 02:59:36PM +0800, Zhang Haoyu wrote:
> >On 20/11/2014 03:20, Zhang Haoyu wrote:
> >> Hi all,
> >> 
> >> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
> >> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
> >> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
> >> bringing very bad experience. But the other keys are okay.
> >> And, linux guest has no this problem.
> >
> >Do you have a trace for this?  What version of QEMU and what UI backend?
> >
> Sorry for forgetting to mention test environment from the start.
> Host: rhel7 with kernel-3.10.0-121
> QEMU: qemu-2.0.2
> Guest: win7(bad),win2008(bad),linux-kernel-3.10.0-121(good)
> 
> No UI backend, directly start the VM via qemu command.
> 
> perf top data when above problem happening: 
Trace it like this: http://www.linux-kvm.org/page/Tracing

--
			Gleb.

Re: [question] lots of interrupts injected to vm when pressingsomekey w/o releasing

[Zhang Haoyu]

>On Thu, Nov 20, 2014 at 02:59:36PM +0800, Zhang Haoyu wrote:
>> >On 20/11/2014 03:20, Zhang Haoyu wrote:
>> >> Hi all,
>> >> 
>> >> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>> >> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
>> >> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
>> >> bringing very bad experience. But the other keys are okay.
>> >> And, linux guest has no this problem.
>> >
>> >Do you have a trace for this?  What version of QEMU and what UI backend?
>> >
>> Sorry for forgetting to mention test environment from the start.
>> Host: rhel7 with kernel-3.10.0-121
>> QEMU: qemu-2.0.2
>> Guest: win7(bad),win2008(bad),linux-kernel-3.10.0-121(good)
>> 
>> No UI backend, directly start the VM via qemu command.
>> 
>> perf top data when above problem happening: 
>Trace it like this: http://www.linux-kvm.org/page/Tracing
trace data while pressing "downArrow" key w/o releasing:(the vm has 2 vcpus)
version = 6
CPU 2 is empty
cpus=16
             kvm-16063 [000]  8312.322731: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-16062 [003]  8312.322732: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16062 [003]  8312.322733: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322733: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-16062 [003]  8312.322736: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16062 [003]  8312.322736: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322736: kvm_entry:            vcpu 1
             kvm-16063 [000]  8312.322737: kvm_exit:             reason CPUID rip 0x806e7fbb info 0 0
             kvm-16063 [000]  8312.322738: kvm_cpuid:            func 0 rax a rbx 756e6547 rcx 6c65746e rdx 49656e69
             kvm-16062 [003]  8312.322738: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16063 [000]  8312.322738: kvm_entry:            vcpu 1
             kvm-16062 [003]  8312.322739: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322739: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-16063 [000]  8312.322740: kvm_pio:              pio_read at 0xb008 size 4 count 1
             kvm-16063 [000]  8312.322740: kvm_entry:            vcpu 1
             kvm-16062 [003]  8312.322741: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16063 [000]  8312.322741: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-16062 [003]  8312.322741: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322742: kvm_pio:              pio_read at 0xb008 size 4 count 1
             kvm-16063 [000]  8312.322742: kvm_entry:            vcpu 1
             kvm-16063 [000]  8312.322743: kvm_exit:             reason IO_INSTRUCTION rip 0x806eda5a info 640008 0
             kvm-16063 [000]  8312.322743: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-16062 [003]  8312.322744: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16063 [000]  8312.322744: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-16062 [003]  8312.322744: kvm_entry:            vcpu 0
             kvm-16062 [003]  8312.322746: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16062 [003]  8312.322747: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322747: kvm_entry:            vcpu 1
             kvm-16063 [000]  8312.322748: kvm_exit:             reason CPUID rip 0x806e7fbb info 0 0
             kvm-16063 [000]  8312.322748: kvm_cpuid:            func 0 rax a rbx 756e6547 rcx 6c65746e rdx 49656e69
             kvm-16063 [000]  8312.322749: kvm_entry:            vcpu 1
             kvm-16062 [003]  8312.322749: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16062 [003]  8312.322749: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322749: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-16063 [000]  8312.322750: kvm_pio:              pio_read at 0xb008 size 4 count 1
             kvm-16063 [000]  8312.322751: kvm_entry:            vcpu 1
             kvm-16062 [003]  8312.322751: kvm_exit:             reason PAUSE_INSTRUCTION rip 0x805466c0 info 0 0
             kvm-16063 [000]  8312.322751: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-16062 [003]  8312.322752: kvm_entry:            vcpu 0
             kvm-16063 [000]  8312.322752: kvm_pio:              pio_read at 0xb008 size 4 count 1
...


trace data while pressing "downArrow" key w/o releasing:(the vm has 1 vcpus)
version = 6
CPU 4 is empty
CPU 5 is empty
CPU 6 is empty
CPU 7 is empty
CPU 10 is empty
CPU 11 is empty
CPU 12 is empty
CPU 13 is empty
CPU 14 is empty
CPU 15 is empty
cpus=16
             kvm-27755 [002] 19299.396888: kvm_set_irq:          gsi 8 level 1 source 0
             kvm-27755 [002] 19299.396891: kvm_pic_set_irq:      chip 1 pin 0 (edge|masked)
             kvm-27755 [002] 19299.396895: kvm_apic_accept_irq:  apicid 0 vec 209 (Fixed|edge)
             kvm-27755 [002] 19299.396895: kvm_ioapic_set_irq:   pin 8 dst 1 vec=209 (Fixed|logical|edge)
             kvm-27769 [000] 19299.396901: kvm_inj_virq:         irq 209
             kvm-27769 [000] 19299.396903: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.396906: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f29 info 700040 0
             kvm-27769 [000] 19299.396908: kvm_pio:              pio_write at 0x70 size 1 count 1
             kvm-27769 [000] 19299.397039: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.397045: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397047: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f31 info 710048 0
             kvm-27769 [000] 19299.397047: kvm_pio:              pio_read at 0x71 size 1 count 1
             kvm-27769 [000] 19299.397048: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.397050: kvm_set_irq:          gsi 8 level 0 source 0
             kvm-27769 [000] 19299.397051: kvm_pic_set_irq:      chip 1 pin 0 (edge|masked)
             kvm-27769 [000] 19299.397051: kvm_ioapic_set_irq:   pin 8 dst 1 vec=209 (Fixed|logical|edge)
             kvm-27769 [000] 19299.397053: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397053: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f3b info 700040 0
             kvm-27769 [000] 19299.397054: kvm_pio:              pio_write at 0x70 size 1 count 1
             kvm-27769 [000] 19299.397054: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.397056: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397056: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f43 info 710048 0
             kvm-27769 [000] 19299.397057: kvm_pio:              pio_read at 0x71 size 1 count 1
             kvm-27769 [000] 19299.397057: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.397058: kvm_set_irq:          gsi 8 level 0 source 0
             kvm-27769 [000] 19299.397059: kvm_pic_set_irq:      chip 1 pin 0 (edge|masked)
             kvm-27769 [000] 19299.397059: kvm_ioapic_set_irq:   pin 8 dst 1 vec=209 (Fixed|logical|edge)
             kvm-27769 [000] 19299.397060: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397061: kvm_exit:             reason APIC_ACCESS rip 0x806e7f18 info 10b0 0
             kvm-27769 [000] 19299.397062: kvm_apic:             apic_write APIC_EOI = 0x0
             kvm-27769 [000] 19299.397062: kvm_eoi:              apicid 0 vector 209
             kvm-27769 [000] 19299.397063: kvm_ack_irq:          irqchip IOAPIC pin 8
             kvm-27769 [000] 19299.397064: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397066: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-27769 [000] 19299.397066: kvm_pio:              pio_read at 0xb008 size 4 count 1
             kvm-27769 [000] 19299.397067: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397068: kvm_exit:             reason IO_INSTRUCTION rip 0x806edf72 info b008000b 0
             kvm-27769 [000] 19299.397069: kvm_pio:              pio_read at 0xb008 size 4 count 1
             kvm-27769 [000] 19299.397069: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.397070: kvm_exit:             reason HLT rip 0xf878c161 info 0 0
             kvm-27755 [002] 19299.412667: kvm_set_irq:          gsi 8 level 1 source 0
             kvm-27755 [002] 19299.412668: kvm_pic_set_irq:      chip 1 pin 0 (edge|masked)
             kvm-27755 [002] 19299.412671: kvm_apic_accept_irq:  apicid 0 vec 209 (Fixed|edge)
             kvm-27755 [002] 19299.412672: kvm_ioapic_set_irq:   pin 8 dst 1 vec=209 (Fixed|logical|edge)
             kvm-27769 [000] 19299.412678: kvm_inj_virq:         irq 209
             kvm-27769 [000] 19299.412679: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.412683: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f29 info 700040 0
             kvm-27769 [000] 19299.412684: kvm_pio:              pio_write at 0x70 size 1 count 1
             kvm-27769 [000] 19299.412686: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.412712: kvm_entry:            vcpu 0
             kvm-27769 [000] 19299.412713: kvm_exit:             reason IO_INSTRUCTION rip 0x806e5f31 info 710048 0
             kvm-27769 [000] 19299.412713: kvm_pio:              pio_read at 0x71 size 1 count 1
             kvm-27769 [000] 19299.412714: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-27769 [000] 19299.412716: kvm_set_irq:          gsi 8 level 0 source 0

Thanks,
Zhang Haoyu

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 21/11/2014 15:20, Zhang, Yang Z wrote:
> Zhang Haoyu wrote on 2014-11-20:
>> Hi all,
>>
>> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of
>> interrupts will be injected to vm(win7/win2008), about 8000/s, the
>> system become very slow, bringing very bad experience. But the other keys are okay.
>> And, linux guest has no this problem.
>>
>> If I remove the commit of 0bc830b05c667218d703f2026ec866c49df974fc, then
>> the problem disappeared, but win7 guest got stuck at booting stage. And
>> so strange that If the vm has only one vcpu, then the problem also
>> disappeared.
>>
>> Any ideas?
> 
> It looks commit 0bc830 doesn't do the right thing. The right point
> to clear an edge triggered interrupt in ioapic->irr is after userspace
> changes the irq line status. Otherwise, there may cause interrupt storm
> if a device sets the irq line in a fix edge continuously. 
>
> See below code:
> ioapic_set_irq:
> 	.....
>     old_irr = ioapic->irr;
>     ioapic->irr |= mask;
>     if ((edge && old_irr == ioapic->irr) ||
>         (!edge && entry.fields.remote_irr)) { 
>         ret = 0;						 // normally, we should break from here. But we never go to here due to (edge && old_irr != ioapic->irr) now.
>         goto out;
>     }   

The IRR register means an interrupt was received and not serviced yet,
similar to the LAPIC or PIC register.  It is not the same thing as the
interrupt line level (it happens to be for level-triggered interrupts).

We observed lost interrupts during migration, and fixing the semantics
of IRR was necessary in order to reinject those properly (commit
673f7b4257).  If QEMU sends KVM_IRQ_LINE twice with level=1 it should be
fixed---it is not supposed to do so.  Commit 0bc830b05 makes the kernel
IOAPIC behave the same way as QEMU's.

If you want the old semantics of KVM_IRQ_LINE, that requires a separate
register, different from IRR but it is not easy because they were buggy:
the level of the interrupt is not part of the IOAPIC state structs in
KVM, and it is not migrated in QEMU either.

Paolo

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 25/11/2014 04:15, Zhang, Yang Z wrote:
> > The IRR register means an interrupt was received and not serviced yet,
> > similar to the LAPIC or PIC register.  It is not the same thing as the
> > interrupt line level (it happens to be for level-triggered interrupts).
>
> Yes, but commit(0bc830b05) changes the behavior: before it ,
> ioapic->irr is cleared only when userspace lower the irq level. With it,
> it is cleared after the edge interrupt is serviced by ioapic. As you
> mentioned below, if QEMU tried to set a line twice, than there will be
> two interrupts for guest which only one interrupt before commit(0bc830b05).

Indeed, but that shouldn't happen.  It would be a QEMU bug, since the
all-QEMU implementation of the ioapic is doing the same as commit 0bc830b05.

Paolo

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 28/11/2014 12:59, Zhang, Yang Z wrote:
> 
> According the feedback from Haoyu on my test patch which skipping the
> interrupt injection if irq line is active (See another thread), it seems
> QEMU does not follow the rule. But my patch is just a workaround. I
> guess we should have more though on this issue to find a better solution.

Yes, I agree.

Paolo

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

Hi Paolo, Yang
What's the status of this problem?

Thanks,
Zhang Haoyu

On 2014-12-04 00:13:49, Paolo Bonzini wrote:
>
>
>On 28/11/2014 12:59, Zhang, Yang Z wrote:
>> 
>> According the feedback from Haoyu on my test patch which skipping the
>> interrupt injection if irq line is active (See another thread), it seems
>> QEMU does not follow the rule. But my patch is just a workaround. I
>> guess we should have more though on this issue to find a better solution.
>
>Yes, I agree.
>
>Paolo

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 15/12/2014 10:39, Zhang Haoyu wrote:
> Hi Paolo, Yang
> What's the status of this problem?

I will look at Yang's patch after the end of the merge window.

Paolo

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

>Hi all,
>
>If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
>will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
>bringing very bad experience. But the other keys are okay.

Sorry for wrong description, the interrupt rate is normal, 
but huge numbers of vmexit induced by PIO were produced.

Thanks,
Zhang Haoyu
>And, linux guest has no this problem.
>
>If I remove the commit of 0bc830b05c667218d703f2026ec866c49df974fc, then the
>problem disappeared, but win7 guest got stuck at booting stage.
>And so strange that If the vm has only one vcpu, then the problem also disappeared.
>
>Any ideas?
>
>Thanks,
>Zhang Haoyu

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Paolo Bonzini]

On 24/11/2014 13:17, Zhang Haoyu wrote:
>> Hi all,
>>
>> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
>> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
>> bringing very bad experience. But the other keys are okay.
> 
> Sorry for wrong description, the interrupt rate is normal, 
> but huge numbers of vmexit induced by PIO were produced.

This is expected when running Windows without paravirtualized time
counter (-cpu ...,hv_time).

Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Zhang Haoyu]

>>> Hi all,
>>>
>>> If I press the one of "Insert/Delete/Home/End/PageUp/PageDown/UpArrow/
>>> DownArrow/LeftArrow/RightArrow" key w/o releasing, then lots of interrupts
>>> will be injected to vm(win7/win2008), about 8000/s, the system become very slow,
>>> bringing very bad experience. But the other keys are okay.
>> 
>> Sorry for wrong description, the interrupt rate is normal, 
>> but huge numbers of vmexit induced by PIO were produced.
>
>This is expected when running Windows without paravirtualized time
>counter (-cpu ...,hv_time).
>
I tested win-server-2008 with "-cpu core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
this problem still happened, about 200,000 vmexits per-second, 
bringing very bad experience, just like being stuck.

Thanks,
Zhang Haoyu

>Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Paolo Bonzini]

On 25/11/2014 02:54, Zhang Haoyu wrote:
> I tested win-server-2008 with "-cpu core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
> this problem still happened, about 200,000 vmexits per-second, 
> bringing very bad experience, just like being stuck.

Please upload a full trace somewhere, or at least the "perf report" output.

Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Zhang Haoyu]

>> I tested win-server-2008 with "-cpu core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>> this problem still happened, about 200,000 vmexits per-second, 
>> bringing very bad experience, just like being stuck.
>
>Please upload a full trace somewhere, or at least the "perf report" output.
>
# perf kvm stat report --event=vmexit
Warning:
Processed 4912765 events and lost 81 chunks!
Check IO/CPU overload!

Analyze events for all VCPUs:

             VM-EXIT    Samples  Samples%     Time%         Avg time

   PAUSE_INSTRUCTION    1248620    60.74%    23.33%      0.83us ( +-   0.02% )
      IO_INSTRUCTION     799619    38.89%    74.49%      4.13us ( +-   6.93% )
  EXTERNAL_INTERRUPT       2629     0.13%     0.47%      7.93us ( +-   1.27% )
              VMCALL       1785     0.09%     0.04%      0.98us ( +-   0.30% )
         APIC_ACCESS       1495     0.07%     0.11%      3.38us ( +-   1.65% )
       EXCEPTION_NMI       1188     0.06%     0.03%      1.26us ( +-   1.66% )
 TPR_BELOW_THRESHOLD        273     0.01%     0.01%      1.57us ( +-   1.32% )
   PENDING_INTERRUPT        226     0.01%     0.01%      1.38us ( +-   2.59% )
                 HLT          6     0.00%     1.51%  11153.81us ( +-  15.24% )
       EPT_MISCONFIG          2     0.00%     0.00%     15.46us ( +-  23.93% )

Total Samples:2055843, Total events handled time:4438794.59us.

# perf kvm stat report --event=ioport
Warning:
Processed 4912765 events and lost 81 chunks!
Check IO/CPU overload!

Analyze events for all VCPUs:

      IO Port Access    Samples  Samples%     Time%         Avg time

            0x64:PIN     799032    99.93%    99.84%      3.42us ( +-   8.35% )
           0x3fd:PIN        300     0.04%     0.08%      6.88us ( +-   3.45% )
            0x60:PIN        274     0.03%     0.09%      8.53us ( +-   3.07% )
         0xb000:POUT          2     0.00%     0.00%      7.96us ( +-   3.16% )
          0xb000:PIN          2     0.00%     0.00%      8.16us ( +-   2.31% )
          0xb008:PIN          2     0.00%     0.00%      1.53us ( +-  13.66% )
          0xafe0:PIN          2     0.00%     0.00%      3.62us ( +-   0.84% )
          0xafe1:PIN          2     0.00%     0.00%      2.76us ( +-   2.99% )

Total Samples:799616, Total events handled time:2739038.53us.

# trace-cmd report
version = 6
CPU 4 is empty
CPU 5 is empty
CPU 6 is empty
CPU 7 is empty
CPU 9 is empty
CPU 11 is empty
CPU 12 is empty
CPU 13 is empty
cpus=16
             kvm-22783 [003]   721.255618: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255619: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255622: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22784 [014]   721.255623: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255623: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255623: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255623: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255625: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255626: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255626: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255627: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255628: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255628: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255628: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255629: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255630: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255631: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22784 [014]   721.255632: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22783 [003]   721.255632: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255632: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255632: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255634: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22784 [014]   721.255634: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255635: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255636: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255636: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255636: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255637: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255637: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255638: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255640: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255640: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255640: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255640: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255641: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255642: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22784 [014]   721.255643: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255643: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255645: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255645: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255645: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255645: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255646: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255647: kvm_entry:            vcpu 1
             kvm-22784 [014]   721.255649: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255649: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255649: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255649: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255650: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255651: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255652: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22783 [003]   721.255653: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255653: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255653: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22784 [014]   721.255654: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
             kvm-22783 [003]   721.255655: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
             kvm-22784 [014]   721.255655: kvm_entry:            vcpu 1
             kvm-22783 [003]   721.255655: kvm_entry:            vcpu 0
             kvm-22784 [014]   721.255657: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
             kvm-22784 [014]   721.255658: kvm_pio:              pio_read at 0x64 size 1 count 1
             kvm-22783 [003]   721.255658: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
...

And, if I remove the commit of 0bc830b0, the problem disappeared.

Thanks,
Zhang Haoyu

>Paolo

Re: [question] lots of interrupts injected to vm when pressing somekey w/o releasing

[Paolo Bonzini]

On 25/11/2014 12:20, Zhang Haoyu wrote:
>>> I tested win-server-2008 with "-cpu core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>>> this problem still happened, about 200,000 vmexits per-second, 
>>> bringing very bad experience, just like being stuck.
>>
>> Please upload a full trace somewhere, or at least the "perf report" output.
>>
> # perf kvm stat report --event=vmexit
> Warning:
> Processed 4912765 events and lost 81 chunks!
> Check IO/CPU overload!
> 
> Analyze events for all VCPUs:
> 
>              VM-EXIT    Samples  Samples%     Time%         Avg time
> 
>    PAUSE_INSTRUCTION    1248620    60.74%    23.33%      0.83us ( +-   0.02% )
>       IO_INSTRUCTION     799619    38.89%    74.49%      4.13us ( +-   6.93% )
>   EXTERNAL_INTERRUPT       2629     0.13%     0.47%      7.93us ( +-   1.27% )
>               VMCALL       1785     0.09%     0.04%      0.98us ( +-   0.30% )
>          APIC_ACCESS       1495     0.07%     0.11%      3.38us ( +-   1.65% )
>        EXCEPTION_NMI       1188     0.06%     0.03%      1.26us ( +-   1.66% )
>  TPR_BELOW_THRESHOLD        273     0.01%     0.01%      1.57us ( +-   1.32% )
>    PENDING_INTERRUPT        226     0.01%     0.01%      1.38us ( +-   2.59% )
>                  HLT          6     0.00%     1.51%  11153.81us ( +-  15.24% )
>        EPT_MISCONFIG          2     0.00%     0.00%     15.46us ( +-  23.93% )
> 
> Total Samples:2055843, Total events handled time:4438794.59us.
> 
> # perf kvm stat report --event=ioport
> Warning:
> Processed 4912765 events and lost 81 chunks!
> Check IO/CPU overload!
> 
> Analyze events for all VCPUs:
> 
>       IO Port Access    Samples  Samples%     Time%         Avg time
> 
>             0x64:PIN     799032    99.93%    99.84%      3.42us ( +-   8.35% )
>            0x3fd:PIN        300     0.04%     0.08%      6.88us ( +-   3.45% )
>             0x60:PIN        274     0.03%     0.09%      8.53us ( +-   3.07% )
>          0xb000:POUT          2     0.00%     0.00%      7.96us ( +-   3.16% )
>           0xb000:PIN          2     0.00%     0.00%      8.16us ( +-   2.31% )
>           0xb008:PIN          2     0.00%     0.00%      1.53us ( +-  13.66% )
>           0xafe0:PIN          2     0.00%     0.00%      3.62us ( +-   0.84% )
>           0xafe1:PIN          2     0.00%     0.00%      2.76us ( +-   2.99% )
> 
> Total Samples:799616, Total events handled time:2739038.53us.
> 
> # trace-cmd report
> version = 6
> CPU 4 is empty
> CPU 5 is empty
> CPU 6 is empty
> CPU 7 is empty
> CPU 9 is empty
> CPU 11 is empty
> CPU 12 is empty
> CPU 13 is empty
> cpus=16
>              kvm-22783 [003]   721.255618: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255619: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255622: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22784 [014]   721.255623: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255623: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255623: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255623: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255625: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255626: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255626: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255627: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255628: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255628: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255628: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255629: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255630: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255631: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22784 [014]   721.255632: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22783 [003]   721.255632: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255632: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255632: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255634: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22784 [014]   721.255634: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255635: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255636: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255636: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255636: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255637: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255637: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255638: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255640: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255640: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255640: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255640: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255641: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255642: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22784 [014]   721.255643: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255643: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255645: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255645: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255645: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255645: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255646: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255647: kvm_entry:            vcpu 1
>              kvm-22784 [014]   721.255649: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255649: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255649: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255649: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255650: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255651: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255652: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22783 [003]   721.255653: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255653: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255653: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22784 [014]   721.255654: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>              kvm-22783 [003]   721.255655: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
>              kvm-22784 [014]   721.255655: kvm_entry:            vcpu 1
>              kvm-22783 [003]   721.255655: kvm_entry:            vcpu 0
>              kvm-22784 [014]   721.255657: kvm_exit:             reason IO_INSTRUCTION rip 0xfffff88000cdd23b info 640008 0
>              kvm-22784 [014]   721.255658: kvm_pio:              pio_read at 0x64 size 1 count 1
>              kvm-22783 [003]   721.255658: kvm_exit:             reason PAUSE_INSTRUCTION rip 0xfffff80001688a9e info 0 0
> ...
> 
> And, if I remove the commit of 0bc830b0, the problem disappeared.

Please send the full trace file.  If you compress it, it should be small.

Paolo

RE: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

>>>>>> I tested win-server-2008 with "-cpu 
>>>>>> core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>>>>>> this problem still happened, about 200,000 vmexits per-second, 
>>>>>> bringing very bad experience, just like being stuck.
>>>>> 
>>>>> Please upload a full trace somewhere, or at least the "perf report" output.
>>>>> 
>>>> 
>>>> And, if I remove the commit of 0bc830b0, the problem disappeared.
>>> 
>>> Please send the full trace file.  If you compress it, it should be small.
>>> 
>> See the attach 1, please.
>> 
>>> Paolo
>
>Can you try the follow draft patch to see whether it solve your problem? This patch is based on commit 0bc830b0.
>
After applying this patch, VM got stuck with black-screen at boot stage,
# trace-cmd report:
version = 6
CPU 0 is empty
CPU 1 is empty
CPU 2 is empty
CPU 3 is empty
CPU 5 is empty
CPU 7 is empty
cpus=8
             kvm-1266  [004] 14399.834397: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [004] 14399.834403: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [004] 14399.834411: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
             kvm-1266  [004] 14399.834412: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [004] 14402.180013: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [004] 14402.180019: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [004] 14402.180028: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
             kvm-1266  [004] 14402.180029: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [004] 14404.525627: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [004] 14404.525634: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [004] 14404.525641: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
             kvm-1266  [004] 14404.525642: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [004] 14406.871238: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [004] 14406.871245: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [004] 14406.871254: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
             kvm-1266  [004] 14406.871256: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [006] 14409.216849: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [006] 14409.216855: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [006] 14409.216862: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
             kvm-1266  [006] 14409.216863: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [006] 14411.562475: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [006] 14411.562481: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [006] 14411.562489: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
             kvm-1266  [006] 14411.562491: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
             kvm-1266  [004] 14413.908074: kvm_set_irq:          gsi 9 level 1 source 0
             kvm-1266  [004] 14413.908080: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
             kvm-1266  [004] 14413.908088: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
             kvm-1266  [004] 14413.908089: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)

Thanks,
Zhang Haoyu

>diff --git a/virt/kvm/ioapic.c b/virt/kvm/ioapic.c
>index 25e16a6..8f4e211 100644
>--- a/virt/kvm/ioapic.c
>+++ b/virt/kvm/ioapic.c
>@@ -305,6 +305,7 @@ static int ioapic_service(struct kvm_ioapic *ioapic, int irq, bool line_status)
>        return ret;
> }
> 
>+static int irq_status[256];
> int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>                       int level, bool line_status)
> {
>@@ -312,10 +313,13 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>        u32 mask = 1 << irq;
>        union kvm_ioapic_redirect_entry entry;
>        int ret, irq_level;
>+       int old_irq;
> 
>        BUG_ON(irq < 0 || irq >= IOAPIC_NUM_PINS);
> 
>        spin_lock(&ioapic->lock);
>+       old_irq = irq_status[irq];
>+       irq_status[irq] = level;
>        old_irr = ioapic->irr;
>        irq_level = __kvm_irq_line_state(&ioapic->irq_states[irq],
>                                         irq_source_id, level);
>@@ -332,6 +336,10 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>                        goto out;
>                }
>                ioapic->irr |= mask;
>+               if (edge && old_irq == irq_status[irq] && old_irq) {
>+                       ret = 0;
>+                       goto out;
>+               }
>                if ((edge && old_irr != ioapic->irr) ||
>                    (!edge && !entry.fields.remote_irr))
>                        ret = ioapic_service(ioapic, irq, line_status);
>
>Best regards,
>Yang

RE: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

>>>>>>>> I tested win-server-2008 with "-cpu
>>>>>>>> core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>>>>>>>> this problem still happened, about 200,000 vmexits per-second,
>>>>>>>> bringing very bad experience, just like being stuck.
>>>>>>> 
>>>>>>> Please upload a full trace somewhere, or at least the "perf report"
>>>>>>> output.
>>>>>>> 
>>>>>> 
>>>>>> And, if I remove the commit of 0bc830b0, the problem disappeared.
>>>>> 
>>>>> Please send the full trace file.  If you compress it, it should be small.
>>>>> 
>>>> See the attach 1, please.
>>>> 
>>>>> Paolo
>>> 
>>> Can you try the follow draft patch to see whether it solve your
>>> problem? This patch is based on commit 0bc830b0.
>>> 
>> After applying this patch, VM got stuck with black-screen at boot
>
>It is works well in my side. And this patch does fix the issue in my box.
>I am using window 2008 R2 for testing, here is the qemu cmdline:
>qemu-system-x86_64 -enable-kvm -m 4G -smp 4 -net nic,macaddr=00:12:41:41:13:41 -net tap,script=/etc/kvm/qemu-ifup win2k8.qcow
>
>Can you provide your configuration for me to test?
>
/usr/bin/kvm -id 2284096534876 -chardev socket,id=qmp,path=/var/run/qemu-server/2284096534876.qmp,server,nowait -mon chardev=qmp,mode=control -vnc :0,websocket,to=200,x509,password -pidfile /var/run/qemu-server/2284096534876.pid -daemonize -name win2008-x64 -smp sockets=1,cores=2 -cpu core2duo,hv_spinlocks=0xffff,hv_relaxed -nodefaults -vga cirrus -no-hpet -k en-us -boot menu=on,splash-time=8000 -m 4096 -usb -drive if=none,id=drive-ide0,media=cdrom,aio=threads -device ide-cd,bus=ide.0,unit=0,drive=drive-ide0,id=ide0,bootindex=100 -drive file=/sf/data/local/images/host-4061863144dc/d23a20df36a5/win2008-x64.vm/vm-disk-1.qcow2,if=none,id=drive-ide1,cache=none,aio=threads -device ide-hd,bus=ide.0,unit=1,drive=drive-ide1,id=ide1 -netdev type=tap,id=net0,ifname=228409653487600,script=/sf/etc/kvm
 /vtp-bridge,vhost=on,vhostforce=on -device virtio-net-pci,romfile=,mac=FE:FC:FE:99:4C:2E,netdev=net0,bus=pci.0,addr=0x12,id=net0 -rtc driftfix=slew,clock=rt,base=localtime -global kvm-pit.lo
 st_tick_policy=discard -global PIIX4_PM.disable_s3=1 -global PIIX4_PM.disable_s4=1 -chardev socket,path=/var/run/qemu-server/2284096534876.virtser,server,nowait,id=channelser -device virtio-serial,max_ports=2,ioeventfd=off -device virtserialport,chardev=channelser,name=channelser.virtserial0.0 -bios /sf/share/kvm/bios.bin.1

You can change "-id" option to "-uuid".

Thanks,
Zhang Haoyu
>> stage, # trace-cmd report:
>> version = 6
>> CPU 0 is empty
>> CPU 1 is empty
>> CPU 2 is empty
>> CPU 3 is empty
>> CPU 5 is empty
>> CPU 7 is empty
>> cpus=8
>>              kvm-1266  [004] 14399.834397: kvm_set_irq:          gsi 9
>>              level 1 source 0 kvm-1266  [004] 14399.834403:
>>              kvm_pic_set_irq:      chip 1 pin 1 (edge|masked) kvm-1266 
>>              [004] 14399.834411: kvm_apic_accept_irq: apicid 0 vec 177
>>              (LowPrio|level) kvm-1266  [004] 14399.834412:
>>              kvm_ioapic_set_irq:   pin 9 dst 3 vec=177
>>              (LowPrio|logical|level) kvm-1266  [004] 14402.180013:
>>              kvm_set_irq:          gsi 9 level 1 source 0 kvm-1266 
>>              [004] 14402.180019: kvm_pic_set_irq:      chip 1 pin 1
>>              (edge|masked) kvm-1266  [004] 14402.180028:
>>              kvm_apic_accept_irq: apicid 1 vec 177 (LowPrio|level)
>>              kvm-1266  [004] 14402.180029: kvm_ioapic_set_irq:   pin 9
>>              dst 3 vec=177 (LowPrio|logical|level) kvm-1266  [004]
>>              14404.525627: kvm_set_irq:          gsi 9 level 1 source 0
>>              kvm-1266  [004] 14404.525634: kvm_pic_set_irq:      chip 1
>>              pin 1 (edge|masked) kvm-1266  [004] 14404.525641:
>>              kvm_apic_accept_irq: apicid 0 vec 177 (LowPrio|level)
>>              kvm-1266  [004] 14404.525642: kvm_ioapic_set_irq:   pin 9
>>              dst 3 vec=177 (LowPrio|logical|level) kvm-1266  [004]
>>              14406.871238: kvm_set_irq:          gsi 9 level 1 source 0
>>              kvm-1266  [004] 14406.871245: kvm_pic_set_irq:      chip 1
>>              pin 1 (edge|masked) kvm-1266  [004] 14406.871254:
>>              kvm_apic_accept_irq: apicid 1 vec 177 (LowPrio|level)
>>              kvm-1266  [004] 14406.871256: kvm_ioapic_set_irq:   pin 9
>>              dst 3 vec=177 (LowPrio|logical|level) kvm-1266  [006]
>>              14409.216849: kvm_set_irq:          gsi 9 level 1 source 0
>>              kvm-1266  [006] 14409.216855: kvm_pic_set_irq:      chip 1
>>              pin 1 (edge|masked) kvm-1266  [006] 14409.216862:
>>              kvm_apic_accept_irq: apicid 0 vec 177 (LowPrio|level)
>>              kvm-1266  [006] 14409.216863: kvm_ioapic_set_irq:   pin 9
>>              dst 3 vec=177 (LowPrio|logical|level) kvm-1266  [006]
>>              14411.562475: kvm_set_irq:          gsi 9 level 1 source 0
>>              kvm-1266  [006] 14411.562481: kvm_pic_set_irq:      chip 1
>>              pin 1 (edge|masked) kvm-1266  [006] 14411.562489:
>>              kvm_apic_accept_irq: apicid 1 vec 177 (LowPrio|level)
>>              kvm-1266  [006] 14411.562491: kvm_ioapic_set_irq:   pin 9
>>              dst 3 vec=177 (LowPrio|logical|level) kvm-1266  [004]
>>              14413.908074: kvm_set_irq:          gsi 9 level 1 source 0
>>              kvm-1266  [004] 14413.908080: kvm_pic_set_irq:      chip 1
>>              pin 1 (edge|masked) kvm-1266  [004] 14413.908088:
>>              kvm_apic_accept_irq: apicid 0 vec 177 (LowPrio|level)
>>              kvm-1266  [004] 14413.908089: kvm_ioapic_set_irq:   pin 9
>> dst 3 vec=177 (LowPrio|logical|level)
>> 
>> Thanks,
>> Zhang Haoyu
>> 
>Best regards,
>Yang

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Wanpeng Li]

Hi all,
On Thu, Nov 27, 2014 at 03:20:43PM +0800, Zhang Haoyu wrote:
>>>>>>> I tested win-server-2008 with "-cpu 
>>>>>>> core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>>>>>>> this problem still happened, about 200,000 vmexits per-second, 
>>>>>>> bringing very bad experience, just like being stuck.
>>>>>> 
>>>>>> Please upload a full trace somewhere, or at least the "perf report" output.
>>>>>> 
>>>>> 
>>>>> And, if I remove the commit of 0bc830b0, the problem disappeared.
>>>> 
>>>> Please send the full trace file.  If you compress it, it should be small.
>>>> 
>>> See the attach 1, please.
>>> 
>>>> Paolo
>>
>>Can you try the follow draft patch to see whether it solve your problem? This patch is based on commit 0bc830b0.
>>
>After applying this patch, VM got stuck with black-screen at boot stage,
># trace-cmd report:
>version = 6
>CPU 0 is empty
>CPU 1 is empty
>CPU 2 is empty
>CPU 3 is empty
>CPU 5 is empty
>CPU 7 is empty
>cpus=8
>             kvm-1266  [004] 14399.834397: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [004] 14399.834403: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [004] 14399.834411: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>             kvm-1266  [004] 14399.834412: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [004] 14402.180013: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [004] 14402.180019: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [004] 14402.180028: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>             kvm-1266  [004] 14402.180029: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [004] 14404.525627: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [004] 14404.525634: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [004] 14404.525641: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>             kvm-1266  [004] 14404.525642: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [004] 14406.871238: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [004] 14406.871245: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [004] 14406.871254: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>             kvm-1266  [004] 14406.871256: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [006] 14409.216849: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [006] 14409.216855: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [006] 14409.216862: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>             kvm-1266  [006] 14409.216863: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [006] 14411.562475: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [006] 14411.562481: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [006] 14411.562489: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>             kvm-1266  [006] 14411.562491: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>             kvm-1266  [004] 14413.908074: kvm_set_irq:          gsi 9 level 1 source 0
>             kvm-1266  [004] 14413.908080: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>             kvm-1266  [004] 14413.908088: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>             kvm-1266  [004] 14413.908089: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>
>Thanks,
>Zhang Haoyu
>
>>diff --git a/virt/kvm/ioapic.c b/virt/kvm/ioapic.c
>>index 25e16a6..8f4e211 100644
>>--- a/virt/kvm/ioapic.c
>>+++ b/virt/kvm/ioapic.c
>>@@ -305,6 +305,7 @@ static int ioapic_service(struct kvm_ioapic *ioapic, int irq, bool line_status)
>>        return ret;
>> }
>> 
>>+static int irq_status[256];
>> int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>                       int level, bool line_status)
>> {
>>@@ -312,10 +313,13 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>        u32 mask = 1 << irq;
>>        union kvm_ioapic_redirect_entry entry;
>>        int ret, irq_level;
>>+       int old_irq;
>> 

I'm not sure which version of kvm the patch is against, anyway, all the 
modification should be moved to ioapic_set_irq() against the upstream 
kvm, I test the patch w/ win2k8 guest and w/o the Haoyu's comand line 
and it can fix the bug mentioned by Haoyu, in addition, press any key 
can reproduce the bug on my side instead of the small set which Haoyu 
mentioned.

Regards,
Wanpeng Li 

>>        BUG_ON(irq < 0 || irq >= IOAPIC_NUM_PINS);
>> 
>>        spin_lock(&ioapic->lock);
>>+       old_irq = irq_status[irq];
>>+       irq_status[irq] = level;
>>        old_irr = ioapic->irr;
>>        irq_level = __kvm_irq_line_state(&ioapic->irq_states[irq],
>>                                         irq_source_id, level);
>>@@ -332,6 +336,10 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>                        goto out;
>>                }
>>                ioapic->irr |= mask;
>>+               if (edge && old_irq == irq_status[irq] && old_irq) {
>>+                       ret = 0;
>>+                       goto out;
>>+               }
>>                if ((edge && old_irr != ioapic->irr) ||
>>                    (!edge && !entry.fields.remote_irr))
>>                        ret = ioapic_service(ioapic, irq, line_status);
>>
>>Best regards,
>>Yang
>
>--
>To unsubscribe from this list: send the line "unsubscribe kvm" in
>the body of a message to majordomo@vger.kernel.org
>More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [question] lots of interrupts injected to vm when pressing some key w/o releasing

[Zhang Haoyu]

>Hi all,
>On Thu, Nov 27, 2014 at 03:20:43PM +0800, Zhang Haoyu wrote:
>>>>>>>> I tested win-server-2008 with "-cpu 
>>>>>>>> core2duo,hv_spinlocks=0xffff,hv_relaxed,hv_time",
>>>>>>>> this problem still happened, about 200,000 vmexits per-second, 
>>>>>>>> bringing very bad experience, just like being stuck.
>>>>>>> 
>>>>>>> Please upload a full trace somewhere, or at least the "perf report" output.
>>>>>>> 
>>>>>> 
>>>>>> And, if I remove the commit of 0bc830b0, the problem disappeared.
>>>>> 
>>>>> Please send the full trace file.  If you compress it, it should be small.
>>>>> 
>>>> See the attach 1, please.
>>>> 
>>>>> Paolo
>>>
>>>Can you try the follow draft patch to see whether it solve your problem? This patch is based on commit 0bc830b0.
>>>
>>After applying this patch, VM got stuck with black-screen at boot stage,
>># trace-cmd report:
>>version = 6
>>CPU 0 is empty
>>CPU 1 is empty
>>CPU 2 is empty
>>CPU 3 is empty
>>CPU 5 is empty
>>CPU 7 is empty
>>cpus=8
>>             kvm-1266  [004] 14399.834397: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [004] 14399.834403: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [004] 14399.834411: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>>             kvm-1266  [004] 14399.834412: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [004] 14402.180013: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [004] 14402.180019: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [004] 14402.180028: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>>             kvm-1266  [004] 14402.180029: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [004] 14404.525627: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [004] 14404.525634: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [004] 14404.525641: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>>             kvm-1266  [004] 14404.525642: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [004] 14406.871238: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [004] 14406.871245: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [004] 14406.871254: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>>             kvm-1266  [004] 14406.871256: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [006] 14409.216849: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [006] 14409.216855: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [006] 14409.216862: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>>             kvm-1266  [006] 14409.216863: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [006] 14411.562475: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [006] 14411.562481: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [006] 14411.562489: kvm_apic_accept_irq:  apicid 1 vec 177 (LowPrio|level)
>>             kvm-1266  [006] 14411.562491: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>             kvm-1266  [004] 14413.908074: kvm_set_irq:          gsi 9 level 1 source 0
>>             kvm-1266  [004] 14413.908080: kvm_pic_set_irq:      chip 1 pin 1 (edge|masked)
>>             kvm-1266  [004] 14413.908088: kvm_apic_accept_irq:  apicid 0 vec 177 (LowPrio|level)
>>             kvm-1266  [004] 14413.908089: kvm_ioapic_set_irq:   pin 9 dst 3 vec=177 (LowPrio|logical|level)
>>
>>Thanks,
>>Zhang Haoyu
>>
>>>diff --git a/virt/kvm/ioapic.c b/virt/kvm/ioapic.c
>>>index 25e16a6..8f4e211 100644
>>>--- a/virt/kvm/ioapic.c
>>>+++ b/virt/kvm/ioapic.c
>>>@@ -305,6 +305,7 @@ static int ioapic_service(struct kvm_ioapic *ioapic, int irq, bool line_status)
>>>        return ret;
>>> }
>>> 
>>>+static int irq_status[256];
>>> int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>>                       int level, bool line_status)
>>> {
>>>@@ -312,10 +313,13 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>>        u32 mask = 1 << irq;
>>>        union kvm_ioapic_redirect_entry entry;
>>>        int ret, irq_level;
>>>+       int old_irq;
>>> 
>
>I'm not sure which version of kvm the patch is against, anyway, all the 
>modification should be moved to ioapic_set_irq() against the upstream 
>kvm, I test the patch w/ win2k8 guest and w/o the Haoyu's comand line 
>and it can fix the bug mentioned by Haoyu, in addition, press any key 
>can reproduce the bug on my side instead of the small set which Haoyu 
>mentioned.
>
Yang's patch indeed can fix the problem.
Our rtc optimization together with Yang' patch causes the stuck happened at boot stage.

Thanks,
Zhang Haoyu

>Regards,
>Wanpeng Li 
>
>>>        BUG_ON(irq < 0 || irq >= IOAPIC_NUM_PINS);
>>> 
>>>        spin_lock(&ioapic->lock);
>>>+       old_irq = irq_status[irq];
>>>+       irq_status[irq] = level;
>>>        old_irr = ioapic->irr;
>>>        irq_level = __kvm_irq_line_state(&ioapic->irq_states[irq],
>>>                                         irq_source_id, level);
>>>@@ -332,6 +336,10 @@ int kvm_ioapic_set_irq(struct kvm_ioapic *ioapic, int irq, int irq_source_id,
>>>                        goto out;
>>>                }
>>>                ioapic->irr |= mask;
>>>+               if (edge && old_irq == irq_status[irq] && old_irq) {
>>>+                       ret = 0;
>>>+                       goto out;
>>>+               }
>>>                if ((edge && old_irr != ioapic->irr) ||
>>>                    (!edge && !entry.fields.remote_irr))
>>>                        ret = ioapic_service(ioapic, irq, line_status);
>>>
>>>Best regards,
>>>Yang