[ovirt-users] Simple way to activate live merge in FC20 cluster

Fri Nov 21 00:38:06 UTC 2014

On Thu, Nov 20, 2014 at 8:13 PM, Markus Stockhausen <stockhausen at collogia.de
> wrote:

> Hi Bob,
>
> looking at http://koji.fedoraproject.org/koji/packageinfo?packageID=91
> I think FC20 will stay at 1.1.3. History shows:
>
>
[snip]

> ________________________________________
> Von: Bob Doolittle [bob at doolittle.us.com]
> Gesendet: Donnerstag, 20. November 2014 19:38
> An: Markus Stockhausen
> Cc: s k; users at ovirt.org; Daniel Helgenberger; Coffee Chou
> Betreff: Re: Simple way to activate live merge in FC20 cluster
>
> Thanks Markus, but I have a single, self-hosted node, so cannot migrate
> VMs.
>
> Is it your assumption that F20 will never be updated with libvirt 1.2.9?
>
> If that's the case, my best course (in a month or so when F21 is
> released) is probably to export all my VMs, install F21,
> reinstall/reconfigure oVirt, import the old Export Domain, and then
> import my VMs again.
>
> -Bob
>
> On 11/20/2014 01:20 PM, Markus Stockhausen wrote:
> > Hi Bob,
> >
> > if your are on a cluster with FC20 hypervisor nodes wthout virt-preview
> > (like we run it with qemu 1.6.2) the simplest way to get live merge
> features
> > should be - beware NOT FULLY TESTED!
> >
> > 1) choose a single host (we only need a single one if we think about the
> required setup)
> > 2) Install libvirt from virt-preview repos. DON'T UPDATE QEMU AS YOU
> BREAK LIVE MIGRATION!
> > 3) migrate VMs you want to live merge to the host
> > 4) do the live merge
> > 5) migrate VMs back to original host
> >
>

Hello,
following the flow, as I have now an all-in-one environment based on F20
and oVirt 3.5. As it is both my engine and my hypervisor, I should be in
the best situation....
live merge is supposed to be supported on file based storage, that should
match what I have (local on Host).

In fact, installing oVirt AIO on F20 automatically gives the virt-preview
repo through the ovirt-3.5-dependencies.repo file and I see:

[root at tekkaman qemu]# rpm -q libvirt
libvirt-1.2.9.1-1.fc20.x86_64

[root at tekkaman qemu]# vdsClient -s 0 getVdsCaps | grep -i merge
    liveMerge = 'true'

[root at tekkaman qemu]# rpm -q qemu
qemu-1.6.2-10.fc20.x86_64

Created a CentOS 7 x86_64 VM with a VirtIO-SCSI disk and after install I
powered off and run it normally.
Then I took a snapshot (while VM powered on) and then ran a yum update.
At the end I reboot the VM with the new kernel installed and tried to
delete the snapshot and the task indeed started:
Snapshot 'test per live merge' deletion for VM 'c7' was initiated by admin.

but about a minute later I got error:
Failed to delete snapshot 'test per live merge' for VM 'c7'.

here below relevant parts in log files.
What did I miss in the workflow?

BTW: both during the live snapshot and during the live merge I got
disconnected both from spice console and from an ssh session open into VM
(I could reconnect on both): is this expected? I hope not so..

Gianluca

engine.log
2014-11-21 01:16:00,182 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-3) [3337208b] Failed in MergeVDS method
2014-11-21 01:16:00,183 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-3) [3337208b] Command
org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand return value
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=52,
mMessage=Merge failed]]
2014-11-21 01:16:00,184 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-3) [3337208b] HostName = local_host
2014-11-21 01:16:00,190 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-3) [3337208b] Command MergeVDSCommand(HostName = local_host,
MergeVDSCommandParameters{HostId = aab9571f-da17-4c3c-9e6b-d0224b84c31e,
vmId=0ba6a56b-542c-480e-8bab-88aea9195302,
storagePoolId=65c9777e-23f1-4f04-8cea-e7c8871dc88b,
storageDomainId=0a8035e6-e41d-40ff-a154-e0a374f264b2,
imageGroupId=8a0ba67f-78c0-4ded-9bda-97bb9424e385,
imageId=1fdc7440-2465-49ec-8368-141afc0721f1,
baseImageId=cd7dd270-0895-411d-bc97-c5ad0ebd80b1,
topImageId=1fdc7440-2465-49ec-8368-141afc0721f1, bandwidth=0}) execution
failed. Exception: VDSErrorException: VDSGenericException:
VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52
2014-11-21 01:16:00,191 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-3) [3337208b] FINISH, MergeVDSCommand, log id: 70748b53
2014-11-21 01:16:00,192 ERROR [org.ovirt.engine.core.bll.MergeCommand]
(pool-7-thread-3) [3337208b] Command org.ovirt.engine.core.bll.MergeCommand
throw Vdc Bll exception. With error message VdcBLLException:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException:
VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge
failed, code = 52 (Failed with error mergeErr and code 52)
2014-11-21 01:16:00,205 ERROR [org.ovirt.engine.core.bll.MergeCommand]
(pool-7-thread-3) [3337208b] Transaction rolled-back for command:
org.ovirt.engine.core.bll.MergeCommand.
2014-11-21 01:16:09,888 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(DefaultQuartzScheduler_Worker-55) task id
f245da80-58ce-4e2e-bb5a-0261cf71de0d is in pre-polling  period and should
not be polled. Pre-polling period is 60,000 millis.
2014-11-21 01:16:09,889 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(DefaultQuartzScheduler_Worker-55) task id
c7c363f1-98b8-468c-8fca-cf3116d00221 is in pre-polling  period and should
not be polled. Pre-polling period is 60,000 millis.
2014-11-21 01:16:10,080 ERROR
[org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler_Worker-56) [1457fcca] Failed child command status
for step MERGE

vdsm.log
Thread-266::DEBUG::2014-11-21
01:16:00,144::resourceManager::641::Storage.ResourceManager::(releaseResource)
Resource 'Storag
e.0a8035e6-e41d-40ff-a154-e0a374f264b2' is free, finding out if anyone is
waiting for it.
Thread-266::DEBUG::2014-11-21
01:16:00,144::resourceManager::649::Storage.ResourceManager::(releaseResource)
No one is waitin
g for resource 'Storage.0a8035e6-e41d-40ff-a154-e0a374f264b2', Clearing
records.
Thread-266::DEBUG::2014-11-21
01:16:00,144::task::993::Storage.TaskManager.Task::(_decref)
Task=`95f79027-3613-4f05-9d2d-02f8
c7975f02`::ref 0 aborting False
Thread-266::INFO::2014-11-21 01:16:00,158::vm::5743::vm.Vm::(merge)
vmId=`0ba6a56b-542c-480e-8bab-88aea9195302`::Starting mer
ge with jobUUID='2247fea2-df73-407e-ad16-4622af7f52aa'
Thread-266::DEBUG::2014-11-21
01:16:00,160::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
ecode: 67 edom: 10
level: 2 message: unsupported configuration: active commit not supported
with this QEMU binary
Thread-266::ERROR::2014-11-21 01:16:00,161::vm::5751::vm.Vm::(merge)
vmId=`0ba6a56b-542c-480e-8bab-88aea9195302`::Live merge failed (job:
2247fea2-df73-407e-ad16-4622af7f52aa)
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 5747, in merge
    flags)
  File "/usr/share/vdsm/virt/vm.py", line 670, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line
111, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 638, in
blockCommit
    if ret == -1: raise libvirtError ('virDomainBlockCommit() failed',
dom=self)
libvirtError: unsupported configuration: active commit not supported with
this QEMU binary
Thread-266::DEBUG::2014-11-21
01:16:00,181::BindingXMLRPC::1139::vds::(wrapper) return merge with
{'status': {'message': 'Merge failed', 'code': 52}}
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,656::__init__::375::IOProcess::(_processLogs) (null)|Receiving
request...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,657::__init__::375::IOProcess::(_processLogs) (null)|Queuing
request in the thread pool...
Thread-26::DEBUG::2014-11-21
01:16:00,658::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd
if=/rhev/data-center/mnt/_data_DATA2/b24b94c7-5935-4940-9152-36ecd370ba7c/dom_md/metadata
iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,659::__init__::375::IOProcess::(_processLogs) Extracting request
information...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,668::__init__::375::IOProcess::(_processLogs) (7100) Got request
for method 'statvfs'
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,668::__init__::375::IOProcess::(_processLogs) (7100) Queuing
response
Thread-26::DEBUG::2014-11-21
01:16:00,687::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n588 bytes (588 B) copied,
0.020396 s, 28.8 kB/s\n'; <rc> = 0
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,688::__init__::375::IOProcess::(_processLogs) (null)|Receiving
request...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,689::__init__::375::IOProcess::(_processLogs) (null)|Queuing
request in the thread pool...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,690::__init__::375::IOProcess::(_processLogs) Extracting request
information...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,690::__init__::375::IOProcess::(_processLogs) (7101) Got request
for method 'statvfs'
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,691::__init__::375::IOProcess::(_processLogs) (7101) Queuing
response
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,691::__init__::375::IOProcess::(_processLogs) (null)|Receiving
request...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,691::__init__::375::IOProcess::(_processLogs) Queuing request in
the thread pool...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,691::__init__::375::IOProcess::(_processLogs) Extracting request
information...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,692::__init__::375::IOProcess::(_processLogs) (null)|(7102) Got
request for method 'access'
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,693::__init__::375::IOProcess::(_processLogs) (7102) Queuing
response
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,693::__init__::375::IOProcess::(_processLogs) (null)|Receiving
request...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,693::__init__::375::IOProcess::(_processLogs) Queuing request in
the thread pool...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,694::__init__::375::IOProcess::(_processLogs) (null)|Extracting
request information...
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,695::__init__::375::IOProcess::(_processLogs) (7103) Got request
for method 'access'
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,695::__init__::375::IOProcess::(_processLogs) (7103) Queuing
response
ioprocess communication (4939)::DEBUG::2014-11-21
01:16:00,695::__init__::375::IOProcess::(_processLogs) (null)|Receiving req
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20141121/815c5e3b/attachment-0001.html>