I have a VM that was exported successfully to an export domain, but when I
tried to re-import into the Data Center it fails with the following logs.
Hoping someone can shed the light on why it's failing to import the VM into
the Cluster. It seems concerning when it says: "VDSGenericException:
VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = low level
Image copy failed, code = 261".
Help anyone?
2017-08-30 02:14:03,617 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand]
(ajp--127.0.0.1-8702-4) START, GetVmsInfoVDSCommand( storagePoolId =
ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit = false,
storageDomainId = 4cde55bd-328e-40a7-9b0e-b4a5d576d896, vmIdList = null),
log id: 74730ee
2017-08-30 02:14:03,639 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand]
(ajp--127.0.0.1-8702-4) FINISH, GetVmsInfoVDSCommand, log id: 74730ee
2017-08-30 02:14:06,103 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-32) VM job
07fd15a8-1e41-4cfa-bddd-c2ecef6568a8: In progress (no change)
2017-08-30 02:14:06,313 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-34) VM job
80378e33-1efd-4f25-8550-81d4922c5440: In progress (no change)
2017-08-30 02:14:06,319 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-36) VM job
1d9fca66-c709-4c2b-a0c3-bf1b1048149c: In progress (no change)
2017-08-30 02:14:06,320 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-36) VM job
d063300d-7d0f-4bfe-856e-4b0fa450726d: In progress (no change)
2017-08-30 02:14:06,321 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-34) VM job
ebf6911c-ae9f-4fb1-93ae-1c1cbe242e5e: In progress (no change)
2017-08-30 02:14:06,324 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-34) VM job
a6c48586-5c02-4b81-a54d-a199d7c4befe: In progress (no change)
2017-08-30 02:14:06,506 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-35) VM job
2b1f11c9-4852-4cf3-8a6d-1ac242d05420: In progress (no change)
2017-08-30 02:14:20,291 INFO [org.ovirt.engine.core.bll.ImportVmCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] Lock Acquired to object EngineLock
[exclusiveLocks= key: las01-622-003__2017-08-29__13.01.30 value: VM_NAME
, sharedLocks= key: 02137593-5f11-4f07-afc0-5d3992a26b38 value: REMOTE_VM
]
2017-08-30 02:14:20,302 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] START, GetVmsInfoVDSCommand(
storagePoolId = ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit =
false, storageDomainId = 4cde55bd-328e-40a7-9b0e-b4a5d576d896, vmIdList =
null), log id: 3672c4a9
2017-08-30 02:14:20,320 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] FINISH, GetVmsInfoVDSCommand, log id:
3672c4a9
2017-08-30 02:14:20,887 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImagesListVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] START, GetImagesListVDSCommand(
storagePoolId = ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit =
false, sdUUID = 39b260fb-0e4e-414d-972f-8ebd87ce7643), log id: 692a8a42
2017-08-30 02:14:20,904 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImagesListVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] FINISH, GetImagesListVDSCommand, return:
[d91aa8be-7929-43e3-8891-e5b35389150f,
420f239a-177b-407e-bb22-c93f984c8735, 7cc223ed-d7cd-4d0e-85fd-05a9a82d3315,
e7879ce5-5af3-48ab-ab1c-26540cf785b5], log id: 692a8a42
2017-08-30 02:14:20,911 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DoesImageExistVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] START, DoesImageExistVDSCommand(
storagePoolId = ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit =
false, storageDomainId = 4cde55bd-328e-40a7-9b0e-b4a5d576d896, imageGroupId
= f0b7e806-64d9-49ea-a52c-7fe70be2138b, imageId =
53b161c8-1751-41cf-b0bb-444bd603d136), log id: 707f904c
2017-08-30 02:14:20,929 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DoesImageExistVDSCommand]
(ajp--127.0.0.1-8702-5) [338f07a0] FINISH, DoesImageExistVDSCommand,
return: true, log id: 707f904c
2017-08-30 02:14:21,058 INFO [org.ovirt.engine.core.bll.ImportVmCommand]
(org.ovirt.thread.pool-8-thread-26) [338f07a0] Running command:
ImportVmCommand internal: false. Entities affected : ID:
39b260fb-0e4e-414d-972f-8ebd87ce7643 Type: StorageAction group
IMPORT_EXPORT_VM with role type ADMIN
2017-08-30 02:14:21,274 INFO
[org.ovirt.engine.core.bll.CopyImageGroupCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] Running command:
CopyImageGroupCommand internal: true. Entities affected : ID:
39b260fb-0e4e-414d-972f-8ebd87ce7643 Type: Storage
2017-08-30 02:14:21,417 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-99) VM job
07fd15a8-1e41-4cfa-bddd-c2ecef6568a8: In progress (no change)
2017-08-30 02:14:21,426 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] START, CopyImageVDSCommand(
storagePoolId = ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit =
false, storageDomainId = 4cde55bd-328e-40a7-9b0e-b4a5d576d896, imageGroupId
= f0b7e806-64d9-49ea-a52c-7fe70be2138b, imageId =
53b161c8-1751-41cf-b0bb-444bd603d136, dstImageGroupId =
f0b7e806-64d9-49ea-a52c-7fe70be2138b, vmId =
02137593-5f11-4f07-afc0-5d3992a26b38, dstImageId =
53b161c8-1751-41cf-b0bb-444bd603d136, imageDescription = ,
dstStorageDomainId = 39b260fb-0e4e-414d-972f-8ebd87ce7643, copyVolumeType =
LeafVol, volumeFormat = RAW, preallocate = Sparse, postZero = false, force
= true), log id: 7bd35902
2017-08-30 02:14:21,428 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] -- executeIrsBrokerCommand:
calling 'copyImage' with two new parameters: description and UUID
2017-08-30 02:14:21,429 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] -- copyImage parameters:
sdUUID=4cde55bd-328e-40a7-9b0e-b4a5d576d896
spUUID=ff545917-da81-43a2-a5e0-b43b185ee8e8
vmGUID=02137593-5f11-4f07-afc0-5d3992a26b38
srcImageGUID=f0b7e806-64d9-49ea-a52c-7fe70be2138b
srcVolUUID=53b161c8-1751-41cf-b0bb-444bd603d136
dstImageGUID=f0b7e806-64d9-49ea-a52c-7fe70be2138b
dstVolUUID=53b161c8-1751-41cf-b0bb-444bd603d136
descr=
dstSdUUID=39b260fb-0e4e-414d-972f-8ebd87ce7643
2017-08-30 02:14:21,528 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] FINISH, CopyImageVDSCommand,
return: 00000000-0000-0000-0000-000000000000, log id: 7bd35902
2017-08-30 02:14:21,542 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(org.ovirt.thread.pool-8-thread-26) [5637f152] CommandAsyncTask::Adding
CommandMultiAsyncTasks object for command
14530608-260e-4988-8fb4-1fab452ae215
2017-08-30 02:14:21,544 INFO
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
(org.ovirt.thread.pool-8-thread-26) [5637f152]
CommandMultiAsyncTasks::AttachTask: Attaching task
f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d to command
14530608-260e-4988-8fb4-1fab452ae215.
2017-08-30 02:14:21,569 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(org.ovirt.thread.pool-8-thread-26) [5637f152] Adding task
f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d (Parent Command ImportVm, Parameters
Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling
hasn't started yet..
2017-08-30 02:14:21,742 INFO
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] START,
SetVmStatusVDSCommand( vmId = 02137593-5f11-4f07-afc0-5d3992a26b38, status
= ImageLocked, exit status = Normal), log id: 67bbeffa
2017-08-30 02:14:21,749 INFO
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
(org.ovirt.thread.pool-8-thread-26) [5637f152] FINISH,
SetVmStatusVDSCommand, log id: 67bbeffa
2017-08-30 02:14:21,774 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-98) VM job
80378e33-1efd-4f25-8550-81d4922c5440: In progress (no change)
2017-08-30 02:14:21,777 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-98) VM job
ebf6911c-ae9f-4fb1-93ae-1c1cbe242e5e: In progress (no change)
2017-08-30 02:14:21,779 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-98) VM job
a6c48586-5c02-4b81-a54d-a199d7c4befe: In progress (no change)
2017-08-30 02:14:21,797 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-26) [5637f152] Correlation ID: 338f07a0,
Job ID: 51514883-1f74-4d1e-80e3-24c94b9a75c8, Call Stack: null, Custom
Event ID: -1, Message: Starting to import Vm
las01-622-003__2017-08-29__13.01.30 to Data Center las01, Cluster
las01-switch
2017-08-30 02:14:21,799 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(org.ovirt.thread.pool-8-thread-26) [5637f152]
BaseAsyncTask::startPollingTask: Starting to poll task
f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d.
2017-08-30 02:14:21,799 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-97) VM job
1d9fca66-c709-4c2b-a0c3-bf1b1048149c: In progress (no change)
2017-08-30 02:14:21,803 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-97) VM job
d063300d-7d0f-4bfe-856e-4b0fa450726d: In progress (no change)
2017-08-30 02:14:21,934 INFO
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-6) VM job
2b1f11c9-4852-4cf3-8a6d-1ac242d05420: In progress (no change)
2017-08-30 02:14:23,927 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(DefaultQuartzScheduler_Worker-5) Polling and updating Async Tasks: 1
tasks, 1 tasks to poll now
2017-08-30 02:14:23,941 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(DefaultQuartzScheduler_Worker-5) Failed in HSMGetAllTasksStatusesVDS method
2017-08-30 02:14:23,943 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(DefaultQuartzScheduler_Worker-5) SPMAsyncTask::PollTask: Polling task
f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d (Parent Command ImportVm, Parameters
Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned
status finished, result 'cleanSuccess'.
2017-08-30 02:14:23,959 ERROR
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(DefaultQuartzScheduler_Worker-5) BaseAsyncTask::logEndTaskFailure: Task
f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d (Parent Command ImportVm, Parameters
Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended
with failure:
-- Result: cleanSuccess
-- Message: VDSGenericException: VDSErrorException: Failed to
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261,
-- Exception: VDSGenericException: VDSErrorException: Failed to
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261
2017-08-30 02:14:23,964 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(DefaultQuartzScheduler_Worker-5) CommandAsyncTask::endActionIfNecessary:
All tasks of command 14530608-260e-4988-8fb4-1fab452ae215 has ended ->
executing endAction
2017-08-30 02:14:23,966 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(DefaultQuartzScheduler_Worker-5) CommandAsyncTask::endAction: Ending
action for 1 tasks (command ID: 14530608-260e-4988-8fb4-1fab452ae215):
calling endAction .
2017-08-30 02:14:23,969 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(org.ovirt.thread.pool-8-thread-43) CommandAsyncTask::endCommandAction
[within thread] context: Attempting to endAction ImportVm, executionIndex: 0
2017-08-30 02:14:24,008 ERROR [org.ovirt.engine.core.bll.ImportVmCommand]
(org.ovirt.thread.pool-8-thread-43) Ending command with failure:
org.ovirt.engine.core.bll.ImportVmCommand
2017-08-30 02:14:24,100 ERROR
[org.ovirt.engine.core.bll.CopyImageGroupCommand]
(org.ovirt.thread.pool-8-thread-43) [5637f152] Ending command with failure:
org.ovirt.engine.core.bll.CopyImageGroupCommand
2017-08-30 02:14:24,113 INFO
[org.ovirt.engine.core.bll.RemoveImageCommand]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] Running command:
RemoveImageCommand internal: true. Entities affected : ID:
39b260fb-0e4e-414d-972f-8ebd87ce7643 Type: Storage
2017-08-30 02:14:24,193 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] START,
DeleteImageGroupVDSCommand( storagePoolId =
ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit = false,
storageDomainId = 39b260fb-0e4e-414d-972f-8ebd87ce7643, imageGroupId =
f0b7e806-64d9-49ea-a52c-7fe70be2138b, postZeros = false, forceDelete =
false), log id: 29fac779
2017-08-30 02:14:24,218 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] Command
DeleteImageGroupVDSCommand( storagePoolId =
ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit = false,
storageDomainId = 39b260fb-0e4e-414d-972f-8ebd87ce7643, imageGroupId =
f0b7e806-64d9-49ea-a52c-7fe70be2138b, postZeros = false, forceDelete =
false) execution failed. Exception: IrsOperationFailedNoFailoverException:
IRSGenericException: IRSErrorException: Image does not exist in domain:
u'image=f0b7e806-64d9-49ea-a52c-7fe70be2138b,
domain=39b260fb-0e4e-414d-972f-8ebd87ce7643'
2017-08-30 02:14:24,220 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] FINISH,
DeleteImageGroupVDSCommand, log id: 29fac779
2017-08-30 02:14:24,221 INFO
[org.ovirt.engine.core.bll.RemoveImageCommand]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] Disk
f0b7e806-64d9-49ea-a52c-7fe70be2138b doesnt exist on storage domain
39b260fb-0e4e-414d-972f-8ebd87ce7643, rolling forward
2017-08-30 02:14:24,360 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(org.ovirt.thread.pool-8-thread-43) [20e1b3d3] Removed task
86cc1a36-6c76-47f7-8c3e-d2d7dc02fcdc from DataBase
2017-08-30 02:14:24,411 INFO [org.ovirt.engine.core.bll.ImportVmCommand]
(org.ovirt.thread.pool-8-thread-43) Lock freed to object EngineLock
[exclusiveLocks= key: las01-622-003__2017-08-29__13.01.30 value: VM_NAME
, sharedLocks= key: 02137593-5f11-4f07-afc0-5d3992a26b38 value: REMOTE_VM
]
2017-08-30 02:14:24,429 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-43) Correlation ID: 338f07a0, Job ID:
51514883-1f74-4d1e-80e3-24c94b9a75c8, Call Stack: null, Custom Event ID:
-1, Message: Failed to import Vm las01-622-003__2017-08-29__13.01.30 to
Data Center las01, Cluster las01-switch
2017-08-30 02:14:24,430 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(org.ovirt.thread.pool-8-thread-43) CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type ImportVm completed, handling the
result.
2017-08-30 02:14:24,431 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(org.ovirt.thread.pool-8-thread-43) CommandAsyncTask::HandleEndActionResult
[within thread]: endAction for action type ImportVm succeeded, clearing
tasks.
2017-08-30 02:14:24,440 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(org.ovirt.thread.pool-8-thread-43) SPMAsyncTask::ClearAsyncTask:
Attempting to clear task f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d
2017-08-30 02:14:24,443 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(org.ovirt.thread.pool-8-thread-43) START, SPMClearTaskVDSCommand(
storagePoolId = ff545917-da81-43a2-a5e0-b43b185ee8e8, ignoreFailoverLimit =
false, taskId = f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d), log id: 483bc9a3
2017-08-30 02:14:24,446 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(org.ovirt.thread.pool-8-thread-43) START, HSMClearTaskVDSCommand(HostName
= las01-002-003, HostId = 4c396d88-fe8d-43f3-8fbb-291e88c5c815,
taskId=f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d), log id: 5ee245c
2017-08-30 02:14:24,458 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(org.ovirt.thread.pool-8-thread-43) FINISH, HSMClearTaskVDSCommand, log id:
5ee245c
2017-08-30 02:14:24,459 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(org.ovirt.thread.pool-8-thread-43) FINISH, SPMClearTaskVDSCommand, log id:
483bc9a3
2017-08-30 02:14:24,471 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(org.ovirt.thread.pool-8-thread-43) BaseAsyncTask::removeTaskFromDB:
Removed task f7762dfe-a9f6-4a09-aea3-7f42ddfcfa6d from DataBase
2017-08-30 02:14:24,472 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(org.ovirt.thread.pool-8-thread-43) CommandAsyncTask::HandleEndActionResult
[within thread]: Removing CommandMultiAsyncTasks object for entity
14530608-260e-4988-8fb4-1fab452ae215
--
Devin Acosta
Red Hat Certified Architect, LinuxStack