Hello, we have recently updated few ovirts from 4.2.5 to 4.2.8 version
(actually 9 ovirt engine nodes), where the live storage migration
stopped to work, and leave auto-generated snapshot behind.
If we power the guest VM down, the migration works as expected. Is there
a known bug for this? Shall we open a new one?
Setup:
ovirt - Dell PowerEdge R630
- CentOS Linux release 7.6.1810 (Core)
- ovirt-engine-4.2.8.2-1.el7.noarch
- kernel-3.10.0-957.10.1.el7.x86_64
hypervisors - Dell PowerEdge R640
- CentOS Linux release 7.6.1810 (Core)
- kernel-3.10.0-957.10.1.el7.x86_64
- vdsm-4.20.46-1.el7.x86_64
- libvirt-5.0.0-1.el7.x86_64
- qemu-kvm-ev-2.12.0-18.el7_6.3.1.x86_64
storage domain - netapp NFS share
logs are attached
--
Ladislav Humenik
System administrator
2019-04-12 10:39:25,503+0200 INFO (jsonrpc/0) [api.virt] START
diskReplicateStart(srcDisk={'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}, dstDisk={'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'244dfdfb-2662-4103-9d39-2b13153f2047', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}) from=::ffff:10.76.98.4,57566,
flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
vmId=71f27df0-f54f-4a2e-a51c-e61aa26b370d (api:46)
2019-04-12 10:39:25,513+0200 INFO (jsonrpc/0) [vdsm.api] START
prepareImage(sdUUID='244dfdfb-2662-4103-9d39-2b13153f2047',
spUUID='b1a475aa-c084-46e5-b65a-bf4a47143c88',
imgUUID='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
leafUUID='5c2738a4-4279-4cc3-a0de-6af1095f8879', allowIllegal=False)
from=::ffff:10.76.98.4,57566, flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
task_id=78dde3c9-74fb-4588-8cfa-117f0bbe2d2d (api:46)
2019-04-12 10:39:25,630+0200 INFO (jsonrpc/0) [storage.StorageDomain] Fixing
permissions on
/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2
(fileSD:623)
2019-04-12 10:39:25,631+0200 INFO (jsonrpc/0) [storage.StorageDomain] Fixing
permissions on
/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879
(fileSD:623)
2019-04-12 10:39:25,632+0200 INFO (jsonrpc/0) [storage.StorageDomain] Creating
domain run directory
u'/var/run/vdsm/storage/244dfdfb-2662-4103-9d39-2b13153f2047' (fileSD:577)
2019-04-12 10:39:25,632+0200 INFO (jsonrpc/0) [storage.fileUtils] Creating
directory: /var/run/vdsm/storage/244dfdfb-2662-4103-9d39-2b13153f2047 mode:
None (fileUtils:197)
2019-04-12 10:39:25,632+0200 INFO (jsonrpc/0) [storage.StorageDomain] Creating
symlink from
/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be
to
/var/run/vdsm/storage/244dfdfb-2662-4103-9d39-2b13153f2047/9a66bf0f-1333-4931-ad58-f6f1aa1143be
(fileSD:580)
2019-04-12 10:39:25,637+0200 INFO (jsonrpc/0) [vdsm.api] FINISH prepareImage
return={'info': {'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'type': 'file'}, 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'imgVolumesInfo': [{'domainID': '244dfdfb-2662-4103-9d39-2b13153f2047',
'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2',
'volumeID': u'cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2', 'leasePath':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2.lease',
'imageID': '9a66bf0f-1333-4931-ad58-f6f1aa1143be'}, {'domainID':
'244dfdfb-2662-4103-9d39-2b13153f2047', 'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'volumeID': u'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'leasePath':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879.lease',
'imageID': '9a66bf0f-1333-4931-ad58-f6f1aa1143be'}]}
from=::ffff:10.76.98.4,57566, flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
task_id=78dde3c9-74fb-4588-8cfa-117f0bbe2d2d (api:52)
2019-04-12 10:39:25,637+0200 INFO (jsonrpc/0) [vds] prepared volume path:
/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879
(clientIF:497)
2019-04-12 10:39:25,642+0200 INFO (jsonrpc/0) [vdsm.api] START
teardownImage(sdUUID='244dfdfb-2662-4103-9d39-2b13153f2047',
spUUID='b1a475aa-c084-46e5-b65a-bf4a47143c88',
imgUUID='9a66bf0f-1333-4931-ad58-f6f1aa1143be', volUUID=None)
from=::ffff:10.76.98.4,57566, flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
task_id=7975136c-d4e2-47ff-a940-d7f9c9e94b19 (api:46)
2019-04-12 10:39:25,643+0200 INFO (jsonrpc/0) [storage.StorageDomain] Removing
image rundir link
u'/var/run/vdsm/storage/244dfdfb-2662-4103-9d39-2b13153f2047/9a66bf0f-1333-4931-ad58-f6f1aa1143be'
(fileSD:600)
2019-04-12 10:39:25,643+0200 INFO (jsonrpc/0) [vdsm.api] FINISH teardownImage
return=None from=::ffff:10.76.98.4,57566,
flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
task_id=7975136c-d4e2-47ff-a940-d7f9c9e94b19 (api:52)
2019-04-12 10:39:25,643+0200 ERROR (jsonrpc/0) [virt.vm]
(vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d') Unable to start replication for
vda to {'domainID': '244dfdfb-2662-4103-9d39-2b13153f2047', 'volumeInfo':
{'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'type': 'file'}, 'diskType': 'file', 'format': 'cow', 'cache': 'none',
'volumeID': '5c2738a4-4279-4cc3-a0de-6af1095f8879', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'device': 'disk', 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'propagateErrors': 'off', 'volumeChain': [{'domainID':
'244dfdfb-2662-4103-9d39-2b13153f2047', 'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2',
'volumeID': u'cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2', 'leasePath':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2.lease',
'imageID': '9a66bf0f-1333-4931-ad58-f6f1aa1143be'}, {'domainID':
'244dfdfb-2662-4103-9d39-2b13153f2047', 'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879',
'volumeID': u'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'leasePath':
u'/rhev/data-center/mnt/removed-IP-address:_bs01aF1C1v1/244dfdfb-2662-4103-9d39-2b13153f2047/images/9a66bf0f-1333-4931-ad58-f6f1aa1143be/5c2738a4-4279-4cc3-a0de-6af1095f8879.lease',
'imageID': '9a66bf0f-1333-4931-ad58-f6f1aa1143be'}]} (vm:4710)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4704, in
diskReplicateStart
self._startDriveReplication(drive)
File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4843, in
_startDriveReplication
self._dom.blockCopy(drive.name, destxml, flags=flags)
File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 98, in f
ret = attr(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/vdsm/common/libvirtconnection.py",
line 130, in wrapper
ret = f(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/vdsm/common/function.py", line 92, in
wrapper
return func(inst, *args, **kwargs)
File "/usr/lib64/python2.7/site-packages/libvirt.py", line 728, in blockCopy
ret = libvirtmod.virDomainBlockCopy(self._o, disk, destxml, params, flags)
TypeError: block params must be a dictionary
2019-04-12 10:39:25,648+0200 INFO (jsonrpc/0) [api.virt] FINISH
diskReplicateStart return={'status': {'message': 'Drive replication error',
'code': 55}} from=::ffff:10.76.98.4,57566,
flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
vmId=71f27df0-f54f-4a2e-a51c-e61aa26b370d (api:52)
2019-04-12 10:39:25,649+0200 INFO (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
VM.diskReplicateStart failed (error 55) in 0.15 seconds (__init__:573)
2019-04-12 10:39:26,867+0200 INFO (jsonrpc/6) [api.virt] START
diskReplicateFinish(srcDisk={'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}, dstDisk={'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}) from=::ffff:10.76.98.4,57566,
flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
vmId=71f27df0-f54f-4a2e-a51c-e61aa26b370d (api:46)
2019-04-12 10:39:26,867+0200 ERROR (jsonrpc/6) [api] FINISH diskReplicateFinish
error=Replication not in progress.: {'driveName': 'vda', 'vmId':
'71f27df0-f54f-4a2e-a51c-e61aa26b370d', 'srcDisk': {'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}} (api:129)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 122, in
method
ret = func(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/vdsm/API.py", line 571, in
diskReplicateFinish
return self.vm.diskReplicateFinish(srcDisk, dstDisk)
File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4746, in
diskReplicateFinish
srcDisk=srcDisk)
ReplicationNotInProgress: Replication not in progress.: {'driveName': 'vda',
'vmId': '71f27df0-f54f-4a2e-a51c-e61aa26b370d', 'srcDisk': {'device': 'disk',
'poolID': 'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}}
2019-04-12 10:39:26,871+0200 INFO (jsonrpc/6) [api.virt] FINISH
diskReplicateFinish return={'status': {'message': "Replication not in
progress.: {'driveName': 'vda', 'vmId': '71f27df0-f54f-4a2e-a51c-e61aa26b370d',
'srcDisk': {'device': 'disk', 'poolID': 'b1a475aa-c084-46e5-b65a-bf4a47143c88',
'volumeID': '5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}}", 'code': 88}}
from=::ffff:10.76.98.4,57566, flow_id=97b620d9-6e65-4573-9fdf-5b119764fbb7,
vmId=71f27df0-f54f-4a2e-a51c-e61aa26b370d (api:52)
2019-04-12 10:39:26,872+0200 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
VM.diskReplicateFinish failed (error 88) in 0.00 seconds (__init__:573)
2019-04-12 10:39:10,434+02 INFO
[org.ovirt.engine.core.bll.storage.disk.MoveDiskCommand] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Lock Acquired to object
'EngineLock:{exclusiveLocks='[9a66bf0f-1333-4931-ad58-f6f1aa1143be=DISK]',
sharedLocks=''}'
2019-04-12 10:39:10,435+02 INFO
[org.ovirt.engine.core.bll.storage.disk.MoveDiskCommand] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command: MoveDiskCommand
internal: false. Entities affected : ID: 9a66bf0f-1333-4931-ad58-f6f1aa1143be
Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER, ID:
244dfdfb-2662-4103-9d39-2b13153f2047 Type: StorageAction group CREATE_DISK with
role type USER
2019-04-12 10:39:11,226+02 INFO
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command:
LiveMigrateDiskCommand internal: true. Entities affected : ID:
9a66bf0f-1333-4931-ad58-f6f1aa1143be Type: DiskAction group
DISK_LIVE_STORAGE_MIGRATION with role type USER
2019-04-12 10:39:11,598+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command:
CreateSnapshotForVmCommand internal: true. Entities affected : ID:
71f27df0-f54f-4a2e-a51c-e61aa26b370d Type: VMAction group
MANIPULATE_VM_SNAPSHOTS with role type USER
2019-04-12 10:39:11,649+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command:
CreateSnapshotDiskCommand internal: true. Entities affected : ID:
71f27df0-f54f-4a2e-a51c-e61aa26b370d Type: VMAction group
MANIPULATE_VM_SNAPSHOTS with role type USER
2019-04-12 10:39:11,750+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command:
CreateSnapshotCommand internal: true. Entities affected : ID:
00000000-0000-0000-0000-000000000000 Type: Storage
2019-04-12 10:39:11,789+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] START,
CreateVolumeVDSCommand(
CreateVolumeVDSCommandParameters:{storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
ignoreFailoverLimit='false',
storageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageSizeInBytes='21474836480', volumeFormat='COW',
newImageId='5c2738a4-4279-4cc3-a0de-6af1095f8879', imageType='Sparse',
newImageDescription='', imageInitialSizeInBytes='0',
imageId='cbe93bfe-9df0-4f12-a44e-9e8fa6ec24f2',
sourceImageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be'}), log id: 256e961c
2019-04-12 10:39:11,875+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH,
CreateVolumeVDSCommand, return: 5c2738a4-4279-4cc3-a0de-6af1095f8879, log id:
256e961c
2019-04-12 10:39:11,880+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::Adding
CommandMultiAsyncTasks object for command '968047c9-77fa-4c18-a5c5-768c18da863f'
2019-04-12 10:39:11,880+02 INFO
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandMultiAsyncTasks::attachTask:
Attaching task '435ba733-587d-4afb-ae18-505423e6f162' to command
'968047c9-77fa-4c18-a5c5-768c18da863f'.
2019-04-12 10:39:11,898+02 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Adding task
'435ba733-587d-4afb-ae18-505423e6f162' (Parent Command 'CreateSnapshot',
Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'),
polling hasn't started yet..
2019-04-12 10:39:11,936+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(default task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7]
BaseAsyncTask::startPollingTask: Starting to poll task
'435ba733-587d-4afb-ae18-505423e6f162'.
2019-04-12 10:39:12,078+02 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] EVENT_ID:
USER_CREATE_SNAPSHOT(45), Snapshot 'test-migration Auto-generated for Live
Storage Migration' creation for VM 'test-migration' was initiated by
admin@internal-authz.
2019-04-12 10:39:12,092+02 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-53)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'CreateSnapshotDisk' (id:
'4bbf17a1-ed93-4153-9f38-661f8fdbdda4') waiting on child command id:
'968047c9-77fa-4c18-a5c5-768c18da863f' type:'CreateSnapshot' to complete
2019-04-12 10:39:12,094+02 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default
task-49890) [97b620d9-6e65-4573-9fdf-5b119764fbb7] EVENT_ID:
USER_MOVED_DISK(2,008), User admin@internal-authz moving disk test-migration to
domain bs01aF1C1v1.
2019-04-12 10:39:12,098+02 INFO
[org.ovirt.engine.core.bll.storage.disk.MoveDiskCommand] (default task-49890)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Lock freed to object
'EngineLock:{exclusiveLocks='[9a66bf0f-1333-4931-ad58-f6f1aa1143be=DISK]',
sharedLocks=''}'
2019-04-12 10:39:12,266+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-53)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'LiveMigrateDisk' (id:
'913ba8e1-21d5-4eb5-b10c-e26188f89162') waiting on child command id:
'f1e84f78-1069-4c29-8d82-264aac741611' type:'CreateSnapshotForVm' to complete
2019-04-12 10:39:12,375+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-53)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'CreateSnapshotForVm' (id:
'f1e84f78-1069-4c29-8d82-264aac741611') waiting on child command id:
'4bbf17a1-ed93-4153-9f38-661f8fdbdda4' type:'CreateSnapshotDisk' to complete
2019-04-12 10:39:12,759+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command
[id=968047c9-77fa-4c18-a5c5-768c18da863f]: Updating status to 'SUCCEEDED', The
command end method logic will be executed by one of its parent commands.
2019-04-12 10:39:12,761+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type 'CreateSnapshot' completed, handling
the result.
2019-04-12 10:39:12,761+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type 'CreateSnapshot' succeeded, clearing
tasks.
2019-04-12 10:39:12,761+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] SPMAsyncTask::ClearAsyncTask: Attempting
to clear task '435ba733-587d-4afb-ae18-505423e6f162'
2019-04-12 10:39:12,762+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
ignoreFailoverLimit='false', taskId='435ba733-587d-4afb-ae18-505423e6f162'}),
log id: 31fe3b1f
2019-04-12 10:39:12,762+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, HSMClearTaskVDSCommand(HostName =
destination.server.lan,
HSMTaskGuidBaseVDSCommandParameters:{hostId='21ce9c45-a9d8-4d09-86a7-fc6308f00f9c',
taskId='435ba733-587d-4afb-ae18-505423e6f162'}), log id: 1587a805
2019-04-12 10:39:12,772+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, HSMClearTaskVDSCommand, log id:
1587a805
2019-04-12 10:39:12,772+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, SPMClearTaskVDSCommand, log id:
31fe3b1f
2019-04-12 10:39:12,774+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] BaseAsyncTask::removeTaskFromDB: Removed
task '435ba733-587d-4afb-ae18-505423e6f162' from DataBase
2019-04-12 10:39:12,774+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-26)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: Removing CommandMultiAsyncTasks object for entity
'968047c9-77fa-4c18-a5c5-768c18da863f'
2019-04-12 10:39:14,378+02 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'CreateSnapshotDisk' id:
'4bbf17a1-ed93-4153-9f38-661f8fdbdda4' child commands
'[968047c9-77fa-4c18-a5c5-768c18da863f]' executions were completed, status
'SUCCEEDED'
2019-04-12 10:39:14,378+02 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'CreateSnapshotDisk' id:
'4bbf17a1-ed93-4153-9f38-661f8fdbdda4' Updating status to 'SUCCEEDED', The
command end method logic will be executed by one of its parent commands.
2019-04-12 10:39:14,574+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'LiveMigrateDisk' (id:
'913ba8e1-21d5-4eb5-b10c-e26188f89162') waiting on child command id:
'f1e84f78-1069-4c29-8d82-264aac741611' type:'CreateSnapshotForVm' to complete
2019-04-12 10:39:14,728+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-50)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, SnapshotVDSCommand(HostName =
source.server.lan,
SnapshotVDSCommandParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d'}), log id: 193ef300
2019-04-12 10:39:14,923+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-50)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, SnapshotVDSCommand, log id:
193ef300
2019-04-12 10:39:16,034+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-87)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'CreateSnapshotForVm' id:
'f1e84f78-1069-4c29-8d82-264aac741611' child commands
'[4bbf17a1-ed93-4153-9f38-661f8fdbdda4]' executions were completed, status
'SUCCEEDED'
2019-04-12 10:39:17,147+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Ending command
'org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand' successfully.
2019-04-12 10:39:17,155+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Ending command
'org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand' successfully.
2019-04-12 10:39:17,164+02 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Ending command
'org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand' successfully.
2019-04-12 10:39:17,178+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, GetImageInfoVDSCommand(
GetImageInfoVDSCommandParameters:{storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
ignoreFailoverLimit='false',
storageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'}), log id: 435242ed
2019-04-12 10:39:17,180+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, GetVolumeInfoVDSCommand(HostName
= destination.server.lan,
GetVolumeInfoVDSCommandParameters:{hostId='21ce9c45-a9d8-4d09-86a7-fc6308f00f9c',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
storageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'}), log id: 86330ee
2019-04-12 10:39:17,248+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, GetVolumeInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@ec8f9e0e, log
id: 86330ee
2019-04-12 10:39:17,248+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, GetImageInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@ec8f9e0e, log
id: 435242ed
2019-04-12 10:39:17,315+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetQemuImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START,
GetQemuImageInfoVDSCommand(HostName = source.server.lan,
GetVolumeInfoVDSCommandParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
storageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'}), log id: 65d0a661
2019-04-12 10:39:17,762+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetQemuImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-3)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, GetQemuImageInfoVDSCommand,
return:
org.ovirt.engine.core.common.businessentities.storage.QemuImageInfo@2235c69f,
log id: 65d0a661
2019-04-12 10:39:19,016+02 INFO
[org.ovirt.engine.core.bll.storage.lsm.CreateImagePlaceholderCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Running command:
CreateImagePlaceholderCommand internal: true.
2019-04-12 10:39:19,027+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START,
CloneImageGroupStructureVDSCommand(
TargetDomainImageGroupVDSCommandParameters:{storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
ignoreFailoverLimit='false',
storageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
dstDomainId='244dfdfb-2662-4103-9d39-2b13153f2047'}), log id: 405bcde1
2019-04-12 10:39:19,070+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH,
CloneImageGroupStructureVDSCommand, log id: 405bcde1
2019-04-12 10:39:19,074+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::Adding
CommandMultiAsyncTasks object for command '6a0155ad-cef8-45b3-b6db-909f6574ea5a'
2019-04-12 10:39:19,074+02 INFO
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandMultiAsyncTasks::attachTask:
Attaching task 'dbe54fea-ff1b-476f-b570-6182923273c0' to command
'6a0155ad-cef8-45b3-b6db-909f6574ea5a'.
2019-04-12 10:39:19,086+02 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Adding task
'dbe54fea-ff1b-476f-b570-6182923273c0' (Parent Command
'CreateImagePlaceholder', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't
started yet..
2019-04-12 10:39:19,093+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] BaseAsyncTask::startPollingTask:
Starting to poll task 'dbe54fea-ff1b-476f-b570-6182923273c0'.
2019-04-12 10:39:21,292+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-98)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'LiveMigrateDisk' (id:
'913ba8e1-21d5-4eb5-b10c-e26188f89162') waiting on child command id:
'6a0155ad-cef8-45b3-b6db-909f6574ea5a' type:'CreateImagePlaceholder' to complete
2019-04-12 10:39:22,772+02 INFO
[org.ovirt.engine.core.bll.storage.lsm.CreateImagePlaceholderCommand]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Ending command
'org.ovirt.engine.core.bll.storage.lsm.CreateImagePlaceholderCommand'
successfully.
2019-04-12 10:39:22,781+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type 'CreateImagePlaceholder' completed,
handling the result.
2019-04-12 10:39:22,781+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type 'CreateImagePlaceholder' succeeded,
clearing tasks.
2019-04-12 10:39:22,781+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] SPMAsyncTask::ClearAsyncTask: Attempting
to clear task 'dbe54fea-ff1b-476f-b570-6182923273c0'
2019-04-12 10:39:22,782+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
ignoreFailoverLimit='false', taskId='dbe54fea-ff1b-476f-b570-6182923273c0'}),
log id: 7a12d0c3
2019-04-12 10:39:22,784+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START, HSMClearTaskVDSCommand(HostName =
destination.server.lan,
HSMTaskGuidBaseVDSCommandParameters:{hostId='21ce9c45-a9d8-4d09-86a7-fc6308f00f9c',
taskId='dbe54fea-ff1b-476f-b570-6182923273c0'}), log id: 227b7a73
2019-04-12 10:39:22,800+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, HSMClearTaskVDSCommand, log id:
227b7a73
2019-04-12 10:39:22,800+02 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, SPMClearTaskVDSCommand, log id:
7a12d0c3
2019-04-12 10:39:22,803+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] BaseAsyncTask::removeTaskFromDB: Removed
task 'dbe54fea-ff1b-476f-b570-6182923273c0' from DataBase
2019-04-12 10:39:22,803+02 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-18)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] CommandAsyncTask::HandleEndActionResult
[within thread]: Removing CommandMultiAsyncTasks object for entity
'6a0155ad-cef8-45b3-b6db-909f6574ea5a'
2019-04-12 10:39:25,501+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START,
VmReplicateDiskStartVDSCommand(HostName = source.server.lan,
VmReplicateDiskParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
srcStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
targetStorageDomainId='244dfdfb-2662-4103-9d39-2b13153f2047',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'}), log id: 5bb50cbf
2019-04-12 10:39:25,650+02 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Failed in 'VmReplicateDiskStartVDS'
method
2019-04-12 10:39:25,655+02 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] EVENT_ID:
VDS_BROKER_COMMAND_FAILURE(10,802), VDSM source.server.lan command
VmReplicateDiskStartVDS failed: Drive replication error
2019-04-12 10:39:25,655+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand'
return value 'StatusOnlyReturn [status=Status [code=55, message=Drive
replication error]]'
2019-04-12 10:39:25,655+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] HostName = source.server.lan
2019-04-12 10:39:25,655+02 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command
'VmReplicateDiskStartVDSCommand(HostName = source.server.lan,
VmReplicateDiskParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
srcStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
targetStorageDomainId='244dfdfb-2662-4103-9d39-2b13153f2047',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'})' execution failed:
VDSGenericException: VDSErrorException: Failed to VmReplicateDiskStartVDS,
error = Drive replication error, code = 55
2019-04-12 10:39:25,655+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, VmReplicateDiskStartVDSCommand,
log id: 5bb50cbf
2019-04-12 10:39:25,655+02 ERROR
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Failed VmReplicateDiskStart (Disk
'9a66bf0f-1333-4931-ad58-f6f1aa1143be' , VM
'71f27df0-f54f-4a2e-a51c-e61aa26b370d')
2019-04-12 10:39:25,657+02 ERROR
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'LiveMigrateDisk' id:
'913ba8e1-21d5-4eb5-b10c-e26188f89162' with children
[f1e84f78-1069-4c29-8d82-264aac741611, 6a0155ad-cef8-45b3-b6db-909f6574ea5a]
failed when attempting to perform the next operation, marking as 'ACTIVE'
2019-04-12 10:39:25,657+02 ERROR
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] EngineException: Drive replication error
(Failed with error replicaErr and code 55):
org.ovirt.engine.core.common.errors.EngineException: EngineException: Drive
replication error (Failed with error replicaErr and code 55)
at
org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand.replicateDiskStart(LiveMigrateDiskCommand.java:499)
[bll.jar:]
at
org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand.performNextOperation(LiveMigrateDiskCommand.java:233)
[bll.jar:]
at
org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback.childCommandsExecutionEnded(SerialChildCommandsExecutionCallback.java:32)
[bll.jar:]
at
org.ovirt.engine.core.bll.ChildCommandsCallbackBase.doPolling(ChildCommandsCallbackBase.java:68)
[bll.jar:]
at
org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:146)
[bll.jar:]
at
org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:107)
[bll.jar:]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_201]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[rt.jar:1.8.0_201]
at
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
[javax.enterprise.concurrent-1.0.jar:]
at
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534)
[javax.enterprise.concurrent-1.0.jar:]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_201]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_201]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_201]
at
org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)
[javax.enterprise.concurrent-1.0.jar:]
at
org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)
2019-04-12 10:39:25,658+02 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-94)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command 'LiveMigrateDisk' id:
'913ba8e1-21d5-4eb5-b10c-e26188f89162' child commands
'[f1e84f78-1069-4c29-8d82-264aac741611, 6a0155ad-cef8-45b3-b6db-909f6574ea5a]'
executions were completed, status 'FAILED'
2019-04-12 10:39:26,864+02 ERROR
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Ending command
'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand' with failure.
2019-04-12 10:39:26,864+02 ERROR
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Failed during live storage migration of
disk '9a66bf0f-1333-4931-ad58-f6f1aa1143be' of vm
'71f27df0-f54f-4a2e-a51c-e61aa26b370d', attempting to end replication before
deleting the target disk
2019-04-12 10:39:26,865+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] START,
VmReplicateDiskFinishVDSCommand(HostName = source.server.lan,
VmReplicateDiskParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
srcStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
targetStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'}), log id: 747f64ab
2019-04-12 10:39:26,876+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand'
return value 'StatusOnlyReturn [status=Status [code=88, message=Replication not
in progress.: {'driveName': 'vda', 'vmId':
'71f27df0-f54f-4a2e-a51c-e61aa26b370d', 'srcDisk': {'device': 'disk', 'poolID':
'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}}]]'
2019-04-12 10:39:26,876+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] HostName = source.server.lan
2019-04-12 10:39:26,876+02 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Command
'VmReplicateDiskFinishVDSCommand(HostName = source.server.lan,
VmReplicateDiskParameters:{hostId='126f25f1-866d-4d88-b1da-390aff771265',
vmId='71f27df0-f54f-4a2e-a51c-e61aa26b370d',
storagePoolId='b1a475aa-c084-46e5-b65a-bf4a47143c88',
srcStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
targetStorageDomainId='e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5',
imageGroupId='9a66bf0f-1333-4931-ad58-f6f1aa1143be',
imageId='5c2738a4-4279-4cc3-a0de-6af1095f8879'})' execution failed:
VDSGenericException: VDSErrorException: Failed in vdscommand to
VmReplicateDiskFinishVDS, error = Replication not in progress.: {'driveName':
'vda', 'vmId': '71f27df0-f54f-4a2e-a51c-e61aa26b370d', 'srcDisk': {'device':
'disk', 'poolID': 'b1a475aa-c084-46e5-b65a-bf4a47143c88', 'volumeID':
'5c2738a4-4279-4cc3-a0de-6af1095f8879', 'domainID':
'e5bb3e8a-a9c6-4581-8c6a-67d4ee7609f5', 'imageID':
'9a66bf0f-1333-4931-ad58-f6f1aa1143be'}}
2019-04-12 10:39:26,876+02 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] FINISH, VmReplicateDiskFinishVDSCommand,
log id: 747f64ab
2019-04-12 10:39:26,876+02 WARN
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Replication is not in progress,
proceeding with removing the target disk
2019-04-12 10:39:26,876+02 ERROR
[org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-77)
[97b620d9-6e65-4573-9fdf-5b119764fbb7] Attempting to delete the target of disk
'9a66bf0f-1333-4931-ad58-f6f1aa1143be' of vm
'71f27df0-f54f-4a2e-a51c-e61aa26b370d'
_______________________________________________
Users mailing list -- users@ovirt.org
To unsubscribe send an email to users-le...@ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/VSKUEPUOPJDSRWYYMZEKAVTZ62YP6UK2/
