Bug 1046317

Summary: kernel fails to boot under virtualization, kernel panic in intel_pstate_timer_func
Product: [Fedora] Fedora Reporter: Kashyap Chamarthy <kchamart>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED RAWHIDE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: acathrow, dirk.brandewie, gansalmon, itamar, jonathan, kernel-maint, madhu.chinakonda, mbooth, ptoscano, rjones
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-01-11 15:46:45 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:
Bug Depends On:    
Bug Blocks: 910269    

Description Kashyap Chamarthy 2013-12-24 13:51:29 UTC
Description of problem
-----------------------

 Libguestfs fails to create an appliance with  (either through 'direct' of 'libvirt' backends with a Kernel panic. libguestfs-test-tool result below.


Version
-------

    $ uname -r; rpm -q libvirt libguestfs qemu-system-x86
    3.13.0-0.rc4.git5.1.fc21.x86_64
    libvirt-1.1.3.1-2.fc20.x86_64
    libguestfs-1.25.18-1.fc21.x86_64
    qemu-system-x86-1.6.1-2.fc20.x86_64


How reproducible: Consistently.


Steps to Reproduce
------------------

Run libguestfs diagnostics test tool:

   $ export LIBGUESTFS_BACKEND=libvirt
   $ guestfish get-backend
   libvirt
   # Run the tool:
   $ libguestfs-test-tool

Repeat the above with 'direct' backend:

   $ export LIBGUESTFS_BACKEND=direct
   $ guestfish get-backend
   direct
   $ libguestfs-test-tool

(NOTE: SELinux was Permissive in both cases)


Actual results
--------------

Libguestfs fails to create appliance

With direct backend:
======
$ libguestfs-test-tool
     ************************************************************
     *                    IMPORTANT NOTICE
     *
     * When reporting bugs, include the COMPLETE, UNEDITED
     * output below in your bug report.
     *
     ************************************************************
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/root/bin
SELinux: Permissive
guestfs_get_append: (null)
guestfs_get_backend: libvirt
guestfs_get_autosync: 1
guestfs_get_cachedir: /var/tmp
guestfs_get_direct: 0
guestfs_get_hv: /usr/bin/qemu-kvm
guestfs_get_memsize: 500
guestfs_get_network: 0
guestfs_get_path: /usr/lib64/guestfs
guestfs_get_pgroup: 0
guestfs_get_program: libguestfs-test-tool
guestfs_get_recovery_proc: 1
guestfs_get_selinux: 0
guestfs_get_smp: 1
guestfs_get_tmpdir: /tmp
guestfs_get_trace: 0
guestfs_get_verbose: 1
host_cpu: x86_64
Launching appliance, timeout set to 600 seconds.
libguestfs: launch: program=libguestfs-test-tool
libguestfs: launch: version=1.25.18fedora=21,release=1.fc21,libvirt
libguestfs: launch: backend registered: unix
libguestfs: launch: backend registered: uml
libguestfs: launch: backend registered: libvirt
libguestfs: launch: backend registered: direct
libguestfs: launch: backend=libvirt
libguestfs: launch: tmpdir=/tmp/libguestfs61jk02
libguestfs: launch: umask=0022
libguestfs: launch: euid=0
libguestfs: libvirt version = 1001003 (1.1.3)
libguestfs: guest random name = guestfs-a89x7io0ks9bnvw2
libguestfs: [00000ms] connect to libvirt
libguestfs: opening libvirt handle: URI = NULL, auth = virConnectAuthPtrDefault, flags = 0
libguestfs: successfully opened libvirt handle: conn = 0x7fcba3406810
libguestfs: [00025ms] get libvirt capabilities
libguestfs: [00109ms] parsing capabilities XML
libguestfs: [00110ms] build appliance
libguestfs: command: run: /usr/bin/supermin-helper
libguestfs: command: run: \ --verbose
libguestfs: command: run: \ -f checksum
libguestfs: command: run: \ --host-cpu x86_64
libguestfs: command: run: \ /usr/lib64/guestfs/supermin.d
supermin helper [00000ms] whitelist = (not specified)
supermin helper [00000ms] host_cpu = x86_64
supermin helper [00000ms] dtb_wildcard = (not specified)
supermin helper [00000ms] inputs:
supermin helper [00000ms] inputs[0] = /usr/lib64/guestfs/supermin.d
supermin helper [00000ms] outputs:
supermin helper [00000ms] kernel = (none)
supermin helper [00000ms] dtb = (none)
supermin helper [00000ms] initrd = (none)
supermin helper [00000ms] appliance = (none)
checking modpath /lib/modules/3.13.0-0.rc4.git5.1.fc21.x86_64 is a directory
checking modpath /lib/modules/3.11.9-300.fc20.x86_64 is a directory
checking modpath /lib/modules/3.11.10-301.fc20.x86_64 is a directory
picked kernel vmlinuz-3.13.0-0.rc4.git5.1.fc21.x86_64
supermin helper [00001ms] finished creating kernel
supermin helper [00003ms] visiting /usr/lib64/guestfs/supermin.d
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d/base.img.gz
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d/daemon.img.gz
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d/hostfiles
supermin helper [00171ms] visiting /usr/lib64/guestfs/supermin.d/init.img
supermin helper [00171ms] visiting /usr/lib64/guestfs/supermin.d/udev-rules.img
supermin helper [00171ms] adding kernel modules
supermin helper [00481ms] finished creating appliance
libguestfs: checksum of existing appliance: f57789a6f4cb6b6252712b3f88eba1a60423b533f24c7580ac2700e4b058dbbe
libguestfs: command: run: qemu-img
libguestfs: command: run: \ create
libguestfs: command: run: \ -f qcow2
libguestfs: command: run: \ -b /var/tmp/.guestfs-0/root.31997
libguestfs: command: run: \ -o backing_fmt=raw
libguestfs: command: run: \ /tmp/libguestfs61jk02/snapshot2
Formatting '/tmp/libguestfs61jk02/snapshot2', fmt=qcow2 size=4294967296 backing_file='/var/tmp/.guestfs-0/root.31997' backing_fmt='raw' encryption=off cluster_size=65536 lazy_refcounts=off 
libguestfs: [00716ms] create libvirt XML
libguestfs: libvirt XML:\n<?xml version="1.0"?>\n<domain type="kvm" xmlns:qemu="http://libvirt.org/schemas/domain/qemu/1.0">\n  <name>guestfs-a89x7io0ks9bnvw2</name>\n  <memory unit="MiB">500</memory>\n  <currentMemory unit="MiB">500</currentMemory>\n  <cpu mode="host-passthrough">\n    <model fallback="allow"/>\n  </cpu>\n  <vcpu>1</vcpu>\n  <clock offset="utc">\n    <timer name="kvmclock" present="yes"/>\n  </clock>\n  <os>\n    <type>hvm</type>\n    <kernel>/var/tmp/.guestfs-0/kernel.31997</kernel>\n    <initrd>/var/tmp/.guestfs-0/initrd.31997</initrd>\n    <cmdline>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=screen</cmdline>\n  </os>\n  <on_reboot>destroy</on_reboot>\n  <devices>\n    <controller type="scsi" index="0" model="virtio-scsi"/>\n    <disk device="disk" type="file">\n      <source file="/tmp/libguestfs61jk02/scratch.1"/>\n      <target dev="sda" bus="scsi"/>\n      <driver name="qemu" type="raw" cache="unsafe"/>\n      <address type="drive" controller="0" bus="0" target="0" unit="0"/>\n    </disk>\n    <disk type="file" device="disk">\n      <source file="/tmp/libguestfs61jk02/snapshot2"/>\n      <target dev="sdb" bus="scsi"/>\n      <driver name="qemu" type="qcow2" cache="unsafe"/>\n      <address type="drive" controller="0" bus="0" target="1" unit="0"/>\n      <shareable/>\n    </disk>\n    <serial type="unix">\n      <source mode="connect" path="/tmp/libguestfs61jk02/console.sock"/>\n      <target port="0"/>\n    </serial>\n    <channel type="unix">\n      <source mode="connect" path="/tmp/libguestfs61jk02/guestfsd.sock"/>\n      <target type="virtio" name="org.libguestfs.channel.0"/>\n    </channel>\n  </devices>\n  <qemu:commandline>\n    <qemu:env name="TMPDIR" value="/var/tmp"/>\n  </qemu:commandline>\n</domain>\n
libguestfs: command: run: ls
libguestfs: command: run: \ -a
libguestfs: command: run: \ -l
libguestfs: command: run: \ -Z /var/tmp/.guestfs-0
libguestfs: drwxr-xr-x. root root unconfined_u:object_r:user_tmp_t:s0 .
libguestfs: drwxrwxrwt. root root system_u:object_r:tmp_t:s0       ..
libguestfs: -rwxr-xr-x. root root unconfined_u:object_r:user_tmp_t:s0 checksum
libguestfs: -rw-r--r--. root root system_u:object_r:virt_content_t:s0 initrd
libguestfs: -rw-r--r--. root root system_u:object_r:virt_content_t:s0 initrd.31997
libguestfs: -rw-r--r--. root root system_u:object_r:virt_content_t:s0 kernel
libguestfs: -rw-r--r--. root root system_u:object_r:virt_content_t:s0 kernel.31997
libguestfs: -rw-r--r--. qemu qemu system_u:object_r:virt_content_t:s0 root
libguestfs: -rw-r--r--. qemu qemu system_u:object_r:virt_content_t:s0 root.31997
libguestfs: command: run: ls
libguestfs: command: run: \ -a
libguestfs: command: run: \ -l
libguestfs: command: run: \ -Z /tmp/libguestfs61jk02
libguestfs: drwxr-xr-x. root root unconfined_u:object_r:user_tmp_t:s0 .
libguestfs: drwxrwxrwt. root root system_u:object_r:tmp_t:s0       ..
libguestfs: srw-rw----. root qemu unconfined_u:object_r:user_tmp_t:s0 console.sock
libguestfs: srw-rw----. root qemu unconfined_u:object_r:user_tmp_t:s0 guestfsd.sock
libguestfs: -rw-------. root root unconfined_u:object_r:user_tmp_t:s0 scratch.1
libguestfs: -rw-r--r--. root root unconfined_u:object_r:user_tmp_t:s0 snapshot2
libguestfs: -rwxr-xr-x. root root unconfined_u:object_r:user_tmp_t:s0 umask-check
libguestfs: [00787ms] launch libvirt guest
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.13.0-0.rc4.git5.1.fc21.x86_64 (mockbuild@bkernel02) (gcc version 4.8.2 20131212 (Red Hat 4.8.2-7) (GCC) ) #1 SMP Sat Dec 21 13:25:39 UTC 2013
[    0.000000] 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=screen
[    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 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.4 present.
[    0.000000] Hypervisor detected: KVM
[    0.000000] e820: last_pfn = 0x1f400 max_arch_pfn = 0x400000000
[    0.000000] x86 PAT enabled: cpu 0, old 0x70406, new 0x7010600070106
[    0.000000] found SMP MP-table at [mem 0x000f17f0-0x000f17ff] mapped at [ffff8800000f17f0]
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] Using GB pages for direct mapping
[    0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[    0.000000] init_memory_mapping: [mem 0x1f000000-0x1f1fffff]
[    0.000000] init_memory_mapping: [mem 0x1c000000-0x1effffff]
[    0.000000] init_memory_mapping: [mem 0x00100000-0x1bffffff]
[    0.000000] init_memory_mapping: [mem 0x1f200000-0x1f3fffff]
[    0.000000] RAMDISK: [mem 0x1f255000-0x1f3effff]
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3fffff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x1f3fffff]
[    0.000000]   NODE_DATA [mem 0x1f22e000-0x1f254fff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:1f1ae001, 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-0x0009efff]
[    0.000000]   node   0: [mem 0x00100000-0x1f3fffff]
[    0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org
[    0.000000] Intel MultiProcessor Specification v1.4
[    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, 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: [mem 0x0009f000-0x0009ffff]
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[    0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[    0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] PERCPU: Embedded 477 pages/cpu @ffff88001ee00000 s1925056 r8192 d20544 u2097152
[    0.000000] kvm-clock: cpu 0, msr 0:1f1ae001, primary cpu clock
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 1ee0e140
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 125881
[    0.000000] Policy zone: DMA32
[    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=screen
[    0.000000] Disabling memory control group subsystem
[    0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[    0.000000] Memory: 468064K/511608K available (7626K kernel code, 1583K rwdata, 3212K rodata, 3656K init, 12716K bss, 43544K reserved)
[    0.000000] SLUB: HWalign=64, 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=8192 to nr_cpu_ids=1.
[    0.000000] NR_IRQS:524544 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: 6367 kB
[    0.000000]  per task-struct memory footprint: 2688 bytes
[    0.000000] kmemleak: Kernel memory leak detector disabled
[    0.000000] tsc: Detected 1864.644 MHz processor
[    0.004000] Calibrating delay loop (skipped) preset value.. 3729.28 BogoMIPS (lpj=1864644)
[    0.008042] pid_max: default: 32768 minimum: 301
[    0.011288] Security Framework initialized
[    0.014123] SELinux:  Disabled at boot.
[    0.018483] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.024075] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.028160] Mount-cache hash table entries: 256
[    0.038760] Initializing cgroup subsys memory
[    0.040398] Initializing cgroup subsys devices
[    0.042080] Initializing cgroup subsys freezer
[    0.044078] Initializing cgroup subsys net_cls
[    0.046056] Initializing cgroup subsys blkio
[    0.048045] Initializing cgroup subsys perf_event
[    0.050055] Initializing cgroup subsys hugetlb
[    0.055599] mce: CPU supports 10 MCE banks
[    0.059537] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.059537] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.059537] tlb_flushall_shift: 5
[    2.557741] Freeing SMP alternatives memory: 24K (ffffffff8211f000 - ffffffff82125000)
[    2.713445] ftrace: allocating 25927 entries in 102 pages
[    2.744552] Enabling x2apic
[    2.745000] Enabled x2apic
[    2.745042] Switched APIC routing to physical x2apic.
[    2.780000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    2.780008] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (fam: 06, model: 2a, stepping: 01)
[    2.866642] APIC timer disabled due to verification failure
[    2.879379] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
[    2.907514] watchdog: disabled (inside virtual machine)
[    2.908045] x86: Booted up 1 node, 1 CPUs
[    2.909010] smpboot: Total of 1 processors activated (3729.28 BogoMIPS)
[    2.953422] devtmpfs: initialized
[    2.986303] atomic64 test passed for x86-64 platform with CX8 and with SSE
[    2.987008] pinctrl core: initialized pinctrl subsystem
[    3.014010] RTC time:  4:59:11, date: 11/27/12
[    3.025263] NET: Registered protocol family 16
[    3.036517] cpuidle: using governor menu
[    3.051112] PCI: Using configuration type 1 for base access
[    3.096303] bio: create slab <bio-0> at 0
[    3.106070] ACPI: Interpreter disabled.
[    3.115506] vgaarb: loaded
[    3.124262] SCSI subsystem initialized
[    3.133518] usbcore: registered new interface driver usbfs
[    3.145083] usbcore: registered new interface driver hub
[    3.156220] usbcore: registered new device driver usb
[    3.167902] PCI: Probing PCI hardware
[    3.176276] PCI host bridge to bus 0000:00
[    3.178010] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[    3.180009] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]
[    3.182009] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    3.349544] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]
[    3.365309] NetLabel: Initializing
[    3.366008] NetLabel:  domain hash size = 128
[    3.367007] NetLabel:  protocols = UNLABELED CIPSOv4
[    3.383010] NetLabel:  unlabeled traffic allowed by default
[    3.401127] Switched to clocksource kvm-clock
[    3.612704] pnp: PnP ACPI: disabled
[    3.657420] NET: Registered protocol family 2
[    3.667886] TCP established hash table entries: 4096 (order: 3, 32768 bytes)
[    3.680939] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)
[    3.693109] TCP: Hash tables configured (established 4096 bind 4096)
[    3.704434] TCP: reno registered
[    3.710208] UDP hash table entries: 256 (order: 3, 49152 bytes)
[    3.720675] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)
[    3.734930] NET: Registered protocol family 1
[    3.742806] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    3.753557] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    3.763836] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    3.775550] pci 0000:00:01.2: PCI->APIC IRQ transform: INT D -> IRQ 35
[    3.790473] Unpacking initramfs...
[    3.828960] Freeing initrd memory: 1644K (ffff88001f255000 - ffff88001f3f0000)
[    4.470673] DMA-API: preallocated 65536 debug entries
[    4.479649] DMA-API: debugging enabled by kernel config
[    4.489623] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    4.506048] Scanning for low memory corruption every 60 seconds
[    4.520588] cryptomgr_test (24) used greatest stack depth: 6648 bytes left
[    4.533862] cryptomgr_test (23) used greatest stack depth: 6304 bytes left
[    4.545966] cryptomgr_test (22) used greatest stack depth: 6128 bytes left
[    4.558542] cryptomgr_test (21) used greatest stack depth: 6016 bytes left
[    4.570750] kworker/u2:0 (29) used greatest stack depth: 5632 bytes left
[    4.583578] kworker/u2:1 (31) used greatest stack depth: 5240 bytes left
[    4.596866] cryptomgr_test (26) used greatest stack depth: 5104 bytes left
[    4.609678] alg: No test for __gcm-aes-aesni (__driver-gcm-aes-aesni)
[    4.627548] Initialise system trusted keyring
[    4.635580] audit: initializing netlink socket (disabled)
[    4.644827] type=2000 audit(1353992352.223:1): initialized
[    4.697855] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    4.770476] zbud: loaded
[    4.781555] VFS: Disk quotas dquot_6.5.2
[    4.788907] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    4.812627] msgmni has been set to 917
[    4.821022] Key type big_key registered
[    4.836758] alg: No test for stdrng (krng)
[    4.843963] NET: Registered protocol family 38
[    4.851782] Key type asymmetric registered
[    4.859117] Asymmetric key parser 'x509' registered
[    4.868053] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    4.881871] io scheduler noop registered
[    4.889177] io scheduler deadline registered
[    4.898921] io scheduler cfq registered (default)
[    4.924739] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    4.934604] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    4.947818] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    5.017587] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    5.063809] Non-volatile memory driver v1.3
[    5.075619] Linux agpgart interface v0.103
[    5.130943] scsi0 : ata_piix
[    5.149706] scsi1 : ata_piix
[    5.162043] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc0a0 irq 14
[    5.181561] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0a8 irq 15
[    5.210916] libphy: Fixed MDIO Bus: probed
[    5.226556] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    5.248443] ehci-pci: EHCI PCI platform driver
[    5.256494] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    5.267228] ohci-pci: OHCI PCI platform driver
[    5.274971] uhci_hcd: USB Universal Host Controller Interface driver
[    5.287408] uhci_hcd 0000:00:01.2: PCI->APIC IRQ transform: INT D -> IRQ 35
[    5.301353] uhci_hcd 0000:00:01.2: UHCI Host Controller
[    5.311995] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[    5.326351] uhci_hcd 0000:00:01.2: irq 35, io base 0x0000c040
[    5.338469] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[    5.350786] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    5.364365] usb usb1: Product: UHCI Host Controller
[    5.374246] usb usb1: Manufacturer: Linux 3.13.0-0.rc4.git5.1.fc21.x86_64 uhci_hcd
[    5.397085] usb usb1: SerialNumber: 0000:00:01.2
[    5.413924] hub 1-0:1.0: USB hub found
[    5.421573] hub 1-0:1.0: 2 ports detected
[    5.433626] usbcore: registered new interface driver usbserial
[    5.444719] usbcore: registered new interface driver usbserial_generic
[    5.457612] usbserial: USB Serial support registered for generic
[    5.468939] i8042: PNP: No PS/2 controller found. Probing ports directly.
[    5.492474] serio: i8042 KBD port at 0x60,0x64 irq 1
[    5.502707] serio: i8042 AUX port at 0x60,0x64 irq 12
[    5.514913] mousedev: PS/2 mouse device common for all mice
[    5.531992] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    5.555586] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    5.569826] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram
[    5.583892] device-mapper: uevent: version 1.0.3
[    5.594932] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com
[    5.698699] Intel P-state driver initializing.
[    5.719048] Intel pstate controlling: cpu 0
[    5.726438] cpufreq: __cpufreq_add_dev: ->get() failed
[    5.735501] divide error: 0000 [#1] SMP 
[    5.736319] Modules linked in:
[    5.736319] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.13.0-0.rc4.git5.1.fc21.x86_64 #1
[    5.736319] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[    5.736319] task: ffff88001ea20000 ti: ffff88001e9bc000 task.ti: ffff88001e9bc000
[    5.736319] RIP: 0010:[<ffffffff815c551d>]  [<ffffffff815c551d>] intel_pstate_timer_func+0x11d/0x2b0
[    5.736319] RSP: 0000:ffff88001ee03e00  EFLAGS: 00010246
[    5.736319] RAX: 0000000000000000 RBX: ffff88001a4afb10 RCX: 0000000000006100
[    5.736319] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[    5.736319] RBP: ffff88001ee03e20 R08: 0000000000000000 R09: 0000000000000000
[    5.736319] R10: ffff88001ea20000 R11: 0000000000000000 R12: 00000da01ea20000
[    5.736319] R13: 1ea200001ea20000 R14: ffffffff815c5400 R15: ffff88001a4afb10
[    5.736319] FS:  0000000000000000(0000) GS:ffff88001ee00000(0000) knlGS:0000000000000000
[    5.736319] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[    5.736319] CR2: 0000000000000000 CR3: 0000000001c0c000 CR4: 00000000000006f0
[    5.736319] Stack:
[    5.736319]  fffffffb1a4afb58 ffffffff821a4500 ffff88001a4afb58 0000000000000100
[    5.736319]  ffff88001ee03e90 ffffffff81083e9a ffffffff81083e15 ffffffff82d5ed40
[    5.736319]  ffffffff82590490 0000000000000000 ffffffff81ac39de 0000000000000000
[    5.736319] Call Trace:
[    5.736319]  <IRQ> 
[    5.736319]  [<ffffffff81083e9a>] call_timer_fn+0x8a/0x310
[    5.736319]  [<ffffffff81083e15>] ? call_timer_fn+0x5/0x310
[    5.736319]  [<ffffffff815c5400>] ? pid_param_set+0x130/0x130
[    5.736319]  [<ffffffff81084354>] run_timer_softirq+0x234/0x380
[    5.736319]  [<ffffffff8107aee4>] __do_softirq+0x104/0x430
[    5.736319]  [<ffffffff8107b5fd>] irq_exit+0xcd/0xe0
[    5.736319]  [<ffffffff81770596>] do_IRQ+0x56/0xc0
[    5.736319]  [<ffffffff817650b2>] common_interrupt+0x72/0x72
[    5.736319]  <EOI> 
[    5.736319]  [<ffffffff810e15cd>] ? vprintk_emit+0x1dd/0x5e0
[    5.736319]  [<ffffffff81757719>] printk+0x67/0x69
[    5.736319]  [<ffffffff815c1493>] __cpufreq_add_dev.isra.13+0x883/0x8d0
[    5.736319]  [<ffffffff815c14f0>] cpufreq_add_dev+0x10/0x20
[    5.736319]  [<ffffffff814a14d1>] subsys_interface_register+0xb1/0xf0
[    5.736319]  [<ffffffff815bf5cf>] cpufreq_register_driver+0x9f/0x210
[    5.736319]  [<ffffffff81fb19af>] intel_pstate_init+0x27d/0x3be
[    5.736319]  [<ffffffff81761e3e>] ? mutex_unlock+0xe/0x10
[    5.736319]  [<ffffffff81fb1732>] ? cpufreq_gov_dbs_init+0x12/0x12
[    5.736319]  [<ffffffff8100214a>] do_one_initcall+0xfa/0x1b0
[    5.736319]  [<ffffffff8109dbf5>] ? parse_args+0x225/0x3f0
[    5.736319]  [<ffffffff81f64193>] kernel_init_freeable+0x1fc/0x287
[    5.736319]  [<ffffffff81f638d0>] ? do_early_param+0x88/0x88
[    5.736319]  [<ffffffff8174b530>] ? rest_init+0x150/0x150
[    5.736319]  [<ffffffff8174b53e>] kernel_init+0xe/0x130
[    5.736319]  [<ffffffff8176e27c>] ret_from_fork+0x7c/0xb0
[    5.736319]  [<ffffffff8174b530>] ? rest_init+0x150/0x150
[    5.736319] Code: c1 e0 05 48 63 bc 03 10 01 00 00 48 63 83 d0 00 00 00 48 63 d6 48 c1 e2 08 c1 e1 08 4c 63 c2 48 c1 e0 08 48 98 48 c1 e0 08 48 99 <49> f7 f8 48 98 48 0f af f8 48 c1 ff 08 29 f9 89 ca c1 fa 1f 89 
[    5.736319] RIP  [<ffffffff815c551d>] intel_pstate_timer_func+0x11d/0x2b0
[    5.736319]  RSP <ffff88001ee03e00>
[    6.396576] ---[ end trace 7c6c316068159299 ]---
[    6.404759] Kernel panic - not syncing: Fatal exception in interrupt
[    6.405680] Rebooting in 1 seconds..libguestfs: error: appliance closed the connection unexpectedly, see earlier error messages
libguestfs: child_cleanup: 0x7fcba3406190: child process died
libguestfs: error: guestfs_launch failed, see earlier error messages
libguestfs-test-tool: failed to launch appliance
libguestfs: closing guestfs handle 0x7fcba3406190 (state 0)
libguestfs: command: run: rm
libguestfs: command: run: \ -rf /tmp/libguestfs61jk02
======

Expected results
----------------

Libguestfs should create appliance successfully.

Comment 1 Kashyap Chamarthy 2013-12-24 13:54:11 UTC
With 'direct' backend:

======
$ libguestfs-test-tool

     ************************************************************
     *                    IMPORTANT NOTICE
     *
     * When reporting bugs, include the COMPLETE, UNEDITED
     * output below in your bug report.
     *
     ************************************************************
LIBGUESTFS_BACKEND=direct
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/root/bin
SELinux: Permissive
guestfs_get_append: (null)
guestfs_get_backend: direct
guestfs_get_autosync: 1
guestfs_get_cachedir: /var/tmp
guestfs_get_direct: 0
guestfs_get_hv: /usr/bin/qemu-kvm
guestfs_get_memsize: 500
guestfs_get_network: 0
guestfs_get_path: /usr/lib64/guestfs
guestfs_get_pgroup: 0
guestfs_get_program: libguestfs-test-tool
guestfs_get_recovery_proc: 1
guestfs_get_selinux: 0
guestfs_get_smp: 1
guestfs_get_tmpdir: /tmp
guestfs_get_trace: 0
guestfs_get_verbose: 1
host_cpu: x86_64
Launching appliance, timeout set to 600 seconds.
libguestfs: launch: program=libguestfs-test-tool
libguestfs: launch: version=1.25.18fedora=21,release=1.fc21,libvirt
libguestfs: launch: backend registered: unix
libguestfs: launch: backend registered: uml
libguestfs: launch: backend registered: libvirt
libguestfs: launch: backend registered: direct
libguestfs: launch: backend=direct
libguestfs: launch: tmpdir=/tmp/libguestfswnVOx7
libguestfs: launch: umask=0022
libguestfs: launch: euid=0
libguestfs: command: run: /usr/bin/supermin-helper
libguestfs: command: run: \ --verbose
libguestfs: command: run: \ -f checksum
libguestfs: command: run: \ --host-cpu x86_64
libguestfs: command: run: \ /usr/lib64/guestfs/supermin.d
supermin helper [00000ms] whitelist = (not specified)
supermin helper [00000ms] host_cpu = x86_64
supermin helper [00000ms] dtb_wildcard = (not specified)
supermin helper [00000ms] inputs:
supermin helper [00000ms] inputs[0] = /usr/lib64/guestfs/supermin.d
supermin helper [00000ms] outputs:
supermin helper [00000ms] kernel = (none)
supermin helper [00000ms] dtb = (none)
supermin helper [00000ms] initrd = (none)
supermin helper [00000ms] appliance = (none)
checking modpath /lib/modules/3.13.0-0.rc4.git5.1.fc21.x86_64 is a directory
checking modpath /lib/modules/3.11.9-300.fc20.x86_64 is a directory
checking modpath /lib/modules/3.11.10-301.fc20.x86_64 is a directory
picked kernel vmlinuz-3.13.0-0.rc4.git5.1.fc21.x86_64
supermin helper [00002ms] finished creating kernel
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d/base.img.gz
supermin helper [00004ms] visiting /usr/lib64/guestfs/supermin.d/daemon.img.gz
supermin helper [00005ms] visiting /usr/lib64/guestfs/supermin.d/hostfiles
supermin helper [00214ms] visiting /usr/lib64/guestfs/supermin.d/init.img
supermin helper [00214ms] visiting /usr/lib64/guestfs/supermin.d/udev-rules.img
supermin helper [00214ms] adding kernel modules
supermin helper [00464ms] finished creating appliance
libguestfs: checksum of existing appliance: f57789a6f4cb6b6252712b3f88eba1a60423b533f24c7580ac2700e4b058dbbe
libguestfs: [00496ms] begin testing qemu features
libguestfs: command: run: /usr/bin/qemu-kvm
libguestfs: command: run: \ -display none
libguestfs: command: run: \ -help
libguestfs: command: run: /usr/bin/qemu-kvm
libguestfs: command: run: \ -display none
libguestfs: command: run: \ -version
libguestfs: qemu version 1.6
libguestfs: command: run: /usr/bin/qemu-kvm
libguestfs: command: run: \ -display none
libguestfs: command: run: \ -machine accel=kvm:tcg
libguestfs: command: run: \ -device ?
libguestfs: [01006ms] finished testing qemu features
[01018ms] /usr/bin/qemu-kvm \
    -global virtio-blk-pci.scsi=off \
    -nodefconfig \
    -enable-fips \
    -nodefaults \
    -display none \
    -machine accel=kvm:tcg \
    -cpu host,+kvmclock \
    -m 500 \
    -no-reboot \
    -no-hpet \
    -kernel /var/tmp/.guestfs-0/kernel.32370 \
    -initrd /var/tmp/.guestfs-0/initrd.32370 \
    -device virtio-scsi-pci,id=scsi \
    -drive file=/tmp/libguestfswnVOx7/scratch.1,cache=unsafe,format=raw,id=hd0,if=none \
    -device scsi-hd,drive=hd0 \
    -drive file=/var/tmp/.guestfs-0/root.32370,snapshot=on,id=appliance,cache=unsafe,if=none \
    -device scsi-hd,drive=appliance \
    -device virtio-serial-pci \
    -serial stdio \
    -device sga \
    -chardev socket,path=/tmp/libguestfswnVOx7/guestfsd.sock,id=channel0 \
    -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \
    -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=screen'
\x1b[1;256r\x1b[256;256H\x1b[6n
Google, Inc.
Serial Graphics Adapter 08/14/13
SGABIOS $Id: sgabios.S 8 2010-04-22 00:03:40Z nlaredo $ (mockbuild@) Wed Aug 14 23:57:08 UTC 2013
Term: 80x24
4 0
\x1b[2J
SeaBIOS (version ?-20130815_004056-)


Booting from ROM...


Probing EDD (edd=off to disable)... ok

\x1b[2J[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.13.0-0.rc4.git5.1.fc21.x86_64 (mockbuild@bkernel02) (gcc version 4.8.2 20131212 (Red Hat 4.8.2-7) (GCC) ) #1 SMP Sat Dec 21 13:25:39 UTC 2013
[    0.000000] 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=screen
[    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-0x000000001f3fdfff] usable
[    0.000000] BIOS-e820: [mem 0x000000001f3fe000-0x000000001f3fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.4 present.
[    0.000000] Hypervisor detected: KVM
[    0.000000] e820: last_pfn = 0x1f3fe max_arch_pfn = 0x400000000
[    0.000000] x86 PAT enabled: cpu 0, old 0x70406, new 0x7010600070106
[    0.000000] found SMP MP-table at [mem 0x000f17f0-0x000f17ff] mapped at [ffff8800000f17f0]
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] Using GB pages for direct mapping
[    0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[    0.000000] init_memory_mapping: [mem 0x1f000000-0x1f1fffff]
[    0.000000] init_memory_mapping: [mem 0x1c000000-0x1effffff]
[    0.000000] init_memory_mapping: [mem 0x00100000-0x1bffffff]
[    0.000000] init_memory_mapping: [mem 0x1f200000-0x1f3fdfff]
[    0.000000] RAMDISK: [mem 0x1f255000-0x1f3effff]
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3fdfff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x1f3fdfff]
[    0.000000]   NODE_DATA [mem 0x1f22e000-0x1f254fff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:1f1ae001, 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-0x0009efff]
[    0.000000]   node   0: [mem 0x00100000-0x1f3fdfff]
[    0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org
[    0.000000] Intel MultiProcessor Specification v1.4
[    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, 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: [mem 0x0009f000-0x0009ffff]
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[    0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[    0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] PERCPU: Embedded 477 pages/cpu @ffff88001ee00000 s1925056 r8192 d20544 u2097152
[    0.000000] kvm-clock: cpu 0, msr 0:1f1ae001, primary cpu clock
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 1ee0e140
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 125879
[    0.000000] Policy zone: DMA32
[    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=screen
[    0.000000] Disabling memory control group subsystem
[    0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[    0.000000] Memory: 468052K/511600K available (7626K kernel code, 1583K rwdata, 3212K rodata, 3656K init, 12716K bss, 43548K reserved)
[    0.000000] SLUB: HWalign=64, 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=8192 to nr_cpu_ids=1.
[    0.000000] NR_IRQS:524544 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: 6367 kB
[    0.000000]  per task-struct memory footprint: 2688 bytes
[    0.000000] kmemleak: Kernel memory leak detector disabled
[    0.000000] tsc: Detected 1864.644 MHz processor
[    0.004000] Calibrating delay loop (skipped) preset value.. 3729.28 BogoMIPS (lpj=1864644)
[    0.007040] pid_max: default: 32768 minimum: 301
[    0.010322] Security Framework initialized
[    0.013087] SELinux:  Disabled at boot.
[    0.017411] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.022280] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.025061] Mount-cache hash table entries: 256
[    0.034232] Initializing cgroup subsys memory
[    0.036340] Initializing cgroup subsys devices
[    0.038078] Initializing cgroup subsys freezer
[    0.040077] Initializing cgroup subsys net_cls
[    0.042052] Initializing cgroup subsys blkio
[    0.045042] Initializing cgroup subsys perf_event
[    0.047054] Initializing cgroup subsys hugetlb
[    0.052148] mce: CPU supports 10 MCE banks
[    0.056107] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.056107] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.056107] tlb_flushall_shift: 5
[    2.458212] Freeing SMP alternatives memory: 24K (ffffffff8211f000 - ffffffff82125000)
[    2.658249] ftrace: allocating 25927 entries in 102 pages
[    2.689524] Enabling x2apic
[    2.690000] Enabled x2apic
[    2.690042] Switched APIC routing to physical x2apic.
[    2.724000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    2.731007] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (fam: 06, model: 2a, stepping: 01)
[    2.856000] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
[    2.865849] watchdog: disabled (inside virtual machine)
[    2.866009] x86: Booted up 1 node, 1 CPUs
[    2.867009] smpboot: Total of 1 processors activated (3729.28 BogoMIPS)
[    2.877615] devtmpfs: initialized
[    2.902078] atomic64 test passed for x86-64 platform with CX8 and with SSE
[    2.903007] pinctrl core: initialized pinctrl subsystem
[    2.906008] RTC time:  5:01:28, date: 11/27/12
[    2.908225] NET: Registered protocol family 16
[    2.910789] cpuidle: using governor menu
[    2.917516] PCI: Using configuration type 1 for base access
[    2.949217] bio: create slab <bio-0> at 0
[    2.951516] ACPI: Interpreter disabled.
[    2.954229] vgaarb: loaded
[    2.957395] SCSI subsystem initialized
[    2.959428] usbcore: registered new interface driver usbfs
[    2.960185] usbcore: registered new interface driver hub
[    2.962090] usbcore: registered new device driver usb
[    2.964186] PCI: Probing PCI hardware
[    2.966452] PCI host bridge to bus 0000:00
[    2.967019] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[    2.968029] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]
[    2.969021] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    3.003117] pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
[    3.004112] pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
[    3.054456] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]
[    3.059235] NetLabel: Initializing
[    3.060008] NetLabel:  domain hash size = 128
[    3.061006] NetLabel:  protocols = UNLABELED CIPSOv4
[    3.062238] NetLabel:  unlabeled traffic allowed by default
[    3.063289] Switched to clocksource kvm-clock
[    3.245627] pnp: PnP ACPI: disabled
[    3.283480] NET: Registered protocol family 2
[    3.293367] TCP established hash table entries: 4096 (order: 3, 32768 bytes)
[    3.305819] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)
[    3.318302] TCP: Hash tables configured (established 4096 bind 4096)
[    3.329491] TCP: reno registered
[    3.335218] UDP hash table entries: 256 (order: 3, 49152 bytes)
[    3.345560] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)
[    3.359487] NET: Registered protocol family 1
[    3.367263] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    3.377674] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    3.387837] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    3.400725] Unpacking initramfs...
[    3.422574] Freeing initrd memory: 1644K (ffff88001f255000 - ffff88001f3f0000)
[    3.881376] DMA-API: preallocated 65536 debug entries
[    3.890136] DMA-API: debugging enabled by kernel config
[    3.899660] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    3.914617] Scanning for low memory corruption every 60 seconds
[    3.927383] cryptomgr_test (24) used greatest stack depth: 6648 bytes left
[    3.939977] cryptomgr_test (23) used greatest stack depth: 6304 bytes left
[    3.951580] cryptomgr_test (22) used greatest stack depth: 6128 bytes left
[    3.963400] cryptomgr_test (21) used greatest stack depth: 6016 bytes left
[    3.975569] kworker/u2:0 (29) used greatest stack depth: 5632 bytes left
[    3.989328] cryptomgr_test (26) used greatest stack depth: 5104 bytes left
[    4.001950] alg: No test for __gcm-aes-aesni (__driver-gcm-aes-aesni)
[    4.017551] Initialise system trusted keyring
[    4.024983] audit: initializing netlink socket (disabled)
[    4.033806] type=2000 audit(1353992488.587:1): initialized
[    4.079738] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    4.136589] zbud: loaded
[    4.146233] VFS: Disk quotas dquot_6.5.2
[    4.153761] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    4.175444] msgmni has been set to 917
[    4.183915] Key type big_key registered
[    4.197238] alg: No test for stdrng (krng)
[    4.204549] NET: Registered protocol family 38
[    4.212464] Key type asymmetric registered
[    4.219634] Asymmetric key parser 'x509' registered
[    4.228794] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    4.242278] io scheduler noop registered
[    4.249235] io scheduler deadline registered
[    4.257932] io scheduler cfq registered (default)
[    4.280719] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    4.290638] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    4.303602] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    4.365820] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    4.405905] Non-volatile memory driver v1.3
[    4.418655] Linux agpgart interface v0.103
[    4.452699] scsi0 : ata_piix
[    4.467263] scsi1 : ata_piix
[    4.477592] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14
[    4.495760] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15
[    4.521872] libphy: Fixed MDIO Bus: probed
[    4.534827] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.556439] ehci-pci: EHCI PCI platform driver
[    4.565280] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.576744] ohci-pci: OHCI PCI platform driver
[    4.584863] uhci_hcd: USB Universal Host Controller Interface driver
[    4.597788] usbcore: registered new interface driver usbserial
[    4.608287] usbcore: registered new interface driver usbserial_generic
[    4.620271] usbserial: USB Serial support registered for generic
[    4.631395] i8042: PNP: No PS/2 controller found. Probing ports directly.
[    4.652775] serio: i8042 KBD port at 0x60,0x64 irq 1
[    4.661730] serio: i8042 AUX port at 0x60,0x64 irq 12
[    4.674591] mousedev: PS/2 mouse device common for all mice
[    4.689636] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    4.711414] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    4.724152] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram
[    4.737205] device-mapper: uevent: version 1.0.3
[    4.746899] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com
[    4.839784] Intel P-state driver initializing.
[    4.859972] Intel pstate controlling: cpu 0
[    4.867653] cpufreq: __cpufreq_add_dev: ->get() failed
[    4.877269] divide error: 0000 [#1] SMP 
[    4.878127] Modules linked in:
[    4.878127] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.13.0-0.rc4.git5.1.fc21.x86_64 #1
[    4.878127] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[    4.878127] task: ffff88001ea20000 ti: ffff88001e9bc000 task.ti: ffff88001e9bc000
[    4.878127] RIP: 0010:[<ffffffff815c551d>]  [<ffffffff815c551d>] intel_pstate_timer_func+0x11d/0x2b0
[    4.878127] RSP: 0000:ffff88001ee03e18  EFLAGS: 00010246
[    4.878127] RAX: 0000000000000000 RBX: ffff88001a454348 RCX: 0000000000006100
[    4.878127] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[    4.878127] RBP: ffff88001ee03e38 R08: 0000000000000000 R09: 0000000000000000
[    4.878127] R10: ffff88001ea20000 R11: 0000000000000000 R12: 00000c0a1ea20000
[    4.878127] R13: 1ea200001ea20000 R14: ffffffff815c5400 R15: ffff88001a454348
[    4.878127] FS:  0000000000000000(0000) GS:ffff88001ee00000(0000) knlGS:0000000000000000
[    4.878127] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[    4.878127] CR2: 0000000000000000 CR3: 0000000001c0c000 CR4: 00000000000006f0
[    4.878127] Stack:
[    4.878127]  fffffffb1a454390 ffffffff821a4500 ffff88001a454390 0000000000000100
[    4.878127]  ffff88001ee03ea8 ffffffff81083e9a ffffffff81083e15 ffffffff82d5ed40
[    4.878127]  ffffffff8258cc60 0000000000000000 ffffffff81ac39de 0000000000000000
[    4.878127] Call Trace:
[    4.878127]  <IRQ> 
[    4.878127]  [<ffffffff81083e9a>] call_timer_fn+0x8a/0x310
[    4.878127]  [<ffffffff81083e15>] ? call_timer_fn+0x5/0x310
[    4.878127]  [<ffffffff815c5400>] ? pid_param_set+0x130/0x130
[    4.878127]  [<ffffffff81084354>] run_timer_softirq+0x234/0x380
[    4.878127]  [<ffffffff8107aee4>] __do_softirq+0x104/0x430
[    4.878127]  [<ffffffff8107b5fd>] irq_exit+0xcd/0xe0
[    4.878127]  [<ffffffff81770645>] smp_apic_timer_interrupt+0x45/0x60
[    4.878127]  [<ffffffff8176efb2>] apic_timer_interrupt+0x72/0x80
[    4.878127]  <EOI> 
[    4.878127]  [<ffffffff810e15cd>] ? vprintk_emit+0x1dd/0x5e0
[    4.878127]  [<ffffffff81757719>] printk+0x67/0x69
[    4.878127]  [<ffffffff815c1493>] __cpufreq_add_dev.isra.13+0x883/0x8d0
[    4.878127]  [<ffffffff815c14f0>] cpufreq_add_dev+0x10/0x20
[    4.878127]  [<ffffffff814a14d1>] subsys_interface_register+0xb1/0xf0
[    4.878127]  [<ffffffff815bf5cf>] cpufreq_register_driver+0x9f/0x210
[    4.878127]  [<ffffffff81fb19af>] intel_pstate_init+0x27d/0x3be
[    4.878127]  [<ffffffff81761e3e>] ? mutex_unlock+0xe/0x10
[    4.878127]  [<ffffffff81fb1732>] ? cpufreq_gov_dbs_init+0x12/0x12
[    4.878127]  [<ffffffff8100214a>] do_one_initcall+0xfa/0x1b0
[    4.878127]  [<ffffffff8109dbf5>] ? parse_args+0x225/0x3f0
[    4.878127]  [<ffffffff81f64193>] kernel_init_freeable+0x1fc/0x287
[    4.878127]  [<ffffffff81f638d0>] ? do_early_param+0x88/0x88
[    4.878127]  [<ffffffff8174b530>] ? rest_init+0x150/0x150
[    4.878127]  [<ffffffff8174b53e>] kernel_init+0xe/0x130
[    4.878127]  [<ffffffff8176e27c>] ret_from_fork+0x7c/0xb0
[    4.878127]  [<ffffffff8174b530>] ? rest_init+0x150/0x150
[    4.878127] Code: c1 e0 05 48 63 bc 03 10 01 00 00 48 63 83 d0 00 00 00 48 63 d6 48 c1 e2 08 c1 e1 08 4c 63 c2 48 c1 e0 08 48 98 48 c1 e0 08 48 99 <49> f7 f8 48 98 48 0f af f8 48 c1 ff 08 29 f9 89 ca c1 fa 1f 89 
[    4.878127] RIP  [<ffffffff815c551d>] intel_pstate_timer_func+0x11d/0x2b0
[    4.878127]  RSP <ffff88001ee03e18>
[    5.438189] ---[ end trace f166110ed22cc37a ]---
[    5.446428] Kernel panic - not syncing: Fatal exception in interrupt
[    5.447389] Rebooting in 1 seconds..libguestfs: error: appliance closed the connection unexpectedly, see earlier error messages
libguestfs: child_cleanup: 0x7f2420f1d190: child process died
libguestfs: sending SIGTERM to process 32393
libguestfs: error: guestfs_launch failed, see earlier error messages
libguestfs-test-tool: failed to launch appliance
libguestfs: closing guestfs handle 0x7f2420f1d190 (state 0)
libguestfs: command: run: rm
libguestfs: command: run: \ -rf /tmp/libguestfswnVOx7
======
$ echo $?
1
======

Comment 2 Kashyap Chamarthy 2013-12-24 13:58:13 UTC
[. . .]
> libguestfs: launch: tmpdir=/tmp/libguestfs61jk02
> libguestfs: launch: umask=0022
> libguestfs: launch: euid=0
> libguestfs: libvirt version = 1001003 (1.1.3)
> libguestfs: guest random name = guestfs-a89x7io0ks9bnvw2

appliance qemu command line:
==========
$ cat /var/log/libvirt/qemu/guestfs-a89x7io0ks9bnvw2.log
2012-11-27 04:59:03.152+0000: starting up
LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=none TMPDIR=/var/tmp /usr/bin/qemu-kvm -name guestfs-a89x7io0ks9bnvw2 -S -machine pc-i440fx-1.6,accel=kvm,usb=off -cpu host,+kvmclock -m 500 -realtime mlock=off -smp 1,sockets=1,cores=1,threads=1 -uuid 5eba7315-b1e8-44fd-a378-ca7b69300ba3 -nographic -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/guestfs-a89x7io0ks9bnvw2.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-reboot -no-acpi -kernel /var/tmp/.guestfs-0/kernel.31997 -initrd /var/tmp/.guestfs-0/initrd.31997 -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=screen -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/tmp/libguestfs61jk02/scratch.1,if=none,id=drive-scsi0-0-0-0,format=raw,cache=unsafe -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=/tmp/libguestfs61jk02/snapshot2,if=none,id=drive-scsi0-0-1-0,format=qcow2,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=/tmp/libguestfs61jk02/console.sock -device isa-serial,chardev=charserial0,id=serial0 -chardev socket,id=charchannel0,path=/tmp/libguestfs61jk02/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=0x4
Domain id=6 is tainted: custom-argv
Domain id=6 is tainted: host-cpu
2012-11-27 04:59:17.253+0000: shutting down
==========

Comment 3 Richard W.M. Jones 2013-12-24 14:02:17 UTC
Note that the kernel version affected by this bug is
3.13.0-0.rc4.git5.1.fc21.x86_64

Comment 4 Richard W.M. Jones 2013-12-24 14:03:12 UTC
Also these bugs could be avoided in future by adding
qemu-sanity-check to the kernel RPM (in %check).

http://people.redhat.com/~rjones/qemu-sanity-check/

Comment 5 Josh Boyer 2013-12-24 14:37:14 UTC
I sent the report upstream.  We'll see what they say.

Comment 6 Josh Boyer 2013-12-24 14:44:32 UTC
It would also be helpful to know the first kernel this actually fails with.  There are no changes to intel_pstate in the 3.13 kernel since the initial merge window was open.

Comment 7 Kashyap Chamarthy 2013-12-26 10:05:11 UTC
(In reply to Josh Boyer from comment #5)
> I sent the report upstream.  We'll see what they say.

You inadvertently missed to note this bugzilla link in your lkml post.

Also reported it in Kernel bugzilla -- https://bugzilla.kernel.org/show_bug.cgi?id=67761

Comment 8 Josh Boyer 2013-12-27 13:46:52 UTC
(In reply to Kashyap Chamarthy from comment #7)
> (In reply to Josh Boyer from comment #5)
> > I sent the report upstream.  We'll see what they say.
> 
> You inadvertently missed to note this bugzilla link in your lkml post.

That's what I get for working while I'm supposed to be on PTO.

> Also reported it in Kernel bugzilla --
> https://bugzilla.kernel.org/show_bug.cgi?id=67761

Thanks.

Comment 9 Richard W.M. Jones 2013-12-27 16:43:58 UTC
FWIW I cannot reproduce this.

However I am testing this inside a VM, and nested
virtualization is disabled.  Could this bug be caused
by nested virt?

kernel-3.13.0-0.rc3.git5.1.fc21.x86_64
qemu-1.7.0-3.fc21.x86_64

Comment 10 Kashyap Chamarthy 2013-12-27 17:34:13 UTC
(In reply to Richard W.M. Jones from comment #9)
> FWIW I cannot reproduce this.
> 
> However I am testing this inside a VM, and nested
> virtualization is disabled.  Could this bug be caused
> by nested virt?

Possibly. Gah, I forgot to note this is in a nested environment.

Host is running RHEL7. Here's the versions:

  $ uname -r; rpm -q libvirt-daemon-kvm qemu-kvm-rhev
  3.10.0-52.el7.x86_64
  libvirt-daemon-kvm-1.1.1-12.el7.x86_64
  qemu-kvm-rhev-1.5.3-19.el7.x86_64

Comment 11 Kashyap Chamarthy 2013-12-31 10:07:52 UTC
This upstream patch fixes the Divide Error: https://patchwork.kernel.org/patch/3421271/

stdout of libguestfs-test-tool which shows successful boot-up 
of a nested KVM guest: https://bugzilla.kernel.org/attachment.cgi?id=120401

Comment 12 Dirk Brandewie 2014-01-03 20:02:45 UTC
I believe the patch above is masking the real issue where the MSRs and not being handled correctly in the nested environment.

Please try this patch.
commit 5594b89bee7f83200c1a70bf95d50ac35e4fe3f8
Author: Dirk Brandewie <dirk.j.brandewie@intel.com>
Date:   Fri Jan 3 11:44:15 2014 -0800

    x86/kvm: Handle MSR_PLATFORM_INFO, MSR_IA32_MPERF and MSR_IA32_APERF MSRs
    
    Handle MSRs correctly when read from a nested KVM
    
    Signed-off-by: Dirk Brandewie <dirk.j.brandewie@intel.com>
---
 arch/x86/kvm/x86.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index 5d004da..390ef27 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -2336,6 +2336,9 @@ int kvm_get_msr_common(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata)
 
 	switch (msr) {
 	case MSR_IA32_PLATFORM_ID:
+	case MSR_IA32_MPERF:
+	case MSR_IA32_APERF:
+	case MSR_PLATFORM_INFO:
 	case MSR_IA32_EBL_CR_POWERON:
 	case MSR_IA32_DEBUGCTLMSR:
 	case MSR_IA32_LASTBRANCHFROMIP:

Comment 13 Josh Boyer 2014-01-05 14:09:23 UTC
(In reply to Dirk Brandewie from comment #12)
> I believe the patch above is masking the real issue where the MSRs and not
> being handled correctly in the nested environment.

The above patch is already in -rc7, which is what rawhide is now at as well.  We could try your patch, but if Rafael's is actually masking things then it won't provide clear results either way.  Could you follow up on the upstream thread?

Comment 14 Josh Boyer 2014-01-11 15:46:45 UTC
Dirk's final patch is now also upstream and in the rc7-git5 snapshot.