Bug#782774: linux-image-3.16.0-4-amd64: Nested KVM regression: "BUG: soft lockup - CPU#1 stuck for 22s! [qemu-system-x86:1221]"
Package: src:linux
Version: 3.16.7-ckt9-2
Severity: normal
In a level 1 KVM guest, starting a level 2 KVM guest with QEMU fails and
triggers "soft lockup" messages on the serial console. Then the level 1 KVM
guest becomes unresponsive.
That's a regression since Wheezy: this does not happen (everything works fine,
on the very same level 1 KVM guest, when running Wheezy's kernel.
The host system is running Wheezy + Linux from wheezy-backports.
The level 1 KVM guest is running Jessie, and is using statically allocated
HugePages as its memory backend.
The level 2 KVM guest is started with:
sudo qemu-system-x86_64 -cdrom /srv/tails-i386-1.3.2.iso -m 1280 -nographic -machine pc-0.15,accel=kvm
I could also reproduce this bug with:
-machine pc-0.15,accel=kvm,mem-merge=off
-machine pc-q35-2.1,accel=kvm
The various messages I could see on the serial console can be found at
https://labs.riseup.net/code/issues/9157 -- you'll see there various other
tests and their results.
See in particular:
https://labs.riseup.net/code/attachments/download/739/trace1
https://labs.riseup.net/code/attachments/download/740/trace2
If you prefer, I can attach these logs to this bug report.
I can also reproduce the bug with the 3.19.3-1~exp1 kernel.
-- Package-specific info:
** Version:
Linux version 3.16.0-4-amd64 (debian-kernel@lists.debian.org) (gcc version 4.8.4 (Debian 4.8.4-1) ) #1 SMP Debian 3.16.7-ckt9-2 (2015-04-13)
** Command line:
BOOT_IMAGE=/vmlinuz-3.16.0-4-amd64 root=/dev/mapper/vg1-root ro apparmor=1 security=apparmor console=ttyS0,115200n8 quiet
** Not tainted
** Kernel log:
[ 0.643097] uhci_hcd: USB Universal Host Controller Interface driver
[ 0.643499] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 0.643509] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 0.643534] uhci_hcd 0000:00:01.2: detected 2 ports
[ 0.643655] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c0c0
[ 0.643774] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[ 0.643777] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.643779] usb usb1: Product: UHCI Host Controller
[ 0.643782] usb usb1: Manufacturer: Linux 3.16.0-4-amd64 uhci_hcd
[ 0.643784] usb usb1: SerialNumber: 0000:00:01.2
[ 0.643934] hub 1-0:1.0: USB hub found
[ 0.643942] hub 1-0:1.0: 2 ports detected
[ 0.646119] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
[ 0.648472] SCSI subsystem initialized
[ 0.648633] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[ 0.649339] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
[ 0.649946] libata version 3.00 loaded.
[ 0.651443] ata_piix 0000:00:01.1: version 2.13
[ 0.652063] scsi0 : ata_piix
[ 0.652184] scsi1 : ata_piix
[ 0.652226] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14
[ 0.652228] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15
[ 0.664521] FDC 0 is a S82078B
[ 0.681997] virtio-pci 0000:00:03.0: irq 40 for MSI/MSI-X
[ 0.682018] virtio-pci 0000:00:03.0: irq 41 for MSI/MSI-X
[ 0.682037] virtio-pci 0000:00:03.0: irq 42 for MSI/MSI-X
[ 0.682676] virtio-pci 0000:00:04.0: irq 43 for MSI/MSI-X
[ 0.682801] virtio-pci 0000:00:04.0: irq 44 for MSI/MSI-X
[ 0.684580] vda: vda1 vda2
[ 0.685193] virtio-pci 0000:00:06.0: irq 45 for MSI/MSI-X
[ 0.685214] virtio-pci 0000:00:06.0: irq 46 for MSI/MSI-X
[ 0.686163] vdb: unknown partition table
[ 0.686666] virtio-pci 0000:00:07.0: irq 47 for MSI/MSI-X
[ 0.686686] virtio-pci 0000:00:07.0: irq 48 for MSI/MSI-X
[ 0.687637] vdc: unknown partition table
[ 0.869798] device-mapper: uevent: version 1.0.3
[ 0.869907] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com
[ 0.956079] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 1.040014] raid6: sse2x1 4759 MB/s
[ 1.108009] raid6: sse2x2 7184 MB/s
[ 1.176014] raid6: sse2x4 8373 MB/s
[ 1.176016] raid6: using algorithm sse2x4 (8373 MB/s)
[ 1.176017] raid6: using ssse3x2 recovery algorithm
[ 1.176514] xor: automatically using best checksumming function:
[ 1.204911] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[ 1.204916] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[ 1.204918] usb 1-1: Product: QEMU USB Tablet
[ 1.204921] usb 1-1: Manufacturer: QEMU 1.1.2
[ 1.204923] usb 1-1: SerialNumber: 42
[ 1.213391] hidraw: raw HID events driver (C) Jiri Kosina
[ 1.216009] avx : 18136.000 MB/sec
[ 1.221592] Btrfs loaded
[ 1.222239] usbcore: registered new interface driver usbhid
[ 1.222243] usbhid: USB HID core driver
[ 1.225889] input: QEMU 1.1.2 QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
[ 1.226109] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU 1.1.2 QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[ 1.499054] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
[ 1.540148] tsc: Refined TSC clocksource calibration: 1799.962 MHz
[ 3.140909] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory.
[ 3.234219] fuse init (API version 7.23)
[ 3.290834] loop: module loaded
[ 3.413794] systemd-udevd[195]: starting version 215
[ 3.782819] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
[ 3.782827] ACPI: Power Button [PWRF]
[ 3.874144] input: PC Speaker as /devices/platform/pcspkr/input/input4
[ 3.892594] [drm] Initialized drm 1.1.0 20060810
[ 3.935690] ppdev: user-space parallel port driver
[ 3.942719] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0
[ 4.037948] AVX version of gcm_enc/dec engaged.
[ 4.041123] alg: No test for __gcm-aes-aesni (__driver-gcm-aes-aesni)
[ 4.069710] alg: No test for crc32 (crc32-pclmul)
[ 4.145293] intel_rapl: no valid rapl domains found in package 0
[ 4.158321] intel_rapl: no valid rapl domains found in package 0
[ 4.392146] EXT4-fs (dm-0): re-mounted. Opts: errors=remount-ro
[ 4.455201] EXT4-fs (vdb): recovery complete
[ 4.455208] EXT4-fs (vdb): mounted filesystem with ordered data mode. Opts: acl
[ 4.455282] EXT4-fs (vdc): recovery complete
[ 4.455289] EXT4-fs (vdc): mounted filesystem with ordered data mode. Opts: acl
[ 4.742382] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input5
[ 5.220431] EXT4-fs (vda1): mounting ext2 file system using the ext4 subsystem
[ 5.227651] EXT4-fs (vda1): mounted filesystem without journal. Opts: (null)
[ 5.234126] systemd-journald[177]: Received request to flush runtime journal from PID 1
[ 5.561185] audit: type=1400 audit(1429286754.484:2): apparmor="STATUS" operation="profile_load" name="/{usr/,}bin/ping" pid=492 comm="apparmor_parser"
[ 5.568313] audit: type=1400 audit(1429286754.492:3): apparmor="STATUS" operation="profile_load" name="gst_plugin_scanner" pid=492 comm="apparmor_parser"
[ 5.582990] audit: type=1400 audit(1429286754.504:4): apparmor="STATUS" operation="profile_load" name="/sbin/klogd" pid=492 comm="apparmor_parser"
[ 5.605687] audit: type=1400 audit(1429286754.528:5): apparmor="STATUS" operation="profile_load" name="/sbin/syslog-ng" pid=492 comm="apparmor_parser"
[ 5.667149] audit: type=1400 audit(1429286754.588:6): apparmor="STATUS" operation="profile_load" name="/sbin/syslogd" pid=492 comm="apparmor_parser"
[ 5.693422] audit: type=1400 audit(1429286754.616:7): apparmor="STATUS" operation="profile_load" name="system_tor" pid=492 comm="apparmor_parser"
[ 5.746398] audit: type=1400 audit(1429286754.668:8): apparmor="STATUS" operation="profile_load" name="/usr/lib/chromium-browser/chromium-browser" pid=492 comm="apparmor_parser"
[ 5.746405] audit: type=1400 audit(1429286754.668:9): apparmor="STATUS" operation="profile_load" name="browser_java" pid=492 comm="apparmor_parser"
[ 5.746409] audit: type=1400 audit(1429286754.668:10): apparmor="STATUS" operation="profile_load" name="browser_openjdk" pid=492 comm="apparmor_parser"
[ 5.746413] audit: type=1400 audit(1429286754.668:11): apparmor="STATUS" operation="profile_load" name="chromium_browser_sandbox" pid=492 comm="apparmor_parser"
[ 6.338748] RPC: Registered named UNIX socket transport module.
[ 6.338753] RPC: Registered udp transport module.
[ 6.338755] RPC: Registered tcp transport module.
[ 6.338757] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 6.362961] FS-Cache: Loaded
[ 6.393745] FS-Cache: Netfs 'nfs' registered for caching
[ 6.435512] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[ 26.092089] random: nonblocking pool is initialized
** Model information
sys_vendor: Bochs
product_name: Bochs
product_version:
chassis_vendor: Bochs
chassis_version:
bios_vendor: Bochs
bios_version: Bochs
** Loaded modules:
nfsd
auth_rpcgss
oid_registry
nfs_acl
nfs
lockd
fscache
sunrpc
kvm_intel
kvm
crc32_pclmul
ghash_clmulni_intel
aesni_intel
aes_x86_64
lrw
gf128mul
glue_helper
ablk_helper
cryptd
i2c_piix4
ttm
ppdev
joydev
drm_kms_helper
psmouse
drm
pcspkr
i2c_core
parport_pc
evdev
virtio_balloon
serio_raw
parport
processor
thermal_sys
button
loop
fuse
autofs4
ext4
crc16
mbcache
jbd2
hid_generic
btrfs
usbhid
hid
xor
raid6_pq
dm_mod
md_mod
ata_generic
virtio_blk
virtio_net
crct10dif_pclmul
crct10dif_common
crc32c_intel
floppy
ata_piix
libata
scsi_mod
virtio_pci
uhci_hcd
virtio_ring
virtio
ehci_hcd
usbcore
usb_common
** PCI devices:
00:00.0 Host bridge [0600]: Intel Corporation 440FX - 82441FX PMC [Natoma] [8086:1237] (rev 02)
Subsystem: Red Hat, Inc Qemu virtual machine [1af4:1100]
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
00:01.0 ISA bridge [0601]: Intel Corporation 82371SB PIIX3 ISA [Natoma/Triton II] [8086:7000]
Subsystem: Red Hat, Inc Qemu virtual machine [1af4:1100]
Physical Slot: 1
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
00:01.1 IDE interface [0101]: Intel Corporation 82371SB PIIX3 IDE [Natoma/Triton II] [8086:7010] (prog-if 80 [Master])
Subsystem: Red Hat, Inc Qemu virtual machine [1af4:1100]
Physical Slot: 1
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Region 0: [virtual] Memory at 000001f0 (32-bit, non-prefetchable) [size=8]
Region 1: [virtual] Memory at 000003f0 (type 3, non-prefetchable)
Region 2: [virtual] Memory at 00000170 (32-bit, non-prefetchable) [size=8]
Region 3: [virtual] Memory at 00000370 (type 3, non-prefetchable)
Region 4: I/O ports at c120 [size=16]
Kernel driver in use: ata_piix
00:01.2 USB controller [0c03]: Intel Corporation 82371SB PIIX3 USB [Natoma/Triton II] [8086:7020] (rev 01) (prog-if 00 [UHCI])
Subsystem: Red Hat, Inc QEMU Virtual Machine [1af4:1100]
Physical Slot: 1
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin D routed to IRQ 11
Region 4: I/O ports at c0c0 [size=32]
Kernel driver in use: uhci_hcd
00:01.3 Bridge [0680]: Intel Corporation 82371AB/EB/MB PIIX4 ACPI [8086:7113] (rev 03)
Subsystem: Red Hat, Inc Qemu virtual machine [1af4:1100]
Physical Slot: 1
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Interrupt: pin A routed to IRQ 9
Kernel driver in use: piix4_smbus
00:02.0 VGA compatible controller [0300]: Cirrus Logic GD 5446 [1013:00b8] (prog-if 00 [VGA controller])
Subsystem: Red Hat, Inc QEMU Virtual Machine [1af4:1100]
Physical Slot: 2
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Region 0: Memory at fc000000 (32-bit, prefetchable) [size=32M]
Region 1: Memory at febf0000 (32-bit, non-prefetchable) [size=4K]
Expansion ROM at febd0000 [disabled] [size=64K]
00:03.0 Ethernet controller [0200]: Red Hat, Inc Virtio network device [1af4:1000]
Subsystem: Red Hat, Inc Device [1af4:0001]
Physical Slot: 3
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin A routed to IRQ 10
Region 0: I/O ports at c0e0 [size=32]
Region 1: Memory at febf1000 (32-bit, non-prefetchable) [size=4K]
Expansion ROM at febe0000 [disabled] [size=64K]
Capabilities: <access denied>
Kernel driver in use: virtio-pci
00:04.0 SCSI storage controller [0100]: Red Hat, Inc Virtio block device [1af4:1001]
Subsystem: Red Hat, Inc Device [1af4:0002]
Physical Slot: 4
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin A routed to IRQ 11
Region 0: I/O ports at c000 [size=64]
Region 1: Memory at febf2000 (32-bit, non-prefetchable) [size=4K]
Capabilities: <access denied>
Kernel driver in use: virtio-pci
00:05.0 Unclassified device [00ff]: Red Hat, Inc Virtio memory balloon [1af4:1002]
Subsystem: Red Hat, Inc Device [1af4:0005]
Physical Slot: 5
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin A routed to IRQ 10
Region 0: I/O ports at c100 [size=32]
Kernel driver in use: virtio-pci
00:06.0 SCSI storage controller [0100]: Red Hat, Inc Virtio block device [1af4:1001]
Subsystem: Red Hat, Inc Device [1af4:0002]
Physical Slot: 6
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin A routed to IRQ 11
Region 0: I/O ports at c040 [size=64]
Region 1: Memory at febf3000 (32-bit, non-prefetchable) [size=4K]
Capabilities: <access denied>
Kernel driver in use: virtio-pci
00:07.0 SCSI storage controller [0100]: Red Hat, Inc Virtio block device [1af4:1001]
Subsystem: Red Hat, Inc Device [1af4:0002]
Physical Slot: 7
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0
Interrupt: pin A routed to IRQ 10
Region 0: I/O ports at c080 [size=64]
Region 1: Memory at febf4000 (32-bit, non-prefetchable) [size=4K]
Capabilities: <access denied>
Kernel driver in use: virtio-pci
** USB devices:
Bus 001 Device 002: ID 0627:0001 Adomax Technology Co., Ltd
Bus 001 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
-- System Information:
Debian Release: 8.0
APT prefers testing
APT policy: (990, 'testing'), (1, 'unstable')
Architecture: amd64 (x86_64)
Kernel: Linux 3.16.0-4-amd64 (SMP w/3 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages linux-image-3.16.0-4-amd64 depends on:
ii debconf [debconf-2.0] 1.5.56
ii initramfs-tools [linux-initramfs-tool] 0.120
ii kmod 18-3
ii linux-base 3.5
ii module-init-tools 18-3
Versions of packages linux-image-3.16.0-4-amd64 recommends:
ii firmware-linux-free 3.3
ii irqbalance 1.0.6-3
Versions of packages linux-image-3.16.0-4-amd64 suggests:
pn debian-kernel-handbook <none>
ii extlinux 3:6.03+dfsg-5
ii grub-pc 2.02~beta2-22
pn linux-doc-3.16 <none>
Versions of packages linux-image-3.16.0-4-amd64 is related to:
pn firmware-atheros <none>
pn firmware-bnx2 <none>
pn firmware-bnx2x <none>
pn firmware-brcm80211 <none>
pn firmware-intelwimax <none>
pn firmware-ipw2x00 <none>
pn firmware-ivtv <none>
pn firmware-iwlwifi <none>
pn firmware-libertas <none>
pn firmware-linux <none>
pn firmware-linux-nonfree <none>
pn firmware-myricom <none>
pn firmware-netxen <none>
pn firmware-qlogic <none>
pn firmware-ralink <none>
pn firmware-realtek <none>
pn xen-hypervisor <none>
-- debconf information:
linux-image-3.16.0-4-amd64/prerm/removing-running-kernel-3.16.0-4-amd64: true
linux-image-3.16.0-4-amd64/postinst/depmod-error-initrd-3.16.0-4-amd64: false
linux-image-3.16.0-4-amd64/postinst/mips-initrd-3.16.0-4-amd64:
Reply to: