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'