Re: [ovirt-users] oVirt 3.5.6 / VM Import Fails

On 30 Aug 2017, at 04:19, Devin Acosta <devin(a)pabstatencio.com&gt; wrote: 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 _______________________________________________ Users mailing list Users(a)ovirt.org http://lists.ovirt.org/mailman/listinfo/users