Bug 1022471

Summary: Met "Broke affinity for irq ..." in KVM guest kernel log with "virito driver + MSI"
Product: Red Hat Enterprise Linux 6 Reporter: Sibiao Luo <sluo>
Component: qemu-kvmAssignee: Virtualization Maintenance <virt-maint>
Status: CLOSED NOTABUG QA Contact: Virtualization Bugs <virt-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.5CC: acathrow, alex.williamson, bsarathy, chayang, flang, juzhang, michen, mkenneth, qzhang, virt-maint, xfu
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-10-23 13:24:47 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Sibiao Luo 2013-10-23 11:05:45 UTC
Description of problem:
Met "Broke affinity for irq ..." in KVM guest kernel log with "virito driver + MSI".
(1).If disable the MSI via append 'pci=nomsi' in guest kernel line, there is no any "Broke affinity for irq xxx" message appear in guest kernel log.
(2).If use the 'IDE + e1000 + MSI', there also no "Broke affinity for irq xxx" message appear in guest kernel log.

Version-Release number of selected component (if applicable):
host info:
2.6.32-424.el6.x86_64
qemu-kvm-0.12.1.2-2.414.el6.x86_64
seabios-0.6.1.2-28.el6.x86_64
host info:
2.6.32-424.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
1.boot guest with 'virtio-blk + virtio-nic + MSI'.
e.g:# /usr/libexec/qemu-kvm -M pc -S -cpu host -enable-kvm -m 2G -smp 2,sockets=2,cores=1,threads=1 -no-kvm-pit-reinjection -usb -device usb-tablet,id=input0 -name sluo -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,max_ports=16,vectors=0,bus=pci.0,addr=0x3 -chardev socket,id=channel1,path=/tmp/helloworld1,server,nowait -device virtserialport,chardev=channel1,name=com.redhat.rhevm.vdsm,bus=virtio-serial0.0,id=port1 -chardev socket,id=channel2,path=/tmp/helloworld2,server,nowait -device virtserialport,chardev=channel2,name=com.redhat.rhevm.vdsm,bus=virtio-serial0.0,id=port2 -drive file=/home/RHEL-6.5-Snapshot-4-Server-x86_64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop -device virtio-blk-pci,vectors=0,bus=pci.0,addr=0x4,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=00:01:02:B6:40:21,bus=pci.0,addr=0x5 -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x6 -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -drive file=/home/my-data-disk.raw,if=none,id=drive-data-disk,format=raw,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x7,drive=drive-data-disk,id=data-disk -k en-us -boot menu=on -qmp tcp:0:4444,server,nowait -serial unix:/tmp/ttyS0,server,nowait -vnc :1 -spice disable-ticketing,port=5931 -monitor stdio

# cat /proc/interrupts
           CPU0       CPU1      
  0:        155          0   IO-APIC-edge      timer
  1:        111          0   IO-APIC-edge      i8042
  4:        173          0   IO-APIC-edge      serial
  7:          0          0   IO-APIC-edge      parport0
  8:          0          0   IO-APIC-edge      rtc0
  9:          0          0   IO-APIC-fasteoi   acpi
 10:          1          0   IO-APIC-fasteoi   virtio0
 11:       3581       3492   IO-APIC-fasteoi   uhci_hcd:usb1, virtio1, virtio3
 12:        104          0   IO-APIC-edge      i8042
 14:          0          0   IO-APIC-edge      ata_piix
 15:       1556          0   IO-APIC-edge      ata_piix
 24:          0          0   PCI-MSI-edge      virtio4-config
 25:        284          0   PCI-MSI-edge      virtio4-requests
 26:          0          0   PCI-MSI-edge      virtio2-config
 27:        264       7410   PCI-MSI-edge      virtio2-input
 28:          1          0   PCI-MSI-edge      virtio2-output
NMI:         10         11   Non-maskable interrupts
LOC:      23704      22719   Local timer interrupts
SPU:          0          0   Spurious interrupts
PMI:         10         11   Performance monitoring interrupts
IWI:          0          0   IRQ work interrupts
RES:       2886       3587   Rescheduling interrupts
CAL:         13        180   Function call interrupts
TLB:        447        638   TLB shootdowns
TRM:          0          0   Thermal event interrupts
THR:          0          0   Threshold APIC interrupts
MCE:          0          0   Machine check exceptions
MCP:          2          2   Machine check polls
ERR:          0
MIS:          0

# dmesg | grep irq
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
nr_irqs_gsi: 24
NR_IRQS:33024 nr_irqs:424
pnp 00:01: [irq 8]
pnp 00:02: [irq 1]
pnp 00:03: [irq 12]
pnp 00:04: [irq 6]
pnp 00:05: [irq 7]
pnp 00:06: [irq 4]
ipmi_si: Trying default-specified kcs state machine at i/o address 0xca2, slave address 0x0, irq 0
ipmi_si: Trying default-specified smic state machine at i/o address 0xca9, slave address 0x0, irq 0
ipmi_si: Trying default-specified bt state machine at i/o address 0xe4, slave address 0x0, irq 0
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c020
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc000 irq 14
ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc008 irq 15
  alloc irq_desc for 24 on node -1
  alloc kstat_irqs on node -1
virtio-pci 0000:00:07.0: irq 24 for MSI/MSI-X
  alloc irq_desc for 25 on node -1
  alloc kstat_irqs on node -1
virtio-pci 0000:00:07.0: irq 25 for MSI/MSI-X
  alloc irq_desc for 26 on node -1
  alloc kstat_irqs on node -1
virtio-pci 0000:00:05.0: irq 26 for MSI/MSI-X
  alloc irq_desc for 27 on node -1
  alloc kstat_irqs on node -1
virtio-pci 0000:00:05.0: irq 27 for MSI/MSI-X
  alloc irq_desc for 28 on node -1
  alloc kstat_irqs on node -1
virtio-pci 0000:00:05.0: irq 28 for MSI/MSI-X
parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
2.shotdown guest.
guest ]# poweroff

Actual results:
after step 2, there is "Broke affinity for irq ..." in KVM guest kernel log.
...
init: Re-executing /sbin/init
Halting system...
ACPI: Preparing to enter system sleep state S5
Disabling non-boot CPUs ...
Broke affinity for irq 9
Broke affinity for irq 11
Broke affinity for irq 27
SMP alternatives: switching to UP code
Power down.

Expected results:
there should no "Broke affinity for irq xxx" message appear in guest kernel log.

Additional info:

Comment 1 Sibiao Luo 2013-10-23 11:08:30 UTC
The whole kernel log when shotdown guest.

# nc -U /tmp/ttyS0
Stopping certmonger: [  OK  ]
Stopping rhsmcertd...[  OK  ]
Stopping atd: [  OK  ]
Stopping cups: [  OK  ]
Stopping abrt daemon: [  OK  ]
Stopping sshd: [  OK  ]
Shutting down postfix: [  OK  ]
Stopping crond: [  OK  ]
Stopping automount: [  OK  ]
Stopping acpi daemon: [  OK  ]
Stopping HAL daemon: [  OK  ]
Stopping block device availability: Deactivating block devices:
  [SKIP]: unmount of vg_dhcp71101-lv_root (dm-0) mounted on /
[  OK  ]
Stopping NetworkManager daemon: [  OK  ]
Stopping system message bus: [  OK  ]
Stopping rpcbind: [  OK  ]
Stopping auditd: type=1305 audit(1382488877.995:13): audit_pid=0 old=1354 auid=4294967295 ses=4294967295 subj=system_u:system_r:auditd_t:s0 res=1
[  OK  ]
type=1305 audit(1382488878.101:14): audit_enabled=0 old=1 auid=4294967295 ses=4294967295 subj=system_u:system_r:auditctl_t:s0 res=1
Shutting down system logger: [  OK  ]
Shutting down interface eth0:  [  OK  ]
Shutting down loopback interface:  [  OK  ]
ip6tables: Setting chains to policy ACCEPT: filter [  OK  ]
ip6tables: Flushing firewall rules: [  OK  ]
ip6tables: Unloading modules: [  OK  ]
iptables: Setting chains to policy ACCEPT: filter [  OK  ]
iptables: Flushing firewall rules: [  OK  ]
iptables: Unloading modules: [  OK  ]
Stopping monitoring for VG vg_dhcp71101:   2 logical volume(s) in volume group "vg_dhcp71101" unmonitored
[  OK  ]
Sending all processes the TERM signal... [  OK  ]
Sending all processes the KILL signal... [  OK  ]
Saving random seed:  [  OK  ]
Syncing hardware clock to system time [  OK  ]
Turning off swap:  [  OK  ]
Turning off quotas:  [  OK  ]
Unmounting file systems:  [  OK  ]
init: Re-executing /sbin/init
Halting system...
ACPI: Preparing to enter system sleep state S5
Disabling non-boot CPUs ...
Broke affinity for irq 9
Broke affinity for irq 11
Broke affinity for irq 27
SMP alternatives: switching to UP code
Power down.

Comment 2 Alex Williamson 2013-10-23 13:24:47 UTC
Why is this a bug?  The guest is shutting down and disabling non-boot CPUs.  If an IRQ is assigned to a CPU being disabled then affinity is broken.  This is not a bug, this is simply saying that the affinity configured (likely via irqbalanced) is now lost.  Re-open if I'm missing some reason for this to be triaged further.

Comment 3 Sibiao Luo 2013-10-24 02:18:30 UTC
(In reply to Alex Williamson from comment #2)
> Why is this a bug?  The guest is shutting down and disabling non-boot CPUs. 
> If an IRQ is assigned to a CPU being disabled then affinity is broken.  This
> is not a bug, this is simply saying that the affinity configured (likely via
> irqbalanced) is now lost.  Re-open if I'm missing some reason for this to be
> triaged further.
OK, good catch, we will highlight in our MSI feature wiki page, thanks for your explains.