Bug 857026 - qemu on i686 hangs at boot; APIC emulation in qemu (or kernel) is broken
qemu on i686 hangs at boot; APIC emulation in qemu (or kernel) is broken
Status: CLOSED INSUFFICIENT_DATA
Product: Fedora
Classification: Fedora
Component: qemu (Show other bugs)
18
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Fedora Virtualization Maintainers
Fedora Extras Quality Assurance
: Reopened
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-09-13 08:16 EDT by Richard W.M. Jones
Modified: 2013-06-27 06:16 EDT (History)
13 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-06-23 11:20:58 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)

  None (edit)
Description Richard W.M. Jones 2012-09-13 08:16:05 EDT
Description of problem:

qemu (32 bit ONLY) hangs during boot.  See below for the
messages.  It uses 100% of CPU during this time, but appears
to make no progress.

Note that this is running from libvirt, and the binary is
qemu-system-x86_64 (chosen by libvirt -- I've no idea if that
is correct).

The command line (from libvirt) is also below.

[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 3.6.0-0.rc4.git2.1.fc18.i686 (mockbuild@) (gcc version 4.7.1 20120720 (Red Hat 4.7.1-5) (GCC) ) #1 SMP Fri Sep 7 13:00:10 UTC 2012
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3fffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] Notice: NX (Execute Disable) protection missing in CPU!
[    0.000000] DMI 2.4 present.
[    0.000000] e820: last_pfn = 0x1f400 max_arch_pfn = 0x100000
[    0.000000] found SMP MP-table at [mem 0x000fdaf0-0x000fdaff] mapped at [c00fdaf0]
[    0.000000] init_memory_mapping: [mem 0x00000000-0x1f3fffff]
[    0.000000] RAMDISK: [mem 0x1f2f2000-0x1f3eefff]
[    0.000000] 0MB HIGHMEM available.
[    0.000000] 500MB LOWMEM available.
[    0.000000]   mapped low ram: 0 - 1f400000
[    0.000000]   low ram: 0 - 1f400000
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x00010000-0x00ffffff]
[    0.000000]   Normal   [mem 0x01000000-0x1f3fffff]
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x00010000-0x0009efff]
[    0.000000]   node   0: [mem 0x00100000-0x1f3fffff]
[    0.000000] Using APIC driver default
[    0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org
[    0.000000] Intel MultiProcessor Specification v1.4
[    0.000000]     Virtual Wire compatibility mode.
[    0.000000] MPTABLE: OEM ID: BOCHSCPU
[    0.000000] MPTABLE: Product ID: 0.1         
[    0.000000] MPTABLE: APIC at: 0xFEE00000
[    0.000000] Processor #0 (Bootup-CPU)
[    0.000000] IOAPIC[0]: apic_id 0 already used, trying 1
[    0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
[    0.000000] Processors: 1
[    0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
[    0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000f0000
[    0.000000] PM: Registered nosave memory: 00000000000f0000 - 0000000000100000
[    0.000000] e820: [mem 0x1f400000-0xfffbffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on bare hardware
[    0.000000] setup_percpu: NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] PERCPU: Embedded 334 pages/cpu @dedbc000 s1345152 r0 d22912 u1368064
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 126887
[    0.000000] Kernel command line: panic=1 console=ttyS0 udevtimeout=600 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm 
[    0.000000] Disabling memory control group subsystem
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] __ex_table already sorted, skipping sort
[    0.000000] Initializing CPU#0
[    0.000000] Initializing HighMem for node 0 (00000000:00000000)
[    0.000000] Memory: 486628k/512000k available (6160k kernel code, 24920k reserved, 2912k data, 2020k init, 0k highmem)
[    0.000000] virtual kernel memory layout:
[    0.000000]     fixmap  : 0xffa96000 - 0xfffff000   (5540 kB)
[    0.000000]     pkmap   : 0xff400000 - 0xff800000   (4096 kB)
[    0.000000]     vmalloc : 0xdfc00000 - 0xff3fe000   ( 503 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xdf400000   ( 500 MB)
[    0.000000]       .init : 0xc0cdd000 - 0xc0ed6000   (2020 kB)
[    0.000000]       .data : 0xc0a04031 - 0xc0cdc340   (2912 kB)
[    0.000000]       .text : 0xc0400000 - 0xc0a04031   (6160 kB)
[    0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[    0.000000] SLUB: Genslabs=15, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] \tRCU lockdep checking is enabled.
[    0.000000] \tRCU restricting CPUs from NR_CPUS=32 to nr_cpu_ids=1.
[    0.000000] NR_IRQS:2304 nr_irqs:256 16
[    0.000000] Console: colour *CGA 80x25
[    0.000000] console [ttyS0] enabled
[    0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.000000] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.000000] ... MAX_LOCK_DEPTH:          48
[    0.000000] ... MAX_LOCKDEP_KEYS:        8191
[    0.000000] ... CLASSHASH_SIZE:          4096
[    0.000000] ... MAX_LOCKDEP_ENTRIES:     16384
[    0.000000] ... MAX_LOCKDEP_CHAINS:      32768
[    0.000000] ... CHAINHASH_SIZE:          16384
[    0.000000]  memory used by lock dependency info: 3823 kB
[    0.000000]  per task-struct memory footprint: 1920 bytes
[    0.000000] kmemleak: Kernel memory leak detector disabled
[    0.000000] tsc: Fast TSC calibration failed
[    0.000000] tsc: Unable to calibrate against PIT
[    0.000000] tsc: No reference (HPET/PMTIMER) available
[    0.000000] tsc: Marking TSC unstable due to could not calculate TSC khz
[    0.017997] Calibrating delay loop... 179.96 BogoMIPS (lpj=89984)
[    0.045993] pid_max: default: 32768 minimum: 301
[    0.064990] Security Framework initialized
[    0.072988] SELinux:  Disabled at boot.
[    0.098984] Mount-cache hash table entries: 512
[    0.205968] Initializing cgroup subsys cpuacct
[    0.207968] Initializing cgroup subsys memory
[    0.216967] Initializing cgroup subsys devices
[    0.218966] Initializing cgroup subsys freezer
[    0.219966] Initializing cgroup subsys net_cls
[    0.223965] Initializing cgroup subsys blkio
[    0.226965] Initializing cgroup subsys perf_event
[    0.244962] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.244962] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.244962] tlb_flushall_shift is 0x6
[    0.249962] SMP alternatives: switching to UP code
[    0.463929] Freeing SMP alternatives: 20k freed
[    0.466929] ftrace: allocating 22884 entries in 45 pages
[    0.657899] Enabling APIC mode:  Flat.  Using 1 I/O APICs
[    0.660899] ------------[ cut here ]------------
[    0.662899] WARNING: at arch/x86/kernel/apic/apic.c:1337 setup_local_APIC+0x2c3/0x3d6()
[    0.664898] Hardware name: Bochs
[    0.667898] Modules linked in:
[    0.670898] Pid: 1, comm: swapper/0 Not tainted 3.6.0-0.rc4.git2.1.fc18.i686 #1
[    0.671897] Call Trace:
[    0.672897]  [<c04402a2>] warn_slowpath_common+0x72/0xa0
[    0.674897]  [<c09eaa26>] ? setup_local_APIC+0x2c3/0x3d6
[    0.675897]  [<c09eaa26>] ? setup_local_APIC+0x2c3/0x3d6
[    0.678896]  [<c04402f2>] warn_slowpath_null+0x22/0x30
[    0.679896]  [<c09eaa26>] setup_local_APIC+0x2c3/0x3d6
[    0.680896]  [<c09f0711>] ? printk+0x4d/0x4f
[    0.683896]  [<c0ce9112>] native_smp_prepare_cpus+0x244/0x30d
[    0.684895]  [<c0cdda6d>] kernel_init+0x77/0x1b0
[    0.686895]  [<c0cdd9f6>] ? start_kernel+0x397/0x397
[    0.689895]  [<c0a03502>] kernel_thread_helper+0x6/0x10
[    0.694894] ---[ end trace 270b698500879276 ]---
[    0.700893] ..TIMER: vector=0x41 apic1=-1 pin1=2 apic2=-1 pin2=-1
[    0.700893] smpboot: CPU0: Intel QEMU Virtual CPU version 1.1.91 stepping 03


/bin/qemu-system-x86_64 -name guestfs-vggupb6u5bikxkep -S -M pc-1.2 -cpu qemu32 -no-kvm -m 500 -smp 1,sockets=1,cores=1,threads=1 -uuid 6ba247d8-7f5b-ad3e-b572-b60dd8279c59 -nographic -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/home/rjones/.config/libvirt/qemu/lib/guestfs-vggupb6u5bikxkep.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-reboot -no-shutdown -no-acpi -kernel /home/rjones/d/libguestfs/.guestfs-1000/kernel.1853 -initrd /home/rjones/d/libguestfs/.guestfs-1000/initrd.1853 -append panic=1 console=ttyS0 udevtimeout=600 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm  -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x4 -drive file=/tmp/libguestfs-test-tool-sda-nC6ZvQ,if=none,id=drive-scsi0-0-0-0,format=raw -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=1 -drive file=/home/rjones/d/libguestfs/.guestfs-1000/root.1853,if=none,id=drive-scsi0-0-1-0,format=raw,cache=unsafe -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=1,lun=0,drive=drive-scsi0-0-1-0,id=scsi0-0-1-0 -chardev socket,id=charserial0,path=/home/rjones/d/libguestfs/libguestfsBoqDqo/console.sock -device isa-serial,chardev=charserial0,id=serial0 -chardev socket,id=charchannel0,path=/home/rjones/d/libguestfs/libguestfsBoqDqo/guestfsd.sock -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.libguestfs.channel.0 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 -set drive.drive-scsi0-0-1-0.snapshot=on

Version-Release number of selected component (if applicable):

qemu-1.2.0-0.4.rc1.fc18.i686
libvirt-0.10.1-2.fc18.i686
kernel-3.6.0-0.rc4.git2.1.fc18.i686

How reproducible:

100%

Steps to Reproduce:
1. make quickcheck in libguestfs (or libguestfs-test-tool)
Comment 1 Richard W.M. Jones 2012-09-13 08:20:14 EDT
I just realized I was running the older qemu.  However
I get the same problem with an updated qemu:

qemu-1.2.0-3.fc18.i686
Comment 2 Richard W.M. Jones 2012-09-13 08:32:12 EDT
There's also a bug in libvirt where it's running the wrong
qemu binary.  Dan is fixing that.  I'll use his fix and see
if it makes any difference.
Comment 3 Richard W.M. Jones 2012-09-13 10:06:18 EDT
Same problem happens with qemu-system-i386.
Comment 4 Richard W.M. Jones 2012-09-13 10:23:33 EDT
Adding "noapic" to the kernel command line fixes it.
Kernel bug?  Interaction between APIC emulation in qemu
and the kernel?

/me generally wishes 32 bit would go away.
Comment 5 Daniel Berrange 2012-09-13 10:30:04 EDT
Could well be a Seabios issue. Might want to try updating to seabios 1.7.1, or downgrading to an older version 1.6.3 version to see if anything changes
Comment 6 Fedora Update System 2012-09-13 10:44:22 EDT
libvirt-0.10.1-4.fc18 has been submitted as an update for Fedora 18.
https://admin.fedoraproject.org/updates/FEDORA-2012-13853/libvirt-0.10.1-4.fc18
Comment 7 Richard W.M. Jones 2012-09-13 11:16:00 EDT
Setting back to NEW state.  This bug is something to do
with the kernel or qemu, and probably not a bug in libvirt.
Comment 8 Fedora Update System 2012-09-18 16:02:15 EDT
libvirt-0.10.1-4.fc18 has been pushed to the Fedora 18 stable repository.  If problems still persist, please make note of it in this bug report.
Comment 9 Richard W.M. Jones 2012-09-18 18:13:06 EDT
Reopen, see comment 7.
Comment 10 Richard W.M. Jones 2012-11-24 10:02:42 EST
This seems to still be a problem even with the latest Rawhide
as of today.

In libguestfs we are working around it by passing noapic on
the kernel command line (i386 only).
Comment 11 Cole Robinson 2012-12-14 17:49:24 EST
Marcelo, gleb, any of this sound familiar?
Comment 12 Richard W.M. Jones 2012-12-14 17:58:19 EST
I haven't tested this since we started to use the lpj=
option.  Setting NEEDINFO to me only.
Comment 13 Gleb Natapov 2012-12-15 01:52:46 EST
(In reply to comment #11)
> Marcelo, gleb, any of this sound familiar?
 
First of all check with -enable-kvm and drop -no-kvm. Second what's at  arch/x86/kernel/apic/apic.c:1337
in this specific kernel?
Comment 14 Marcelo Tosatti 2012-12-19 20:46:23 EST
[    0.000000] tsc: Fast TSC calibration failed
[    0.000000] tsc: Unable to calibrate against PIT
[    0.000000] tsc: No reference (HPET/PMTIMER) available
[    0.000000] tsc: Marking TSC unstable due to could not calculate TSC khz
[    0.017997] Calibrating delay loop... 179.96 BogoMIPS (lpj=89984)

Does that differ significantly from the host? If so, then that is likely the issue 

Warning is:

       if (queued) {
                        if (cpu_has_tsc) {
                                rdtscll(ntsc);
                                max_loops = (cpu_khz << 10) - (ntsc - tsc);
                        } else
                                max_loops--;
                }
        } while (queued && max_loops > 0);
        WARN_ON(max_loops <= 0);


BTW, Richard, do you still need the lpj= setting with guest or host using different HZ
values? (that is broken, as you noted, BTW).
Comment 15 Richard W.M. Jones 2012-12-20 07:07:18 EST
[Note this is a Fedora 32 bit TCG-related bug and hence not relevant
to RHEL, or very much at all since few people use 32 bit]

I've just done another test build under Koji, 32 bit, TCG without
the noapic flag, and it's still hanging, so the bug is still
present.

We are now passing lpj= on the kernel command line, and it seems to
make no difference.

(In reply to comment #14)
> [    0.000000] tsc: Fast TSC calibration failed
> [    0.000000] tsc: Unable to calibrate against PIT
> [    0.000000] tsc: No reference (HPET/PMTIMER) available
> [    0.000000] tsc: Marking TSC unstable due to could not calculate TSC khz
> [    0.017997] Calibrating delay loop... 179.96 BogoMIPS (lpj=89984)
> 
> Does that differ significantly from the host? If so, then that is likely the
> issue 

lpj being passed is the same as on the host (but note that "host"
here is the L1 hypervisor, since everything is nested and using TCG).

> BTW, Richard, do you still need the lpj= setting with guest or host using
> different HZ
> values? (that is broken, as you noted, BTW).

It would still be useful to have lpj exported in /proc/cpuinfo.

In the libguestfs case mostly the host kernel is identical to the
appliance kernel, so HZ values would normally be identical.
Comment 16 Marcelo Tosatti 2012-12-20 16:18:27 EST
Can you please provide output of failure with lpj= ?
Comment 17 Richard W.M. Jones 2013-06-27 06:16:30 EDT
I've verified this is fixed now.

Note You need to log in before you can comment on or make changes to this bug.