guestmount hang on

guestmount.log

===== Test starts here =====
LIBGUESTFS_DEBUG=1
TMPDIR=(not set)
libguestfs: new guestfs handle 0xaee700
library version: 1.16.19rhel=6,release=1.el6
guestfs_get_append: (null)
guestfs_get_attach_method: appliance
guestfs_get_autosync: 1
guestfs_get_direct: 0
guestfs_get_memsize: 500
guestfs_get_network: 0
guestfs_get_path: /usr/lib64/guestfs
guestfs_get_pgroup: 0
guestfs_get_qemu: /usr/libexec/qemu-kvm
guestfs_get_recovery_proc: 1
guestfs_get_selinux: 0
guestfs_get_smp: 1
guestfs_get_trace: 0
guestfs_get_verbose: 1
host_cpu: x86_64
Launching appliance, timeout set to 600 seconds.
libguestfs: [00015ms] febootstrap-supermin-helper --verbose -f checksum '/usr/lib64/guestfs/supermin.d' x86_64
supermin helper [00000ms] whitelist = (not specified), host_cpu = x86_64, kernel = (null), initrd = (null), appliance = (null)
supermin helper [00000ms] inputs[0] = /usr/lib64/guestfs/supermin.d
checking modpath /lib/modules/2.6.32-220.el6.x86_64 is a directory
picked vmlinuz-2.6.32-220.el6.x86_64 because modpath /lib/modules/2.6.32-220.el6.x86_64 exists
supermin helper [00023ms] finished creating kernel
supermin helper [00024ms] visiting /usr/lib64/guestfs/supermin.d
supermin helper [00031ms] visiting /usr/lib64/guestfs/supermin.d/base.img
supermin helper [00035ms] visiting /usr/lib64/guestfs/supermin.d/daemon.img
supermin helper [00042ms] visiting /usr/lib64/guestfs/supermin.d/hostfiles
supermin helper [00399ms] visiting /usr/lib64/guestfs/supermin.d/init.img
supermin helper [00399ms] adding kernel modules
supermin helper [00676ms] finished creating appliance
libguestfs: [00746ms] begin testing qemu features
libguestfs: [00761ms] finished testing qemu features
libguestfs: accept_from_daemon: 0xaee700 g->state = 1
[00762ms] /usr/libexec/qemu-kvm \
    -global virtio-blk-pci.scsi=off \
    -drive file=/tmp/libguestfs-test-tool-sda-GTY91T,cache=off,format=raw,if=virtio \
    -nodefconfig \
    -machine accel=kvm:tcg \
    -nodefaults \
    -nographic \
    -m 500 \
    -no-reboot \
    -no-hpet \
    -device virtio-serial \
    -serial stdio \
    -chardev socket,path=/tmp/libguestfseA2wVp/guestfsd.sock,id=channel0 \
    -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \
    -kernel /var/tmp/.guestfs-0/kernel.3072 \
    -initrd /var/tmp/.guestfs-0/initrd.3072 \
    -append 'panic=1 console=ttyS0 udevtimeout=300 no_timer_check acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_verbose=1 TERM=xterm ' \
    -drive file=/var/tmp/.guestfs-0/root.3072,snapshot=on,if=virtio,cache=unsafeInitializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.32-220.el6.x86_64 ([email protected]) (gcc version 4.4.6 20110731 (Red Hat 4.4.6-3) (GCC) ) #1 SMP Tue Dec 6 19:48:22 GMT 2011
Command line: panic=1 console=ttyS0 udevtimeout=300 no_timer_check acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_verbose=1 TERM=xterm 
KERNEL supported cpus:
  Intel GenuineIntel
  AMD AuthenticAMD
  Centaur CentaurHauls
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009bc00 (usable)
 BIOS-e820: 000000000009bc00 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000001f3fd000 (usable)
 BIOS-e820: 000000001f3fd000 - 000000001f400000 (reserved)
 BIOS-e820: 00000000feffc000 - 00000000ff000000 (reserved)
 BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
DMI 2.4 present.
SMBIOS version 2.4 @ 0xFDA50
last_pfn = 0x1f3fd max_arch_pfn = 0x400000000
PAT not supported by CPU.
init_memory_mapping: 0000000000000000-000000001f3fd000
RAMDISK: 1f1b2000 - 1f3ef800
No NUMA configuration found
Faking a node at 0000000000000000-000000001f3fd000
Bootmem setup node 0 0000000000000000-000000001f3fd000
  NODE_DATA [0000000000009000 - 000000000003cfff]
  bootmap [000000000003d000 -  0000000000040e7f] pages 4
(7 early reservations) ==> bootmem [0000000000 - 001f3fd000]
  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
  #1 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
  #2 [0001000000 - 000200c7e4]    TEXT DATA BSS ==> [0001000000 - 000200c7e4]
  #3 [001f1b2000 - 001f3ef800]          RAMDISK ==> [001f1b2000 - 001f3ef800]
  #4 [000009bc00 - 0000100000]    BIOS reserved ==> [000009bc00 - 0000100000]
  #5 [000200d000 - 000200d051]              BRK ==> [000200d000 - 000200d051]
  #6 [0000008000 - 0000009000]          PGTABLE ==> [0000008000 - 0000009000]
found SMP MP-table at [ffff8800000fda70] fda70
kvm-clock: Using msrs 4b564d01 and 4b564d00
kvm-clock: cpu 0, msr 0:1c1df41, 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 -> 0x0000009b
    0: 0x00000100 -> 0x0001f3fd
SFI: Simple Firmware Interface v0.7 http://simplefirmware.org
Intel MultiProcessor Specification v1.4
MPTABLE: OEM ID: BOCHSCPU
MPTABLE: Product ID: 0.1         
MPTABLE: APIC at: 0xFEE00000
Processor #0 (Bootup-CPU)
I/O APIC #1 Version 17 at 0xFEC00000.
Processors: 1
SMP: Allowing 1 CPUs, 0 hotplug CPUs
PM: Registered nosave memory: 000000000009b000 - 000000000009c000
PM: Registered nosave memory: 000000000009c000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000f0000
PM: Registered nosave memory: 00000000000f0000 - 0000000000100000
Allocating PCI resources starting at 1f400000 (gap: 1f400000:dfbfc000)
Booting paravirtualized kernel on KVM
NR_CPUS:4096 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
PERCPU: Embedded 30 pages/cpu @ffff880002200000 s92696 r8192 d21992 u2097152
pcpu-alloc: s92696 r8192 d21992 u2097152 alloc=1*2097152
pcpu-alloc: [0] 0 
kvm-clock: cpu 0, msr 0:2215f41, primary cpu clock
Built 1 zonelists in Node order, mobility grouping on.  Total pages: 126041
Policy zone: DMA32
Kernel command line: panic=1 console=ttyS0 udevtimeout=300 no_timer_check acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_verbose=1 TERM=xterm 
[    0.000000] Disabling memory control group subsystem
[    0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[    0.000000] Checking aperture...
[    0.000000] No AGP bridge found
[    0.000000] Memory: 484048k/511988k available (5084k kernel code, 408k absent, 27532k reserved, 7229k data, 1244k init)
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS:33024 nr_irqs:256
[    0.000000] Console: colour *CGA 80x25
[    0.000000] console [ttyS0] enabled
[    0.000000] Detected 1999.694 MHz processor.
[    0.001999] Calibrating delay loop (skipped) preset value.. 3999.38 BogoMIPS (lpj=1999694)
[    0.002386] pid_max: default: 32768 minimum: 301
[    0.003288] Security Framework initialized
[    0.004023] SELinux:  Disabled at boot.
[    0.006191] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.007262] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.008147] Mount-cache hash table entries: 256
[    0.010248] Initializing cgroup subsys ns
[    0.011030] Initializing cgroup subsys cpuacct
[    0.011614] Initializing cgroup subsys memory
[    0.012042] Initializing cgroup subsys devices
[    0.013016] Initializing cgroup subsys freezer
[    0.014031] Initializing cgroup subsys net_cls
[    0.014662] Initializing cgroup subsys blkio
[    0.015027] Initializing cgroup subsys perf_event
[    0.016707] mce: CPU supports 10 MCE banks
[    0.017160] alternatives: switching to unfair spinlock
[    0.024411] SMP alternatives: switching to UP code
[    0.057720] Freeing SMP alternatives: 33k freed
[    0.058057] ftrace: converting mcount calls to 0f 1f 44 00 00
[    0.059016] ftrace: allocating 20776 entries in 82 pages
[    0.061103] Setting APIC routing to flat
[    0.066280] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.067007] CPU0: Intel QEMU Virtual CPU version 1.0,1 stepping 03
[    0.170300] Performance Events: unsupported p6 CPU model 2 no PMU driver, software events only.
[    0.170992] NMI watchdog disabled (cpu0): hardware events not enabled
[    0.171019] Brought up 1 CPUs
[    0.171237] Total of 1 processors activated (3999.38 BogoMIPS).
[    0.172233] devtmpfs: initialized
[    0.175135] regulator: core version 0.5
[    0.175453] NET: Registered protocol family 16
[    0.177057] PCI: Using configuration type 1 for base access
[    0.178200] bio: create slab <bio-0> at 0
[    0.178587] ACPI: Interpreter disabled.
[    0.178925] vgaarb: loaded
[    0.179542] SCSI subsystem initialized
[    0.180090] usbcore: registered new interface driver usbfs
[    0.180494] usbcore: registered new interface driver hub
[    0.180880] usbcore: registered new device driver usb
[    0.181077] PCI: Probing PCI hardware
[    0.182483] pci 0000:00:01.3: quirk: region b000-b03f claimed by PIIX4 ACPI
[    0.183008] pci 0000:00:01.3: quirk: region b100-b10f claimed by PIIX4 SMB
[    0.190806] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]
[    0.192304] NetLabel: Initializing
[    0.192784] NetLabel:  domain hash size = 128
[    0.193007] NetLabel:  protocols = UNLABELED CIPSOv4
[    0.194050] NetLabel:  unlabeled traffic allowed by default
[    0.195183] Switching to clocksource kvm-clock
[    0.214535] pnp: PnP ACPI: disabled
[    0.215695] NET: Registered protocol family 2
[    0.216591] IP route cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.218785] TCP established hash table entries: 16384 (order: 6, 262144 bytes)
[    0.220036] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[    0.221118] TCP: Hash tables configured (established 16384 bind 16384)
[    0.222031] TCP reno registered
[    0.222700] NET: Registered protocol family 1
[    0.223458] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.224472] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    0.225402] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.226444] Trying to unpack rootfs image as initramfs...
[    0.230138] Freeing initrd memory: 2294k freed
[    0.231326] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    0.233186] audit: initializing netlink socket (disabled)
[    0.233979] type=2000 audit(1348471547.233:1): initialized
[    0.252184] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.254316] VFS: Disk quotas dquot_6.5.2
[    0.254909] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.256066] msgmni has been set to 949
[    0.257173] alg: No test for stdrng (krng)
[    0.257774] ksign: Installing public key data
[    0.258500] Loading keyring
[    0.258917] - Added public key 3A25C209CBB1D210
[    0.259654] - User ID: CentOS (Kernel Module GPG key)
[    0.260518] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.261694] io scheduler noop registered
[    0.262360] io scheduler anticipatory registered
[    0.262997] io scheduler deadline registered
[    0.263731] io scheduler cfq registered (default)
[    0.264705] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    0.265644] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    0.266671] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.269847] Non-volatile memory driver v1.3
[    0.270558] Linux agpgart interface v0.103
[    0.271335] crash memory driver: version 1.1
[    0.271936] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
\xffffffff[    0.519434] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[    0.522607] brd: module loaded
[    0.523984] loop: module loaded
[    0.524651] input: Macintosh mouse button emulation as /devices/virtual/input/input0
[    0.526069] Fixed MDIO Bus: probed
[    0.526901] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.528068] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.529180] uhci_hcd: USB Universal Host Controller Interface driver
[    0.530416] PNP: No PS/2 controller found. Probing ports directly.
[    0.532749] serio: i8042 KBD port at 0x60,0x64 irq 1
[    0.533571] serio: i8042 AUX port at 0x60,0x64 irq 12
[    0.534665] mice: PS/2 mouse device common for all mice
[    0.536293] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    0.538194] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    0.539339] rtc0: alarms up to one day, 114 bytes nvram
[    0.545149] cpuidle: using governor ladder
[    0.545753] cpuidle: using governor menu
[    0.547547] usbcore: registered new interface driver hiddev
[    0.548472] usbcore: registered new interface driver usbhid
[    0.549364] usbhid: v2.6:USB HID core driver
[    0.550208] TCP cubic registered
[    0.550677] Initializing XFRM netlink socket
[    0.551409] NET: Registered protocol family 17
[    0.552351] registered taskstats version 1
[    0.553549] rtc_cmos rtc_cmos: setting system clock to 2012-09-24 07:25:47 UTC (1348471547)
[    0.554879] Initalizing network drop monitor service
[    0.555761] Freeing unused kernel memory: 1244k freed
[    0.558439] Write protecting the kernel read-only data: 10240k
[    0.559754] Freeing unused kernel memory: 1040k freed
[    0.563882] Freeing unused kernel memory: 1760k freed
febootstrap: mounting /proc
febootstrap: uptime: 0.56 0.30
febootstrap: ext2 mini initrd starting up: 3.12 zlib
febootstrap: mounting /sys
febootstrap: internal insmod libcrc32c.ko
febootstrap: internal insmod crc32c-intel.ko
insmod: init_module: crc32c-intel.ko: No such device
febootstrap: internal insmod crc-itu-t.ko
febootstrap: internal insmod crc-t10dif.ko
febootstrap: internal insmod crc-ccitt.ko
febootstrap: internal insmod crc7.ko
febootstrap: internal insmod mbcache.ko
febootstrap: internal insmod cdrom.ko
febootstrap: internal insmod sr_mod.ko
febootstrap: internal insmod ata_piix.ko
[    0.625990] scsi0 : ata_piix
[    0.626707] scsi1 : ata_piix
[    0.627304] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc0a0 irq 14
[    0.628375] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0a8 irq 15
febootstrap: internal insmod scsi_transport_spi.ko
febootstrap: internal insmod sym53c8xx.ko
febootstrap: internal insmod sd_mod.ko
febootstrap: internal insmod virtio_ring.ko
febootstrap: internal insmod virtio.ko
febootstrap: internal insmod virtio-rng.ko
febootstrap: internal insmod virtio_console.ko
febootstrap: internal insmod virtio_blk.ko
febootstrap: internal insmod virtio_net.ko
febootstrap: internal insmod virtio_pci.ko
[    0.858250] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10
[    0.878511] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11
[    0.881691]  vda: unknown partition table
[    0.883814] virtio-pci 0000:00:04.0: PCI->APIC IRQ transform: INT A -> IRQ 11
[    0.885954]  vdb:
[    0.979703] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input2
[  240.233218] INFO: task init:1 blocked for more than 120 seconds.
[  240.234297] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  240.235582] init          D 0000000000000000     0     1      0 0x00000000
[  240.236802]  ffff88001e9ab5d8 0000000000000082 ffff880000000000 00000000c7fdf800
[  240.238269]  0000000100000000 ffff88001e9316e0 000000000000038c ffffffffaf9ff2a5
[  240.239619]  ffff88001e9a9a78 ffff88001e9abfd8 000000000000f4e8 ffff88001e9a9a78
[  240.240978] Call Trace:
[  240.241561]  [<ffffffff8109b809>] ? ktime_get_ts+0xa9/0xe0
[  240.242560]  [<ffffffff81110b10>] ? sync_page+0x0/0x50
[  240.243525]  [<ffffffff814ed1c3>] io_schedule+0x73/0xc0
[  240.244510]  [<ffffffff81110b4d>] sync_page+0x3d/0x50
[  240.245378]  [<ffffffff814eda2a>] __wait_on_bit_lock+0x5a/0xc0
[  240.246345]  [<ffffffff811ae7b0>] ? blkdev_get_block+0x0/0x70
[  240.247295]  [<ffffffff81110ae7>] __lock_page+0x67/0x70
[  240.248176]  [<ffffffff81090c30>] ? wake_bit_function+0x0/0x50
[  240.249022]  [<ffffffff811129ea>] do_read_cache_page+0xca/0x180
[  240.250004]  [<ffffffff811af760>] ? blkdev_readpage+0x0/0x20
[  240.250960]  [<ffffffff81112ae9>] read_cache_page_async+0x19/0x20
[  240.251960]  [<ffffffff81112afe>] read_cache_page+0xe/0x20
[  240.252889]  [<ffffffff811e6ee0>] read_dev_sector+0x30/0xa0
[  240.253836]  [<ffffffff811e9c11>] read_lba+0x101/0x110
[  240.254678]  [<ffffffff811ea105>] find_valid_gpt+0xd5/0x6b0
[  240.255581]  [<ffffffff8106a9d1>] ? vprintk+0x1d1/0x4f0
[  240.256438]  [<ffffffff811ea75f>] efi_partition+0x7f/0x370
[  240.257298]  [<ffffffff814ec42d>] ? printk+0x41/0x44
[  240.258113]  [<ffffffff811e7c17>] rescan_partitions+0x1a7/0x470
[  240.258983]  [<ffffffff811afec6>] __blkdev_get+0x1b6/0x3c0
[  240.259876]  [<ffffffff811b00e0>] blkdev_get+0x10/0x20
[  240.260701]  [<ffffffff811e70a5>] register_disk+0x155/0x170
[  240.261598]  [<ffffffff81258816>] add_disk+0xa6/0x160
[  240.262447]  [<ffffffffa00adf6b>] virtblk_probe+0x49f/0x55c [virtio_blk]
[  240.263493]  [<ffffffffa00ad170>] ? blk_done+0x0/0x110 [virtio_blk]
[  240.264485]  [<ffffffffa0095370>] virtio_dev_probe+0xd0/0x110 [virtio]
[  240.265532]  [<ffffffff81346630>] driver_probe_device+0xa0/0x2a0
[  240.266490]  [<ffffffff813468e0>] ? __device_attach+0x0/0x60
[  240.267373]  [<ffffffff81346933>] __device_attach+0x53/0x60
[  240.268230]  [<ffffffff81345514>] bus_for_each_drv+0x64/0x90
[  240.269111]  [<ffffffff813469fc>] device_attach+0x8c/0xa0
[  240.269910]  [<ffffffff813452bd>] bus_probe_device+0x2d/0x50
[  240.270838]  [<ffffffff813437b7>] device_add+0x527/0x650
[  240.271702]  [<ffffffff8134c96b>] ? pm_runtime_init+0xcb/0xe0
[  240.272653]  [<ffffffff813438fe>] device_register+0x1e/0x30
[  240.273577]  [<ffffffffa00954ab>] register_virtio_device+0x7b/0xa0 [virtio]
[  240.274653]  [<ffffffff81285ae0>] ? pci_request_selected_regions+0x10/0x20
[  240.275726]  [<ffffffffa00c0003>] virtio_pci_probe+0x17c/0x1c4 [virtio_pci]
[  240.276825]  [<ffffffff81289aa7>] local_pci_probe+0x17/0x20
[  240.277726]  [<ffffffff8128ac91>] pci_device_probe+0x101/0x120
[  240.278679]  [<ffffffff81346492>] ? driver_sysfs_add+0x62/0x90
[  240.279630]  [<ffffffff81346630>] driver_probe_device+0xa0/0x2a0
[  240.280601]  [<ffffffff813468db>] __driver_attach+0xab/0xb0
[  240.281508]  [<ffffffff81346830>] ? __driver_attach+0x0/0xb0
[  240.282434]  [<ffffffff81345894>] bus_for_each_dev+0x64/0x90
[  240.283309]  [<ffffffff813463ce>] driver_attach+0x1e/0x20
[  240.284156]  [<ffffffff81345cd0>] bus_add_driver+0x200/0x300
[  240.284991]  [<ffffffff81346c06>] driver_register+0x76/0x140
[  240.285925]  [<ffffffff814f2525>] ? notifier_call_chain+0x55/0x80
[  240.286899]  [<ffffffff8128aef6>] __pci_register_driver+0x56/0xd0
[  240.287855]  [<ffffffff81096e75>] ? __blocking_notifier_call_chain+0x65/0x80
[  240.288954]  [<ffffffffa00c3000>] ? virtio_pci_init+0x0/0x20 [virtio_pci]
[  240.290009]  [<ffffffffa00c301e>] virtio_pci_init+0x1e/0x20 [virtio_pci]
[  240.291058]  [<ffffffff8100204c>] do_one_initcall+0x3c/0x1d0
[  240.291877]  [<ffffffff810af641>] sys_init_module+0xe1/0x250
[  240.292805]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b