Re: virtio_net sometimes didn't work

["Michael S. Tsirkin" <mst@redhat.com>]

On Wed, Feb 16, 2011 at 04:00:15PM +0800, lidong chen wrote:
> how to info pci in qemu?

just type it at the monitor prompt.

> the usb controller also used irq 11, i think the interrupt maybe cause by this.
> i will modify qemu, ignore -usb,and try again.
> 
> i add some debug code, printk the ioaddr of vdev.
> 
>         static int i;
>         /* reading the ISR has the effect of also clearing it so it's very
>          * important to save off the value. */
>         isr = ioread8(vp_dev->ioaddr + VIRTIO_PCI_ISR);
> 
>         /* It's definitely not us if the ISR was not high */
>         if (!isr) {
>                 i++;
>                 if( i==10000 ) {
>                         printk(KERN_EMERG "22222");
>                         printk(KERN_EMERG "ioaddr %p", vp_dev->ioaddr );
>                         i=0;
>                 }
>                 return IRQ_NONE;
>         }

OK, so we seem to get it right.
Try to stick the printout in qemu
    case VIRTIO_PCI_ISR:
        /* reading from the ISR also clears it. */
        ret = vdev->isr;
        vdev->isr = 0;
        qemu_set_irq(proxy->pci_dev.irq[0], 0);

see whether it's the baloon device or the virtio net
device that gets to handle the reads.

> ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
> ACPI: PCI Interrupt 0000:00:03.0[A] -> Link [LNKC] -> GSI 11 (level,
> high) -> IRQ 11
> 22222<0>ioaddr 0001c040<0>22222<0>ioaddr 0001c040<0>22222<0>ioaddr
> 0001c040<0>22222<0>ioaddr 0001c040<0>22222<0>ioaddr
> 0001c040<0>22222<0>ioaddr 0001c040<0>22222<0>ioaddr
> 0001c040<0>22222<0>ioaddr 0001c040<0>22222<0>ioaddr
> 0001c040<0>22222<0>ioaddr 0001c040<3>irq 11: nobody cared (try booting
> with the "irqpoll" option)
>  [<c01457b0>] __report_bad_irq+0x2b/0x69
>  [<c0145979>] note_interrupt+0x18b/0x1b2
>  [<c01452a9>] handle_IRQ_event+0x26/0x51
>  [<c014537f>] __do_IRQ+0xab/0xdc
>  [<c0106445>] do_IRQ+0x46/0x53
>  [<c0104e8a>] common_interrupt+0x1a/0x20
>  [<c01276f2>] __do_softirq+0x4f/0xc2
>  [<c0127793>] do_softirq+0x2e/0x32
>  [<c0104f3c>] apic_timer_interrupt+0x1c/0x30
>  [<c02ae9fe>] _spin_unlock_irqrestore+0x6/0x7
>  [<c01455dc>] setup_irq+0xab/0x108
>  [<f8a9a09b>] vp_interrupt+0x0/0x114 [virtio_pci]
>  [<c01456ad>] request_irq+0x74/0x90
>  [<f8a9a2fb>] virtio_pci_probe+0x14c/0x1c2 [virtio_pci]
>  [<c01d4096>] pci_device_probe+0x36/0x57
>  [<c022f935>] driver_probe_device+0x42/0x8b
>  [<c022fa23>] __driver_attach+0x4a/0x71
>  [<c022f9d9>] __driver_attach+0x0/0x71
>  [<c022f45a>] bus_for_each_dev+0x39/0x5b
>  [<c022f89f>] driver_attach+0x11/0x13
>  [<c022f9d9>] __driver_attach+0x0/0x71
>  [<c022f17d>] bus_add_driver+0x64/0xfd
>  [<c01d41f9>] __pci_register_driver+0x6c/0x8e
>  [<f8830020>] virtio_pci_init+0x20/0x34 [virtio_pci]
>  [<c013b216>] sys_init_module+0x1749/0x18c2
>  [<c014ab9b>] generic_file_read+0x9a/0xaf
>  [<c0167011>] vfs_read+0xa8/0x150
>  [<c0103dcb>] sysenter_past_esp+0x54/0x79
> handlers:
> [<f8a9a09b>] (vp_interrupt+0x0/0x114 [virtio_pci])
> Disabling IRQ #11
> 
> 
> the output of lspci -vv
> 00:00.0 Host bridge: Intel Corporation 440FX - 82441FX PMC [Natoma] (rev 02)
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 
> 00:01.0 ISA bridge: Intel Corporation 82371SB PIIX3 ISA [Natoma/Triton II]
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Latency: 0
> 
> 00:01.1 IDE interface: Intel Corporation 82371SB PIIX3 IDE
> [Natoma/Triton II] (prog-if 80 [Master])
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Latency: 0
> 	Region 4: I/O ports at c000 [size=16]
> 
> 00:01.2 USB Controller: Intel Corporation 82371SB PIIX3 USB
> [Natoma/Triton II] (rev 01) (prog-if 00 [UHCI])
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Latency: 0
> 	Interrupt: pin D routed to IRQ 11
> 	Region 4: I/O ports at c020 [size=32]
> 
> 00:01.3 Bridge: Intel Corporation 82371AB/EB/MB PIIX4 ACPI (rev 03)
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 9
> 
> 00:02.0 VGA compatible controller: Cirrus Logic GD 5446 (prog-if 00
> [VGA controller])
> 	Subsystem: Unknown device 1af4:1100
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Region 0: Memory at f0000000 (32-bit, prefetchable) [size=32M]
> 	Region 1: Memory at f2000000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f2010000 [disabled] [size=64K]
> 
> 00:03.0 RAM memory: Unknown device 1af4:1002
> 	Subsystem: Unknown device 1af4:0005
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 11
> 	Region 0: I/O ports at c040 [size=32]
> 
> 00:04.0 Ethernet controller: Unknown device 1af4:1000
> 	Subsystem: Unknown device 1af4:0001
> 	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Latency: 0
> 	Interrupt: pin A routed to IRQ 10
> 	Region 0: I/O ports at c060 [size=32]
> 	Region 1: Memory at f2020000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f2030000 [disabled] [size=64K]
> 	Capabilities: [40] MSI-X: Enable- Mask- TabSize=3
> 		Vector table: BAR=1 offset=00000000
> 		PBA: BAR=1 offset=00000800
> 
> 00:05.0 Ethernet controller: Unknown device 1af4:1000
> 	Subsystem: Unknown device 1af4:0001
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 10
> 	Region 0: I/O ports at c080 [size=32]
> 	Region 1: Memory at f2040000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f2050000 [disabled] [size=64K]
> 	Capabilities: [40] MSI-X: Enable- Mask- TabSize=3
> 		Vector table: BAR=1 offset=00000000
> 		PBA: BAR=1 offset=00000800
> 
> 00:06.0 Ethernet controller: Unknown device 1af4:1000
> 	Subsystem: Unknown device 1af4:0001
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 11
> 	Region 0: I/O ports at c0a0 [size=32]
> 	Region 1: Memory at f2060000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f2070000 [disabled] [size=64K]
> 	Capabilities: [40] MSI-X: Enable- Mask- TabSize=3
> 		Vector table: BAR=1 offset=00000000
> 		PBA: BAR=1 offset=00000800
> 
> 00:07.0 Ethernet controller: Unknown device 1af4:1000
> 	Subsystem: Unknown device 1af4:0001
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 11
> 	Region 0: I/O ports at c0c0 [size=32]
> 	Region 1: Memory at f2080000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f2090000 [disabled] [size=64K]
> 	Capabilities: [40] MSI-X: Enable- Mask- TabSize=3
> 		Vector table: BAR=1 offset=00000000
> 		PBA: BAR=1 offset=00000800
> 
> 00:08.0 Ethernet controller: Unknown device 1af4:1000
> 	Subsystem: Unknown device 1af4:0001
> 	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B-
> 	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
> <TAbort- <MAbort- >SERR- <PERR-
> 	Interrupt: pin A routed to IRQ 10
> 	Region 0: I/O ports at c0e0 [size=32]
> 	Region 1: Memory at f20a0000 (32-bit, non-prefetchable) [size=4K]
> 	Expansion ROM at f20b0000 [disabled] [size=64K]
> 	Capabilities: [40] MSI-X: Enable- Mask- TabSize=3
> 		Vector table: BAR=1 offset=00000000
> 		PBA: BAR=1 offset=00000800
> 
> 2011/2/16 Michael S. Tsirkin <mst@redhat.com>:
> > On Wed, Feb 16, 2011 at 09:53:25AM +0800, lidong chen wrote:
> >> because of some other work, i could not focus on this problem last month.
> >>
> >> now i find the wrong vaule of isr cause this problem.
> >> in function vp_interrupt, the isr is 0, and the virtio_balloon pci
> >> device have 100000 times initerrupts. then IRQ #11 disabled.
> >>
> >> static irqreturn_t vp_interrupt(int irq, void *opaque)
> >> {
> >>       struct virtio_pci_device *vp_dev = opaque;
> >>       struct virtio_pci_vq_info *info;
> >>       irqreturn_t ret = IRQ_NONE;
> >>       unsigned long flags;
> >>       u8 isr;
> >>
> >>       /* reading the ISR has the effect of also clearing it so it's very
> >>        * important to save off the value. */
> >>       isr = ioread8(vp_dev->ioaddr + VIRTIO_PCI_ISR);
> >>
> >>       /* It's definitely not us if the ISR was not high */
> >>       if (!isr)
> >>               return IRQ_NONE;   //return from here
> >>
> >
> > This implies that io addr values got swapped between the
> > devices. Try lspci -vv in guest and info pci in qemu and compare
> > the io address values.
> >
> >>
> >>
> >> 2010/12/9 Michael S. Tsirkin <mst@redhat.com>:
> >> > On Fri, Nov 26, 2010 at 10:38:33AM +0800, lidong chen wrote:
> >> >> Does this message appear on boot, or after some stress?
> >> >> on boot, and only appear when boot from network.
> >> >>
> >> >> Which qemu-kvm version?
> >> >> [root@kvm-4slot ~]# /usr/libexec/qemu-kvm --version
> >> >> QEMU PC emulator version 0.12.1 (qemu-kvm-0.12.1.2), Copyright (c)
> >> >> 2003-2008 Fabrice Bellard
> >> >
> >> > what happens with the latest qemu?
> >> >
> >> >> Does cherry-picking 3fff0179e33cd7d0a688dab65700c46ad089e934 help?
> >> >> the virtio_pci have already used this patch, still have this problem.
> >> >>
> >> >> What does info irqs show in qemu?
> >> >> how to collect this information?
> >> >>
> >> >> but I found if modify the slot number of balloon device from 0x03 to
> >> >> 0x09, the problem solved.
> >> >>
> >> >>     <memballoon model='virtio'>
> >> >>       <alias name='balloon0'/>
> >> >>       <address type='pci' domain='0x0000' bus='0x00' slot='0x09'
> >> >> function='0x0'/>
> >> >>     </memballoon>
> >> >
> >> > Interesting. Is it possible that even after baloon is moved,
> >> > there's still the message in guest, only this time
> >> > things keep going afterwards?
> >> >
> >> >> and i found someone else also meet this problem.
> >> >> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/584675
> >> >>
> >> >>
> >> >>
> >> >> 2010/11/25 Michael S. Tsirkin <mst@redhat.com>:
> >> >> > On Thu, Nov 25, 2010 at 10:21:24PM +0800, lidong chen wrote:
> >> >> >> [version]
> >> >> >> the host os version is 2.6.32
> >> >> >
> >> >> > Which qemu-kvm version?
> >> >> >
> >> >> >> the guest os version is 2.6.16
> >> >> >>
> >> >> >> [dmesg]
> >> >> >> ACPI: (supports S3 S4 S5)
> >> >> >> Freeing unused kernel memory: 200k freed
> >> >> >> input: ImExPS/2 Generic Explorer Mouse as /class/input/input2
> >> >> >> ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
> >> >> >> ACPI: PCI Interrupt 0000:00:03.0[A] -> Link [LNKC] -> GSI 11 (level,
> >> >> >> high) -> IRQ 11
> >> >> >> io address 0001c040ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
> >> >> >> ACPI: PCI Interrupt 0000:00:04.0[A] -> Link [LNKD] -> GSI 10 (level,
> >> >> >> high) -> IRQ 10
> >> >> >> io address 0001c060ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
> >> >> >> ACPI: PCI Interrupt 0000:00:05.0[A] -> Link [LNKA] -> GSI 10 (level,
> >> >> >> high) -> IRQ 10
> >> >> >> io address 0001c080ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
> >> >> >> ACPI: PCI Interrupt 0000:00:06.0[A] -> Link [LNKB] -> GSI 11 (level,
> >> >> >> high) -> IRQ 11
> >> >> >> io address 0001c0a0<6>ACPI: PCI Interrupt 0000:00:07.0[A] -> Link
> >> >> >> [LNKC] -> GSI 11 (level, high) -> IRQ 11
> >> >> >> io address 0001c0c0<6>ACPI: PCI Interrupt 0000:00:08.0[A] -> Link
> >> >> >> [LNKD] -> GSI 10 (level, high) -> IRQ 10
> >> >> >> io address 0001c0e0
> >> >> >> irq 11: nobody cared (try booting with the "irqpoll" option)
> >> >> >>  [<c01457b0>] __report_bad_irq+0x2b/0x69
> >> >> >>  [<c0145979>] note_interrupt+0x18b/0x1b2
> >> >> >>  [<c01452a9>] handle_IRQ_event+0x26/0x51
> >> >> >>  [<c014537f>] __do_IRQ+0xab/0xdc
> >> >> >>  [<c0106445>] do_IRQ+0x46/0x53
> >> >> >>  [<c0104e8a>] common_interrupt+0x1a/0x20
> >> >> >>  [<c01276f2>] __do_softirq+0x4f/0xc2
> >> >> >>  [<c0127793>] do_softirq+0x2e/0x32
> >> >> >>  [<c0104f3c>] apic_timer_interrupt+0x1c/0x30
> >> >> >>  [<c0102d55>] default_idle+0x2e/0x5c
> >> >> >>  [<c0102e14>] cpu_idle+0x91/0xad
> >> >> >>  [<c03946e5>] start_kernel+0x34c/0x353
> >> >> >> handlers:
> >> >> >> [<f88252ee>] (vp_interrupt+0x0/0x3e [virtio_pci])
> >> >> >> Disabling IRQ #11
> >> >> >
> >> >> > Does this message appear on boot, or after some stress?
> >> >> > Does cherry-picking 3fff0179e33cd7d0a688dab65700c46ad089e934 help?
> >> >> > Happens with a newer kernel as guest?
> >> >> > What does info irqs show in qemu?
> >> >> >
> >> >> >
> >> >> > --
> >> >> > MST
> >> >> > --
> >> >> > 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
> >> >> >
> >> >
> >