Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1031488

Summary: Restore the mask bit correctly in eoi_ioapic_irq()
Product: Red Hat Enterprise Linux 6 Reporter: FuXiangChun <xfu>
Component: kernelAssignee: jason wang <jasowang>
Status: CLOSED ERRATA QA Contact: Virtualization Bugs <virt-bugs>
Severity: medium Docs Contact:
Priority: high    
Version: 6.6CC: drjones, hhuang, huding, jasowang, juzhang, lersek, michen, pbonzini, prarit, qzhang, rbalakri, rhod, rkrcmar, virt-maint, xfu, xwei
Target Milestone: pre-dev-freeze   
Target Release: 6.6   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32-465.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-10-14 05:32:18 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:
Embargoed:
Attachments:
Description Flags
full-command-line
none
call trace log after migration and trigger kernel panic
none
dmesg log on rhel6.5 host
none
/proc/interrupts on rhel6.5 host
none
dmesg log on rhel7.0 host
none
/proc/interrupts on rhel7.0 host
none
call trace log after sysrq
none
call trace log of two e1000 nics and sysrq
none
guest demsg info with one rtl8139 and one e1000 and debug kernel
none
sysrq call trace log of one e1000, one rtl8139 and debug kernel
none
guest demsg info with two e1000 and debug kernel
none
sysrq call trace log of two e1000 and debug kernel none

Comment 5 Orit Wasserman 2013-11-26 15:34:16 UTC 
an you please provide the output of /proc/cpuinfo on both hosts?
Comment 7 Orit Wasserman 2013-11-27 07:19:51 UTC 
Another question, is this scenario works on Intel hosts?
Comment 8 FuXiangChun 2013-11-27 08:36:29 UTC 
(In reply to Orit Wasserman from comment #7)
> Another question, is this scenario works on Intel hosts?

Hit the same issue on Intel host
Comment 9 Paolo Bonzini 2013-12-20 23:11:06 UTC 
If kdump is failing, IOAPIC or APIC could be the component that is being migrated erroneously.
Comment 10 Paolo Bonzini 2014-03-10 14:35:36 UTC 
FuXiangChun,

could you please try to reproduce with "-machine kernel_irqchip=off"?
Comment 11 FuXiangChun 2014-03-11 02:07:37 UTC 
(In reply to Paolo Bonzini from comment #10)
> FuXiangChun,
> 
> could you please try to reproduce with "-machine kernel_irqchip=off"?

Paolo,
I tested this scenario with "-machine kernel_irqchip=off" in rhel7 host(since rhel6 host don't support option kernel_irqchip. only add it to qemu-kvm command line on rhel7 des host).

result:
guest hand in destination host when migration finish.
Comment 12 FuXiangChun 2014-03-11 03:27:54 UTC 
Paolo,
Ignore comment 11. It is a wrong scenarios.

Re-tested this issue with two scenarios.

1. Boot rhel6 guest with -no-kvm-irqchip in src rhel6 host. and Boot rhel6 guest with "-machine kernel_irqchip=off" option in des rhel7 host.

2.Boot rhel6 guest with -no-kvm-irqchip option in rhel6 and rhel7 host.

result:
Both scenarios got the same result as comment 0(still can reproduce this bug)

Another. when using -no-kvm-irqchip option and virtio-nic-pci device as the same time in qemu-kvm command line.  it will cause qemu-kvm process quit(Segmentation fault). I filed a new bug(1074762) to track it.
Comment 16 FuXiangChun 2014-04-17 07:17:06 UTC 
Retested this bug with qemu-kvm command line & qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg.x86_64.rpm

result:
1. guest can create vmcore file 
2. guest will restart after vmcore is created

This is guest console message.

# SysRq : Trigger a crash
BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
PGD 3e21d067 PUD 3e63c067 PMD 0 
Oops: 0002 [#1] SMP 
last sysfs file: /sys/devices/virtual/block/dm-0/queue/hw_sector_size
CPU 2 
Modules linked in: fuse 8021q garp stp llc ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 uinput ppdev parport_pc parport microcode sg virtio_net i2c_piix4 i2c_core ext4 jbd2 mbcache virtio_blk sr_mod cdrom virtio_pci virtio_ring virtio pata_acpi ata_generic ata_piix dm_mirror dm_region_hash dm_log dm_mod [last unloaded: mperf]

Pid: 2217, comm: bash Not tainted 2.6.32-431.17.1.el6.x86_64 #1 Red Hat KVM
RIP: 0010:[<ffffffff8134b516>]  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
RSP: 0018:ffff88011e7f9e18  EFLAGS: 00010096
RAX: 0000000000000010 RBX: 0000000000000063 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000063
RBP: ffff88011e7f9e18 R08: ffffffff81c068c0 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff81b01a40 R14: 0000000000000286 R15: 0000000000000007
FS:  00007f9e0c4f8700(0000) GS:ffff880081200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000003abc8000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process bash (pid: 2217, threadinfo ffff88011e7f8000, task ffff88011d817500)
Stack:
 ffff88011e7f9e68 ffffffff8134b7d2 ffff88011d817500 ffff880000000000
<d> 0000000000000300 0000000000000002 ffff8800bed6ea80 00007f9e0c506000
<d> 0000000000000002 fffffffffffffffb ffff88011e7f9e98 ffffffff8134b88e
Call Trace:
 [<ffffffff8134b7d2>] __handle_sysrq+0x132/0x1a0
 [<ffffffff8134b88e>] write_sysrq_trigger+0x4e/0x50
 [<ffffffff811f2f1e>] proc_reg_write+0x7e/0xc0
 [<ffffffff81188c38>] vfs_write+0xb8/0x1a0
 [<ffffffff81189531>] sys_write+0x51/0x90
 [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Code: d0 88 81 a3 2c fe 81 c9 c3 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 0f 1f 44 00 00 c7 05 bd 08 75 00 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c9 c3 55 48 89 e5 0f 1f 44 00 00 8d 47 
RIP  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
 RSP <ffff88011e7f9e18>
CR2: 0000000000000000
Initializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.32-431.17.1.el6.x86_64 (mockbuild.eng.bos.redhat.com) (gcc version 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC) ) #1 SMP Fri Apr 11 17:27:00 EDT 2014
Command line: ro root=/dev/mapper/VolGroup-LogVol_root rd_NO_LUKS console=tty0 console=ttyS0,115200 LANG=en_US.UTF-8 rd_NO_MD SYSFONT=latarcyrheb-sun16 rd_LVM_LV=VolGroup/LogVol_swap rd_LVM_LV=VolGroup/LogVol_root KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off  memmap=exactmap memmap=627K@4K memmap=131449K@49779K elfcorehdr=181228K memmap=4K$0K memmap=9K$631K memmap=64K$960K memmap=12K$3670004K memmap=272K$4194032K
KERNEL supported cpus:
  Intel GenuineIntel
  AMD AuthenticAMD
  Centaur CentaurHauls
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000100 - 000000000009dc00 (usable)
 BIOS-e820: 000000000009dc00 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 00000000dfffd000 (usable)
 BIOS-e820: 00000000dfffd000 - 00000000e0000000 (reserved)
 BIOS-e820: 00000000fffbc000 - 0000000100000000 (reserved)
 BIOS-e820: 0000000100000000 - 0000000120000000 (usable)
last_pfn = 0x120000 max_arch_pfn = 0x400000000
user-defined physical RAM map:
 user: 0000000000000000 - 0000000000001000 (reserved)
 user: 0000000000001000 - 000000000009dc00 (usable)
 user: 000000000009dc00 - 00000000000a0000 (reserved)
 user: 00000000000f0000 - 0000000000100000 (reserved)
 user: 000000000309cc00 - 000000000b0fb000 (usable)
 user: 00000000dfffd000 - 00000000e0000000 (reserved)
 user: 00000000fffbc000 - 0000000100000000 (reserved)
DMI 2.4 present.
SMBIOS version 2.4 @ 0xFD9F0
Hypervisor detected: KVM
last_pfn = 0xb0fb max_arch_pfn = 0x400000000
x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
CPU MTRRs all blank - virtualized system.
x2apic enabled by BIOS, switching to x2apic ops
init_memory_mapping: 0000000000000000-000000000b0fb000
RAMDISK: 0ac08000 - 0b0eef3e
ACPI: RSDP 00000000000fd9c0 00014 (v00 BOCHS )
ACPI: RSDT 00000000dfffd310 00038 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
ACPI: FACP 00000000dffffda0 00074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
ACPI: DSDT 00000000dfffd890 024A2 (v01   BXPC   BXDSDT 00000001 INTL 20090123)
ACPI: FACS 00000000dffffd40 00040
ACPI: SSDT 00000000dfffd6c0 001C1 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
ACPI: APIC 00000000dfffd5c0 00090 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
ACPI: SRAT 00000000dfffd460 00160 (v01 BOCHS  BXPCSRAT 00000001 BXPC 00000001)
ACPI: SSDT 00000000dfffd350 0010F (v01   BXPC BXSSDTPC 00000001 INTL 20090123)
Setting APIC routing to cluster x2apic.
SRAT: PXM 0 -> APIC 0 -> Node 0
SRAT: PXM 1 -> APIC 1 -> Node 1
SRAT: PXM 2 -> APIC 2 -> Node 2
SRAT: PXM 3 -> APIC 3 -> Node 3
SRAT: Node 0 PXM 0 0-a0000
SRAT: Node 0 PXM 0 100000-40000000
SRAT: Node 1 PXM 1 40000000-80000000
SRAT: Node 2 PXM 2 80000000-c0000000
SRAT: Node 3 PXM 3 c0000000-e0000000
SRAT: Node 3 PXM 3 100000000-120000000
Bootmem setup node 0 0000000000000000-000000000b0fb000
  NODE_DATA [000000000000b440 - 000000000003f43f]
  bootmap [0000000000040000 -  000000000004161f] pages 2
(8 early reservations) ==> bootmem [0000000000 - 000b0fb000]
  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
  #1 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
  #2 [0004000000 - 0005020aa4]    TEXT DATA BSS ==> [0004000000 - 0005020aa4]
  #3 [000ac08000 - 000b0eef3e]          RAMDISK ==> [000ac08000 - 000b0eef3e]
  #4 [000009dc00 - 0000100000]    BIOS reserved ==> [000009dc00 - 0000100000]
  #5 [0005021000 - 0005021081]              BRK ==> [0005021000 - 0005021081]
  #6 [0000008000 - 0000009000]          PGTABLE ==> [0000008000 - 0000009000]
  #7 [0000009000 - 000000b440]       MEMNODEMAP ==> [0000009000 - 000000b440]
found SMP MP-table at [ffff8800000fda10] fda10
kvm-clock: Using msrs 4b564d01 and 4b564d00
kvm-clock: cpu 0, msr 0:4c247c1, boot clock
Zone PFN ranges:
  DMA      0x00000001 -> 0x00001000
  DMA32    0x00001000 -> 0x00100000
  Normal   0x00100000 -> 0x00100000
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
    0: 0x00000001 -> 0x0000009d
    0: 0x0000309d -> 0x0000b0fb
ACPI: PM-Timer IO Port: 0xb008
Setting APIC routing to cluster x2apic.
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
ACPI: NR_CPUS/possible_cpus limit of 1 almost reached. Keeping one slot for boot cpu.  Processor 0/0x0 ignored.
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
ACPI: NR_CPUS/possible_cpus limit of 1 almost reached. Keeping one slot for boot cpu.  Processor 1/0x1 ignored.
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] enabled)
ACPI: LAPIC (acpi_id[0x03] lapic_id[0x03] enabled)
ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 3/0x3 ignored.
ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
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)
Using ACPI (MADT) for SMP configuration information
4 Processors exceeds NR_CPUS limit of 1
SMP: Allowing 1 CPUs, 0 hotplug CPUs
PM: Registered nosave memory: 000000000009d000 - 000000000009e000
PM: Registered nosave memory: 000000000009e000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000f0000
PM: Registered nosave memory: 00000000000f0000 - 0000000000100000
PM: Registered nosave memory: 0000000000100000 - 000000000309d000
Allocating PCI resources starting at b0fb000 (gap: b0fb000:d4f02000)
Booting paravirtualized kernel on KVM
NR_CPUS:4096 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:4
PERCPU: Embedded 31 pages/cpu @ffff880003200000 s94872 r8192 d23912 u2097152
pcpu-alloc: s94872 r8192 d23912 u2097152 alloc=1*2097152
pcpu-alloc: [0] 0 
kvm-clock: cpu 0, msr 0:32167c1, primary cpu clock
kvm-stealtime: cpu 0, msr 320e880
Built 1 zonelists in Node order, mobility grouping on.  Total pages: 32398
Policy zone: DMA32
Kernel command line: ro root=/dev/mapper/VolGroup-LogVol_root rd_NO_LUKS console=tty0 console=ttyS0,115200 LANG=en_US.UTF-8 rd_NO_MD SYSFONT=latarcyrheb-sun16 rd_LVM_LV=VolGroup/LogVol_swap rd_LVM_LV=VolGroup/LogVol_root KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off  memmap=exactmap memmap=627K@4K memmap=131449K@49779K elfcorehdr=181228K memmap=4K$0K memmap=9K$631K memmap=64K$960K memmap=12K$3670004K memmap=272K$4194032K
Misrouted IRQ fixup and polling support enabled
This may significantly impact system performance
Disabling memory control group subsystem
PID hash table entries: 512 (order: 0, 4096 bytes)
Checking aperture...
No AGP bridge found
AMD-Vi disabled by default: pass amd_iommu=on to enable
Memory: 105824k/181228k available (5326k kernel code, 49156k absent, 26248k reserved, 7013k data, 1280k init)
Hierarchical RCU implementation.
NR_IRQS:33024 nr_irqs:256
Spurious LAPIC timer interrupt on cpu 0
Console: colour dummy device 80x25
console [tty0] enabled
console [ttyS0] enabled
Detected 2000.038 MHz processor.
Calibrating delay loop (skipped) preset value.. 4000.07 BogoMIPS (lpj=2000038)
pid_max: default: 32768 minimum: 301
Security Framework initialized
SELinux:  Initializing.
Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
Mount-cache hash table entries: 256
Initializing cgroup subsys ns
Initializing cgroup subsys cpuacct
Initializing cgroup subsys memory
Initializing cgroup subsys devices
Initializing cgroup subsys freezer
Initializing cgroup subsys net_cls
Initializing cgroup subsys blkio
Initializing cgroup subsys perf_event
Initializing cgroup subsys net_prio
alternatives: switching to unfair spinlock
SMP alternatives: switching to UP code
Freeing SMP alternatives: 36k freed
ACPI: Core revision 20090903
ftrace: converting mcount calls to 0f 1f 44 00 00
ftrace: allocating 21778 entries in 86 pages
APIC routing finalized to physical x2apic.
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: AMD Opteron 22xx (Gen 2 Class Opteron) stepping 01
Performance Events: Broken PMU hardware detected, using software events only.
NMI watchdog disabled (cpu0): hardware events not enabled
Brought up 1 CPUs
Total of 1 processors activated (4000.07 BogoMIPS).
x86 PAT enabled: cpu 0, old 0x70106, new 0x7010600070106
devtmpfs: initialized
regulator: core version 0.5
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: Using configuration type 1 for base access
bio: create slab <bio-0> at 0
ACPI: Interpreter enabled
ACPI: (supports S0 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: No dock devices found.
PCI: Ignoring host bridge windows from ACPI; if necessary, use "pci=use_crs" and report a bug
ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
PCI host bridge to bus 0000:00
pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffffff]
pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
ACPI: PCI Interrupt Link [LNKA] (IRQs 5 10 11) *0, disabled.
ACPI: PCI Interrupt Link [LNKB] (IRQs 5 10 11) *0, disabled.
ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
ACPI: PCI Interrupt Link [LNKD] (IRQs 5 *10 11)
ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
vgaarb: loaded
vgaarb: bridge control possible 0000:00:02.0
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
Switching to clocksource kvm-clock
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 7 devices
ACPI: ACPI bus type pnp unregistered
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 1, 8192 bytes)
TCP established hash table entries: 4096 (order: 4, 65536 bytes)
TCP bind hash table entries: 4096 (order: 4, 65536 bytes)
TCP: Hash tables configured (established 4096 bind 4096)
TCP reno registered
NET: Registered protocol family 1
pci 0000:00:00.0: Limiting direct PCI/PCI transfers
pci 0000:00:01.0: Activating ISA DMA hang workarounds
Trying to unpack rootfs image as initramfs...
Freeing initrd memory: 5019k freed
audit: initializing netlink socket (disabled)
type=2000 audit(1397718256.301:1): initialized
HugeTLB registered 2 MB page size, pre-allocated 0 pages
VFS: Disk quotas dquot_6.5.2
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
msgmni has been set to 216
alg: No test for stdrng (krng)
ksign: Installing public key data
Loading keyring
- Added public key B6CDEB7C22180B1C
- User ID: Red Hat, Inc. (Kernel Module GPG key)
- Added public key D4A26C9CCD09BEDA
- User ID: Red Hat Enterprise Linux Driver Update Program <secalert>
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
pciehp: PCI Express Hot Plug Controller Driver version: 0.4
acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
acpiphp: Slot [1] registered
acpiphp: Slot [2] registered
acpiphp: Slot [3] registered
acpiphp: Slot [4] registered
acpiphp: Slot [5] registered
acpiphp: Slot [6] registered
acpiphp: Slot [7] registered
acpiphp: Slot [8] registered
acpiphp: Slot [9] registered
acpiphp: Slot [10] registered
acpiphp: Slot [11] registered
acpiphp: Slot [12] registered
acpiphp: Slot [13] registered
acpiphp: Slot [14] registered
acpiphp: Slot [15] registered
acpiphp: Slot [16] registered
acpiphp: Slot [17] registered
acpiphp: Slot [18] registered
acpiphp: Slot [19] registered
acpiphp: Slot [20] registered
acpiphp: Slot [21] registered
acpiphp: Slot [22] registered
acpiphp: Slot [23] registered
acpiphp: Slot [24] registered
acpiphp: Slot [25] registered
acpiphp: Slot [26] registered
acpiphp: Slot [27] registered
acpiphp: Slot [28] registered
acpiphp: Slot [29] registered
acpiphp: Slot [30] registered
acpiphp: Slot [31] registered
ipmi message handler version 39.2
IPMI System Interface driver.
ipmi_si: Adding default-specified kcs state machine
ipmi_si: Trying default-specified kcs state machine at i/o address 0xca2, slave address 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Adding default-specified smic state machine
ipmi_si: Trying default-specified smic state machine at i/o address 0xca9, slave address 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Adding default-specified bt state machine
ipmi_si: Trying default-specified bt state machine at i/o address 0xe4, slave address 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Unable to find any System Interface(s)
input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
ACPI: Power Button [PWRF]
ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 4/0x1 ignored.
Unable to map lapic to logical cpu number
processor LNXCPU:02: BIOS reported wrong ACPI id 0 for the processor
ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 5/0x3 ignored.
Unable to map lapic to logical cpu number
[Firmware Bug]: No valid trip found
GHES: HEST is not enabled!
Non-volatile memory driver v1.3
Linux agpgart interface v0.103
crash memory driver: version 1.1
Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
�serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
brd: module loaded
loop: module loaded
input: Macintosh mouse button emulation as /devices/virtual/input/input1
Fixed MDIO Bus: probed
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
uhci_hcd: USB Universal Host Controller Interface driver
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
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input2
rtc_cmos 00:01: RTC can wake from S4
rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
rtc0: alarms up to one day, 114 bytes nvram
cpuidle: using governor ladder
cpuidle: using governor menu
EFI Variables Facility v0.08 2004-May-17
usbcore: registered new interface driver hiddev
usbcore: registered new interface driver usbhid
usbhid: v2.6:USB HID core driver
GRE over IPv4 demultiplexor driver
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 17
registered taskstats version 1
rtc_cmos 00:01: setting system clock to 2014-04-17 23:24:16 UTC (1397777056)
Initalizing network drop monitor service
Freeing unused kernel memory: 1280k freed
Write protecting the kernel read-only data: 10240k
Freeing unused kernel memory: 800k freed
Freeing unused kernel memory: 1584k freed
Mounting proc filesystem
Mounting sysfs filesystem
Creating /dev
Creating initial device nodes
setfont: KDFONTOP: Invalid argument
Free memory/Total memory (free %): 81176 / 114548 ( 70.8664 )
Loading dm-mod.ko module
device-mapper: uevent: version 1.0.3
device-mapper: ioctl: 4.24.6-ioctl (2013-01-15) initialised: dm-devel
Loading dm-log.ko module
Loading dm-region-hash.ko module
Loading dm-mirror.ko module
Loading dm-zero.ko module
Loading dm-snapshot.ko module
Loading ipt_REJECT.ko module
Loading nf_defrag_ipv4.ko module
Loading ip_tables.ko module
ip_tables: (C) 2000-2006 Netfilter Core Team
Loading nf_conntrack.ko module
nf_conntrack version 0.5.0 (894 buckets, 3576 max)
Loading ip6_tables.ko module
ip6_tables: (C) 2000-2006 Netfilter Core Team
Loading ipv6.ko module
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
Loading uinput.ko module
Loading sg.ko module
Loading e1000.ko module
e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
e1000: Copyright (c) 1999-2006 Intel Corporation.
Loading mii.ko module
Loading ac97_bus.ko module
Loading i2c-core.ko module
Loading jbd2.ko module
Loading mbcache.ko module
Loading cdrom.ko module
Loading crc-t10dif.ko module
Loading virtio_ring.ko module
Loading virtio.ko module
Loading pata_acpi.ko module
Loading ata_generic.ko module
Loading ata_piix.ko module
scsi0 : ata_piix
scsi1 : ata_piix
ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc000 irq 14
ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc008 irq 15
ata2.00: ATAPI: QEMU DVD-ROM, 0.12.1, max UDMA/100
ata2.00: configured for MWDMA2
scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     1.5. PQ: 0 ANSI: 5
scsi 1:0:0:0: Attached scsi generic sg0 type 5
Loading nf_conntrack_ipv4.ko module
Loading iptable_filter.ko module
Loading ip6t_REJECT.ko module
Loading nf_defrag_ipv6.ko module
Loading xt_state.ko module
Loading ip6table_filter.ko module
Loading 8139too.ko module
8139too Fast Ethernet driver 0.9.28
Loading 8139cp.ko module
8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
Loading virtio_net.ko module
Loading virtio_console.ko module
Loading i2c-piix4.ko module
piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0
Loading ext4.ko module
Loading virtio_scsi.ko module
Loading virtio_blk.ko module
Loading sr_mod.ko module
input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
Refined TSC clocksource calibration: 1999.981 MHz.
ata2: lost interrupt (Status 0x58)
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
sr 1:0:0:0: CDB: Mode Sense(10): 5a 00 2a 00 00 00 00 00 80 00
ata2.00: cmd a0/01:00:00:80:00/00:00:00:00:00/a0 tag 0 dma 16512 in
         res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
ata2.00: status: { DRDY }
ata2: soft resetting link
ata2.00: configured for MWDMA2
ata2: EH complete
sr0: scsi-1 drive
Uniform CD-ROM driver Revision: 3.20
Loading sd_mod.ko module
Loading virtio_pci.ko module
ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
virtio-pci 0000:00:03.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11
 vda: vda1 vda2
ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
virtio-pci 0000:00:04.0: PCI INT A -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10
Loading nf_conntrack_ipv6.ko module
Waiting for required block device discovery
Waiting for device with virtio_ids: fuxc ...
Creating block device loop0
Creating block device loop1
Creating block device loop2
Creating block device loop3
Creating block device loop4
Creating block device loop5
Creating block device loop6
Creating block device loop7
Creating block device ram0
Creating block device ram1
Creating block device ram10
Creating block device ram11
Creating block device ram12
Creating block device ram13
Creating block device ram14
Creating block device ram15
Creating block device ram2
Creating block device ram3
Creating block device ram4
Creating block device ram5
Creating block device ram6
Creating block device ram7
Creating block device ram8
Creating block device ram9
Creating block device sr0
Creating block device vda
 vda: vda1 vda2


Creating Remain Block Devices
Making device-mapper control node
Scanning logical volumes
  Reading all physical volumes.  This may take a while...
  Found volume group "VolGroup" using metadata type lvm2
Activating logical volumes
  2 logical volume(s) in volume group "VolGroup" now active
Free memory/Total memory (free %): 74152 / 114548 ( 64.7344 )
Saving to the local filesystem UUID=116db5b7-d23e-4327-8bb8-d7f0fe76ed79
e2fsck 1.41.12 (17-May-2010)
/dev/mapper/VolGroup-LogVol_root: recovering journal
/dev/mapper/VolGroup-LogVol_root: clean, 133481/1015808 files, 948804/4063232 blocks
EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: 
Free memory/Total memory (free %): 72780 / 114548 ( 63.5367 )
Loading SELINUX policy
type=1404 audit(1397777273.190:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
type=1403 audit(1397777273.767:3): policy loaded auid=4294967295 ses=4294967295
Saving vmcore-dmesg.txt
Saved vmcore-dmesg.txt
Copying data                       : [100 %] 
Saving core complete
Restarting system.
machine restart

Anyway, QE think the build can fix this bug.  about comment's result. maybe I added some other devices to qemu-kvm command line cause guest hang, I will continue to debug this issue with a bigger qemu-kvm command line.
Comment 17 FuXiangChun 2014-04-17 08:36:40 UTC 
Ignore comment16 first. 

Summary testing result.

1.Re-tested this issue with qemu-kvm-1.5.3-60.el7.x86_64 & full qemu-kvm command line(it isn't the same as comment0).I will attached this full qemu-kvm command line.

result:
unused login: fuse init (API version 7.13)
SysRq : Trigger a crash
BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
PGD 11e7c0067 PUD 11ef06067 PMD 0 
Oops: 0002 [#1] SMP 
last sysfs file: /sys/devices/pci0000:00/0000:00:01.1/host0/target0:0:1/0:0:1:0/evt_media_change
CPU 1 
Modules linked in: nls_utf8 fuse 8021q garp stp llc ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 uinput microcode sg 8139too 8139cp mii e1000 virtio_net snd_hda_intel snd_hda_codec snd_hwdep virtio_balloon virtio_console snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc i2c_piix4 i2c_core ext4 jbd2 mbcache sr_mod cdrom virtio_scsi sd_mod crc_t10dif virtio_blk virtio_pci virtio_ring virtio pata_acpi ata_generic ata_piix dm_mirror dm_region_hash dm_log dm_mod [last unloaded: mperf]

Pid: 2494, comm: bash Not tainted 2.6.32-431.17.1.el6.x86_64 #1 Red Hat KVM
RIP: 0010:[<ffffffff8134b516>]  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
RSP: 0018:ffff880075c93e18  EFLAGS: 00010096
RAX: 0000000000000010 RBX: 0000000000000063 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000063
RBP: ffff880075c93e18 R08: ffffffff81c068d0 R09: 0000000000000080
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff81b01a40 R14: 0000000000000286 R15: 0000000000000007
FS:  00007fa40c645700(0000) GS:ffff880041200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000011ef03000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process bash (pid: 2494, threadinfo ffff880075c92000, task ffff88007dd24040)
Stack:
 ffff880075c93e68 ffffffff8134b7d2 ffff88007dd24040 ffff880100000000
<d> 0000000000000300 0000000000000002 ffff88007ee84a40 00007fa40c653000
<d> 0000000000000002 fffffffffffffffb ffff880075c93e98 ffffffff8134b88e
Call Trace:
 [<ffffffff8134b7d2>] __handle_sysrq+0x132/0x1a0
 [<ffffffff8134b88e>] write_sysrq_trigger+0x4e/0x50
 [<ffffffff811f2f1e>] proc_reg_write+0x7e/0xc0
 [<ffffffff81188c38>] vfs_write+0xb8/0x1a0
 [<ffffffff81189531>] sys_write+0x51/0x90
 [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Code: d0 88 81 a3 2c fe 81 c9 c3 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 0f 1f 44 00 00 c7 05 bd 08 75 00 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c9 c3 55 48 89 e5 0f 1f 44 00 00 8d 47 
RIP  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
 RSP <ffff880075c93e18>
CR2: 0000000000000000

This result can reply comment15's needinfo.

2. Retested this bug with qemu-kvm command line as comment0.
2.1 with qemu-kvm-1.5.3-60.el7.x86_64
result:
Pid: 2167, comm: bash Not tainted 2.6.32-431.17.1.el6.x86_64 #1 Red Hat KVM
RIP: 0010:[<ffffffff8134b516>]  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
RSP: 0018:ffff88011ec03e18  EFLAGS: 00010096
RAX: 0000000000000010 RBX: 0000000000000063 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000063
RBP: ffff88011ec03e18 R08: ffffffff81c068c0 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff81b01a40 R14: 0000000000000286 R15: 0000000000000007
FS:  00007fc868b35700(0000) GS:ffff880041200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000011e327000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process bash (pid: 2167, threadinfo ffff88011ec02000, task ffff88011d821500)
Stack:
 ffff88011ec03e68 ffffffff8134b7d2 ffff88011d821500 ffff880100000000
<d> 0000000000000300 0000000000000002 ffff88007ea9de00 00007fc868b43000
<d> 0000000000000002 fffffffffffffffb ffff88011ec03e98 ffffffff8134b88e
Call Trace:
 [<ffffffff8134b7d2>] __handle_sysrq+0x132/0x1a0
 [<ffffffff8134b88e>] write_sysrq_trigger+0x4e/0x50
 [<ffffffff811f2f1e>] proc_reg_write+0x7e/0xc0
 [<ffffffff81188c38>] vfs_write+0xb8/0x1a0
 [<ffffffff81189531>] sys_write+0x51/0x90
 [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Code: d0 88 81 a3 2c fe 81 c9 c3 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 0f 1f 44 00 00 c7 05 bd 08 75 00 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c9 c3 55 48 89 e5 0f 1f 44 00 00 8d 47 
RIP  [<ffffffff8134b516>] sysrq_handle_crash+0x16/0x20
 RSP <ffff88011ec03e18>
CR2: 0000000000000000

2.2.with qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg.x86_64.rpm command line as comment0.

result:
..........
Creating Remain Block Devices
Making device-mapper control node
Scanning logical volumes
  Reading all physical volumes.  This may take a while...
  Found volume group "VolGroup" using metadata type lvm2
Activating logical volumes
  2 logical volume(s) in volume group "VolGroup" now active
Free memory/Total memory (free %): 74152 / 114548 ( 64.7344 )
Saving to the local filesystem UUID=116db5b7-d23e-4327-8bb8-d7f0fe76ed79
e2fsck 1.41.12 (17-May-2010)
/dev/mapper/VolGroup-LogVol_root: recovering journal
/dev/mapper/VolGroup-LogVol_root: clean, 133481/1015808 files, 948804/4063232 blocks
EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: 
Free memory/Total memory (free %): 72780 / 114548 ( 63.5367 )
Loading SELINUX policy
type=1404 audit(1397777273.190:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
type=1403 audit(1397777273.767:3): policy loaded auid=4294967295 ses=4294967295
Saving vmcore-dmesg.txt
Saved vmcore-dmesg.txt
Copying data                       : [100 %] 
Saving core complete
Restarting system.
machine restart

so, If according to qemu-kvm command line as comment 0 & qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg.x86_64.rpm. then guest restart automatically after the vmcore is created.

If according to full qemu-kvm command line(in attachment) & qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg.x86_64.rpm, then will hit call trace.

QE will continue debug this issue with full qemu-kvm command line.
Comment 18 FuXiangChun 2014-04-17 08:37:45 UTC 
Created attachment 887091 [details]
full-command-line
Comment 20 huiqingding 2014-04-22 08:36:56 UTC 
Version-Release number of selected component (if applicable):
rhel6 host:
qemu-kvm-0.12.1.2-2.424.el6.x86_64
2.6.32-459.el6.x86_64

rhel7 host:
qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64
3.10.0-121.el7.x86_64

rhel6.5 guest kernel:
2.6.32-431.el6.x86_64

Tested steps:
1. boot a rhel6.5 guest
#/usr/libexec/qemu-kvm  -M rhel6.5.0 -cpu Westmere,hv_relaxed -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1,maxcpus=160 -k en-us -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5 -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1 -device ich9-usb-uhci1,id=usb1,addr=0x11 -device usb-tablet,id=input0 -device usb-mouse,id=input1 -monitor stdio -serial unix:/tmp/monitor,server,nowait -net none -vnc :1
2. do migration from rhel6.5 host to rhel7.0 host
(qemu) migrate -d tcp:$des-ip:5800
3. inside guest, trigger kernel panic inside guest
# echo c >/proc/sysrq-trigger

Actual results:
after step3, guest can create vmcore file , guest restart automatically after vmcore is created.

Additional info:
Use the command line of comment18, when creating vmcore file, hit call trace as the attchment file.
Comment 21 huiqingding 2014-04-22 08:38:45 UTC 
Created attachment 888384 [details]
call trace log after migration and trigger kernel panic
Comment 22 Laszlo Ersek 2014-04-22 09:03:36 UTC 
Thank you. This looks like more of the same :)

I'm noticing the following: the full command line in comment 18 specifies three network devices:
- virtio-net-pci
- e1000
- rtl8139

In the crashkernel boot log (comment 21):
  Loading e1000.ko module
  ...
  Loading virtio_net.ko module
  ...
  Loading 8139cp.ko module
  irq 11: nobody cared (try booting with the "irqpoll" option)

This seems to imply the same problem as with the ICH9-UHCI[123] controllers -- different PCI interrupt pin assignments; but this time triggered by rtl8139.

Please attach the following files:
(1) Boot the guest (command line as in comment 18) on the RHEL-6.5 source host. Once it has booted to the login prompt, please save the complete dmesg and upload it. Please also upload the contents of the /proc/interrupts file.
(2) Boot the guest (command line as in comment 18) *afresh* (ie. *not* after migration) on the RHEL-7.0 target host. Please upload the same two files (full dmesg and /proc/interrupts).

It is very important that the same command line be used for (1) and (2).

Thanks.
Comment 23 juzhang 2014-04-22 09:07:44 UTC 
Hi Huding,

Can you have a look comment22 and update it?

Best Regards,
Junyi
Comment 24 huiqingding 2014-04-22 09:41:25 UTC 
> Please attach the following files:
> (1) Boot the guest (command line as in comment 18) on the RHEL-6.5 source
> host. Once it has booted to the login prompt, please save the complete dmesg
> and upload it. Please also upload the contents of the /proc/interrupts file.
> (2) Boot the guest (command line as in comment 18) *afresh* (ie. *not* after
> migration) on the RHEL-7.0 target host. Please upload the same two files
> (full dmesg and /proc/interrupts).
> 

I use the same command line (comment 18) to boot a rhel6.5-64 guest on rhel6.5 host and rhel7.0 host. About the log file, please refer to the attchment files.
Comment 25 huiqingding 2014-04-22 09:42:03 UTC 
Created attachment 888419 [details]
dmesg log on rhel6.5 host
Comment 26 huiqingding 2014-04-22 09:42:41 UTC 
Created attachment 888420 [details]
/proc/interrupts on rhel6.5 host
Comment 27 huiqingding 2014-04-22 09:43:19 UTC 
Created attachment 888421 [details]
dmesg log on rhel7.0 host
Comment 28 huiqingding 2014-04-22 09:43:58 UTC 
Created attachment 888423 [details]
/proc/interrupts on rhel7.0 host
Comment 29 Laszlo Ersek 2014-04-22 13:53:34 UTC 
Thank you.

Unfortunately (for the analysis anyway...) I can't find anything wrong, by comparing the dmesgs and /proc/interrupts files. I'd like to ask for two things:

- Please reproduce the problem (ie. migration + sysrq + kdump) with the command line in comment 18, and upload the full dmesg of the kdump kernel.

I'm asking this because the log attached to comment 21 is not detailed enough, and because the log in comment 14, although detailed, was not captured on a host that had the UHCI patch too (plus the qemu command line used then may not even have matched comment 18).

- Similarly to bug 1027565 comment 64, please start removing devices from the command line visible in comment 18, one by one. IOW please try to narrow it down as much as possible. If you find that removal of a specific device makes the problem in the kdump kernel go away, please don't stop removing further (other) devices. Ideally we should end up with a command line where all specified devices are necessary to trigger the problem. Thank you.

(I realize this is a lot of work, but I only have a RHEL-6/RHEL-7 dual-boot laptop on me ATM, so in order to test migration with different command lines, I have to reboot the laptop twice, using savevm after booting RHEL-6 and loadvm after booting RHEL-7. For a specific suspect this is OK, but for narrowing down the set it's very wasteful.)
Comment 30 Radim Krčmář 2014-04-22 14:49:04 UTC 
Paolo recommended disabling in-kernel-irqchip, but it seems we only hit the hang-after-reboot bug, which Laszlo already solved, at that time.
Can you reproduce the nobody-cared trace without in-kernel-irqchip?

Thanks.

(I was able to reproduce the issue from bug 1027565 by live migrating between rhel6 and rhel7 qemu over tcp loopback -- kvm might not matter in this case either, and it would be good to know if it does.)
Comment 31 Laszlo Ersek 2014-04-22 20:49:52 UTC 
(In reply to huiqingding from comment #20)

> Actual results:
> after step3, guest can create vmcore file , guest restart automatically
> after vmcore is created.
>
> Additional info:
> Use the command line of comment18, when creating vmcore file, hit call
> trace as the attchment file.

(In reply to huiqingding from comment #21)
> Created attachment 888384 [details]
> call trace log after migration and trigger kernel panic

I'm unable to reproduce this issue, using the following command line --
kdump works correctly on the target host
(qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64):

/usr/libexec/qemu-kvm \
  -S \
  -M rhel6.5.0 \
  -enable-kvm \
  -m 1024 \
  -smp 4 \
  -drive if=none,cache=none,media=disk,id=disk1,format=qcow2,werror=stop,rerror=stop,file=$HOME/tmp/rhel650.qcow2 \
  -device virtio-blk-pci,drive=disk1,bootindex=1,addr=0x7 \
  -drive if=none,cache=none,media=cdrom,id=cd1,format=raw,file=/mnt/data/isos/RHEL6.5-20131111.0-Server-x86_64-DVD1.iso \
  -device ide-drive,bus=ide.1,unit=0,drive=cd1,bootindex=2 \
  -monitor stdio \
  -nodefaults \
  -nodefconfig \
  -vnc :0 \
  -vga qxl -global qxl-vga.vram_size=33554432 \
  -usbdevice tablet \
  -usbdevice mouse \
  -device ich9-usb-uhci1,addr=0x11 \
  -debugcon file:debug.log -global isa-debugcon.iobase=0x402 \
  -global PIIX4_PM.disable_s3=0 \
  -global PIIX4_PM.disable_s4=0 \
  -device virtio-balloon-pci,indirect_desc=on,event_idx=on,multifunction=on,rombar=100,addr=0x5 \
  -serial unix:/tmp/serial,server,nowait \
  -netdev user,id=net0,net=10.0.2.0/24,hostfwd=tcp:127.0.0.1:2222-:22 \
  -device virtio-net-pci,netdev=net0,multifunction=on,status=on,gso=on,ioeventfd=on,vectors=8,indirect_desc=off,event_idx=off,guest_tso4=off,guest_tso6=on,guest_ecn=off,guest_ufo=on,host_tso4=off,host_tso6=on,host_ecn=on,mrg_rxbuf=off,ctrl_vq=on,host_ufo=on,mrg_rxbuf=on,ctrl_rx=on,ctrl_vlan=on,ctrl_rx_extra=on,ctrl_mac_addr=on,addr=0x9 \
  -netdev user,id=net1,net=10.0.3.0/24 \
  -device e1000,netdev=net1,multifunction=off,addr=0xa \
  -netdev user,id=net2,net=10.0.4.0/24 \
  -device rtl8139,netdev=net2,multifunction=off,addr=0xb \
  -global pvpanic.ioport=0x0505 \
  -soundhw ac97 \
  -device virtio-serial-pci,id=virtio-serial0,max_ports=16,vectors=0,addr=0x4 \
  -device intel-hda,id=sound0,addr=0x6 -device hda-duplex,bus=sound0.0,cad=0 \
  -device virtio-scsi-pci,id=scsi0,vectors=16,indirect_desc=on,event_idx=off,hotplug=on,param_change=off,num_queues=1,max_sectors=512,cmd_per_lun=16,multifunction=on,rombar=64,addr=0x13 \
  -rtc base=utc \
  -no-kvm-irqchip

The above parameters apparently suffice to establish the same PCI devices
and /proc/interrupts contents as listed in comment 25 / command 26. I can't
reproduce the "nobody cared" problem in the crashkernel however, the dump
file is written alright and the VM is rebooted.

(Also note the last param: -no-kvm-irqchip.)

Please try to narrow down the options in comment 18 as far as possible, for
a minimal reproducer. Thanks!
Comment 32 juzhang 2014-04-23 01:58:29 UTC 
Hi Huding, 

Can you have a look comment29 and comment31 and add your comment?

Best Regards,
Junyi
Comment 33 huiqingding 2014-04-23 07:27:06 UTC 
Not do migration, on rhel7.0 host, boot a rhel6.5-64 gust with virtio-balloon, "-usbdevice tablet", e1000 and rtl8139, do sysrq, guest hang, not reboot automatically, can not create vmcore file.

I test "qemu-img-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64" and "qemu-img-1.5.3-60.el7", two machine types: "-M rhel6.5.0/pc-i440fx-rhel7.0.0", the results are same and all failed.

The command line is as following:
/usr/libexec/qemu-kvm \
  -M pc 
  -cpu Westmere,hv_relaxed 
  -enable-kvm  \
  -m 4096 -smp 4,sockets=2,cores=2,threads=1 \
  -nodefconfig \
  -nodefaults \
  -monitor stdio \
  -name test-all-qemu-kvm-option \
  -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5,indirect_desc=on,event_idx=on,multifunction=on,rombar=100 \
  -usbdevice tablet \
  -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 \
  -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1,physical_block_size=512,logical_block_size=512,multifunction=on,scsi=on,event_idx=on,indirect_desc=on,vectors=32,x-data-plane=off,ioeventfd=on,serial=fuxc,discard_granularity=1,min_io_size=4096,opt_io_size=4096 \
  -netdev tap,id=hostnet1,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net1 \
  -device e1000,netdev=hostnet1,id=virtio-net-pci1,mac=00:01:02:03:04:06,bus=pci.0,addr=0xa,multifunction=off \
  -netdev tap,id=hostnet2,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net-rtl8139 \
  -device rtl8139,netdev=hostnet2,id=virtio-net-pci2,mac=00:01:02:03:04:07,bus=pci.0,addr=0xb,multifunction=off -serial unix:/tmp/monitor2,server,nowait \
  -vga qxl \
  -vnc :1

After do sysrq, the log of serial console, please refer to the attachment file.
Comment 34 huiqingding 2014-04-23 07:38:16 UTC 
Created attachment 888788 [details]
call trace log after sysrq
Comment 35 Laszlo Ersek 2014-04-23 12:55:34 UTC 
Huiqing Ding,

you've done an awesome job! Your results in comment 33 and comment 34 let us
separate this issue from migration completely. It's apparently an rtl8139
emulation problem in RHEL-7 qemu-kvm, which is independent of machine type
(rhel6.5.0 vs. pc-i440fx-rhel7.0.0) and also independent of migration.

Let us do the following:

(1) Let's re-scope this bug for rtl8139. From the extremely valuable
crashkernel dmesg in comment 34, my take is the following:
- The normal kernel brings up rtl8139 just fine.
- The normal kernel crashes without bringing down rtl8139. Hence rtl8139
  remains "live" in RHEL-7 qemu-kvm.
- The crashkernel loads the rtl8139 driver module, which starts to poke at
  the NIC's PCI config space (trying to interrogate / configure it).
- However, since the card is still "live" in the emulator (RHEL-7 qemu-kvm),
  this poking at the PCI config space somehow makes the NIC inject an
  interrupt (originally configured by the normal kernel!), *before* the
  crashkernel's driver has a chance to actually program the interrupt and
  set up a handler for it.

Actually, from the acpi_pci_irq_enable() call frame on the stack, my idea is
that the driver is in the middle of setting up the interrupt for the NIC,
but the interrupt (maybe pending from earlier, from the normal kernel?) hits
unexpectedly early, before the driver gets to register the handler.

It could even be a RHEL-6.5 guest kernel issue; with the 8139cp driver
*first* unmasking / enabling the interrupt, and *then* setting up a handler
for it. Normally no interrupt should be pending during driver
initialization, but the crashkernel is special in this regard.

Wow... Look at this RHEL-6 kernel commit:

  commit 74b0cc81ddd171e28806ea1e080cfe945e76a24e
  Author: Jason Wang <jasowang>
  Date:   Mon Sep 17 04:32:46 2012 -0400

      [netdrv] 8139cp: set intr mask after its handler is registered

      Message-id: <1347856366-35950-1-git-send-email-jasowang>
      Patchwork-id: 51105
      O-Subject: [RHEL6.4 PATCH] 8139cp: set intr mask after its handler is
                                 registered
      Bugzilla: 815199
      RH-Acked-by: Thomas Graf <tgraf>
      RH-Acked-by: Jiri Pirko <jpirko>
      RH-Acked-by: Jeff Garzik <jgarzik>

      bugzilla: 815199
      brew build: https://brewweb.devel.redhat.com/taskinfo?taskID=4867409
      upstream: manually cherry pick from
                a8c9cb106fe79c28d6b7f1397652cadd228715ff
      test status: tested locally

      We set intr mask before its handler is registered, this does not work
      well when 8139cp is sharing irq line with other devices. As the irq
      could be enabled by the device before 8139cp's hander is registered
      which may lead unhandled irq. Fix this by introducing an helper
      cp_irq_enable() and call it after request_irq().

      Signed-off-by: Jason Wang <jasowang>
      Signed-off-by: Jarod Wilson <jarod>

This commit (already built into the RHEL-6.4 kernel) should have prevented
this issue in my opinion. CC'ing Jason for help.

Ah... I think I understand. The commit quoted above delays the unmasking of
the interrupt until after the handler is registered. However I think it
doesn't expect that the interrupt may have been already unmasked. (Because
the normal kernel did that.)

So, I think the 8139cp driver should mask the interrupt explicitly, before
doing anything else. Jason, what do you think? Thanks!


(2) I've just realized we don't need to file a new BZ for the ICH9-UHCI[123]
migration problem that has been:
- described in bug 1027565 comment 64 - 66,
- analyzed and fixed in bug 1027565 comment 68, 70 and 71,
- verified preliminarily in bug 1027565 comment 74

because you already pointed out (in bug 1027565 comment 65) the BZ that was
dedicated to this issue: bug 1085701.

Hence, I'm taking bug 1085701, and posting my patch in bug 1027565 comment
71 for it.

Thanks!
Laszlo
Comment 37 jason wang 2014-04-24 05:44:04 UTC 
(In reply to Laszlo Ersek from comment #35)
> Huiqing Ding,
> 
> you've done an awesome job! Your results in comment 33 and comment 34 let us
> separate this issue from migration completely. It's apparently an rtl8139
> emulation problem in RHEL-7 qemu-kvm, which is independent of machine type
> (rhel6.5.0 vs. pc-i440fx-rhel7.0.0) and also independent of migration.
> 
> Let us do the following:
> 
> (1) Let's re-scope this bug for rtl8139. From the extremely valuable
> crashkernel dmesg in comment 34, my take is the following:
> - The normal kernel brings up rtl8139 just fine.
> - The normal kernel crashes without bringing down rtl8139. Hence rtl8139
>   remains "live" in RHEL-7 qemu-kvm.
> - The crashkernel loads the rtl8139 driver module, which starts to poke at
>   the NIC's PCI config space (trying to interrogate / configure it).
> - However, since the card is still "live" in the emulator (RHEL-7 qemu-kvm),
>   this poking at the PCI config space somehow makes the NIC inject an
>   interrupt (originally configured by the normal kernel!), *before* the
>   crashkernel's driver has a chance to actually program the interrupt and
>   set up a handler for it.
> 
> Actually, from the acpi_pci_irq_enable() call frame on the stack, my idea is
> that the driver is in the middle of setting up the interrupt for the NIC,
> but the interrupt (maybe pending from earlier, from the normal kernel?) hits
> unexpectedly early, before the driver gets to register the handler.
> 
> It could even be a RHEL-6.5 guest kernel issue; with the 8139cp driver
> *first* unmasking / enabling the interrupt, and *then* setting up a handler
> for it. Normally no interrupt should be pending during driver
> initialization, but the crashkernel is special in this regard.
> 
> Wow... Look at this RHEL-6 kernel commit:
> 
>   commit 74b0cc81ddd171e28806ea1e080cfe945e76a24e
>   Author: Jason Wang <jasowang>
>   Date:   Mon Sep 17 04:32:46 2012 -0400
> 
>       [netdrv] 8139cp: set intr mask after its handler is registered
> 
>       Message-id: <1347856366-35950-1-git-send-email-jasowang>
>       Patchwork-id: 51105
>       O-Subject: [RHEL6.4 PATCH] 8139cp: set intr mask after its handler is
>                                  registered
>       Bugzilla: 815199
>       RH-Acked-by: Thomas Graf <tgraf>
>       RH-Acked-by: Jiri Pirko <jpirko>
>       RH-Acked-by: Jeff Garzik <jgarzik>
> 
>       bugzilla: 815199
>       brew build: https://brewweb.devel.redhat.com/taskinfo?taskID=4867409
>       upstream: manually cherry pick from
>                 a8c9cb106fe79c28d6b7f1397652cadd228715ff
>       test status: tested locally
> 
>       We set intr mask before its handler is registered, this does not work
>       well when 8139cp is sharing irq line with other devices. As the irq
>       could be enabled by the device before 8139cp's hander is registered
>       which may lead unhandled irq. Fix this by introducing an helper
>       cp_irq_enable() and call it after request_irq().
> 
>       Signed-off-by: Jason Wang <jasowang>
>       Signed-off-by: Jarod Wilson <jarod>
> 
> This commit (already built into the RHEL-6.4 kernel) should have prevented
> this issue in my opinion. CC'ing Jason for help.
> 
> Ah... I think I understand. The commit quoted above delays the unmasking of
> the interrupt until after the handler is registered. However I think it
> doesn't expect that the interrupt may have been already unmasked. (Because
> the normal kernel did that.)
> 
> So, I think the 8139cp driver should mask the interrupt explicitly, before
> doing anything else. Jason, what do you think? Thanks!
> 

Not sure it was the root cause. Since 8139cp driver mask all interrupts during very early stage of probing. We may try to reproduce on real hardware to see if it work.

For QE, please try and check:

- Try to reproduce on a real 8139cp hardware to see whether it was a bug of qemu
- Try to let e1000 share an irq with other device such as usb (you can probably do this through booting a guest with two e1000 nics), and then try to reproduce the issue to see if it still exist. 

Thanks
Comment 38 huiqingding 2014-04-24 07:28:28 UTC 
> - Try to let e1000 share an irq with other device such as usb (you can
> probably do this through booting a guest with two e1000 nics), and then try
> to reproduce the issue to see if it still exist. 

Boot a rhel6.5-64 guest with two e1000 nics, e1000 share an irq with usb device and do sysrq, all hit call trace.
The command line is as following:
/usr/libexec/qemu-kvm \
  -M rhel6.5.0 \
  -cpu Westmere,hv_relaxed \
  -enable-kvm  \
  -m 4096 -smp 4,sockets=2,cores=2,threads=1 \
  -nodefconfig \
  -nodefaults \
  -monitor stdio \
  -name test-all-qemu-kvm-option \
  -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5,indirect_desc=on,event_idx=on,multifunction=on,rombar=100 \
  -usbdevice tablet \
  -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 \
  -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1,physical_block_size=512,logical_block_size=512,multifunction=on,scsi=on,event_idx=on,indirect_desc=on,vectors=32,x-data-plane=off,ioeventfd=on,serial=fuxc,discard_granularity=1,min_io_size=4096,opt_io_size=4096 \
  -netdev tap,id=hostnet1,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net1 \
  -device e1000,netdev=hostnet1,id=virtio-net-pci1,mac=00:01:02:03:04:06,bus=pci.0,addr=0xa,multifunction=off \
  -netdev tap,id=hostnet2,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net-rtl8139 \
  -device e1000,netdev=hostnet2,id=virtio-net-pci2,mac=00:01:02:03:04:07,bus=pci.0,addr=0xb,multifunction=off -serial unix:/tmp/monitor2,server,nowait \
  -vga qxl \
  -vnc :1

The /proc/interrupts inside guest is as following:
# cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
  0:        128          0          0          0   IO-APIC-edge      timer
  1:          6          0          0          0   IO-APIC-edge      i8042
  4:        111          0          0          0   IO-APIC-edge      serial
  8:          0          0          0          0   IO-APIC-edge      rtc0
  9:          0          0          0          0   IO-APIC-fasteoi   acpi
 10:        526          0          0          0   IO-APIC-fasteoi   virtio0, eth0
 11:         85        318          0          0   IO-APIC-fasteoi   uhci_hcd:usb1, eth1
 12:        104          0          0          0   IO-APIC-edge      i8042
 14:          0          0          0          0   IO-APIC-edge      ata_piix
 15:          0          0          0          0   IO-APIC-edge      ata_piix
 24:          0          0          0          0   PCI-MSI-edge      virtio1-config
 25:       4768          0          0          0   PCI-MSI-edge      virtio1-requests
NMI:          0          0          0          0   Non-maskable interrupts
LOC:      11283       7137       6559       4932   Local timer interrupts
SPU:          0          0          0          0   Spurious interrupts
PMI:          0          0          0          0   Performance monitoring interrupts
IWI:          0          0          0          0   IRQ work interrupts
RES:       1230       1925       2004       1587   Rescheduling interrupts
CAL:         76        179        124        185   Function call interrupts
TLB:        578        859        694        716   TLB shootdowns
TRM:          0          0          0          0   Thermal event interrupts
THR:          0          0          0          0   Threshold APIC interrupts
MCE:          0          0          0          0   Machine check exceptions
MCP:          1          1          1          1   Machine check polls
ERR:          0
MIS:          4

After do sysrq, the log of call trace is as the attchment file.
Comment 39 huiqingding 2014-04-24 07:29:34 UTC 
Created attachment 889195 [details]
call trace log of two e1000 nics and sysrq
Comment 42 huiqingding 2014-04-24 08:49:31 UTC 
(In reply to jason wang from comment #37)
> (In reply to Laszlo Ersek from comment #35)
> > Huiqing Ding,
> > 
> > you've done an awesome job! Your results in comment 33 and comment 34 let us
> > separate this issue from migration completely. It's apparently an rtl8139
> > emulation problem in RHEL-7 qemu-kvm, which is independent of machine type
> > (rhel6.5.0 vs. pc-i440fx-rhel7.0.0) and also independent of migration.
> > 
> > Let us do the following:
> > 
> > (1) Let's re-scope this bug for rtl8139. From the extremely valuable
> > crashkernel dmesg in comment 34, my take is the following:
> > - The normal kernel brings up rtl8139 just fine.
> > - The normal kernel crashes without bringing down rtl8139. Hence rtl8139
> >   remains "live" in RHEL-7 qemu-kvm.
> > - The crashkernel loads the rtl8139 driver module, which starts to poke at
> >   the NIC's PCI config space (trying to interrogate / configure it).
> > - However, since the card is still "live" in the emulator (RHEL-7 qemu-kvm),
> >   this poking at the PCI config space somehow makes the NIC inject an
> >   interrupt (originally configured by the normal kernel!), *before* the
> >   crashkernel's driver has a chance to actually program the interrupt and
> >   set up a handler for it.
> > 
> > Actually, from the acpi_pci_irq_enable() call frame on the stack, my idea is
> > that the driver is in the middle of setting up the interrupt for the NIC,
> > but the interrupt (maybe pending from earlier, from the normal kernel?) hits
> > unexpectedly early, before the driver gets to register the handler.
> > 
> > It could even be a RHEL-6.5 guest kernel issue; with the 8139cp driver
> > *first* unmasking / enabling the interrupt, and *then* setting up a handler
> > for it. Normally no interrupt should be pending during driver
> > initialization, but the crashkernel is special in this regard.
> > 
> > Wow... Look at this RHEL-6 kernel commit:
> > 
> >   commit 74b0cc81ddd171e28806ea1e080cfe945e76a24e
> >   Author: Jason Wang <jasowang>
> >   Date:   Mon Sep 17 04:32:46 2012 -0400
> > 
> >       [netdrv] 8139cp: set intr mask after its handler is registered
> > 
> >       Message-id: <1347856366-35950-1-git-send-email-jasowang>
> >       Patchwork-id: 51105
> >       O-Subject: [RHEL6.4 PATCH] 8139cp: set intr mask after its handler is
> >                                  registered
> >       Bugzilla: 815199
> >       RH-Acked-by: Thomas Graf <tgraf>
> >       RH-Acked-by: Jiri Pirko <jpirko>
> >       RH-Acked-by: Jeff Garzik <jgarzik>
> > 
> >       bugzilla: 815199
> >       brew build: https://brewweb.devel.redhat.com/taskinfo?taskID=4867409
> >       upstream: manually cherry pick from
> >                 a8c9cb106fe79c28d6b7f1397652cadd228715ff
> >       test status: tested locally
> > 
> >       We set intr mask before its handler is registered, this does not work
> >       well when 8139cp is sharing irq line with other devices. As the irq
> >       could be enabled by the device before 8139cp's hander is registered
> >       which may lead unhandled irq. Fix this by introducing an helper
> >       cp_irq_enable() and call it after request_irq().
> > 
> >       Signed-off-by: Jason Wang <jasowang>
> >       Signed-off-by: Jarod Wilson <jarod>
> > 
> > This commit (already built into the RHEL-6.4 kernel) should have prevented
> > this issue in my opinion. CC'ing Jason for help.
> > 
> > Ah... I think I understand. The commit quoted above delays the unmasking of
> > the interrupt until after the handler is registered. However I think it
> > doesn't expect that the interrupt may have been already unmasked. (Because
> > the normal kernel did that.)
> > 
> > So, I think the 8139cp driver should mask the interrupt explicitly, before
> > doing anything else. Jason, what do you think? Thanks!
> > 
> 
> Not sure it was the root cause. Since 8139cp driver mask all interrupts
> during very early stage of probing. We may try to reproduce on real hardware
> to see if it work.
> 
> For QE, please try and check:
> 
> - Try to reproduce on a real 8139cp hardware to see whether it was a bug of
> qemu

Sorry, now I cannot find 8139cp hardware. If I can find it, I will test and update the result.

> - Try to let e1000 share an irq with other device such as usb (you can
> probably do this through booting a guest with two e1000 nics), and then try
> to reproduce the issue to see if it still exist. 
> 
> Thanks
Comment 43 Laszlo Ersek 2014-04-24 09:32:23 UTC 
(In reply to huiqingding from comment #39)
> Created attachment 889195 [details]
> call trace log of two e1000 nics and sysrq

This was a useful test again, thanks. There's only one UHCI controller this time, and it's not ICH9-UHCI[123] (and we didn't migrate). It's "piix3-usb-uhci", at 0000:00:01.2.

The call trace is interesting. It looks very similar to the previous one, just the outermost calls have changed from the 8139cp module to e1000. It looks common from acpi_pci_irq_enable() up.

Apparently, bringup of e1000 *and* 8139cp both, in the VM's crashkernel, triggers an unexpected interrupt that nothing else "listening" on IRQ11 (in this case, piix3-usb-uhci) will claim/handle.

I don't understand the following part of the call stack:

 [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
 [<ffffffff8130258d>] ? acpi_ex_pci_config_space_handler+0x0/0x55
 [<ffffffff8107a795>] ? irq_exit+0x85/0x90
 [<ffffffff815310aa>] ? smp_apic_timer_interrupt+0x4a/0x60
 [<ffffffff8100bb93>] ? apic_timer_interrupt+0x13/0x20
 <EOI>  [<ffffffff8152a357>] ? _spin_unlock_irqrestore+0x17/0x20
 [<ffffffff8144081c>] ? pci_conf1_write+0xbc/0xe0
 [<ffffffff81442894>] ? raw_pci_write+0x24/0x50
 [<ffffffff812ec342>] ? acpi_os_write_pci_configuration+0x60/0x6a

What does this mean? Looks as if the handling of the timer interrupt was interleaved with the NIC's interrupt configuration. Did the timer irq handler unmask the NIC's irq too early (while the NIC driver was in the middle of setting up its own handler)?

CC'ing Prarit... :)
Comment 44 Laszlo Ersek 2014-04-24 10:06:14 UTC 
Here's a diff between the crashkernel call traces in comment 34 and comment
39:

--- 8139cp.txt  2014-04-24 11:36:06.549131453 +0200
+++ e1000.txt   2014-04-24 11:35:48.181009275 +0200
@@ -1,75 +1,81 @@
-Loading 8139cp.ko module
-8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
+Loading e1000.ko module
+e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
+e1000: Copyright (c) 1999-2006 Intel Corporation.
+ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
+e1000 0000:00:0a.0: PCI INT A -> Link[LNKB] -> GSI 10 (level, high) -> IRQ 10
+e1000 0000:00:0a.0: eth0: (PCI:33MHz:32-bit) 00:01:02:03:04:06
+e1000 0000:00:0a.0: eth0: Intel(R) PRO/1000 Network Connection
 irq 11: nobody cared (try booting with the "irqpoll" option)
-Pid: 183, comm: insmod Not tainted 2.6.32-431.el6.x86_64 #1
+Pid: 123, comm: insmod Not tainted 2.6.32-431.el6.x86_64 #1
 Call Trace:
  <IRQ>  [<ffffffff810e8feb>] ? __report_bad_irq+0x2b/0xa0
  [<ffffffff810e91ec>] ? note_interrupt+0x18c/0x1d0
  [<ffffffff810e998d>] ? handle_fasteoi_irq+0xcd/0xf0
  [<ffffffff8100faf9>] ? handle_irq+0x49/0xa0
  [<ffffffff81530fdc>] ? do_IRQ+0x6c/0xf0
  [<ffffffff8100b9d3>] ? ret_from_intr+0x0/0x11
  [<ffffffff8107a893>] ? __do_softirq+0x73/0x1e0
  [<ffffffff810ac9ca>] ? tick_program_event+0x2a/0x30
  [<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
  [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
  [<ffffffff8130258d>] ? acpi_ex_pci_config_space_handler+0x0/0x55
  [<ffffffff8107a795>] ? irq_exit+0x85/0x90
  [<ffffffff815310aa>] ? smp_apic_timer_interrupt+0x4a/0x60
  [<ffffffff8100bb93>] ? apic_timer_interrupt+0x13/0x20
  <EOI>  [<ffffffff8152a357>] ? _spin_unlock_irqrestore+0x17/0x20
  [<ffffffff8144081c>] ? pci_conf1_write+0xbc/0xe0
  [<ffffffff81442894>] ? raw_pci_write+0x24/0x50
  [<ffffffff812ec342>] ? acpi_os_write_pci_configuration+0x60/0x6a
  [<ffffffff813025db>] ? acpi_ex_pci_config_space_handler+0x4e/0x55
  [<ffffffff812fb146>] ? acpi_ev_address_space_dispatch+0x170/0x1be
  [<ffffffff811422b9>] ? zone_statistics+0x99/0xc0
  [<ffffffff812ffa75>] ? acpi_ex_access_region+0x235/0x242
- [<ffffffff811422b9>] ? zone_statistics+0x99/0xc0
  [<ffffffff812ffb79>] ? acpi_ex_field_datum_io+0xf7/0x189
  [<ffffffff812ffe67>] ? acpi_ex_write_with_update_rule+0xb5/0xc0
  [<ffffffff81300030>] ? acpi_ex_insert_into_field+0x1be/0x1e2
  [<ffffffff812fe638>] ? acpi_ex_write_data_to_field+0x1a4/0x1c2
  [<ffffffff813028b3>] ? acpi_ex_store_object_to_node+0xa3/0xe6
  [<ffffffff812f9519>] ? acpi_ds_create_operand+0x1f7/0x20a
  [<ffffffff81302aa2>] ? acpi_ex_store+0xc3/0x255
  [<ffffffff813008cc>] ? acpi_ex_opcode_1A_1T_1R+0x361/0x4bc
  [<ffffffff813010ee>] ? acpi_ex_resolve_operands+0x1f2/0x4d4
  [<ffffffff812f820b>] ? acpi_ds_exec_end_op+0xef/0x3dc
  [<ffffffff8130a1aa>] ? acpi_ps_parse_loop+0x7c0/0x946
  [<ffffffff8116fe02>] ? kmem_cache_alloc+0x182/0x190
  [<ffffffff813092c0>] ? acpi_ps_parse_aml+0x9f/0x2de
  [<ffffffff8130aa38>] ? acpi_ps_execute_method+0x1e9/0x2b9
  [<ffffffff813061de>] ? acpi_ns_evaluate+0xe6/0x1ad
  [<ffffffff8130bd55>] ? acpi_rs_set_srs_method_data+0xe8/0x110
  [<ffffffff8130b857>] ? acpi_set_current_resources+0x3c/0x4a
  [<ffffffff812f3844>] ? acpi_pci_link_set+0x133/0x1f0
  [<ffffffff812f3d47>] ? acpi_pci_link_allocate_irq+0x146/0x217
  [<ffffffff812f40f2>] ? acpi_pci_irq_enable+0x8f/0x23a
  [<ffffffff812a8a8d>] ? pci_enable_resources+0x2d/0x180
  [<ffffffff81442a29>] ? pcibios_enable_device+0x39/0x40
  [<ffffffff812a2e9b>] ? do_pci_enable_device+0x4b/0x70
  [<ffffffff812a2f28>] ? __pci_enable_device_flags+0x68/0x80
  [<ffffffff812a2f53>] ? pci_enable_device+0x13/0x20
- [<ffffffffa0149754>] ? cp_init_one+0xf4/0x530 [8139cp]
- [<ffffffff8128460a>] ? kobject_get+0x1a/0x30
+ [<ffffffffa00d18d9>] ? e1000_probe+0x8d/0xe2a [e1000]
+ [<ffffffff81205e1e>] ? __sysfs_add_one+0x7e/0xc0
+ [<ffffffff81205e8c>] ? sysfs_add_one+0x2c/0xd0
  [<ffffffff812a4db7>] ? local_pci_probe+0x17/0x20
  [<ffffffff812a5fa1>] ? pci_device_probe+0x101/0x120
  [<ffffffff8136d712>] ? driver_sysfs_add+0x62/0x90
  [<ffffffff8136d8b0>] ? driver_probe_device+0xa0/0x2a0
  [<ffffffff8136db5b>] ? __driver_attach+0xab/0xb0
  [<ffffffff8136dab0>] ? __driver_attach+0x0/0xb0
  [<ffffffff8136ce64>] ? bus_for_each_dev+0x64/0x90
  [<ffffffff8136d64e>] ? driver_attach+0x1e/0x20
  [<ffffffff8136c698>] ? bus_add_driver+0x1e8/0x2b0
  [<ffffffff8136dea6>] ? driver_register+0x76/0x140
  [<ffffffff81527303>] ? printk+0x41/0x46
  [<ffffffff812a6206>] ? __pci_register_driver+0x56/0xd0
- [<ffffffffa014f000>] ? cp_init+0x0/0x35 [8139cp]
- [<ffffffffa014f033>] ? cp_init+0x33/0x35 [8139cp]
+ [<ffffffffa00e5000>] ? e1000_init_module+0x0/0x8d [e1000]
+ [<ffffffffa00e5054>] ? e1000_init_module+0x54/0x8d [e1000]
  [<ffffffff8100204c>] ? do_one_initcall+0x3c/0x1d0
  [<ffffffff810bc531>] ? sys_init_module+0xe1/0x250
  [<ffffffff8100b072>] ? system_call_fastpath+0x16/0x1b
 handlers:
 [<ffffffff813c3e00>] (usb_hcd_irq+0x0/0x90)
 Disabling IRQ #11

Huiqing Ding, can you please reproduce the issue, but use
"kernel-debug-2.6.32-431.el6.x86_64.rpm" in the guest? The debug kernel has
CONFIG_ACPI_DEBUG enabled, which might help us understand what
acpi_ex_pci_config_space_handler() writes where.

Please also pass the following command line params to the debug guest
kernel:

  ignore_loglevel acpi.debug_layer=0x00400080 acpi.debug_level=0x00000004

and rebuild the kdump image. Thank you.

(The debug layer corresponds to ACPI_PCI_COMPONENT | ACPI_EXECUTER, and the
debug level corresponds to ACPI_LV_INFO).
Comment 45 Laszlo Ersek 2014-04-24 10:08:37 UTC 
Ah, I think it's also necessary to rebuild the initrd. Thanks.
Comment 46 Laszlo Ersek 2014-04-24 12:17:50 UTC 
I tried to reproduce with the command line in comment 38; even adding ",enforce" to the -cpu option. I can't reproduce the problem.

This could be something specific to the host CPU. Comment 6 identified an AMD Phenom(tm) 9600B Quad-Core Processor as the host. Comment 8 confirmed the issue on an unidentified Intel host.
Comment 47 huiqingding 2014-04-25 06:17:02 UTC 
(In reply to Laszlo Ersek from comment #44)

> 
> Huiqing Ding, can you please reproduce the issue, but use
> "kernel-debug-2.6.32-431.el6.x86_64.rpm" in the guest? The debug kernel has
> CONFIG_ACPI_DEBUG enabled, which might help us understand what
> acpi_ex_pci_config_space_handler() writes where.
> 
> Please also pass the following command line params to the debug guest
> kernel:
> 
>   ignore_loglevel acpi.debug_layer=0x00400080 acpi.debug_level=0x00000004
> 
> and rebuild the kdump image. Thank you.
> 
> (The debug layer corresponds to ACPI_PCI_COMPONENT | ACPI_EXECUTER, and the
> debug level corresponds to ACPI_LV_INFO).

The version of qemu-kvm: 
qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64

Test steps:
1. boot a guest with one e1000 nic, one rtl8139 nic, usb device and balloon device
# /usr/libexec/qemu-kvm \
  -M rhel6.5.0 \
  -cpu Westmere,hv_relaxed \
  -enable-kvm  \
  -m 4096 -smp 4,sockets=2,cores=2,threads=1 \
  -nodefconfig \
  -nodefaults \
  -monitor stdio \
  -name test-all-qemu-kvm-option \
  -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5,indirect_desc=on,event_idx=on,multifunction=on,rombar=100 \
  -usbdevice tablet \
  -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 \
  -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1,physical_block_size=512,logical_block_size=512,multifunction=on,scsi=on,event_idx=on,indirect_desc=on,vectors=32,x-data-plane=off,ioeventfd=on,serial=fuxc,discard_granularity=1,min_io_size=4096,opt_io_size=4096 \
  -netdev tap,id=hostnet1,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net1 \
  -device e1000,netdev=hostnet1,id=virtio-net-pci1,mac=00:01:02:03:04:06,bus=pci.0,addr=0xa,multifunction=off \
  -netdev tap,id=hostnet2,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net-rtl8139 \
  -device rtl8139,netdev=hostnet2,id=virtio-net-pci2,mac=00:01:02:03:04:07,bus=pci.0,addr=0xb,multifunction=off -serial unix:/tmp/monitor2,server,nowait \
  -vga qxl \
  -vnc :1
2. install kernel-debug-2.6.32-431.el6.x86_64.rpm inside guest
3. add "ignore_loglevel acpi.debug_layer=0x00400080 acpi.debug_level=0x00000004" to guest kernel line
4. reboot guest and boot guest from kernel-debug-2.6.32-431.el6.x86_64
5. do sysrq inside guest
# echo c > /proc/sysrq-trigger

after step4, save dmesg info.
after step5, save the call trace log of serial console.
Comment 48 huiqingding 2014-04-25 06:36:38 UTC 
Created attachment 889530 [details]
guest demsg info with one rtl8139 and one e1000 and debug kernel
Comment 49 huiqingding 2014-04-25 06:37:47 UTC 
Created attachment 889531 [details]
sysrq call trace log of one e1000, one rtl8139 and debug kernel
Comment 50 huiqingding 2014-04-25 06:39:27 UTC 
The version of qemu-kvm: 
qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64

Test steps:
1. boot a guest with two e1000 nics, usb device and balloon device
# /usr/libexec/qemu-kvm \
  -M rhel6.5.0 \
  -cpu Westmere,hv_relaxed \
  -enable-kvm  \
  -m 4096 -smp 4,sockets=2,cores=2,threads=1 \
  -nodefconfig \
  -nodefaults \
  -monitor stdio \
  -name test-all-qemu-kvm-option \
  -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5,indirect_desc=on,event_idx=on,multifunction=on,rombar=100 \
  -usbdevice tablet \
  -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 \
  -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1,physical_block_size=512,logical_block_size=512,multifunction=on,scsi=on,event_idx=on,indirect_desc=on,vectors=32,x-data-plane=off,ioeventfd=on,serial=fuxc,discard_granularity=1,min_io_size=4096,opt_io_size=4096 \
  -netdev tap,id=hostnet1,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net1 \
  -device e1000,netdev=hostnet1,id=virtio-net-pci1,mac=00:01:02:03:04:06,bus=pci.0,addr=0xa,multifunction=off \
  -netdev tap,id=hostnet2,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net-rtl8139 \
  -device e1000,netdev=hostnet2,id=virtio-net-pci2,mac=00:01:02:03:04:07,bus=pci.0,addr=0xb,multifunction=off -serial unix:/tmp/monitor2,server,nowait \
  -vga qxl \
  -vnc :1
2. install kernel-debug-2.6.32-431.el6.x86_64.rpm inside guest
3. add "ignore_loglevel acpi.debug_layer=0x00400080 acpi.debug_level=0x00000004" to guest kernel line
4. reboot guest and boot guest from kernel-debug-2.6.32-431.el6.x86_64
5. do sysrq inside guest
# echo c > /proc/sysrq-trigger

after step4, save dmesg info.
after step5, save the call trace log of serial console.
Comment 51 huiqingding 2014-04-25 06:40:10 UTC 
Created attachment 889533 [details]
guest demsg info with two e1000 and debug kernel
Comment 52 huiqingding 2014-04-25 06:41:05 UTC 
Created attachment 889534 [details]
sysrq call trace log of two e1000 and debug kernel
Comment 55 Laszlo Ersek 2014-04-25 10:46:03 UTC 
Huding, my request for CONFIG_ACPI_DEBUG in comment 44, and your related answers, are useless. It is my fault. The CONFIG_ACPI_DEBUG option is disbled in the RHEL-6 kernel even for the debug flavor. I can't fathom why this is the case. I'm sorry for asking you to do a useless test. I'm out of ideas; hopefully Jason's comment 53 will allow us to get more info.
Comment 60 jason wang 2014-04-30 05:16:25 UTC 
Borrow the environment from QE:

Several findings:

1 After the hang
# grep "pin 11" /sys/kernel/debug/tracing/trace_pipe
        qemu-kvm-12980 [006] ....  2231.111590: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.111611: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.111735: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.111756: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.111901: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.112003: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.112033: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.112159: kvm_ack_irq: irqchip IOAPIC pin 11
        qemu-kvm-12980 [006] ....  2231.112180: kvm_ack_irq: irqchip IOAPIC pin 11
        ...

Interrupt storm were found for irq #11. This is the unhandled irq from rtl8139 and was re-injected to guest during ioapic EOI broadcast. That why note_interrupt() was called. But more interesting thing is that for note_interrupt() itself, it should try to disable irq through ioapic. But for some reasons the irq 11 was not disabled.

2 More interesting thing:
#  grep APPEND /etc/sysconfig/kdump
KDUMP_COMMANDLINE_APPEND="irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off"

If I replace nr_cpus=1 with max_cpus=1 the problem disappear. unlike "nr_cpus=1" , "max_cpus=1" will also bring up all other vcpus. But it was still unclear the difference of irq routing in those two cases.

So several things need to be investigated:

- whether or not we need some hack to avoid the interrupt storm. I post a patch to solve this in the past but was rejected. (https://lkml.org/lkml/2012/3/12/70). If we don't delay the interrupt injection during EOI, any unhandled irq will cause interrupt storm.
- why note_interrupt() fail to disable irq
- why max_cpus=1 works but nr_cpus=1 not
Comment 61 jason wang 2014-04-30 09:21:34 UTC 
n    (In reply to jason wang from comment #60)
> Borrow the environment from QE:
> 
> Several findings:
> 
> 1 After the hang
> # grep "pin 11" /sys/kernel/debug/tracing/trace_pipe
>         qemu-kvm-12980 [006] ....  2231.111590: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.111611: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.111735: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.111756: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.111901: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.112003: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.112033: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.112159: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         qemu-kvm-12980 [006] ....  2231.112180: kvm_ack_irq: irqchip IOAPIC
> pin 11
>         ...
> 
> Interrupt storm were found for irq #11. This is the unhandled irq from
> rtl8139 and was re-injected to guest during ioapic EOI broadcast. That why
> note_interrupt() was called. But more interesting thing is that for
> note_interrupt() itself, it should try to disable irq through ioapic. But
> for some reasons the irq 11 was not disabled.
> 
> 2 More interesting thing:
> #  grep APPEND /etc/sysconfig/kdump
> KDUMP_COMMANDLINE_APPEND="irqpoll nr_cpus=1 reset_devices
> cgroup_disable=memory mce=off"
> 
> If I replace nr_cpus=1 with max_cpus=1 the problem disappear. unlike
> "nr_cpus=1" , "max_cpus=1" will also bring up all other vcpus. But it was
> still unclear the difference of irq routing in those two cases.
> 
> So several things need to be investigated:
> 
> - whether or not we need some hack to avoid the interrupt storm. I post a
> patch to solve this in the past but was rejected.
> (https://lkml.org/lkml/2012/3/12/70). If we don't delay the interrupt
> injection during EOI, any unhandled irq will cause interrupt storm.
> - why note_interrupt() fail to disable irq

Find the answer, there no method for ioapic to disable an irq.

> - why max_cpus=1 works but nr_cpus=1 not

Well, seems I can reproduce with max_cpus = 1 occasionally.
Comment 62 jason wang 2014-04-30 09:31:26 UTC 
(In reply to huiqingding from comment #57)
> Created attachment 890299 [details]
> call trace log of noirq
> 
> (In reply to jason wang from comment #53)
> > Some thoughts:
> > 
> > To isolate the issue, may worth to try:
> > 
> > - To see if it was a acpi bug, please pass acpi=noirq to kdump kernel by
> > editting the /etc/sysconfig/kdump file and adding acpi=noirq to the
> > KDUMP_COMMANDLINE_APPEND variable. Then try to reproduce.
> > 
> 
> Test version:
> host qemu-kvm: qemu-kvm-1.5.3-60.el7.bz1027565_cdef_seg_ich_uhci.x86_64
> host kernel: kernel-3.10.0-121.el7.x86_64
> guest kernel: kernel-2.6.32-431.el6.x86_64
> 
> KDUMP_COMMANDLINE_APPEND of /etc/sysconfig/kdump is :
> KDUMP_COMMANDLINE_APPEND="irqpoll nr_cpus=1 reset_devices
> cgroup_disable=memory mce=off acpi=noirq"
> 
> do sysrq, the info of serial console is as the attachment file.

The trace is interesting:

 <IRQ> 
 [<ffffffff810ac9ca>] ? tick_program_event+0x2a/0x30
 [<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
 [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
 [<ffffffff8107a795>] ? irq_exit+0x85/0x90
 [<ffffffff815310aa>] ? smp_apic_timer_interrupt+0x4a/0x60
 [<ffffffff8100bb93>] ? apic_timer_interrupt+0x13/0x20
 <EOI> 
 [<ffffffff810ea6ba>] ? probe_irq_on+0x6a/0x1f0
 [<ffffffff813660c1>] ? serial8250_config_port+0x291/0xb10
 [<ffffffff81360644>] ? uart_add_one_port+0x1e4/0x3c0
 [<ffffffff81369821>] ? dev_set_name+0x41/0x50
 [<ffffffff81c5fad5>] ? serial8250_init+0xfe/0x153
 [<ffffffff81c5f620>] ? cn_proc_init+0x23/0x3d

Serial probing is done before uhci_hdc. So probe_irq_on() will unmask irq 11 which will result unhandled irq for rtl8139.

Removing the serial console form the command line. I can also get another call trace when uhci_hcd just unmask irq 11. Then the case is similar to serial console case.

For the case of acpi, still not clear why not get the calltrace just after usb_hdc unmask the irq.
Comment 63 Laszlo Ersek 2014-04-30 10:31:56 UTC 
Is this maybe related?
https://lkml.org/lkml/2014/4/14/803

Asking because "BIOS reported wrong ACPI id 0" is present in the above logs.
Comment 64 jason wang 2014-05-06 10:57:54 UTC 
(In reply to jason wang from comment #61)
> n    (In reply to jason wang from comment #60)
> > Borrow the environment from QE:
> > 
> > Several findings:
> > 
> > 1 After the hang
> > # grep "pin 11" /sys/kernel/debug/tracing/trace_pipe
> >         qemu-kvm-12980 [006] ....  2231.111590: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111611: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111735: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111756: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111901: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112003: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112033: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112159: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112180: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         ...
> > 
> > Interrupt storm were found for irq #11. This is the unhandled irq from
> > rtl8139 and was re-injected to guest during ioapic EOI broadcast. That why
> > note_interrupt() was called. But more interesting thing is that for
> > note_interrupt() itself, it should try to disable irq through ioapic. But
> > for some reasons the irq 11 was not disabled.
> > 
> > 2 More interesting thing:
> > #  grep APPEND /etc/sysconfig/kdump
> > KDUMP_COMMANDLINE_APPEND="irqpoll nr_cpus=1 reset_devices
> > cgroup_disable=memory mce=off"
> > 
> > If I replace nr_cpus=1 with max_cpus=1 the problem disappear. unlike
> > "nr_cpus=1" , "max_cpus=1" will also bring up all other vcpus. But it was
> > still unclear the difference of irq routing in those two cases.
> > 
> > So several things need to be investigated:
> > 
> > - whether or not we need some hack to avoid the interrupt storm. I post a
> > patch to solve this in the past but was rejected.
> > (https://lkml.org/lkml/2012/3/12/70). If we don't delay the interrupt
> > injection during EOI, any unhandled irq will cause interrupt storm.
> > - why note_interrupt() fail to disable irq
> 
> Find the answer, there no method for ioapic to disable an irq.
> 

More investigation:

even if there's no method for ioapic to disable an irq. If an irq was disabled by note_interrupt(), handle_fasteoi_irq() will still mask it:

...
        if (unlikely(!action || (desc->status & IRQ_DISABLED))) {
                desc->status |= IRQ_PENDING;
                if (desc->chip->mask)
                        desc->chip->mask(irq);
                goto out;
        }
...

So the question goes to why it was unmasked again somewhere. After some code search, I find this: since kvm only emulate an ioapic with version of 0x11 without an EOI register, guest kernel will simulate the EOI message manually by    changing the trigger mode to edge and then back to level:

static void __eoi_ioapic_irq(unsigned int irq, struct irq_cfg *cfg)
{
        struct irq_pin_list *entry;

        for_each_irq_pin(entry, cfg->irq_2_pin) {
                if (mp_ioapics[entry->apic].apicver >= 0x20) {
                        /*                                                                                                                                                                                   
                         * Intr-remapping uses pin number as the virtual vector                                                                                                                              
                         * in the RTE. Actual vector is programmed in                                                                                                                                        
                         * intr-remapping table entry. Hence for the io-apic                                                                                                                                 
                         * EOI we use the pin number.                                                                                                                                                        
                         */
                        if (irq_remapped(irq))
                                io_apic_eoi(entry->apic, entry->pin);
                        else
                                io_apic_eoi(entry->apic, cfg->vector);
                } else {
                        __mask_and_edge_IO_APIC_irq(entry);
=>                      __unmask_and_level_IO_APIC_irq(entry);
                }
        }
}

The irq was unmask unconditionally in __unmask_and_level_IO_APIC_irq(). Which will lead the irq to be injected again. The looks wrong.

Looking at upstream, looks it was already been fixed by:
commit e57253a81d9cc7049e9e43bd806ce6cdd297ec1c
Author: Suresh Siddha <suresh.b.siddha>
Date:   Thu Aug 25 12:01:12 2011 -0700

    x86, ioapic: Restore the mask bit correctly in eoi_ioapic_irq()
    
    For older IO-APIC's, we were clearing the remote-IRR by changing
    the RTE trigger mode to edge and then back to level. We wanted
    to mask the RTE during this process, so we were essentially
    doing mask+edge and then to unmask+level.
    
    As part of the commit ca64c47cecd0321b2e0dcbd7aaff44b68ce20654,
    we moved this EOI process earlier where the IO-APIC RTE is
    masked. So we were wrongly unmasking it in the eoi_ioapic_irq().
    
    So change the remote-IRR clear sequence in eoi_ioapic_irq() to
    mask + edge and then restore the previous RTE entry which will
    restore the mask status as well as the level trigger.
    
    Signed-off-by: Suresh Siddha <suresh.b.siddha>
    Cc: Maciej W. Rozycki <macro>
    Cc: Thomas Renninger <trenn>
    Cc: Rafael Wysocki <rjw>
    Cc: lchiquitto
    Cc: jbeulich
    Cc: yinghai
    Link: http://lkml.kernel.org/r/20110825190657.210286410@sbsiddha-desk.sc.intel.com
    Signed-off-by: Ingo Molnar <mingo>

Looks like we need backport this to RHEL6.

> > - why max_cpus=1 works but nr_cpus=1 not
> 
> Well, seems I can reproduce with max_cpus = 1 occasionally.
(In reply to jason wang from comment #61)
> n    (In reply to jason wang from comment #60)
> > Borrow the environment from QE:
> > 
> > Several findings:
> > 
> > 1 After the hang
> > # grep "pin 11" /sys/kernel/debug/tracing/trace_pipe
> >         qemu-kvm-12980 [006] ....  2231.111590: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111611: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111735: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111756: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.111901: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112003: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112033: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112159: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         qemu-kvm-12980 [006] ....  2231.112180: kvm_ack_irq: irqchip IOAPIC
> > pin 11
> >         ...
> > 
> > Interrupt storm were found for irq #11. This is the unhandled irq from
> > rtl8139 and was re-injected to guest during ioapic EOI broadcast. That why
> > note_interrupt() was called. But more interesting thing is that for
> > note_interrupt() itself, it should try to disable irq through ioapic. But
> > for some reasons the irq 11 was not disabled.
> > 
> > 2 More interesting thing:
> > #  grep APPEND /etc/sysconfig/kdump
> > KDUMP_COMMANDLINE_APPEND="irqpoll nr_cpus=1 reset_devices
> > cgroup_disable=memory mce=off"
> > 
> > If I replace nr_cpus=1 with max_cpus=1 the problem disappear. unlike
> > "nr_cpus=1" , "max_cpus=1" will also bring up all other vcpus. But it was
> > still unclear the difference of irq routing in those two cases.
> > 
> > So several things need to be investigated:
> > 
> > - whether or not we need some hack to avoid the interrupt storm. I post a
> > patch to solve this in the past but was rejected.
> > (https://lkml.org/lkml/2012/3/12/70). If we don't delay the interrupt
> > injection during EOI, any unhandled irq will cause interrupt storm.
> > - why note_interrupt() fail to disable irq
> 
> Find the answer, there no method for ioapic to disable an irq.
> 
> > - why max_cpus=1 works but nr_cpus=1 not
> 
> Well, seems I can reproduce with max_cpus = 1 occasionally.
Comment 65 jason wang 2014-05-06 11:00:15 UTC 
I will provide a brew build for this.
Comment 66 jason wang 2014-05-06 11:05:49 UTC 
(In reply to Laszlo Ersek from comment #63)
> Is this maybe related?
> https://lkml.org/lkml/2014/4/14/803
> 
> Asking because "BIOS reported wrong ACPI id 0" is present in the above logs.

Not sure, but looks not since I can reproduce the issue with smp = 1.
Comment 68 huiqingding 2014-05-07 05:04:41 UTC 
On host, the version is as following:
kernel-3.10.0-123.el7.x86_64
qemu-kvm-1.5.3-60.el7_0.1.x86_64

The kernel of rhel6.5-64 is updated to be kernel-2.6.32-462.el6bz1031488.x86_64 

Test steps:
1. boot a rhel6.5-64 guest with two e1000 nics, usb device and balloon device
# /usr/libexec/qemu-kvm \
  -M rhel6.5.0 \
  -cpu Westmere,hv_relaxed \
  -enable-kvm  \
  -m 4096 -smp 4,sockets=2,cores=2,threads=1 \
  -nodefconfig \
  -nodefaults \
  -monitor stdio \
  -name test-all-qemu-kvm-option \
  -device virtio-balloon-pci,id=ballooning,bus=pci.0,addr=0x5,indirect_desc=on,event_idx=on,multifunction=on,rombar=100 \
  -usbdevice tablet \
  -drive file=gluster://10.66.8.240:24007/gv0/rhel6.5-64.qcow2,if=none,id=drive-virtio-disk,format=qcow2,cache=none,aio=native,werror=stop,rerror=stop,media=disk,snapshot=off,bus=1,unit=1 \
  -device virtio-blk-pci,scsi=off,drive=drive-virtio-disk,id=virtio-disk,bus=pci.0,addr=0x7,bootindex=1,physical_block_size=512,logical_block_size=512,multifunction=on,scsi=on,event_idx=on,indirect_desc=on,vectors=32,x-data-plane=off,ioeventfd=on,serial=fuxc,discard_granularity=1,min_io_size=4096,opt_io_size=4096 \
  -netdev tap,id=hostnet1,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net1 \
  -device e1000,netdev=hostnet1,id=virtio-net-pci1,mac=00:01:02:03:04:06,bus=pci.0,addr=0xa,multifunction=off \
  -netdev tap,id=hostnet2,vhost=off,script=/etc/qemu-ifup,downscript=no,ifname=fuxc-net-rtl8139 \
  -device e1000,netdev=hostnet2,id=virtio-net-pci2,mac=00:01:02:03:04:07,bus=pci.0,addr=0xb,multifunction=off -serial unix:/tmp/monitor2,server,nowait \
  -vga qxl \
  -vnc :1

2. do sysrq inside guest
# echo c > /proc/sysrq-trigger

after 2, no call trace on serial console, guest can reboot automatically and vmcore can be created.
Comment 70 RHEL Program Management 2014-05-12 06:20:54 UTC 
This request was evaluated by Red Hat Product Management for
inclusion in a Red Hat Enterprise Linux release.  Product
Management has requested further review of this request by
Red Hat Engineering, for potential inclusion in a Red Hat
Enterprise Linux release for currently deployed products.
This request is not yet committed for inclusion in a release.
Comment 71 Rafael Aquini 2014-05-14 12:35:30 UTC 
Patch(es) available on kernel-2.6.32-465.el6
Comment 74 Xiaoqing Wei 2014-07-28 09:31:54 UTC 
Hello Jason,

Thx for that fix, I guess the patch is for RHEL 6 as a guest OS ?

found that guest os RHEL6(2.6.32-492.el6.x86_64) fine but RHEL7(3.10.0-123.6.3.el7.x86_64) bad.

I tested
0) append "ext4 /dev/mapper/VolGroup-LogVol_root" to /etc/kdump.conf, and rebuild initramfs
1) RHEL 6 as a guest boot from a RHEL 6.5 host(kdump work at this phase)
2) and later mig to RHEL 7 host(kdump work at this phase)

Versions:
guest OS:   2.6.32-492.el6.x86_64

src   host:   2.6.32-492.el6.x86_64 + qemu-kvm-rhev-0.12.1.2-2.431.el6.x86_64
dest host:  3.10.0-132.el7.x86_64 + qemu-kvm-1.5.3-66.el7.x86_64


while testing RHEL7(only img differs), step 2) doesn't work.

guest has 2 e1000 nics, 1 balloon device, and usb tablet as C#68.

detail definition as below:
# virsh dumpxml kdump-rhel6
<domain type='kvm' id='4'>
  <name>kdump-rhel6</name>
  <uuid>fbfd596b-7da0-1249-a741-357c842b0626</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>4</vcpu>
  <resource>
    <partition>/machine</partition>
  </resource>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='utc'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='raw' cache='none' io='native'/>
      <source file='/home/kvm_autotest_root/images/RHEL-Server-6.6-64-virtio.raw'>
        <seclabel model='selinux' relabel='no'/>
      </source>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
    </disk>
    <controller type='virtio-serial' index='0'>
      <alias name='virtio-serial0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </controller>
    <controller type='usb' index='0'>
      <alias name='usb0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'>
      <alias name='pci.0'/>
    </controller>
    <interface type='bridge'>
      <mac address='52:54:00:97:0a:cd'/>
      <source bridge='switch'/>
      <target dev='vnet0'/>
      <model type='e1000'/>
      <alias name='net0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <interface type='bridge'>
      <mac address='52:54:00:0a:94:8b'/>
      <source bridge='virbr0'/>
      <target dev='vnet1'/>
      <model type='e1000'/>
      <alias name='net1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </interface>
    <serial type='pty'>
      <source path='/dev/pts/0'/>
      <target port='0'/>
      <alias name='serial0'/>
    </serial>
    <console type='pty' tty='/dev/pts/0'>
      <source path='/dev/pts/0'/>
      <target type='serial' port='0'/>
      <alias name='serial0'/>
    </console>
    <channel type='spicevmc'>
      <target type='virtio' name='com.redhat.spice.0'/>
      <alias name='channel0'/>
      <address type='virtio-serial' controller='0' bus='0' port='1'/>
    </channel>
    <input type='tablet' bus='usb'>
      <alias name='input0'/>
    </input>
    <input type='mouse' bus='ps2'/>
    <graphics type='spice' port='5900' autoport='yes' listen='127.0.0.1'>
      <listen type='address' address='127.0.0.1'/>
    </graphics>
    <video>
      <model type='qxl' ram='65536' vram='65536' heads='1'/>
      <alias name='video0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <alias name='balloon0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/>
    </memballoon>
  </devices>
  <seclabel type='dynamic' model='selinux' relabel='yes'>
    <label>system_u:system_r:svirt_t:s0:c515,c981</label>
    <imagelabel>system_u:object_r:svirt_image_t:s0:c515,c981</imagelabel>
  </seclabel>
</domain>

translated cmd on src :
/usr/libexec/qemu-kvm -name kdump-rhel6 -S -M rhel6.5.0 -enable-kvm -m 4096 -realtime mlock=off -smp 4,sockets=4,cores=1,threads=1 -uuid fbfd596b-7da0-1249-a741-357c842b0626 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/kdump-rhel6.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5 -drive file=/home/kvm_autotest_root/images/RHEL-Server-6.6-64-virtio.raw,if=none,id=drive-virtio-disk0,format=raw,cache=none,aio=native -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x6,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=22,id=hostnet0 -device e1000,netdev=hostnet0,id=net0,mac=52:54:00:97:0a:cd,bus=pci.0,addr=0x3 -netdev tap,fd=23,id=hostnet1 -device e1000,netdev=hostnet1,id=net1,mac=52:54:00:0a:94:8b,bus=pci.0,addr=0x4 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -device usb-tablet,id=input0 -spice port=5901,addr=127.0.0.1,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.ram_size=67108864 -global qxl-vga.vram_size=67108864 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7


translated cmd on dest:

/usr/libexec/qemu-kvm -name kdump-rhel6 -S -machine rhel6.5.0,accel=kvm,usb=off -m 4096 -realtime mlock=off -smp 4,sockets=4,cores=1,threads=1 -uuid fbfd596b-7da0-1249-a741-357c842b0626 -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/kdump-rhel6.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5 -drive file=/home/kvm_autotest_root/images/RHEL-Server-6.6-64-virtio.raw,if=none,id=drive-virtio-disk0,format=raw,cache=none,aio=native -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x6,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=23,id=hostnet0 -device e1000,netdev=hostnet0,id=net0,mac=52:54:00:97:0a:cd,bus=pci.0,addr=0x3 -netdev tap,fd=24,id=hostnet1 -device e1000,netdev=hostnet1,id=net1,mac=52:54:00:0a:94:8b,bus=pci.0,addr=0x4 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -device usb-tablet,id=input0 -spice port=5900,addr=127.0.0.1,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.ram_size=67108864 -global qxl-vga.vram_size=67108864 -incoming tcp:[::]:49152 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7
Comment 75 Xiaoqing Wei 2014-07-28 09:36:28 UTC 
Hi Jason,
could you pls have a look, if this is not the patch fix scope and need a clone bug, tell me.
thx

RHEL 7 as a guest triggering kdump (service has been confirmed working before mig, and initramfs been rebuilt)



[root@dhcp-9-111 ~]# echo c > /proc/sysrq-trigger 
[  336.158661] SysRq : Trigger a crash
[  336.159014] BUG: unable to handle kernel NULL pointer dereference at           (null)
[  336.159014] IP: [<ffffffff8137b596>] sysrq_handle_crash+0x16/0x20
[  336.159014] PGD 118ac2067 PUD 117985067 PMD 0 
[  336.159014] Oops: 0002 [#1] SMP 
[  336.159014] Modules linked in: binfmt_misc ip6t_rpfilter ip6t_REJECT ipt_REJECT xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw iptable_filter ip_tables sg qxl ttm drm_kms_helper drm i2c_piix4 virtio_console pcspkr virtio_balloon i2c_core serio_raw mperf xfs libcrc32c virtio_blk ata_generic pata_acpi ata_piix virtio_pci virtio_ring virtio libata e1000 floppy dm_mirror dm_region_hash dm_log dm_mod
[  336.164092] CPU: 0 PID: 2308 Comm: bash Not tainted 3.10.0-123.6.3.el7.x86_64 #1
[  336.164092] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
[  336.164092] task: ffff8800d2928000 ti: ffff8801171be000 task.ti: ffff8801171be000
[  336.164092] RIP: 0010:[<ffffffff8137b596>]  [<ffffffff8137b596>] sysrq_handle_crash+0x16/0x20
[  336.164092] RSP: 0018:ffff8801171bfe80  EFLAGS: 00010046
[  336.164092] RAX: 000000000000000f RBX: ffffffff81982660 RCX: 0000000000000000
[  336.164092] RDX: 0000000000000000 RSI: ffff88011fc0e428 RDI: 0000000000000063
[  336.164092] RBP: ffff8801171bfe80 R08: 0000000000000092 R09: 000000000000024c
[  336.164092] R10: 000000000000024b R11: 0000000000000003 R12: 0000000000000063
[  336.164092] R13: 0000000000000246 R14: 0000000000000007 R15: 0000000000000000
[  336.164092] FS:  00007fa36d94f740(0000) GS:ffff88011fc00000(0000) knlGS:0000000000000000
[  336.164092] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  336.164092] CR2: 0000000000000000 CR3: 0000000118033000 CR4: 00000000000006f0
[  336.164092] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  336.164092] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  336.164092] Stack:
[  336.164092]  ffff8801171bfeb8 ffffffff8137bd42 0000000000000002 00007fa36d970000
[  336.164092]  ffff8801171bff48 0000000000000002 0000000000000000 ffff8801171bfed0
[  336.164092]  ffffffff8137c21f ffff8801177dfcc0 ffff8801171bfef0 ffffffff8121674d
[  336.164092] Call Trace:
[  336.164092]  [<ffffffff8137bd42>] __handle_sysrq+0xa2/0x170
[  336.164092]  [<ffffffff8137c21f>] write_sysrq_trigger+0x2f/0x40
[  336.164092]  [<ffffffff8121674d>] proc_reg_write+0x3d/0x80
[  336.164092]  [<ffffffff811af7fd>] vfs_write+0xbd/0x1e0
[  336.164092]  [<ffffffff811b0248>] SyS_write+0x58/0xb0
[  336.164092]  [<ffffffff815f2799>] system_call_fastpath+0x16/0x1b
[  336.164092] Code: 65 34 75 e5 4c 89 ef e8 d9 f7 ff ff eb db 0f 1f 80 00 00 00 00 0f 1f 44 00 00 55 c7 05 40 c3 57 00 01 00 00 00 48 89 e5 0f ae f8 <c6> 04 25 00 00 00 00 01 5d c3 0f 1f 44 00 00 55 31 c0 c7 05 9e 
[  336.164092] RIP  [<ffffffff8137b596>] sysrq_handle_crash+0x16/0x20
[  336.164092]  RSP <ffff8801171bfe80>
[  336.164092] CR2: 0000000000000000
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.10.0-123.6.3.el7.x86_64 (mockbuild.eng.bos.redhat.com) (gcc version 4.8.2 20140120 (Red Hat 4.8.2-16) (GCC) ) #1 SMP Wed Jul 16 15:10:46 EDT 2014
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-3.10.0-123.6.3.el7.x86_64 root=/dev/mapper/rhel_dhcp--9--111-root ro rd.lvm.lv=rhel_dhcp-9-111/root console=tty0 vconsole.keymap=us rd.lvm.lv=rhel_dhcp-9-111/swap vconsole.font=latarcyrheb-sun16 console=ttyS0,115200 LANG=en_US.UTF-8 irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 rootflags=nofail acpi_no_memhotplug disable_cpu_apicid=0 memmap=exactmap memmap=627K@4K memmap=164212K@720896K elfcorehdr=885108K
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000100-0x000000000009dbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009dc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000dfffcfff] usable
[    0.000000] BIOS-e820: [mem 0x00000000dfffd000-0x00000000dfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffbc000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000011fffffff] usable
[    0.000000] e820: last_pfn = 0x120000 max_arch_pfn = 0x400000000
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] e820: user-defined physical RAM map:
[    0.000000] user: [mem 0x0000000000001000-0x000000000009dbff] usable
[    0.000000] user: [mem 0x000000002c000000-0x000000003605cfff] usable
[    0.000000] SMBIOS 2.4 present.
[    0.000000] Hypervisor detected: KVM
[    0.000000] No AGP bridge found
[    0.000000] e820: last_pfn = 0x3605d max_arch_pfn = 0x400000000
[    0.000000] PAT not supported by CPU.
[    0.000000] CPU MTRRs all blank - virtualized system.
[    0.000000] found SMP MP-table at [mem 0x000fd9f0-0x000fd9ff] mapped at [ffff8800000fd9f0]
[    0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[    0.000000] init_memory_mapping: [mem 0x35200000-0x353fffff]
[    0.000000] init_memory_mapping: [mem 0x34000000-0x351fffff]
[    0.000000] init_memory_mapping: [mem 0x2c000000-0x33ffffff]
[    0.000000] init_memory_mapping: [mem 0x35400000-0x3605cfff]
[    0.000000] RAMDISK: [mem 0x35537000-0x36049fff]
[    0.000000] ACPI: RSDP 00000000000fd9a0 00014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 00000000dfffd470 00034 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 00000000dffffda0 00074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 00000000dfffd890 024A2 (v01   BXPC   BXDSDT 00000001 INTL 20090123)
[    0.000000] ACPI: FACS 00000000dffffd40 00040
[    0.000000] ACPI: SSDT 00000000dfffd6c0 001C1 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 00000000dfffd5c0 00090 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: SSDT 00000000dfffd4b0 0010F (v01   BXPC BXSSDTPC 00000001 INTL 20090123)
[    0.000000] NUMA turned off
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000003605cfff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x3605cfff]
[    0.000000]   NODE_DATA [mem 0x35510000-0x35536fff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:354c0001, boot clock
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x00001000-0x00ffffff]
[    0.000000]   DMA32    [mem 0x01000000-0xffffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x00001000-0x0009cfff]
[    0.000000]   node   0: [mem 0x2c000000-0x3605cfff]
[    0.000000] ACPI: PM-Timer IO Port: 0xb008
[    0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[    0.000000] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 1/0x1 ignored.
[    0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] enabled)
[    0.000000] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 2/0x2 ignored.
[    0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x03] enabled)
[    0.000000] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 3/0x3 ignored.
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
[    0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] smpboot: 4 Processors exceeds NR_CPUS limit of 1
[    0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] PM: Registered nosave memory: [mem 0x0009d000-0x2bffffff]
[    0.000000] e820: [mem 0x3605d000-0xffffffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] setup_percpu: NR_CPUS:5120 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] PERCPU: Embedded 29 pages/cpu @ffff880035200000 s86656 r8192 d23936 u2097152
[    0.000000] kvm-clock: cpu 0, msr 0:354c0001, primary cpu clock
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 3520dfc0
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 40543
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: BOOT_IMAGE=/vmlinuz-3.10.0-123.6.3.el7.x86_64 root=/dev/mapper/rhel_dhcp--9--111-root ro rd.lvm.lv=rhel_dhcp-9-111/root console=tty0 vconsole.keymap=us rd.lvm.lv=rhel_dhcp-9-111/swap vconsole.font=latarcyrheb-sun16 console=ttyS0,115200 LANG=en_US.UTF-8 irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 rootflags=nofail acpi_no_memhotplug disable_cpu_apicid=0 memmap=exactmap memmap=627K@4K memmap=164212K@720896K elfcorehdr=885108K
[    0.000000] Misrouted IRQ fixup and polling support enabled
[    0.000000] This may significantly impact system performance
[    0.000000] Disabling memory control group subsystem
[    0.000000] PID hash table entries: 1024 (order: 1, 8192 bytes)
[    0.000000] Checking aperture...
[    0.000000] No AGP bridge found
[    0.000000] Memory: 131976k/885108k available (6107k kernel code, 720272k absent, 32860k reserved, 4064k data, 1584k init)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	RCU restricting CPUs from NR_CPUS=5120 to nr_cpu_ids=1.
[    0.000000] 	Experimental no-CBs for all CPUs
[    0.000000] 	Experimental no-CBs CPUs: 0.
[    0.000000] NR_IRQS:327936 nr_irqs:256 16
[    0.000000] Spurious LAPIC timer interrupt on cpu 0
[    0.000000] Console: colour VGA+ 80x25
[    0.000000] console [tty0] enabled
[    0.000000] console [ttyS0] enabled
[    0.000000] tsc: Detected 3092.972 MHz processor
[    0.002000] Calibrating delay loop (skipped) preset value.. 6185.94 BogoMIPS (lpj=3092972)
[    0.003007] pid_max: default: 32768 minimum: 301
[    0.004024] Security Framework initialized
[    0.005010] SELinux:  Initializing.
[    0.006059] Dentry cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.007052] Inode-cache hash table entries: 16384 (order: 5, 131072 bytes)
[    0.008028] Mount-cache hash table entries: 4096
[    0.009131] Initializing cgroup subsys memory
[    0.010014] Initializing cgroup subsys devices
[    0.011007] Initializing cgroup subsys freezer
[    0.012008] Initializing cgroup subsys net_cls
[    0.013007] Initializing cgroup subsys blkio
[    0.014008] Initializing cgroup subsys perf_event
[    0.016008] Initializing cgroup subsys hugetlb
[    0.017125] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.017125] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.017125] tlb_flushall_shift: 6
[    0.033881] Freeing SMP alternatives: 24k freed
[    0.041423] ACPI: Core revision 20130517
[    0.043165] ACPI: All ACPI Tables successfully acquired
[    0.044429] ftrace: allocating 23390 entries in 92 pages
[    0.053553] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.054004] smpboot: CPU0: Intel QEMU Virtual CPU version (cpu64-rhel6) (fam: 06, model: 0d, stepping: 03)
[    0.058000] Performance Events: Broken PMU hardware detected, using software events only.
[    0.060001] Failed to access perfctr msr (MSR c1 is 0)
[    0.061823] Brought up 1 CPUs
[    0.062003] smpboot: Total of 1 processors activated (6185.94 BogoMIPS)
[    0.063424] NMI watchdog: disabled (cpu0): hardware events not enabled
[    0.064072] devtmpfs: initialized
[    0.066258] EVM: security.selinux
[    0.067002] EVM: security.ima
[    0.067740] EVM: security.capability
[    0.069453] atomic64 test passed for x86-64 platform with CX8 and with SSE
[    0.070032] NET: Registered protocol family 16
[    0.072039] ACPI: bus type PCI registered
[    0.073003] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.074094] PCI: Using configuration type 1 for base access
[    0.076113] bio: create slab <bio-0> at 0
[    0.077053] ACPI: Added _OSI(Module Device)
[    0.078004] ACPI: Added _OSI(Processor Device)
[    0.079002] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.080007] ACPI: Added _OSI(Processor Aggregator Device)
[    0.082781] ACPI: Interpreter enabled
[    0.083004] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S1_] (20130517/hwxface-571)
[    0.085639] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S2_] (20130517/hwxface-571)
[    0.087657] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S3_] (20130517/hwxface-571)
[    0.089633] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S4_] (20130517/hwxface-571)
[    0.092008] ACPI: (supports S0 S5)
[    0.092830] ACPI: Using IOAPIC for interrupt routing
[    0.094019] PCI: Ignoring host bridge windows from ACPI; if necessary, use "pci=use_crs" and report a bug
[    0.095268] ACPI: No dock devices found.
[    0.098677] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.099006] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[    0.100006] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    0.101022] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    0.103096] acpiphp: Slot [1] registered
[    0.103990] acpiphp: Slot [2] registered
[    0.104020] acpiphp: Slot [3] registered
[    0.105028] acpiphp: Slot [4] registered
[    0.106024] acpiphp: Slot [5] registered
[    0.107027] acpiphp: Slot [6] registered
[    0.108022] acpiphp: Slot [7] registered
[    0.109027] acpiphp: Slot [8] registered
[    0.110024] acpiphp: Slot [9] registered
[    0.111027] acpiphp: Slot [10] registered
[    0.112023] acpiphp: Slot [11] registered
[    0.113035] acpiphp: Slot [12] registered
[    0.114020] acpiphp: Slot [13] registered
[    0.115020] acpiphp: Slot [14] registered
[    0.116020] acpiphp: Slot [15] registered
[    0.117025] acpiphp: Slot [16] registered
[    0.118029] acpiphp: Slot [17] registered
[    0.119020] acpiphp: Slot [18] registered
[    0.120027] acpiphp: Slot [19] registered
[    0.120943] acpiphp: Slot [20] registered
[    0.121027] acpiphp: Slot [21] registered
[    0.122021] acpiphp: Slot [22] registered
[    0.123024] acpiphp: Slot [23] registered
[    0.124027] acpiphp: Slot [24] registered
[    0.125021] acpiphp: Slot [25] registered
[    0.126020] acpiphp: Slot [26] registered
[    0.127027] acpiphp: Slot [27] registered
[    0.128023] acpiphp: Slot [28] registered
[    0.129027] acpiphp: Slot [29] registered
[    0.130023] acpiphp: Slot [30] registered
[    0.131027] acpiphp: Slot [31] registered
[    0.133451] PCI host bridge to bus 0000:00
[    0.134005] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.135003] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[    0.136002] pci_bus 0000:00: root bus resource [mem 0x00000000-0xfffffffff]
[    0.169314] pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
[    0.170013] pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
[    0.260522] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    0.262546] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 10 *11)
[    0.264112] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 *10 11)
[    0.266097] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    0.267904] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    0.269123] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 4/0x1 ignored.
[    0.270002] Unable to map lapic to logical cpu number
[    0.271087] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 5/0x2 ignored.
[    0.272001] Unable to map lapic to logical cpu number
[    0.273118] ACPI: NR_CPUS/possible_cpus limit of 1 reached.  Processor 6/0x3 ignored.
[    0.274002] Unable to map lapic to logical cpu number
[    0.275249] ACPI: Enabled 16 GPEs in block 00 to 0F
[    0.276121] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[    0.277002] vgaarb: loaded
[    0.278001] vgaarb: bridge control possible 0000:00:02.0
[    0.279050] SCSI subsystem initialized
[    0.280014] ACPI: bus type USB registered
[    0.281017] usbcore: registered new interface driver usbfs
[    0.282010] usbcore: registered new interface driver hub
[    0.283028] usbcore: registered new device driver usb
[    0.284043] PCI: Using ACPI for IRQ routing
[    0.285240] NetLabel: Initializing
[    0.286002] NetLabel:  domain hash size = 128
[    0.287001] NetLabel:  protocols = UNLABELED CIPSOv4
[    0.288011] NetLabel:  unlabeled traffic allowed by default
[    0.290054] Switching to clocksource kvm-clock
[    0.293819] pnp: PnP ACPI init
[    0.294635] ACPI: bus type PNP registered
[    0.296101] pnp: PnP ACPI: found 5 devices
[    0.297028] ACPI: bus type PNP unregistered
[    0.304230] NET: Registered protocol family 2
[    0.305346] TCP established hash table entries: 2048 (order: 2, 16384 bytes)
[    0.306739] TCP bind hash table entries: 2048 (order: 3, 32768 bytes)
[    0.308000] TCP: Hash tables configured (established 2048 bind 2048)
[    0.309335] TCP: reno registered
[    0.310180] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.311439] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.312753] NET: Registered protocol family 1
[    0.313729] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.315099] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.316566] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[    0.319348] Unpacking initramfs...
[    0.456376] Freeing initrd memory: 11340k freed
[    0.458727] microcode: CPU0 sig=0x6d3, pf=0x1, revision=0x1
[    0.459926] microcode: Microcode Update Driver: v2.00 <tigran.co.uk>, Peter Oruba
[    0.461850] futex hash table entries: 256 (order: 2, 16384 bytes)
[    0.463064] Initialise system trusted keyring
[    0.464093] audit: initializing netlink socket (disabled)
[    0.465324] type=2000 audit(1406538335.333:1): initialized
[    0.482473] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.484397] zbud: loaded
[    0.485193] VFS: Disk quotas dquot_6.5.2
[    0.486110] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.487587] msgmni has been set to 279
[    0.488541] Key type big_key registered
[    0.489737] alg: No test for stdrng (krng)
[    0.490696] NET: Registered protocol family 38
[    0.491761] Key type asymmetric registered
[    0.492695] Asymmetric key parser 'x509' registered
[    0.493849] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.495640] io scheduler noop registered
[    0.496552] io scheduler deadline registered (default)
[    0.497649] io scheduler cfq registered
[    0.498603] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    0.499842] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    0.501270] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    0.502905] ACPI: Power Button [PWRF]
[    0.504033] GHES: HEST is not enabled!
[    0.504922] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.528064] 00:04: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[    0.529699] Non-volatile memory driver v1.3
[    0.530646] Linux agpgart interface v0.103
[    0.531750] crash memory driver: version 1.1
[    0.532799] rdac: device handler registered
[    0.533761] hp_sw: device handler registered
[    0.534707] emc: device handler registered
[    0.535718] alua: device handler registered
[    0.536767] libphy: Fixed MDIO Bus: probed
[    0.537808] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.539086] ehci-pci: EHCI PCI platform driver
[    0.540111] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.542411] ohci-pci: OHCI PCI platform driver
[    0.543408] uhci_hcd: USB Universal Host Controller Interface driver
[    0.546222] uhci_hcd 0000:00:01.2: UHCI Host Controller
[    0.547395] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[    0.549122] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c020
[    0.550391] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[    0.551779] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.553537] usb usb1: Product: UHCI Host Controller
[    0.554669] usb usb1: Manufacturer: Linux 3.10.0-123.6.3.el7.x86_64 uhci_hcd
[    0.556207] usb usb1: SerialNumber: 0000:00:01.2
[    0.557386] hub 1-0:1.0: USB hub found
[    0.558361] hub 1-0:1.0: 2 ports detected
[    0.559517] usbcore: registered new interface driver usbserial
[    0.560774] usbcore: registered new interface driver usbserial_generic
[    0.562042] usbserial: USB Serial support registered for generic
[    0.563482] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    0.566295] serio: i8042 KBD port at 0x60,0x64 irq 1
[    0.567451] serio: i8042 AUX port at 0x60,0x64 irq 12
[    0.568630] mousedev: PS/2 mouse device common for all mice
[    0.571439] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    0.574079] rtc_cmos 00:00: RTC can wake from S4
[    0.577027] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[    0.578584] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
[    0.579919] cpuidle: using governor menu
[    0.581091] hidraw: raw HID events driver (C) Jiri Kosina
[    0.582448] usbcore: registered new interface driver usbhid
[    0.583724] usbhid: USB HID core driver
[    0.584944] drop_monitor: Initializing network drop monitor service
[    0.586376] TCP: cubic registered
[    0.587314] Initializing XFRM netlink socket
[    0.588465] NET: Registered protocol family 10
[    0.589713] NET: Registered protocol family 17
[    0.590849] Loading compiled-in X.509 certificates
[    0.592462] Loaded X.509 cert 'Red Hat Enterprise Linux Driver Update Program (key 3): bf57f3e87362bc7229d9f465321773dfd1f77a80'
[    0.595416] Loaded X.509 cert 'Red Hat Enterprise Linux kpatch signing key: 4d38fd864ebe18c5f0b72e3852e2014c3a676fc8'
[    0.598276] Loaded X.509 cert 'Red Hat Enterprise Linux kernel signing key: 446fb95ce117972adfb83362c129672bb0150713'
[    0.600522] registered taskstats version 1
[    0.603703] Key type trusted registered
[    0.605979] Key type encrypted registered
[    0.608023] IMA: No TPM chip found, activating TPM-bypass!
[    0.609680] rtc_cmos 00:00: setting system clock to 2014-07-28 09:05:32 UTC (1406538332)
[    0.612555] Freeing unused kernel memory: 1584k freed
[    0.616365] systemd[1]: systemd 208 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ)
[    0.619082] systemd[1]: Detected virtualization 'kvm'.
[    0.620303] systemd[1]: Running in initial RAM disk.

Welcome to Red Hat Enterprise Linux Server 7.0 (Maipo) dracut-033-161.el7 (Initramfs)!

[    0.623162] systemd[1]: Set hostname to <dhcp-9-111.nay.redhat.com>.
[    0.642638] systemd[1]: Expecting device dev-disk-by\x2duuid-dc1b0dc7\x2d8231\x2d4c30\x2da0f8\x2d2c8d342bbb38.device...
         Expecting device dev-disk-by\x2duuid-dc1b0dc7\x2d823...bbb38.device...
[    0.646200] systemd[1]: Expecting device dev-mapper-rhel_dhcp\x2d\x2d9\x2d\x2d111\x2dswap.device...
         Expecting device dev-mapper-rhel_dhcp\x2d\x2d9\x2d\x...dswap.device...
[    0.649709] systemd[1]: Expecting device dev-mapper-rhel_dhcp\x2d\x2d9\x2d\x2d111\x2droot.device...
         Expecting device dev-mapper-rhel_dhcp\x2d\x2d9\x2d\x...droot.device...
[    0.653180] systemd[1]: Starting -.slice.
[  OK  ] Created slice -.slice.
[    0.655667] systemd[1]: Created slice -.slice.
[    0.657093] systemd[1]: Starting System Slice.
[  OK  ] Created slice System Slice.
[    0.659671] systemd[1]: Created slice System Slice.
[    0.661808] systemd[1]: Starting Slices.
[  OK  ] Reached target Slices.
[    0.665178] systemd[1]: Reached target Slices.
[    0.666286] systemd[1]: Starting Timers.
[  OK  ] Reached target Timers.
[    0.668732] systemd[1]: Reached target Timers.
[    0.670115] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
[    0.672222] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    0.674276] systemd[1]: Starting Paths.
[  OK  ] Reached target Paths.
[    0.676559] systemd[1]: Reached target Paths.
[    0.677892] systemd[1]: Starting Journal Socket.
[  OK  ] Listening on Journal Socket.
[    0.680432] systemd[1]: Listening on Journal Socket.
[    0.681726] systemd[1]: Starting dracut cmdline hook...
         Starting dracut cmdline hook...
[    0.684450] systemd[1]: Started Load Kernel Modules.
[    0.685688] systemd[1]: Starting Journal Service...
         Starting Journal Service...
[  OK  ] Started Journal Service.
[    0.690622] systemd[1]: Started Journal Service.
[    0.694601] systemd-journald[79]: Vacuuming done, freed 0 bytes
[  OK  ] Listening on udev Kernel Socket.
[  OK  ] Listening on udev Control Socket.
[  OK  ] Reached target Sockets.
         Starting Create list of required static device nodes...rrent kernel...
         Starting Apply Kernel Variables...
[  OK  ] Reached target Swap.
[  OK  ] Reached target Local File Systems.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Create list of required static device nodes ...current kernel.
         Starting Create static device nodes in /dev...
[  OK  ] Started Create static device nodes in /dev.
[  OK  ] Started dracut cmdline hook.
         Starting dracut pre-udev hook...
[    0.810395] device-mapper: uevent: version 1.0.3
[    0.811494] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel
[  OK  ] Started dracut pre-udev hook.
         Starting udev Kernel Device Manager...
[  OK  ] Started udev Kernel Device Manager.
         Starting udev Coldplug all Devices...
[    0.840178] systemd-udevd[199]: starting version 208
         Mounting Configuration File System...
[    0.862098] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[  OK  ] Started udev Coldplug all Devices.
         Starting dracut initqueue hook...
[  OK  ] Mounted Configuration File System.
[  OK  ] Reached target System Initialization.[    0.893540] FDC 0 is a S82078B

[    0.898056] ACPI: bus type ATA registered
[  OK  ] Reached target Basic System.
[    0.912024] scsi0 : ata_piix
[    0.916117] scsi1 : ata_piix
[    0.917034] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc000 irq 14
[    0.918531] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc008 irq 15
         Starting File System Check on /dev/mapper/rhel_dhcp--9--111-root...
systemd-fsck[239]: fsck: error 2 (No such file or directory) while executing fsck.ext2 for /dev/mapper/rhel_dhcp--9--111-root
[  OK  ] Started File System Check on /dev/mapper/rhel_dhcp--9--111-root.
[    1.013757] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[    1.015132] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[    1.016610] usb 1-1: Product: QEMU USB Tablet
[    1.017717] usb 1-1: Manufacturer: QEMU
[    1.018696] usb 1-1: SerialNumber: 42
[    1.030536] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/input/input2
[    1.033533] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[    1.045401] [drm] Initialized drm 1.1.0 20060810
[    1.053226] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
[    1.059261] [drm] Device Version 0.0
[    1.060185] [drm] Compression level 0 log level 0
[    1.061298] [drm] Currently using mode #0, list at 0x488
[    1.062490] [drm] 12286 io pages at offset 0x1000000
[    1.063602] [drm] 16777216 byte draw area at offset 0x0
[    1.064824] [drm] RAM header offset: 0x3ffe000
[    1.066010] [drm] rom modes offset 0x488 for 116 modes
[    1.067338] [TTM] Zone  kernel: Available graphics memory: 72462 kiB
[    1.068772] [TTM] Initializing pool allocator
[    1.069967] [TTM] Initializing DMA pool allocator
[    1.072439] [drm] qxl: 16M of VRAM memory size
[    1.073524] [drm] qxl: 63M of IO pages memory ready (VRAM domain)
[    1.077662] [drm] main mem slot 1 [f0000000,3ffe000)
[    1.079356] [drm] fb mappable at 0xF0000000, size 3145728
[    1.080546] [drm] fb: depth 24, pitch 4096, width 1024, height 768
[    1.083103] fbcon: qxldrmfb (fb0) is primary device
[    1.097248] Console: switching to colour frame buffer device 128x48
[    1.118972] qxl 0000:00:02.0: fb0: qxldrmfb frame buffer device
[    1.119846] qxl 0000:00:02.0: registered panic notifier
[    1.120923] [drm] Initialized qxl 0.1.0 20120117 for 0000:00:02.0 on minor 0
[    1.127630] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[   28.064042] BUG: soft lockup - CPU#0 stuck for 23s! [systemd-udevd:202]
[   28.064070] Modules linked in: virtio_pci(+) virtio_ring virtio ata_generic pata_acpi qxl drm_kms_helper ttm drm i2c_core ata_piix libata floppy dm_mirror dm_region_hash dm_log dm_mod
[   28.064070] CPU: 0 PID: 202 Comm: systemd-udevd Not tainted 3.10.0-123.6.3.el7.x86_64 #1
[   28.064070] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
[   28.064070] task: ffff880030f138e0 ti: ffff880030ec8000 task.ti: ffff880030ec8000
[   28.064070] RIP: 0010:[<ffffffff81066ff3>]  [<ffffffff81066ff3>] __do_softirq+0xa3/0x290
[   28.064070] RSP: 0018:ffff880035203ee8  EFLAGS: 00000206
[   28.064070] RAX: ffff880030ec9fd8 RBX: ffffffff8106fe8e RCX: 0000000000000020
[   28.064070] RDX: 00000000fffb70db RSI: 000000000000e263 RDI: ffff880030f138e0
[   28.064070] RBP: ffff880035203f48 R08: 000000000000000c R09: ffff880035203d90
[   28.064070] R10: 0000000000000000 R11: 0000000000000005 R12: ffff880035203e58
[   28.064070] R13: ffffffff815f341d R14: ffff880035203f48 R15: 0000000000000046
[   28.064070] FS:  00007f36fb316880(0000) GS:ffff880035200000(0000) knlGS:0000000000000000
[   28.064070] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   28.064070] CR2: 00007f36fb826068 CR3: 0000000030ed4000 CR4: 00000000000006b0
[   28.064070] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   28.064070] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   28.064070] Stack:
[   28.064070]  ffff880030ec9fd8 0000000a00402140 00000000fffb70dd ffffffff810bda34
[   28.064070]  ffff880030ec9fd8 ffff880030ec9fd8 0000000000000000 0000000000000046
[   28.064070]  0000000000000001 0000000000000000 000000000000000b 0000000000000008
[   28.064070] Call Trace:
[   28.064070]  <IRQ> 
[   28.064070]  [<ffffffff810bda34>] ? tick_program_event+0x24/0x30
[   28.064070]  [<ffffffff815f40dc>] call_softirq+0x1c/0x30
[   28.064070]  [<ffffffff81014d25>] do_softirq+0x55/0x90
[   28.064070]  [<ffffffff810673e5>] irq_exit+0x115/0x120
[   28.064070]  [<ffffffff815f4ab5>] smp_apic_timer_interrupt+0x45/0x60
[   28.064070]  [<ffffffff815f341d>] apic_timer_interrupt+0x6d/0x80
[   28.064070]  <EOI> 
[   28.064070]  [<ffffffff815e961b>] ? _raw_spin_unlock_irqrestore+0x1b/0x40
[   28.064070]  [<ffffffff814af7e8>] pci_conf1_write+0xb8/0x110
[   28.064070]  [<ffffffff814b3264>] raw_pci_write+0x24/0x50
[   28.064070]  [<ffffffff81320abe>] acpi_os_write_pci_configuration+0x56/0x67
[   28.064070]  [<ffffffff8133a8aa>] acpi_ex_pci_config_space_handler+0x2a/0x40
[   28.064070]  [<ffffffff81334283>] acpi_ev_address_space_dispatch+0x1bf/0x22b
[   28.064070]  [<ffffffff813377e5>] acpi_ex_access_region+0x20e/0x2a2
[   28.064070]  [<ffffffff81337bb2>] acpi_ex_field_datum_io+0x105/0x196
[   28.064070]  [<ffffffff81337d14>] acpi_ex_write_with_update_rule+0xd1/0xf0
[   28.064070]  [<ffffffff81337a77>] acpi_ex_insert_into_field+0x1fe/0x234
[   28.064070]  [<ffffffff81337563>] acpi_ex_write_data_to_field+0x1a4/0x1d1
[   28.064070]  [<ffffffff81320c97>] ? acpi_os_release_object+0xe/0x12
[   28.064070]  [<ffffffff8133b5b1>] acpi_ex_store_object_to_node+0xb1/0x12d
[   28.064070]  [<ffffffff8133b6f9>] acpi_ex_store+0xcc/0x25f
[   28.064070]  [<ffffffff81330a15>] ? acpi_ds_create_operands+0x79/0xe0
[   28.064070]  [<ffffffff81338c13>] acpi_ex_opcode_1A_1T_1R+0x39e/0x4d7
[   28.064070]  [<ffffffff81330f29>] acpi_ds_exec_end_op+0xd0/0x3eb
[   28.064070]  [<ffffffff81343013>] acpi_ps_parse_loop+0x523/0x580
[   28.064070]  [<ffffffff8134b248>] ? acpi_ut_create_generic_state+0x37/0x54
[   28.064070]  [<ffffffff81343b00>] acpi_ps_parse_aml+0x98/0x28c
[   28.064070]  [<ffffffff81344355>] acpi_ps_execute_method+0x1c1/0x26c
[   28.064070]  [<ffffffff8133eaf1>] acpi_ns_evaluate+0x1c1/0x258
[   28.064070]  [<ffffffff813459e5>] acpi_rs_set_srs_method_data+0xee/0x125
[   28.064070]  [<ffffffff81345b40>] acpi_set_current_resources+0x54/0x74
[   28.064070]  [<ffffffff8132a881>] acpi_pci_link_set+0x13c/0x21d
[   28.064070]  [<ffffffff8132ad86>] acpi_pci_link_allocate_irq+0x14e/0x227
[   28.064070]  [<ffffffff8132b3fb>] acpi_pci_irq_enable+0xa9/0x229
[   28.064070]  [<ffffffff812e04df>] ? pci_bus_read_config_word+0x9f/0xb0
[   28.064070]  [<ffffffff812e1eac>] ? pci_read_config_word+0x1c/0x20
[   28.064070]  [<ffffffff814b34d1>] pcibios_enable_device+0x31/0x40
[   28.064070]  [<ffffffff812e888b>] do_pci_enable_device+0x3b/0x60
[   28.064070]  [<ffffffff812e9e68>] pci_enable_device_flags+0xe8/0x140
[   28.064070]  [<ffffffff812e9f13>] pci_enable_device+0x13/0x20
[   28.064070]  [<ffffffffa013014e>] virtio_pci_probe+0xae/0x1a4 [virtio_pci]
[   28.064070]  [<ffffffff812eabd5>] local_pci_probe+0x45/0xa0
[   28.064070]  [<ffffffff812ebfc5>] ? pci_match_device+0xc5/0xd0
[   28.064070]  [<ffffffff812ec149>] pci_device_probe+0x139/0x150
[   28.064070]  [<ffffffff813b67d7>] driver_probe_device+0x87/0x390
[   28.064070]  [<ffffffff813b6bb3>] __driver_attach+0x93/0xa0
[   28.064070]  [<ffffffff813b6b20>] ? __device_attach+0x40/0x40
[   28.064070]  [<ffffffff813b4563>] bus_for_each_dev+0x73/0xc0
[   28.064070]  [<ffffffff813b622e>] driver_attach+0x1e/0x20
[   28.064070]  [<ffffffff813b5d80>] bus_add_driver+0x200/0x2d0
[   28.064070]  [<ffffffff813b7234>] driver_register+0x64/0xf0
[   28.064070]  [<ffffffff812ebe35>] __pci_register_driver+0xa5/0xc0
[   28.064070]  [<ffffffffa0135000>] ? 0xffffffffa0134fff
[   28.064070]  [<ffffffffa013501e>] virtio_pci_driver_init+0x1e/0x1000 [virtio_pci]
[   28.064070]  [<ffffffff810020e2>] do_one_initcall+0xe2/0x190
[   28.064070]  [<ffffffff810ca98b>] load_module+0x129b/0x1a90
[   28.064070]  [<ffffffff812da220>] ? ddebug_proc_write+0xf0/0xf0
[   28.064070]  [<ffffffff810c72c3>] ? copy_module_from_fd.isra.43+0x53/0x150
[   28.064070]  [<ffffffff810cb336>] SyS_finit_module+0xa6/0xd0
[   28.064070]  [<ffffffff815f2799>] system_call_fastpath+0x16/0x1b
[   28.064070] Code: 48 8b 04 25 b0 c7 00 00 48 89 45 c0 48 89 45 c8 48 89 45 a0 0f 1f 40 00 65 c7 04 25 40 19 01 00 00 00 00 00 fb 66 0f 1f 44 00 00 <49> c7 c6 80 70 8c 81 eb 0d 0f 1f 40 00 49 83 c6 08 41 d1 ef 74 
[   56.064059] BUG: soft lockup - CPU#0 stuck for 23s! [systemd-udevd:202]
[   56.064065] Modules linked in: virtio_pci(+) virtio_ring virtio ata_generic pata_acpi qxl drm_kms_helper ttm drm i2c_core ata_piix libata floppy dm_mirror dm_region_hash dm_log dm_mod
[   56.064065] CPU: 0 PID: 202 Comm: systemd-udevd Not tainted 3.10.0-123.6.3.el7.x86_64 #1
[   56.064065] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
[   56.064065] task: ffff880030f138e0 ti: ffff880030ec8000 task.ti: ffff880030ec8000
[   56.064065] RIP: 0010:[<ffffffff81066ff3>]  [<ffffffff81066ff3>] __do_softirq+0xa3/0x290
[   56.064065] RSP: 0018:ffff880035203ee8  EFLAGS: 00000206
[   56.064065] RAX: ffff880030ec9fd8 RBX: ffffffff8106fe8e RCX: 0000000000000020
[   56.064065] RDX: 00000000fffb70db RSI: 000000000000e263 RDI: ffff880030f138e0
[   56.064065] RBP: ffff880035203f48 R08: 000000000000000c R09: ffff880035203d90
[   56.064065] R10: 0000000000000000 R11: 0000000000000005 R12: ffff880035203e58
[   56.064065] R13: ffffffff815f341d R14: ffff880035203f48 R15: 0000000000000046
[   56.064065] FS:  00007f36fb316880(0000) GS:ffff880035200000(0000) knlGS:0000000000000000
[   56.064065] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   56.064065] CR2: 00007f36fb826068 CR3: 0000000030ed4000 CR4: 00000000000006b0
[   56.064065] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   56.064065] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   56.064065] Stack:
[   56.064065]  ffff880030ec9fd8 0000000a00402140 00000000fffb70dd ffffffff810bda34
[   56.064065]  ffff880030ec9fd8 ffff880030ec9fd8 0000000000000000 0000000000000046
[   56.064065]  0000000000000001 0000000000000000 000000000000000b 0000000000000008
[   56.064065] Call Trace:
[   56.064065]  <IRQ> 
[   56.064065]  [<ffffffff810bda34>] ? tick_program_event+0x24/0x30
[   56.064065]  [<ffffffff815f40dc>] call_softirq+0x1c/0x30
[   56.064065]  [<ffffffff81014d25>] do_softirq+0x55/0x90
[   56.064065]  [<ffffffff810673e5>] irq_exit+0x115/0x120
[   56.064065]  [<ffffffff815f4ab5>] smp_apic_timer_interrupt+0x45/0x60
[   56.064065]  [<ffffffff815f341d>] apic_timer_interrupt+0x6d/0x80
[   56.064065]  <EOI> 
[   56.064065]  [<ffffffff815e961b>] ? _raw_spin_unlock_irqrestore+0x1b/0x40
[   56.064065]  [<ffffffff814af7e8>] pci_conf1_write+0xb8/0x110
[   56.064065]  [<ffffffff814b3264>] raw_pci_write+0x24/0x50
[   56.064065]  [<ffffffff81320abe>] acpi_os_write_pci_configuration+0x56/0x67
[   56.064065]  [<ffffffff8133a8aa>] acpi_ex_pci_config_space_handler+0x2a/0x40
[   56.064065]  [<ffffffff81334283>] acpi_ev_address_space_dispatch+0x1bf/0x22b
[   56.064065]  [<ffffffff813377e5>] acpi_ex_access_region+0x20e/0x2a2
[   56.064065]  [<ffffffff81337bb2>] acpi_ex_field_datum_io+0x105/0x196
[   56.064065]  [<ffffffff81337d14>] acpi_ex_write_with_update_rule+0xd1/0xf0
[   56.064065]  [<ffffffff81337a77>] acpi_ex_insert_into_field+0x1fe/0x234
[   56.064065]  [<ffffffff81337563>] acpi_ex_write_data_to_field+0x1a4/0x1d1
[   56.064065]  [<ffffffff81320c97>] ? acpi_os_release_object+0xe/0x12
[   56.064065]  [<ffffffff8133b5b1>] acpi_ex_store_object_to_node+0xb1/0x12d
[   56.064065]  [<ffffffff8133b6f9>] acpi_ex_store+0xcc/0x25f
[   56.064065]  [<ffffffff81330a15>] ? acpi_ds_create_operands+0x79/0xe0
[   56.064065]  [<ffffffff81338c13>] acpi_ex_opcode_1A_1T_1R+0x39e/0x4d7
[   56.064065]  [<ffffffff81330f29>] acpi_ds_exec_end_op+0xd0/0x3eb
[   56.064065]  [<ffffffff81343013>] acpi_ps_parse_loop+0x523/0x580
[   56.064065]  [<ffffffff8134b248>] ? acpi_ut_create_generic_state+0x37/0x54
[   56.064065]  [<ffffffff81343b00>] acpi_ps_parse_aml+0x98/0x28c
[   56.064065]  [<ffffffff81344355>] acpi_ps_execute_method+0x1c1/0x26c
[   56.064065]  [<ffffffff8133eaf1>] acpi_ns_evaluate+0x1c1/0x258
[   56.064065]  [<ffffffff813459e5>] acpi_rs_set_srs_method_data+0xee/0x125
[   56.064065]  [<ffffffff81345b40>] acpi_set_current_resources+0x54/0x74
[   56.064065]  [<ffffffff8132a881>] acpi_pci_link_set+0x13c/0x21d
[   56.064065]  [<ffffffff8132ad86>] acpi_pci_link_allocate_irq+0x14e/0x227
[   56.064065]  [<ffffffff8132b3fb>] acpi_pci_irq_enable+0xa9/0x229
[   56.064065]  [<ffffffff812e04df>] ? pci_bus_read_config_word+0x9f/0xb0
[   56.064065]  [<ffffffff812e1eac>] ? pci_read_config_word+0x1c/0x20
[   56.064065]  [<ffffffff814b34d1>] pcibios_enable_device+0x31/0x40
[   56.064065]  [<ffffffff812e888b>] do_pci_enable_device+0x3b/0x60
[   56.064065]  [<ffffffff812e9e68>] pci_enable_device_flags+0xe8/0x140
[   56.064065]  [<ffffffff812e9f13>] pci_enable_device+0x13/0x20
[   56.064065]  [<ffffffffa013014e>] virtio_pci_probe+0xae/0x1a4 [virtio_pci]
[   56.064065]  [<ffffffff812eabd5>] local_pci_probe+0x45/0xa0
[   56.064065]  [<ffffffff812ebfc5>] ? pci_match_device+0xc5/0xd0
[   56.064065]  [<ffffffff812ec149>] pci_device_probe+0x139/0x150
[   56.064065]  [<ffffffff813b67d7>] driver_probe_device+0x87/0x390
[   56.064065]  [<ffffffff813b6bb3>] __driver_attach+0x93/0xa0
[   56.064065]  [<ffffffff813b6b20>] ? __device_attach+0x40/0x40
[   56.064065]  [<ffffffff813b4563>] bus_for_each_dev+0x73/0xc0
[   56.064065]  [<ffffffff813b622e>] driver_attach+0x1e/0x20
[   56.064065]  [<ffffffff813b5d80>] bus_add_driver+0x200/0x2d0
[   56.064065]  [<ffffffff813b7234>] driver_register+0x64/0xf0
[   56.064065]  [<ffffffff812ebe35>] __pci_register_driver+0xa5/0xc0
[   56.064065]  [<ffffffffa0135000>] ? 0xffffffffa0134fff
[   56.064065]  [<ffffffffa013501e>] virtio_pci_driver_init+0x1e/0x1000 [virtio_pci]
[   56.064065]  [<ffffffff810020e2>] do_one_initcall+0xe2/0x190
[   56.064065]  [<ffffffff810ca98b>] load_module+0x129b/0x1a90
[   56.064065]  [<ffffffff812da220>] ? ddebug_proc_write+0xf0/0xf0
[   56.064065]  [<ffffffff810c72c3>] ? copy_module_from_fd.isra.43+0x53/0x150
[   56.064065]  [<ffffffff810cb336>] SyS_finit_module+0xa6/0xd0
[   56.064065]  [<ffffffff815f2799>] system_call_fastpath+0x16/0x1b
[   56.064065] Code: 48 8b 04 25 b0 c7 00 00 48 89 45 c0 48 89 45 c8 48 89 45 a0 0f 1f 40 00 65 c7 04 25 40 19 01 00 00 00 00 00 fb 66 0f 1f 44 00 00 <49> c7 c6 80 70 8c 81 eb 0d 0f 1f 40 00 49 83 c6 08 41 d1 ef 74 
[   84.064030] BUG: soft lockup - CPU#0 stuck for 23s! [systemd-udevd:202]
[   84.064066] Modules linked in: virtio_pci(+) virtio_ring virtio ata_generic pata_acpi qxl drm_kms_helper ttm drm i2c_core ata_piix libata floppy dm_mirror dm_region_hash dm_log dm_mod
[   84.064066] CPU: 0 PID: 202 Comm: systemd-udevd Not tainted 3.10.0-123.6.3.el7.x86_64 #1
[   84.064066] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007
[   84.064066] task: ffff880030f138e0 ti: ffff880030ec8000 task.ti: ffff880030ec8000
[   84.064066] RIP: 0010:[<ffffffff81066ff3>]  [<ffffffff81066ff3>] __do_softirq+0xa3/0x290
[   84.064066] RSP: 0018:ffff880035203ee8  EFLAGS: 00000206
[   84.064066] RAX: ffff880030ec9fd8 RBX: ffffffff8106fe8e RCX: 0000000000000020
[   84.064066] RDX: 00000000fffb70db RSI: 000000000000e263 RDI: ffff880030f138e0
[   84.064066] RBP: ffff880035203f48 R08: 000000000000000c R09: ffff880035203d90
[   84.064066] R10: 0000000000000000 R11: 0000000000000005 R12: ffff880035203e58
[   84.064066] R13: ffffffff815f341d R14: ffff880035203f48 R15: 0000000000000046
[   84.064066] FS:  00007f36fb316880(0000) GS:ffff880035200000(0000) knlGS:0000000000000000
[   84.064066] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   84.064066] CR2: 00007f36fb826068 CR3: 0000000030ed4000 CR4: 00000000000006b0
[   84.064066] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   84.064066] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   84.064066] Stack:
[   84.064066]  ffff880030ec9fd8 0000000a00402140 00000000fffb70dd ffffffff810bda34
[   84.064066]  ffff880030ec9fd8 ffff880030ec9fd8 0000000000000000 0000000000000046
[   84.064066]  0000000000000001 0000000000000000 000000000000000b 0000000000000008
[   84.064066] Call Trace:
[   84.064066]  <IRQ> 
[   84.064066]  [<ffffffff810bda34>] ? tick_program_event+0x24/0x30
[   84.064066]  [<ffffffff815f40dc>] call_softirq+0x1c/0x30
[   84.064066]  [<ffffffff81014d25>] do_softirq+0x55/0x90
[   84.064066]  [<ffffffff810673e5>] irq_exit+0x115/0x120
[   84.064066]  [<ffffffff815f4ab5>] smp_apic_timer_interrupt+0x45/0x60
[   84.064066]  [<ffffffff815f341d>] apic_timer_interrupt+0x6d/0x80
[   84.064066]  <EOI> 
[   84.064066]  [<ffffffff815e961b>] ? _raw_spin_unlock_irqrestore+0x1b/0x40
[   84.064066]  [<ffffffff814af7e8>] pci_conf1_write+0xb8/0x110
[   84.064066]  [<ffffffff814b3264>] raw_pci_write+0x24/0x50
[   84.064066]  [<ffffffff81320abe>] acpi_os_write_pci_configuration+0x56/0x67
[   84.064066]  [<ffffffff8133a8aa>] acpi_ex_pci_config_space_handler+0x2a/0x40
[   84.064066]  [<ffffffff81334283>] acpi_ev_address_space_dispatch+0x1bf/0x22b
[   84.064066]  [<ffffffff813377e5>] acpi_ex_access_region+0x20e/0x2a2
[   84.064066]  [<ffffffff81337bb2>] acpi_ex_field_datum_io+0x105/0x196
[   84.064066]  [<ffffffff81337d14>] acpi_ex_write_with_update_rule+0xd1/0xf0
[   84.064066]  [<ffffffff81337a77>] acpi_ex_insert_into_field+0x1fe/0x234
[   84.064066]  [<ffffffff81337563>] acpi_ex_write_data_to_field+0x1a4/0x1d1
[   84.064066]  [<ffffffff81320c97>] ? acpi_os_release_object+0xe/0x12
[   84.064066]  [<ffffffff8133b5b1>] acpi_ex_store_object_to_node+0xb1/0x12d
[   84.064066]  [<ffffffff8133b6f9>] acpi_ex_store+0xcc/0x25f
[   84.064066]  [<ffffffff81330a15>] ? acpi_ds_create_operands+0x79/0xe0
[   84.064066]  [<ffffffff81338c13>] acpi_ex_opcode_1A_1T_1R+0x39e/0x4d7
[   84.064066]  [<ffffffff81330f29>] acpi_ds_exec_end_op+0xd0/0x3eb
[   84.064066]  [<ffffffff81343013>] acpi_ps_parse_loop+0x523/0x580
[   84.064066]  [<ffffffff8134b248>] ? acpi_ut_create_generic_state+0x37/0x54
[   84.064066]  [<ffffffff81343b00>] acpi_ps_parse_aml+0x98/0x28c
[   84.064066]  [<ffffffff81344355>] acpi_ps_execute_method+0x1c1/0x26c
[   84.064066]  [<ffffffff8133eaf1>] acpi_ns_evaluate+0x1c1/0x258
[   84.064066]  [<ffffffff813459e5>] acpi_rs_set_srs_method_data+0xee/0x125
[   84.064066]  [<ffffffff81345b40>] acpi_set_current_resources+0x54/0x74
[   84.064066]  [<ffffffff8132a881>] acpi_pci_link_set+0x13c/0x21d
[   84.064066]  [<ffffffff8132ad86>] acpi_pci_link_allocate_irq+0x14e/0x227
[   84.064066]  [<ffffffff8132b3fb>] acpi_pci_irq_enable+0xa9/0x229
[   84.064066]  [<ffffffff812e04df>] ? pci_bus_read_config_word+0x9f/0xb0
[   84.064066]  [<ffffffff812e1eac>] ? pci_read_config_word+0x1c/0x20
[   84.064066]  [<ffffffff814b34d1>] pcibios_enable_device+0x31/0x40
[   84.064066]  [<ffffffff812e888b>] do_pci_enable_device+0x3b/0x60
[   84.064066]  [<ffffffff812e9e68>] pci_enable_device_flags+0xe8/0x140
[   84.064066]  [<ffffffff812e9f13>] pci_enable_device+0x13/0x20
[   84.064066]  [<ffffffffa013014e>] virtio_pci_probe+0xae/0x1a4 [virtio_pci]
[   84.064066]  [<ffffffff812eabd5>] local_pci_probe+0x45/0xa0
[   84.064066]  [<ffffffff812ebfc5>] ? pci_match_device+0xc5/0xd0
[   84.064066]  [<ffffffff812ec149>] pci_device_probe+0x139/0x150
[   84.064066]  [<ffffffff813b67d7>] driver_probe_device+0x87/0x390
[   84.064066]  [<ffffffff813b6bb3>] __driver_attach+0x93/0xa0
[   84.064066]  [<ffffffff813b6b20>] ? __device_attach+0x40/0x40
[   84.064066]  [<ffffffff813b4563>] bus_for_each_dev+0x73/0xc0
[   84.064066]  [<ffffffff813b622e>] driver_attach+0x1e/0x20
[   84.064066]  [<ffffffff813b5d80>] bus_add_driver+0x200/0x2d0
[   84.064066]  [<ffffffff813b7234>] driver_register+0x64/0xf0
[   84.064066]  [<ffffffff812ebe35>] __pci_register_driver+0xa5/0xc0
[   84.064066]  [<ffffffffa0135000>] ? 0xffffffffa0134fff
[   84.064066]  [<ffffffffa013501e>] virtio_pci_driver_init+0x1e/0x1000 [virtio_pci]
[   84.064066]  [<ffffffff810020e2>] do_one_initcall+0xe2/0x190
[   84.064066]  [<ffffffff810ca98b>] load_module+0x129b/0x1a90
[   84.064066]  [<ffffffff812da220>] ? ddebug_proc_write+0xf0/0xf0
[   84.064066]  [<ffffffff810c72c3>] ? copy_module_from_fd.isra.43+0x53/0x150
[   84.064066]  [<ffffffff810cb336>] SyS_finit_module+0xa6/0xd0
[   84.064066]  [<ffffffff815f2799>] system_call_fastpath+0x16/0x1b
[   84.064066] Code: 48 8b 04 25 b0 c7 00 00 48 89 45 c0 48 89 45 c8 48 89 45 a0 0f 1f 40 00 65 c7 04 25 40 19 01 00 00 00 00 00 fb 66 0f 1f 44 00 00 <49> c7 c6 80 70 8c 81 eb 0d 0f 1f 40 00 49 83 c6 08 41 d1 ef 74
Comment 76 jason wang 2014-07-28 09:44:04 UTC 
The patch is only for RHEL6. For RHEL7, you may want to see 

https://bugzilla.redhat.com/show_bug.cgi?id=1095099
Comment 77 Xiaoqing Wei 2014-07-28 10:07:41 UTC 
the RHEL7 part has been tracked by Bug 1095099 - RHEL7.0 guest cannot trigger kernel panic and guest hang

and reproduced on rhel6 kernel 464

so Set this bug verified.

snipped call trace:

Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
BUG: soft lockup - CPU#0 stuck for 67s! [swapper:1]
Modules linked in:
CPU 0 
Modules linked in:

Pid: 1, comm: swapper Not tainted 2.6.32-464.el6.x86_64 #1 Red Hat KVM
RIP: 0010:[<ffffffff8107b903>]  [<ffffffff8107b903>] __do_softirq+0x73/0x1e0
RSP: 0018:ffff880003203ee0  EFLAGS: 00000206
RAX: 0000000000011440 RBX: ffff880003203f40 RCX: 0000000000000020
RDX: ffff88000a5b3fd8 RSI: 000000000000efb0 RDI: 0000000000000380
RBP: ffffffff8100bb93 R08: ffff88000320e100 R09: 0000000013221240
R10: 0000000000000000 R11: 0000000000000000 R12: ffff880003203e60
R13: 0000000000000202 R14: ffffffff81a83dac R15: ffffffff8152e585
FS:  0000000000000000(0000) GS:ffff880003200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000000000000 CR3: 0000000004a85000 CR4: 00000000000006b0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 1, threadinfo ffff88000a5b2000, task ffff88000a5b1500)
Stack:
 ffffffff810adfda ffff880003203f68 000000000000000a ffff88000a5b3fd8
<d> ffff88000a5b3fd8 0000000000011440 0000000013225155 0000000000000046
<d> ffff88000a5b3fd8 ffffffff81a83dac 0000000000000000 0000000000000001
Call Trace:
 <IRQ> 
 [<ffffffff810adfda>] ? tick_program_event+0x2a/0x30
 [<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
 [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
 [<ffffffff8107b805>] ? irq_exit+0x85/0x90
 [<ffffffff8152e58a>] ? smp_apic_timer_interrupt+0x4a/0x60
 [<ffffffff8100bb93>] ? apic_timer_interrupt+0x13/0x20
 <EOI> 
 [<ffffffff810ebd8a>] ? probe_irq_on+0x6a/0x1f0
 [<ffffffff81361d61>] ? serial8250_config_port+0x291/0xb10
 [<ffffffff8135c2e4>] ? uart_add_one_port+0x1e4/0x3c0
 [<ffffffff81365561>] ? dev_set_name+0x41/0x50
 [<ffffffff81c60d86>] ? serial8250_init+0xfe/0x153
 [<ffffffff81c608d1>] ? cn_proc_init+0x23/0x3d
 [<ffffffff81c60c88>] ? serial8250_init+0x0/0x153
 [<ffffffff8100204c>] ? do_one_initcall+0x3c/0x1d0
 [<ffffffff81c278e4>] ? kernel_init+0x29b/0x2f7
 [<ffffffff81077643>] ? sys_wait4+0xa3/0x100
 [<ffffffff8100c20a>] ? child_rip+0xa/0x20
 [<ffffffff81c27649>] ? kernel_init+0x0/0x2f7
 [<ffffffff8100c200>] ? child_rip+0x0/0x20
Code: 8b 55 c0 c7 45 b0 0a 00 00 00 48 89 45 c8 48 89 55 b8 66 0f 1f 44 00 00 65 c7 04 25 80 66 01 00 00 00 00 00 fb 66 0f 1f 44 00 00 <45> 31 ed 49 c7 c4 80 30 a8 81 eb 05 90 49 83 c4 08 f6 c3 01 74 
Call Trace:
 <IRQ>  [<ffffffff810adfda>] ? tick_program_event+0x2a/0x30
 [<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
 [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
 [<ffffffff8107b805>] ? irq_exit+0x85/0x90
 [<ffffffff8152e58a>] ? smp_apic_timer_interrupt+0x4a/0x60
 [<ffffffff8100bb93>] ? apic_timer_interrupt+0x13/0x20
 <EOI>  [<ffffffff810ebd8a>] ? probe_irq_on+0x6a/0x1f0
 [<ffffffff81361d61>] ? serial8250_config_port+0x291/0xb10
 [<ffffffff8135c2e4>] ? uart_add_one_port+0x1e4/0x3c0
 [<ffffffff81365561>] ? dev_set_name+0x41/0x50
 [<ffffffff81c60d86>] ? serial8250_init+0xfe/0x153
 [<ffffffff81c608d1>] ? cn_proc_init+0x23/0x3d
 [<ffffffff81c60c88>] ? serial8250_init+0x0/0x153
 [<ffffffff8100204c>] ? do_one_initcall+0x3c/0x1d0
 [<ffffffff81c278e4>] ? kernel_init+0x29b/0x2f7
 [<ffffffff81077643>] ? sys_wait4+0xa3/0x100
 [<ffffffff8100c20a>] ? child_rip+0xa/0x20
 [<ffffffff81c27649>] ? kernel_init+0x0/0x2f7
 [<ffffffff8100c200>] ? child_rip+0x0/0x20
Comment 78 errata-xmlrpc 2014-10-14 05:32:18 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2014-1392.html