Libguestfs - Nov 2016 - Re: [ovirt-users] OVA import of FC21 VM hangs during virt-v2v conversion?

> On 7 Nov 2016, at 22:16, Derek Atkins <derek@ihtfp.com> wrote:
> 
> Hi,
> 
> My last VM imported in 2 minutes.  This one has been sitting for three
> hours.  I think this is a bug.
well, some time it does take a long time. Are you sure it was hung?
No I/O going on?

adding libguestfs list 

Thanks,
michal
> 
> Just in case it helps, here's a larger piece of the virt-v2v log
> (see the end)
> 
> -derek
> 
> On Mon, November 7, 2016 12:54 pm, Derek Atkins wrote:
>> Hi,
>> 
>> I've successfully imported several VMs already, so I thought I had
the
>> process down.  Each import completed relatively quickly.  So that's
why
>> this one was such a surprise.
>> 
>> I've got a Fedora 21 VM packaged into an OVA.  I copy it to my
ovirt
>> host and then [Virtual Machines] -> Import -> [OVA] and select
the ova
>> file.  Follow the process, assign the correct storage location, and let
>> it go.  Usually it takes only a few minutes, but it's been sitting
in
>> the conversion process for over 20 minutes already (multiple attempts
>> end in the same place).  It's only a 4GB disk; the other imports
were
>> all around the same size and took significantly longer.
>> 
>> I tried running virt-v2v by hand:
>> 
>> LIBGUESTFS_BACKEND=direct virt-v2v -v -x -i ova fedora21.ova -of raw -o
>> null
>> 
>> and it hung here:
>> 
>> guestfsd: main_loop: new request, len 0x28
>> guestfsd: main_loop: proc 26 (aug_close) took 0.03 seconds
>> libguestfs: trace: v2v: aug_close = 0
>> libguestfs: trace: v2v: selinux_relabel
>> "/etc/selinux/targeted/contexts/files/file_contexts"
"/" "force:true"
>> guestfsd: main_loop: new request, len 0x6c
>> commandrvf: stdout=n stderr=y flags=0x0
>> commandrvf: setfiles -F -e /sysroot/dev -e /sysroot/proc -e
>> /sysroot/selinux -e /sysroot/sys -r /sysroot -q
>> /sysroot/etc/selinux/targeted/contexts/files/file_contexts /sysroot/
>> Can't stat exclude path "/sysroot/selinux", No such file
or directory -
>> ignoring.
>> ^C
>> 
>> Any ideas why this VM is different from all the other VMs?
>> 
>> -derek
> 
> [snip]
> installed kernel packages in this guest:
> 	(kernel-core, 3.17.8-300.fc21, x86_64,
> /boot/vmlinuz-3.17.8-300.fc21.x86_64,
> /boot/initramfs-3.17.8-300.fc21.x86_64.img, virtio=true, xen=false,
> debug=false)
> 	(kernel-core, 3.17.4-301.fc21, x86_64,
> /boot/vmlinuz-3.17.4-301.fc21.x86_64,
> /boot/initramfs-3.17.4-301.fc21.x86_64.img, virtio=true, xen=false,
> debug=false)
> libguestfs: trace: v2v: glob_expand "/vmlinuz-*"
> guestfsd: main_loop: new request, len 0x3c
> guestfsd: main_loop: proc 113 (glob_expand) took 0.00 seconds
> libguestfs: trace: v2v: glob_expand = []
> libguestfs: trace: v2v: glob_expand "/boot/vmlinuz-*"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 113 (glob_expand) took 0.00 seconds
> libguestfs: trace: v2v: glob_expand >
["/boot/vmlinuz-0-rescue-aebaf0a54c334c40a3f2a001266b032e",
> "/boot/vmlinuz-3.17.4-301.fc21.x86_64",
> "/boot/vmlinuz-3.17.8-300.fc21.x86_64"]
> libguestfs: trace: v2v: glob_expand "/boot/kernel-*"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 113 (glob_expand) took 0.00 seconds
> libguestfs: trace: v2v: glob_expand = []
> libguestfs: trace: v2v: exists "/sbin/grubby"
> guestfsd: main_loop: new request, len 0x38
> libguestfs: trace: v2v: exists = 1
> libguestfs: trace: v2v: command "grubby --default-kernel"
> guestfsd: main_loop: proc 36 (exists) took 0.00 seconds
> guestfsd: main_loop: new request, len 0x4c
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev /sysroot/dev
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev/pts /sysroot/dev/pts
> mount: mount point /sysroot/dev/pts does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /proc /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/selinux
> mount: mount point /sysroot/selinux does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/sys/fs/selinux
> mount: mount point /sysroot/sys/fs/selinux does not exist
> renaming /sysroot/etc/resolv.conf to /sysroot/etc/bojotzks
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: cp /etc/resolv.conf /sysroot/etc/resolv.conf
> commandrvf: stdout=y stderr=y flags=0x40000
> commandrvf: grubby --default-kernel
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/dev
> renaming /sysroot/etc/bojotzks to /sysroot/etc/resolv.conf
> guestfsd: main_loop: proc 50 (command) took 0.13 seconds
> libguestfs: trace: v2v: command =
"/boot/vmlinuz-3.17.8-300.fc21.x86_64\n"
> libguestfs: trace: v2v: statns
"/boot/vmlinuz-3.17.8-300.fc21.x86_64"
> guestfsd: main_loop: new request, len 0x50
> guestfsd: main_loop: proc 421 (statns) took 0.00 seconds
> libguestfs: trace: v2v: statns = <struct guestfs_statns = st_dev: 2049,
> st_ino: 340, st_mode: 33261, st_nlink: 1, st_uid: 0, st_gid: 0, st_rdev:
> 0, st_size: 5757864, st_blksize: 4096, st_blocks: 11248, st_atime_sec:
> 1420760440, st_atime_nsec: 0, st_mtime_sec: 1420760440, st_mtime_nsec: 0,
> st_ctime_sec: 1421863850, st_ctime_nsec: 600025468, st_spare1: 0,
> st_spare2: 0, st_spare3: 0, st_spare4: 0, st_spare5: 0, st_spare6: 0, >
> libguestfs: trace: v2v: statns
> "/boot/vmlinuz-0-rescue-aebaf0a54c334c40a3f2a001266b032e"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 421 (statns) took 0.00 seconds
> libguestfs: trace: v2v: statns = <struct guestfs_statns = st_dev: 2049,
> st_ino: 23, st_mode: 33261, st_nlink: 1, st_uid: 0, st_gid: 0, st_rdev: 0,
> st_size: 5751144, st_blksize: 4096, st_blocks: 11240, st_atime_sec:
> 1421862777, st_atime_nsec: 612123495, st_mtime_sec: 1421862777,
> st_mtime_nsec: 801108478, st_ctime_sec: 1421862777, st_ctime_nsec:
> 801108478, st_spare1: 0, st_spare2: 0, st_spare3: 0, st_spare4: 0,
> st_spare5: 0, st_spare6: 0, >
> libguestfs: trace: v2v: statns
"/boot/vmlinuz-3.17.4-301.fc21.x86_64"
> guestfsd: main_loop: new request, len 0x50
> guestfsd: main_loop: proc 421 (statns) took 0.00 seconds
> libguestfs: trace: v2v: statns = <struct guestfs_statns = st_dev: 2049,
> st_ino: 20, st_mode: 33261, st_nlink: 1, st_uid: 0, st_gid: 0, st_rdev: 0,
> st_size: 5751144, st_blksize: 4096, st_blocks: 11240, st_atime_sec:
> 1421862777, st_atime_nsec: 619122938, st_mtime_sec: 1417115668,
> st_mtime_nsec: 0, st_ctime_sec: 1421861378, st_ctime_nsec: 221208355,
> st_spare1: 0, st_spare2: 0, st_spare3: 0, st_spare4: 0, st_spare5: 0,
> st_spare6: 0, >
> libguestfs: trace: v2v: statns
"/boot/vmlinuz-3.17.8-300.fc21.x86_64"
> guestfsd: main_loop: new request, len 0x50
> guestfsd: main_loop: proc 421 (statns) took 0.00 seconds
> libguestfs: trace: v2v: statns = <struct guestfs_statns = st_dev: 2049,
> st_ino: 340, st_mode: 33261, st_nlink: 1, st_uid: 0, st_gid: 0, st_rdev:
> 0, st_size: 5757864, st_blksize: 4096, st_blocks: 11248, st_atime_sec:
> 1420760440, st_atime_nsec: 0, st_mtime_sec: 1420760440, st_mtime_nsec: 0,
> st_ctime_sec: 1421863850, st_ctime_nsec: 600025468, st_spare1: 0,
> st_spare2: 0, st_spare3: 0, st_spare4: 0, st_spare5: 0, st_spare6: 0, >
> grub kernels in this guest (first in list is default):
> 	(kernel-core, 3.17.8-300.fc21, x86_64,
> /boot/vmlinuz-3.17.8-300.fc21.x86_64,
> /boot/initramfs-3.17.8-300.fc21.x86_64.img, virtio=true, xen=false,
> debug=false)
> 	(kernel-core, 3.17.4-301.fc21, x86_64,
> /boot/vmlinuz-3.17.4-301.fc21.x86_64,
> /boot/initramfs-3.17.4-301.fc21.x86_64.img, virtio=true, xen=false,
> debug=false)
> 	(kernel-core, 3.17.8-300.fc21, x86_64,
> /boot/vmlinuz-3.17.8-300.fc21.x86_64,
> /boot/initramfs-3.17.8-300.fc21.x86_64.img, virtio=true, xen=false,
> debug=false)
> libguestfs: trace: v2v: is_file
"/var/lib/VBoxGuestAdditions/config"
> "followsymlinks:true"
> guestfsd: main_loop: new request, len 0x54
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 0
> libguestfs: trace: v2v: is_file "/etc/init.d/kudzu"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 0
> libguestfs: trace: v2v: is_file "/etc/sysconfig/kernel"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x48
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 1
> libguestfs: trace: v2v: aug_match
> "/files/etc/sysconfig/kernel/DEFAULTKERNEL/value"
> guestfsd: main_loop: new request, len 0x5c
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match >
["/files/etc/sysconfig/kernel/DEFAULTKERNEL/value"]
> libguestfs: trace: v2v: aug_set
> "/files/etc/sysconfig/kernel/DEFAULTKERNEL/value"
"kernel-core"
> guestfsd: main_loop: new request, len 0x6c
> guestfsd: main_loop: proc 20 (aug_set) took 0.00 seconds
> libguestfs: trace: v2v: aug_set = 0
> libguestfs: trace: v2v: aug_save
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 25 (aug_save) took 0.00 seconds
> libguestfs: trace: v2v: aug_save = 0
> libguestfs: trace: v2v: aug_match "/files/etc/inittab/*/process"
> guestfsd: main_loop: new request, len 0x48
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/securetty/*"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_save
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 25 (aug_save) took 0.00 seconds
> libguestfs: trace: v2v: aug_save = 0
> libguestfs: trace: v2v: aug_match
> "/files/etc/sysconfig/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/default/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match >
["/files/etc/default/grub/GRUB_CMDLINE_LINUX"]
> libguestfs: trace: v2v: aug_match
> "/files/etc/default/grub/GRUB_CMDLINE_LINUX_DEFAULT"
> guestfsd: main_loop: new request, len 0x60
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_get
"/files/etc/default/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get = ""rhgb quiet""
> libguestfs: trace: v2v: is_file "/etc/X11/xorg.conf"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 0
> libguestfs: trace: v2v: is_file "/etc/X11/XF86Config"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 0
> libguestfs: trace: v2v: aug_match
"/files/etc/X11/xorg.conf/Device/Driver"
> guestfsd: main_loop: new request, len 0x54
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/X11/xorg.conf/Device/VendorName"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
"/files/etc/X11/xorg.conf/Device/BoardName"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_save
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 25 (aug_save) took 0.00 seconds
> libguestfs: trace: v2v: aug_save = 0
> block device map:
> 	sda	-> vda
> 	xvda	-> vda
> libguestfs: trace: v2v: aug_match "/files/etc/fstab/*/spec"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = ["/files/etc/fstab/1/spec",
> "/files/etc/fstab/2/spec", "/files/etc/fstab/3/spec"]
> libguestfs: trace: v2v: aug_match
"/files/boot/grub2/grub.cfg/*/kernel/root"
> guestfsd: main_loop: new request, len 0x54
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/boot/grub2/grub.cfg/*/kernel/resume"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
"/files/boot/grub/device.map/*[label()
> != "#comment"]"
> guestfsd: main_loop: new request, len 0x60
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
"/files/etc/sysconfig/grub/boot"
> guestfsd: main_loop: new request, len 0x4c
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/sysconfig/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/default/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match >
["/files/etc/default/grub/GRUB_CMDLINE_LINUX"]
> libguestfs: trace: v2v: aug_match
> "/files/etc/default/grub/GRUB_CMDLINE_LINUX_DEFAULT"
> guestfsd: main_loop: new request, len 0x60
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
"/files/boot/grub2/device.map/*[label()
> != "#comment"]"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match =
["/files/boot/grub2/device.map/hd0",
> "/files/boot/grub2/device.map/hd1"]
> libguestfs: trace: v2v: aug_get "/files/etc/fstab/1/spec"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get =
"UUID=88eeab88-7e17-4df7-b36e-876b6fc9c14f"
> libguestfs: trace: v2v: aug_get "/files/etc/fstab/2/spec"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get =
"UUID=089a81b0-a74b-42dd-b145-ac54fa6e49a4"
> libguestfs: trace: v2v: aug_get "/files/etc/fstab/3/spec"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get =
"UUID=bb65f0f7-7992-4a42-9b47-b952fa815207"
> libguestfs: trace: v2v: aug_get
"/files/etc/default/grub/GRUB_CMDLINE_LINUX"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get = ""rhgb quiet""
> libguestfs: trace: v2v: aug_get
"/files/boot/grub2/device.map/hd0"
> guestfsd: main_loop: new request, len 0x4c
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get = "/dev/sda"
> libguestfs: trace: v2v: aug_set
"/files/boot/grub2/device.map/hd0" "/dev/vda"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 20 (aug_set) took 0.00 seconds
> libguestfs: trace: v2v: aug_set = 0
> libguestfs: trace: v2v: aug_get
"/files/boot/grub2/device.map/hd1"
> guestfsd: main_loop: new request, len 0x4c
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get = "/dev/sda"
> libguestfs: trace: v2v: aug_set
"/files/boot/grub2/device.map/hd1" "/dev/vda"
> guestfsd: main_loop: new request, len 0x58
> guestfsd: main_loop: proc 20 (aug_set) took 0.00 seconds
> libguestfs: trace: v2v: aug_set = 0
> libguestfs: trace: v2v: aug_save
> guestfsd: main_loop: new request, len 0x28
> libguestfs: trace: v2v: aug_save = 0
> libguestfs: trace: v2v: command "grub2-mkconfig -o
/boot/grub2/grub.cfg"
> guestfsd: main_loop: proc 25 (aug_save) took 0.00 seconds
> guestfsd: main_loop: new request, len 0x60
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev /sysroot/dev
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev/pts /sysroot/dev/pts
> mount: mount point /sysroot/dev/pts does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /proc /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/selinux
> mount: mount point /sysroot/selinux does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/sys/fs/selinux
> mount: mount point /sysroot/sys/fs/selinux does not exist
> renaming /sysroot/etc/resolv.conf to /sysroot/etc/6c3fqtab
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: cp /etc/resolv.conf /sysroot/etc/resolv.conf
> commandrvf: stdout=y stderr=y flags=0x40000
> commandrvf: grub2-mkconfig -o /boot/grub2/grub.cfg
> Generating grub configuration file ...
> Found linux image: /boot/vmlinuz-3.17.8-300.fc21.x86_64
> Found initrd image: /boot/initramfs-3.17.8-300.fc21.x86_64.img
> Found linux image: /boot/vmlinuz-3.17.4-301.fc21.x86_64
> Found initrd image: /boot/initramfs-3.17.4-301.fc21.x86_64.img
> Found linux image: /boot/vmlinuz-0-rescue-aebaf0a54c334c40a3f2a001266b032e
> Found initrd image:
> /boot/initramfs-0-rescue-aebaf0a54c334c40a3f2a001266b032e.img
> ERROR: mkdir /var/lock/dmraid
> ERROR: mkdir /var/lock/dmraid
> ERROR: mkdir /var/lock/dmraid
> done
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/dev
> renaming /sysroot/etc/6c3fqtab to /sysroot/etc/resolv.conf
> guestfsd: main_loop: proc 50 (command) took 0.57 seconds
> libguestfs: trace: v2v: command = ""
> libguestfs: trace: v2v: aug_load
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 27 (aug_load) took 0.01 seconds
> libguestfs: trace: v2v: aug_load = 0
> libguestfs: trace: v2v: aug_match "/augeas/files//error"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: rm_f "/etc/blkid/blkid.tab"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 367 (rm_f) took 0.00 seconds
> libguestfs: trace: v2v: rm_f = 0
> libguestfs: trace: v2v: rm_f "/etc/blkid.tab"
> guestfsd: main_loop: new request, len 0x3c
> guestfsd: main_loop: proc 367 (rm_f) took 0.00 seconds
> libguestfs: trace: v2v: rm_f = 0
> libguestfs: trace: v2v: rm_f "/etc/lvm/cache/.cache"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 367 (rm_f) took 0.00 seconds
> libguestfs: trace: v2v: rm_f = 0
> libguestfs: trace: v2v: aug_match "/files/etc/conf.modules/alias[. =~
> regexp('eth[0-9]+')]"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modules.conf/alias[. =~
> regexp('eth[0-9]+')]"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modprobe.conf/alias[. =~
> regexp('eth[0-9]+')]"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modprobe.d/*/alias[. =~
> regexp('eth[0-9]+')]"
> guestfsd: main_loop: new request, len 0x64
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/conf.modules/alias[. =~
> regexp('scsi_hostadapter.*')]"
> guestfsd: main_loop: new request, len 0x6c
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modules.conf/alias[. =~
> regexp('scsi_hostadapter.*')]"
> guestfsd: main_loop: new request, len 0x6c
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modprobe.conf/alias[. =~
> regexp('scsi_hostadapter.*')]"
> guestfsd: main_loop: new request, len 0x70
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match "/files/etc/modprobe.d/*/alias[. =~
> regexp('scsi_hostadapter.*')]"
> guestfsd: main_loop: new request, len 0x6c
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: is_dir "/etc/modprobe.d"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 38 (is_dir) took 0.00 seconds
> libguestfs: trace: v2v: is_dir = 1
> libguestfs: trace: v2v: aug_set
> "/files/etc/modprobe.d/virt-v2v-added.conf/alias[last()+1]"
> "scsi_hostadapter"
> guestfsd: main_loop: new request, len 0x7c
> guestfsd: main_loop: proc 20 (aug_set) took 0.00 seconds
> libguestfs: trace: v2v: aug_set = 0
> libguestfs: trace: v2v: aug_set
>
"/files/etc/modprobe.d/virt-v2v-added.conf/alias[last()]/modulename"
> "virtio_blk"
> guestfsd: main_loop: new request, len 0x80
> guestfsd: main_loop: proc 20 (aug_set) took 0.00 seconds
> libguestfs: trace: v2v: aug_set = 0
> libguestfs: trace: v2v: aug_match
> "/files/etc/conf.modules/alias[modulename =~
> regexp('xennet|xen-vnif|xenblk|xen-vbd')]"
> guestfsd: main_loop: new request, len 0x84
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/modules.conf/alias[modulename =~
> regexp('xennet|xen-vnif|xenblk|xen-vbd')]"
> guestfsd: main_loop: new request, len 0x84
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/modprobe.conf/alias[modulename =~
> regexp('xennet|xen-vnif|xenblk|xen-vbd')]"
> guestfsd: main_loop: new request, len 0x84
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_match
> "/files/etc/modprobe.d/*/alias[modulename =~
> regexp('xennet|xen-vnif|xenblk|xen-vbd')]"
> guestfsd: main_loop: new request, len 0x84
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_save
> guestfsd: main_loop: new request, len 0x28
> libguestfs: trace: v2v: aug_save = 0
> libguestfs: trace: v2v: mv
"/boot/initramfs-3.17.8-300.fc21.x86_64.img"
> "/boot/initramfs-3.17.8-300.fc21.x86_64.img.pre-v2v"
> guestfsd: main_loop: proc 25 (aug_save) took 0.00 seconds
> guestfsd: main_loop: new request, len 0x90
> commandrvf: stdout=n stderr=y flags=0x0
> commandrvf: mv /sysroot/boot/initramfs-3.17.8-300.fc21.x86_64.img
> /sysroot/boot/initramfs-3.17.8-300.fc21.x86_64.img.pre-v2v
> libguestfs: trace: v2v: mv = 0
> libguestfs: trace: v2v: is_file "/sbin/dracut"
"followsymlinks:true"
> guestfsd: main_loop: proc 89 (mv) took 0.00 seconds
> guestfsd: main_loop: new request, len 0x3c
> libguestfs: trace: v2v: is_file = 1
> libguestfs: trace: v2v: command "/sbin/dracut --verbose --add-drivers
> virtio virtio_ring virtio_blk virtio_net virtio_pci
> /boot/initramfs-3.17.8-300.fc21.x86_64.img 3.17.8-300.fc21.x86_64"
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> guestfsd: main_loop: new request, len 0xe4
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev /sysroot/dev
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /dev/pts /sysroot/dev/pts
> mount: mount point /sysroot/dev/pts does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /proc /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/selinux
> mount: mount point /sysroot/selinux does not exist
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: mount --bind /sys/fs/selinux /sysroot/sys/fs/selinux
> mount: mount point /sysroot/sys/fs/selinux does not exist
> renaming /sysroot/etc/resolv.conf to /sysroot/etc/fvo9h3q7
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: cp /etc/resolv.conf /sysroot/etc/resolv.conf
> commandrvf: stdout=y stderr=y flags=0x40000
> commandrvf: /sbin/dracut --verbose --add-drivers "virtio virtio_ring
> virtio_blk virtio_net virtio_pci"
> /boot/initramfs-3.17.8-300.fc21.x86_64.img 3.17.8-300.fc21.x86_64
> No '/dev/log' or 'logger' included for syslog logging
> [   13.635451] dracut[966] No '/dev/log' or 'logger'
included for syslog
> logging
> Executing: /sbin/dracut --verbose --add-drivers "virtio virtio_ring
> virtio_blk virtio_net virtio_pci"
> /boot/initramfs-3.17.8-300.fc21.x86_64.img 3.17.8-300.fc21.x86_64
> [   13.665763] dracut[966] Executing: /sbin/dracut --verbose --add-drivers
> "virtio virtio_ring virtio_blk virtio_net virtio_pci"
> /boot/initramfs-3.17.8-300.fc21.x86_64.img 3.17.8-300.fc21.x86_64
> dracut module 'busybox' will not be installed, because command
'busybox'
> could not be found!
> [   13.783635] dracut[966] dracut module 'busybox' will not be
installed,
> because command 'busybox' could not be found!
> dracut module 'fcoe' will not be installed, because command
'dcbtool'
> could not be found!
> [   13.876843] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'dcbtool' could not be found!
> dracut module 'fcoe' will not be installed, because command
'fipvlan'
> could not be found!
> [   13.879013] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'fipvlan' could not be found!
> dracut module 'fcoe' will not be installed, because command
'lldpad' could
> not be found!
> [   13.881179] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'lldpad' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'dcbtool'
> could not be found!
> [   13.885860] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'dcbtool' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'fipvlan'
> could not be found!
> [   13.888081] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'fipvlan' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'lldpad'
> could not be found!
> [   13.890369] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'lldpad' could not be found!
> dracut module 'iscsi' will not be installed, because command
'iscsistart'
> could not be found!
> [   13.896999] dracut[966] dracut module 'iscsi' will not be
installed,
> because command 'iscsistart' could not be found!
> dracut module 'iscsi' will not be installed, because command
'iscsi-iname'
> could not be found!
> [   13.899112] dracut[966] dracut module 'iscsi' will not be
installed,
> because command 'iscsi-iname' could not be found!
> dracut module 'nbd' will not be installed, because command
'nbd-client'
> could not be found!
> [   13.903211] dracut[966] dracut module 'nbd' will not be
installed,
> because command 'nbd-client' could not be found!
> dracut module 'biosdevname' will not be installed, because command
> 'biosdevname' could not be found!
> [   13.938682] dracut[966] dracut module 'biosdevname' will not be
> installed, because command 'biosdevname' could not be found!
> dracut module 'busybox' will not be installed, because command
'busybox'
> could not be found!
> [   14.007359] dracut[966] dracut module 'busybox' will not be
installed,
> because command 'busybox' could not be found!
> dracut module 'fcoe' will not be installed, because command
'dcbtool'
> could not be found!
> [   14.055331] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'dcbtool' could not be found!
> dracut module 'fcoe' will not be installed, because command
'fipvlan'
> could not be found!
> [   14.057940] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'fipvlan' could not be found!
> dracut module 'fcoe' will not be installed, because command
'lldpad' could
> not be found!
> [   14.059984] dracut[966] dracut module 'fcoe' will not be
installed,
> because command 'lldpad' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'dcbtool'
> could not be found!
> [   14.063472] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'dcbtool' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'fipvlan'
> could not be found!
> [   14.065623] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'fipvlan' could not be found!
> dracut module 'fcoe-uefi' will not be installed, because command
'lldpad'
> could not be found!
> [   14.067865] dracut[966] dracut module 'fcoe-uefi' will not be
> installed, because command 'lldpad' could not be found!
> dracut module 'iscsi' will not be installed, because command
'iscsistart'
> could not be found!
> [   14.072897] dracut[966] dracut module 'iscsi' will not be
installed,
> because command 'iscsistart' could not be found!
> dracut module 'iscsi' will not be installed, because command
'iscsi-iname'
> could not be found!
> [   14.075040] dracut[966] dracut module 'iscsi' will not be
installed,
> because command 'iscsi-iname' could not be found!
> dracut module 'nbd' will not be installed, because command
'nbd-client'
> could not be found!
> [   14.078622] dracut[966] dracut module 'nbd' will not be
installed,
> because command 'nbd-client' could not be found!
> *** Including module: bash ***
> [   14.142802] dracut[966] *** Including module: bash ***
> *** Including module: i18n ***
> [   14.148588] dracut[966] *** Including module: i18n ***
> *** Including module: network ***
> [   14.336325] dracut[966] *** Including module: network ***
> *** Including module: ifcfg ***
> [   16.015612] dracut[966] *** Including module: ifcfg ***
> *** Including module: drm ***
> [   16.021035] dracut[966] *** Including module: drm ***
> *** Including module: plymouth ***
> [   17.051328] dracut[966] *** Including module: plymouth ***
> *** Including module: kernel-modules ***
> [   17.274162] dracut[966] *** Including module: kernel-modules ***
> *** Including module: rootfs-block ***
> [   24.046556] dracut[966] *** Including module: rootfs-block ***
> *** Including module: terminfo ***
> [   24.055831] dracut[966] *** Including module: terminfo ***
> *** Including module: udev-rules ***
> [   24.069906] dracut[966] *** Including module: udev-rules ***
> Skipping udev rule: 91-permissions.rules
> [   24.238349] dracut[966] Skipping udev rule: 91-permissions.rules
> Skipping udev rule: 80-drivers-modprobe.rules
> [   24.240008] dracut[966] Skipping udev rule: 80-drivers-modprobe.rules
> *** Including module: systemd ***
> [   24.258293] dracut[966] *** Including module: systemd ***
> *** Including module: usrmount ***
> [   24.446001] dracut[966] *** Including module: usrmount ***
> *** Including module: base ***
> [   24.449400] dracut[966] *** Including module: base ***
> *** Including module: fs-lib ***
> [   24.506200] dracut[966] *** Including module: fs-lib ***
> *** Including module: shutdown ***
> [   24.519959] dracut[966] *** Including module: shutdown ***
> *** Including modules done ***
> [   24.554250] dracut[966] *** Including modules done ***
> *** Installing kernel module dependencies and firmware ***
> [   24.583486] dracut[966] *** Installing kernel module dependencies and
> firmware ***
> *** Installing kernel module dependencies and firmware done ***
> [   24.900621] dracut[966] *** Installing kernel module dependencies and
> firmware done ***
> *** Resolving executable dependencies ***
> [   24.917031] dracut[966] *** Resolving executable dependencies ***
> *** Resolving executable dependencies done***
> [   25.482622] dracut[966] *** Resolving executable dependencies done***
> *** Hardlinking files ***
> [   25.495828] dracut[966] *** Hardlinking files ***
> *** Hardlinking files done ***
> [   25.505896] dracut[966] *** Hardlinking files done ***
> *** Stripping files ***
> [   25.507966] dracut[966] *** Stripping files ***
> *** Stripping files done ***
> [   25.607024] dracut[966] *** Stripping files done ***
> *** Generating early-microcode cpio image ***
> [   25.609139] dracut[966] *** Generating early-microcode cpio image ***
> *** Constructing GenuineIntel.bin ****
> [   25.616820] dracut[966] *** Constructing GenuineIntel.bin ****
> *** Store current command line parameters ***
> [   25.630768] dracut[966] *** Store current command line parameters ***
> *** Creating image file ***
> [   25.633892] dracut[966] *** Creating image file ***
> *** Creating image file done ***
> [   33.376016] dracut[966] *** Creating image file done ***
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/sys
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/proc
> commandrvf: stdout=n stderr=n flags=0x0
> commandrvf: umount /sysroot/dev
> renaming /sysroot/etc/fvo9h3q7 to /sysroot/etc/resolv.conf
> guestfsd: main_loop: proc 50 (command) took 22.81 seconds
> libguestfs: trace: v2v: command = ""
> libguestfs: trace: v2v: is_file "/usr/sbin/load_policy"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x48
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 1
> libguestfs: trace: v2v: is_file "/etc/selinux/config"
"followsymlinks:true"
> guestfsd: main_loop: new request, len 0x44
> guestfsd: main_loop: proc 37 (is_file) took 0.00 seconds
> libguestfs: trace: v2v: is_file = 1
> libguestfs: trace: v2v: feature_available "selinuxrelabel"
> libguestfs: trace: v2v: internal_feature_available
"selinuxrelabel"
> guestfsd: main_loop: new request, len 0x3c
> guestfsd: main_loop: proc 458 (internal_feature_available) took 0.00
seconds
> libguestfs: trace: v2v: internal_feature_available = 0
> libguestfs: trace: v2v: feature_available = 1
> libguestfs: trace: v2v: aug_init "/" 48
> guestfsd: main_loop: new request, len 0x34
> guestfsd: main_loop: proc 16 (aug_init) took 0.33 seconds
> libguestfs: trace: v2v: aug_init = 0
> libguestfs: trace: v2v: aug_rm
"/augeas/load/*["/etc/selinux/config/" !~
> regexp('^') + glob(incl) + regexp('/.*')]"
> guestfsd: main_loop: new request, len 0x80
> guestfsd: main_loop: proc 22 (aug_rm) took 0.01 seconds
> libguestfs: trace: v2v: aug_rm = 1329
> libguestfs: trace: v2v: aug_load
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 27 (aug_load) took 0.01 seconds
> libguestfs: trace: v2v: aug_load = 0
> libguestfs: trace: v2v: aug_match "/augeas/files//error"
> guestfsd: main_loop: new request, len 0x40
> guestfsd: main_loop: proc 24 (aug_match) took 0.00 seconds
> libguestfs: trace: v2v: aug_match = []
> libguestfs: trace: v2v: aug_get
"/files/etc/selinux/config/SELINUXTYPE"
> guestfsd: main_loop: new request, len 0x54
> guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds
> libguestfs: trace: v2v: aug_get = "targeted"
> libguestfs: trace: v2v: aug_close
> guestfsd: main_loop: new request, len 0x28
> guestfsd: main_loop: proc 26 (aug_close) took 0.03 seconds
> libguestfs: trace: v2v: aug_close = 0
> libguestfs: trace: v2v: selinux_relabel
> "/etc/selinux/targeted/contexts/files/file_contexts"
"/" "force:true"
> guestfsd: main_loop: new request, len 0x6c
> commandrvf: stdout=n stderr=y flags=0x0
> commandrvf: setfiles -F -e /sysroot/dev -e /sysroot/proc -e
> /sysroot/selinux -e /sysroot/sys -r /sysroot -q
> /sysroot/etc/selinux/targeted/contexts/files/file_contexts /sysroot/
> Can't stat exclude path "/sysroot/selinux", No such file or
directory -
> ignoring.
> [HANG HERE]
> 
> -- 
>       Derek Atkins                 617-623-3745
>       derek@ihtfp.com <mailto:derek@ihtfp.com>            
www.ihtfp.com <http://www.ihtfp.com/>
>       Computer and Internet Security Consultant
> 
> _______________________________________________
> Users mailing list
> Users@ovirt.org <mailto:Users@ovirt.org>
> http://lists.ovirt.org/mailman/listinfo/users
<http://lists.ovirt.org/mailman/listinfo/users>

On Wed, Nov 16, 2016 at 09:06:29AM +0200, Michal Skrivanek
wrote:
> 
> > On 7 Nov 2016, at 22:16, Derek Atkins <derek@ihtfp.com> wrote:
> > 
> > Hi,
> > 
> > My last VM imported in 2 minutes.  This one has been sitting for three
> > hours.  I think this is a bug.
> 
> well, some time it does take a long time. Are you sure it was hung?
> No I/O going on?
> 
> adding libguestfs list 
The most likely reason for virt-v2v to hang (actually it's qemu which
is hanging) is that you've run out of disk space.  Most probably in
/var/tmp but best to check all your host filesystems.

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
Fedora Windows cross-compiler. Compile Windows programs, test, and
build Windows installers. Over 100 libraries supported.
http://fedoraproject.org/wiki/MinGW

"Richard W.M. Jones" <rjones@redhat.com> writes:
> On Wed, Nov 16, 2016 at 09:06:29AM +0200, Michal Skrivanek wrote:
>> 
>> > On 7 Nov 2016, at 22:16, Derek Atkins <derek@ihtfp.com>
wrote:
>> > 
>> > Hi,
>> > 
>> > My last VM imported in 2 minutes.  This one has been sitting for
three
>> > hours.  I think this is a bug.
>> 
>> well, some time it does take a long time. Are you sure it was hung?
>> No I/O going on?
>> 
>> adding libguestfs list 
>
> The most likely reason for virt-v2v to hang (actually it's qemu which
> is hanging) is that you've run out of disk space.  Most probably in
> /var/tmp but best to check all your host filesystems.
No, the filesystem had plenty of space.

It eventually did complete, after several hours.  But I don't understand
why this particular VM took so long when others (with similar disk
sizes/usages/configurations) completed in only 1-2 minutes.  Each VM is
effectively exactly the same (it's a build slave), so it's just the
basic installation of the particular Fedora release, the build tools,
and the build slave configuration.  Beyond the underlying fedora release
version, the systems are configured exactly the same.

I migrated four similar VMs.  Three of them completed almost
immediately.  The last too much longer.  The ONLY thing different about
the one that took longer was that I decided to pack the disk first, so I
ran:

  vmware-toolbox-cmd disk shrink /

in the VM prior to packaging it up as an OVA.  All the OVA files are
relatively small and similar in size:

-rw------- 1 warlord warlord  1959553024 Nov  7 10:40 fc20-64.ova
-rw------- 1 warlord warlord  1794907648 Nov  7 12:27 fc21-64.ova
-rw------- 1 warlord warlord  2023595520 Nov  6 10:04 fc22-64.ova
-rw------- 1 warlord warlord  3381622272 Nov  5 16:18 fc23-64.ova

The FC23 and FC22 migrations took the least amount of time, even though
they were the largest.
> Rich.
-derek

-- 
       Derek Atkins                 617-623-3745
       derek@ihtfp.com             www.ihtfp.com
       Computer and Internet Security Consultant