Re: [Qemu-devel] [PATCH] ioapic: allow buggy guests mishandling level-triggered interrupts to make progress

[Vitaly Kuznetsov]

Liran Alon <address@hidden> writes:

>> On 1 Apr 2019, at 18:58, Vitaly Kuznetsov <address@hidden> wrote:
>> 
>> Liran Alon <address@hidden> writes:
>> 
>>>> On 1 Apr 2019, at 16:36, Vitaly Kuznetsov <address@hidden> wrote:
>>>> 
>>>> It was found that Hyper-V 2016 on KVM in some configurations (q35 machine +
>>>> piix4-usb-uhci) hangs on boot. Trace analysis led us to the conclusion that
>>>> it is mishandling level-triggered interrupt performing EOI without fixing
>>>> the root cause.
>>> 
>>> I would rephrase as:
>>> It was found that Hyper-V 2016 on KVM in some configurations (q35 machine + 
>>> piix4-usb-uhci) hangs on boot.
>>> Root-cause was that one of Hyper-V level-triggered interrupt handler 
>>> performs EOI before fixing the root-cause.
>>> This results in IOAPIC keep re-raising the level-triggered interrupt
>>> after EOI because irq-line remains asserted.
>> 
>> Ok, thanks for the suggestion.
>> 
>>> 
>>>> This causes immediate re-assertion and L2 VM (which is
>>>> supposedly expected to fix the cause of the interrupt) is not making any
>>>> progress.
>>> 
>>> I don’t know why you assume this.
>>> From the trace we have examined, it seems that the EOI is performed by 
>>> Hyper-V and not it’s guest
>>> This means that the handler for this level-triggered interrupt is on
>>> Hyper-V and not it’s guest.
>> 
>> If you let it run (with e.g. this patch or by setting preemtion timer >
>> 0) you'll see that MMIO write fixing the cause of the interrupt is
>> happening from L2:
>> 
>> (qemu) info pci:
>> 
>>  Bus  0, device   4, function 0:
>>    USB controller: PCI device 8086:7112
>>      PCI subsystem 1af4:1100
>>      IRQ 23.
>>      BAR4: I/O at 0x6060 [0x607f].
>>      id ""
>> 
>> ...
>>  538597.212494: kvm_exit:             reason VMRESUME rip 0xfffff80004250115 
>> info 0 0
>>  538597.212499: kvm_entry:            vcpu 0
>>  538597.212506: kvm_exit:             reason IO_INSTRUCTION rip 
>> 0xfffff80e02ac6a27 info 60620009 0
>>  538597.212507: kvm_nested_vmexit:    rip fffff80e02ac6a27 reason 
>> IO_INSTRUCTION info1 60620009 info2 0 int_info 0 int_info_err 0
>>  538597.212509: kvm_fpu:              unload
>>  538597.212511: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>>  538597.212516: kvm_fpu:              load
>>  538597.212518: kvm_pio:              pio_read at 0x6062 size 2 count 1 val 
>> 0x1 
>>  538597.212519: kvm_entry:            vcpu 0
>>  538597.212523: kvm_exit:             reason IO_INSTRUCTION rip 
>> 0xfffff80e02ac6a61 info 60640009 0
>>  538597.212523: kvm_nested_vmexit:    rip fffff80e02ac6a61 reason 
>> IO_INSTRUCTION info1 60640009 info2 0 int_info 0 int_info_err 0
>>  538597.212524: kvm_fpu:              unload
>>  538597.212525: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
>>  538597.212528: kvm_fpu:              load
>>  538597.212528: kvm_pio:              pio_read at 0x6064 size 2 count 1 val 
>> 0xf 
>> ...
>> 
>> and this happens after EOI from L1.
>
> I see that the L2 guest is doing I/O read to the device BAR4 but do these 
> reads lower the irq-line?
> I would expect a write to lower the irq-line.
>
> Looking at uhci_port_read(), it seems that offset 0x02 and 0x04 just return a 
> value. Doesn’t lower irq-line.
> (Even though offset 0x04 returns the "interrupt enable register”).
> In contrast, looking at uhci_port_write(), it seems that writing to either 
> offset 0x02 or 0x04 could lower the irq-line.
> So you should look for pio_write to port 0x6062 or 0x6064 to see who
> is actually responsible for lowering the irq-line.

Sorry, I probably like trimming traces too much. Writes happen too:

 [005] 538597.212532: kvm_exit:             reason IO_INSTRUCTION rip 
0xfffff80e02ac6a8f info 60620001 0
 [005] 538597.212533: kvm_nested_vmexit:    rip fffff80e02ac6a8f reason 
IO_INSTRUCTION info1 60620001 info2 0 int_info 0 int_info_err 0
 [005] 538597.212534: kvm_pio:              pio_write at 0x6062 size 2 count 1 
val 0x1 
 [005] 538597.212534: kvm_fpu:              unload
 [005] 538597.212535: kvm_userspace_exit:   reason KVM_EXIT_IO (2)
 [005] 538597.212543: kvm_fpu:              load
 [005] 538597.212544: kvm_entry:            vcpu 0
 [005] 538597.212547: kvm_exit:             reason IO_INSTRUCTION rip 
0xfffff80e02ac6a9c info 60640001 0
 [005] 538597.212548: kvm_nested_vmexit:    rip fffff80e02ac6a9c reason 
IO_INSTRUCTION info1 60640001 info2 0 int_info 0 int_info_err 0
 [005] 538597.212548: kvm_pio:              pio_write at 0x6064 size 2 count 1 
val 0x0 
 [005] 538597.212549: kvm_fpu:              unload
 [005] 538597.212550: kvm_userspace_exit:   reason KVM_EXIT_IO (2)

and this likely lowers the line. I honestly have no idea how this all
works on real hw but the comment in kernel ioapic says something about
non-immediate delivery of the reasserted interrupt. True or not, this
gives me some peace of mind :-)

-- 
Vitaly