libvirt block commit stuck at 100%

[Ishmael]

Hi,

I would like to report was seems to be a bug:

Libvirt block commit stuck at 100%

libvirtd (libvirt) 1.3.4
QEMU emulator version 2.3.0
Ubuntu Release: 15.10

I attempted an abort, which works fine but block commit still get stuck at 100%

root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --info
Active Block Commit: [100 %]

root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --abort

root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --info
No current block job for /mnt/diskimage-backups/newvm.snap-201606210230.qcow2

root@node:~# virsh blockcommit newvm vda --active --verbose --pivot

root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --info
Active Block Commit: [ 72 %]

root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --info
Active Block Commit: [ 72 %]

root@node:~#
root@node:~# virsh blockjob newvm /mnt/diskimage-backups/newvm.snap-201606210230.qcow2 --info
Active Block Commit: [100 %]

It stays there for day so far. Please assist. see logs below.

root@node:~# tail -100 /var/log/libvirt/qemu/newvm.log

2016-06-02 11:00:55.056+0000: shutting down
2016-06-02 11:01:07.173+0000: starting up libvirt version: 1.3.4, qemu version: 2.3.0 (Debian 1:2.3+dfsg-5ubuntu9.4), hostname: node.sanren.ac.za
LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin QEMU_AUDIO_DRV=spice /usr/bin/kvm-spice -name newvm,debug-threads=on -S -machine pc-i440fx-trusty,accel=kvm,usb=off -m 4096 -realtime mlock=off -smp 2,sockets=2,cores=1,threads=1 -uuid f75ea4e5-d551-1d25-6f6d-a3891ce9d6c2 -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/domain-20-newvm/monitor.sock,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5 -drive if=none,id=drive-ide0-1-0,readonly=on -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0 -drive file=/var/lib/libvirt/images/newvm.qcow2,format=qcow2,if=none,id=drive-virtio-disk0 -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x6,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=33,id=hostnet0,vhost=on,vhostfd=35 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:3f:a0:4f,bus=pci.0,addr=0x3 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -device usb-tablet,id=input0 -spice port=5911,addr=127.0.0.1,disable-ticketing,seamless-migration=on -device qxl-vga,id=video0,ram_size=67108864,vram_size=67108864,vram64_size_mb=0,vgamem_mb=16,bus=pci.0,addr=0x2 -device intel-hda,id=sound0,bus=pci.0,addr=0x4 -device hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7 -msg timestamp=on
Domain id=20 is tainted: high-privileges
char device redirected to /dev/pts/13 (label charserial0)
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 1.011000 ms, bitrate 23011235955 bps (21945.224719 Mbps)
inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer:
red_channel_client_disconnect: rcc=0x564d61cfb550 (channel=0x564d60c9b4a0 type=3 id=0)
red_channel_client_disconnect: rcc=0x7efcdc2462e0 (channel=0x7efcdc21f3a0 type=2 id=0)
red_channel_client_disconnect: rcc=0x7efcdc2a3160 (channel=0x7efcdc21f970 type=4 id=0)
red_channel_client_disconnect: rcc=0x564d61cbaff0 (channel=0x564d60c8ff20 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x564d61cbaff0
red_client_destroy: destroy client 0x564d623512f0 with #channels=4
red_dispatcher_disconnect_cursor_peer:
red_dispatcher_disconnect_display_peer:
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.173000 ms, bitrate 13128205128 bps (12520.032051 Mbps)
red_dispatcher_set_cursor_peer:
inputs_connect: inputs channel client create
red_channel_client_disconnect: rcc=0x564d61cfb550 (channel=0x564d60c9b4a0 type=3 id=0)
red_channel_client_disconnect: rcc=0x7efcdc245ff0 (channel=0x7efcdc21f970 type=4 id=0)
red_channel_client_disconnect: rcc=0x7efcdc24aa60 (channel=0x7efcdc21f3a0 type=2 id=0)
red_channel_client_disconnect: rcc=0x564d61cbaff0 (channel=0x564d60c8ff20 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x564d61cbaff0
red_client_destroy: destroy client 0x564d60c85700 with #channels=4
red_dispatcher_disconnect_display_peer:
red_dispatcher_disconnect_cursor_peer:
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.276000 ms, bitrate 15753846153 bps (15024.038461 Mbps)
red_channel_client_disconnect: rcc=0x564d61cbaff0 (channel=0x564d60c8ff20 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x564d61cbaff0
red_client_destroy: destroy client 0x564d60c85700 with #channels=1
Formatting '/mnt/diskimage-backups/newvm.snap-201606070230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606080230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606090230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606100230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606110230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606120230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606130230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606140230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606150230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606160230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606170230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606180230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606190230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606200230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
Formatting '/mnt/diskimage-backups/newvm.snap-201606210230.qcow2', fmt=qcow2 size=214748364800 backing_file='/var/lib/libvirt/images/newvm.qcow2' backing_fmt='qcow2' encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.165000 ms, bitrate 14422535211 bps (13754.401408 Mbps)
((null):25947): Spice-Warning **: red_channel.c:546:red_channel_client_send_ping: getsockopt failed, Operation not supported
red_dispatcher_set_cursor_peer:
inputs_connect: inputs channel client create
((null):25947): Spice-Warning **: red_channel.c:546:red_channel_client_send_ping: getsockopt failed, Operation not supported
red_channel_client_disconnect: rcc=0x564d61e1ee70 (channel=0x564d60c9b4a0 type=3 id=0)
red_channel_client_disconnect: rcc=0x7efcdc2504c0 (channel=0x7efcdc21f3a0 type=2 id=0)
red_channel_client_disconnect: rcc=0x7efcdc249850 (channel=0x7efcdc21f970 type=4 id=0)
red_channel_client_disconnect: rcc=0x564d60e656d0 (channel=0x564d60c8ff20 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x564d60e656d0
red_client_destroy: destroy client 0x564d60c85700 with #channels=4
red_dispatcher_disconnect_display_peer:
red_dispatcher_disconnect_cursor_peer:
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.174000 ms, bitrate 10666666666 bps (10172.526041 Mbps)
((null):25947): Spice-Warning **: red_channel.c:546:red_channel_client_send_ping: getsockopt failed, Operation not supported
inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer:
((null):25947): Spice-Warning **: red_channel.c:546:red_channel_client_send_ping: getsockopt failed, Operation not supported
red_channel_client_disconnect: rcc=0x564d60e656d0 (channel=0x564d60c9b4a0 type=3 id=0)
red_channel_client_disconnect: rcc=0x7efcdc247610 (channel=0x7efcdc21f3a0 type=2 id=0)
red_channel_client_disconnect: rcc=0x7efcdcaa4560 (channel=0x7efcdc21f970 type=4 id=0)
red_channel_client_disconnect: rcc=0x564d61fc8bb0 (channel=0x564d60c8ff20 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x564d61fc8bb0
red_client_destroy: destroy client 0x564d6283d760 with #channels=4
red_dispatcher_disconnect_cursor_peer:
red_dispatcher_disconnect_display_peer:

[ALU (c-launchpadmail)]

I had something similar happen. I think it is related to this bug: https://bugzilla.redhat.com/show_bug.cgi?id=1197592 " blockcopy always failed when with option "--pivot" "

This was on Ubuntu Server 16.04.1

$ uname -a
Linux oslo 4.4.0-31-generic #50-Ubuntu SMP Wed Jul 13 00:07:12 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

$ virsh --version
1.3.1

$ dpkg --list | grep libvirt
ii libvirt-bin 1.3.1-1ubuntu10.1 amd64 programs for the libvirt library
ii libvirt0:amd64 1.3.1-1ubuntu10.1 amd64 library for interfacing with different virtualization systems

To fix requires an upgrade to libvirt-1.3.2-1.el7

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Alexandre (totalworlddomination)]

Strangely in the last weeks, the --quiesce stopped working out of the blue (new version of qemu/libvirt/virsh?) and now I randomly get this on a VM when backing all my VMs. Not sure if the two are related.

Both the original image and the snapshot get updated unless I abort the snapshot stuck at 100%, in which it is the one being actively updated, but I can never pivot back to the original file.

TL;DR: KVM backups are now almost impossible to manage.

$ uname -a
Linux node0 4.4.0-37-generic #56-Ubuntu SMP Mon Aug 29 16:50:40 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

$ virsh version
Compiled against library: libvirt 1.3.1
Using library: libvirt 1.3.1
Using API: QEMU 1.3.1
Running hypervisor: QEMU 2.5.0

packages:
ii libvirt-bin 1.3.1-1ubuntu10.2 amd64 programs for the libvirt library
ii libvirt0:amd64 1.3.1-1ubuntu10.2 amd64 library for interfacing with different virtualization systems

[Joshua Powers (powersj)]

Thank you for taking the time to report this bug and helping to make Ubuntu better.

There isn't really enough information here for a developer to confirm this issue is a bug, or to begin working on it, so I am marking this bug Incomplete for now. Also could you clarify if this is occurring consistently or intermittently.

If you can provide exact steps so that a developer can reproduce the original problem, then please add them to this bug and change the status back to New.