cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Pawel (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-10385) migrateVirtualMachineWithVolume - Can not see storage pool on host
Date Wed, 20 Jun 2018 08:03:00 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-10385?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Pawel updated CLOUDSTACK-10385:
-------------------------------
    Description: 
Can not live migrate vm between clusters.

No problem on offline migration.

 

Environment: cloudstack 4.11.0.0  on Centos 7 / 2 Clusters with 1 HBA LUN as primary storage / 2x XenServer 7.0 all updates /  1xNFS as Secondary storage.

 

Management log:

________________________________________________________________________
{quote}2018-06-20 09:47:01,996 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3) (logid:0edb9558) ===START=== 172.16.5.138 – GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
 2018-06-20 09:47:02,003 DEBUG [c.c.a.ApiServer] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) CIDRs from which account 'Acct[a573e024-6a61-11e8-a8cd-ce2c80d34f23-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
 2018-06-20 09:47:02,027 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:6a548f01) Add job-56 into job monitoring
 2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) submit async job-56, details: AsyncJobVO {id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"
Unknown macro: \{"interface com.cloud.vm.VirtualMachine"}
","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
 2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Executing AsyncJobVO {id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"
Unknown macro: \{"interface com.cloud.vm.VirtualMachine"}
","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
 2018-06-20 09:47:02,035 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) ===END=== 172.16.5.138 – GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
 2018-06-20 09:47:02,124 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56 ctx-59fa1bf9) (logid:323a3c37) Sync job-57 execution on object VmWorkJobQueue.3
 2018-06-20 09:47:02,562 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Processing Seq 2-7588: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"
Unknown macro: \{n "connections"}
","wait":0}}] }
 2018-06-20 09:47:02,567 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Sending Seq 2-7588: { Ans: , MgmtId: 226690535214883, via: 2, Ver: v1, Flags: 100010, [\{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
 2018-06-20 09:47:02,757 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Execute sync-queue item: SyncQueueItemVO \{id:16, queueId: 3, contentType: AsyncJob, contentId: 57, lastProcessMsid: 226690535214883, lastprocessNumber: 10, lastProcessTime: Wed Jun 20 09:47:02 CEST 2018, created: Wed Jun 20 09:47:02 CEST 2018}
 2018-06-20 09:47:02,760 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Schedule queued job-57
 2018-06-20 09:47:02,782 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:9efb6d13) Add job-57 into job monitoring
 2018-06-20 09:47:02,790 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Executing AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}
 2018-06-20 09:47:02,791 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Run VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
 2018-06-20 09:47:02,795 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Execute VM work job: com.cloud.vm.VmWorkMigrateWithStorage\{"srcHostId":1,"destHostId":4,"volumeToPool":{},"userId":2,"accountId":2,"vmId":3,"handlerName":"VirtualMachineManagerImpl"}
 2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) LocalStoragePoolAllocator trying to find storage pool to fit the vm
 2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator looking for storage pool
 2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Looking for pools in dc: 1 pod:1 cluster:2. Disabled pools will be ignored.
 2018-06-20 09:47:02,814 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found pools matching tags: [Pool[2|PreSetup]]
 2018-06-20 09:47:02,819 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking if storage pool is suitable, name: null ,poolId: 2
 2018-06-20 09:47:02,823 INFO [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Storage pool null (2) does not supply IOPS capacity, assuming enough capacity
 2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool 2 for storage, totalSize: 2199010672640, usedBytes: 8388608, usedPct: 3.8147190936227435E-6, disable threshold: 0.85
 2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Destination pool id: 2
 2018-06-20 09:47:02,835 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) pool id for the volume with id: 3 is 1
 2018-06-20 09:47:02,836 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found storage pool TESTY01-C02-LUN01 of type PreSetup with overprovisioning factor 2
 2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total over provisioned capacity calculated is 2 * 2199010672640
 2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total capacity of the pool TESTY01-C02-LUN01 id: 2 is 4398021345280
 2018-06-20 09:47:02,838 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool: 2 for volume allocation [Vol[3|vm=3|ROOT]], maxSize : 4398021345280, totalAllocatedSize : 21474836480, askingSize : 0, allocated disable threshold: 0.85
 2018-06-20 09:47:02,839 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
 2018-06-20 09:47:02,840 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ZoneWideStoragePoolAllocator to find storage pool
 2018-06-20 09:47:02,854 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Service SecurityGroup is not supported in the network id=204
 2018-06-20 09:47:02,861 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Preparing 1 volumes for VM[User|i-2-3-VM]
 2018-06-20 09:47:02,931 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Running to Migrating with event: MigrationRequestedvm's original host id: 1 new host id: 4 host id before state transition: 1
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) We are allocating VM, increasing the used capacity of this host:4
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used CPU: 0 , Free CPU:36176 ,Requested CPU: 1000
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used RAM: 0 , Free RAM:46665293824 ,Requested RAM: 1073741824
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) CPU STATS after allocation: for host: 4, old used: 0, old reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used:1000, reserved:0; requested cpu:1000,alloc_from_last:false
 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) RAM STATS after allocation: for host: 4, old used: 0, old reserved: 0, total: 46665293824; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
 2018-06-20 09:47:03,023 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Sending { Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":
Unknown macro: \{"hypervisortoolsversion"}
,"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":
Unknown macro: \{"PromiscuousMode"}
,"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[{"t":
Unknown macro: \{"id"}
,"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
 2018-06-20 09:47:03,024 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Executing: { Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":
Unknown macro: \{"hypervisortoolsversion"}
,"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":
Unknown macro: \{"PromiscuousMode"}
,"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[{"t":
Unknown macro: \{"id"}
,"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
 2018-06-20 09:47:03,026 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:098e161a) Seq 4-9149062643003165816: Executing request
 *2018-06-20 09:47:03,044 ERROR [c.c.h.x.r.w.x.XenServer610MigrateWithStorageReceiveCommandWrapper] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Migration of vm i-2-3-VM with storage failed due to com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc*
 *com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc*
 *at* com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
 at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
 2018-06-20 09:47:03,045 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Response Received:
 2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Processing: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110, [\{"com.cloud.agent.api.MigrateWithStorageReceiveAnswer":{"result":false,"details":"Exception: com.cloud.utils.exception.CloudRuntimeException\nMessage: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\nStack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)\n\tat com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)\n\tat java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n","wait":0}}] }
 2018-06-20 09:47:03,045 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: No more commands found
 2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Received: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110,
Unknown macro: \{ MigrateWithStorageReceiveAnswer }
}
 2018-06-20 09:47:03,045 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration with storage of vm VM[User|i-2-3-VM] failed. Details: Exception: com.cloud.utils.exception.CloudRuntimeException
 Message: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
 Stack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
 at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)

2018-06-20 09:47:03,046 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) copy failed
 com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
 at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.migrateVmWithVolumesAcrossCluster(XenServerStorageMotionStrategy.java:346)
 at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.copyAsync(XenServerStorageMotionStrategy.java:122)
 at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:90)
 at org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(VolumeServiceImpl.java:1646)
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1054)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
 2018-06-20 09:47:03,073 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@7e53770d), no need to delete from object in store ref table
 2018-06-20 09:47:03,074 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
 2018-06-20 09:47:03,074 INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration was unsuccessful. Cleaning up: VM[User|i-2-3-VM]
 2018-06-20 09:47:03,076 WARN [o.a.c.alerts] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) AlertType:: 17 | dataCenterId:: 1 | podId:: 1 | clusterId:: null | message:: Unable to migrate vm i-2-3-VM from host cloud-host026 in zone DC1 and pod DC1
 2018-06-20 09:47:03,079 DEBUG [c.c.a.AlertManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Have already sent: 1 emails for alert type '17' – skipping send email
 2018-06-20 09:47:03,090 DEBUG [c.c.a.m.AgentAttache] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Routed from 226690535214883
 2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Sending \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
 2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
 2018-06-20 09:47:03,090 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:4160eebe) Seq 4-9149062643003165817: Executing request
 2018-06-20 09:47:03,097 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Response Received:
 2018-06-20 09:47:03,098 DEBUG [c.c.a.t.Request] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Processing: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 10, [\{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
 2018-06-20 09:47:03,098 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Unable to find listener.
 2018-06-20 09:47:03,118 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Migrating to Running with event: OperationFailedvm's original host id: 1 new host id: 1 host id before state transition: 4
 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total RAM: 46665294976 and RAM after applying overprovisioning: 46665293824
 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release cpu from host: 4, old used: 1000,reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release mem from host: 4, old used: 1073741824,reserved: 0, total: 46665293824; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
 2018-06-20 09:47:03,153 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 2018-06-20 09:47:03,153 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 2018-06-20 09:47:03,154 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done with run of VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
 2018-06-20 09:47:03,154 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Unable to complete AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}, job origin:56
 com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
 2018-06-20 09:47:03,161 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Complete async job-57, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWlsZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItMy1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAQjdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzcQB-AAwAAAn5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmFnZXNxAH4ADAAAE3txAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAMAAAAPnEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAbc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAT4nEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAkV0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAwAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOHEAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAAAhFxAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAfgAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg
 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Publish async job-57 complete on message bus
 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs related to job-57
 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Update db status for job-57
 2018-06-20 09:47:03,172 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs joined with job-57 and disjoin all subjobs created from job- 57
 2018-06-20 09:47:03,269 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done executing com.cloud.vm.VmWorkMigrateWithStorage for job-57
 2018-06-20 09:47:03,271 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Remove job-57 from job monitoring
 2018-06-20 09:47:03,404 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
 com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
 2018-06-20 09:47:03,405 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Complete async job-56, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. "}
{quote}

  was:
Can not live migrate vm between clusters.

No problem on offline migration.

 

Environment: cloudstack 4.11.0.0  on Centos 7 / 2 Clusters with 1 HBA LUN as primary storage / 2x XenServer 7.0 all updates /  1xNFS as Secondary storage.

 

Management log:

________________________________________________________________________
{quote}2018-06-20 09:47:01,996 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3) (logid:0edb9558) ===START=== 172.16.5.138 -- GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
2018-06-20 09:47:02,003 DEBUG [c.c.a.ApiServer] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) CIDRs from which account 'Acct[a573e024-6a61-11e8-a8cd-ce2c80d34f23-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
2018-06-20 09:47:02,027 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:6a548f01) Add job-56 into job monitoring
2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) submit async job-56, details: AsyncJobVO \{id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"d31eb0b0-9948-4c98-9264-bfa7e87d18e2\",\"interface com.cloud.host.Host\":\"f05b52a1-8624-4b9c-a3fd-610e62ebe91d\"}","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Executing AsyncJobVO \{id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"d31eb0b0-9948-4c98-9264-bfa7e87d18e2\",\"interface com.cloud.host.Host\":\"f05b52a1-8624-4b9c-a3fd-610e62ebe91d\"}","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2018-06-20 09:47:02,035 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) ===END=== 172.16.5.138 -- GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
2018-06-20 09:47:02,124 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56 ctx-59fa1bf9) (logid:323a3c37) Sync job-57 execution on object VmWorkJobQueue.3
2018-06-20 09:47:02,562 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Processing Seq 2-7588: \{ Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2018-06-20 09:47:02,567 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Sending Seq 2-7588: \{ Ans: , MgmtId: 226690535214883, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2018-06-20 09:47:02,757 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Execute sync-queue item: SyncQueueItemVO \{id:16, queueId: 3, contentType: AsyncJob, contentId: 57, lastProcessMsid: 226690535214883, lastprocessNumber: 10, lastProcessTime: Wed Jun 20 09:47:02 CEST 2018, created: Wed Jun 20 09:47:02 CEST 2018}
2018-06-20 09:47:02,760 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Schedule queued job-57
2018-06-20 09:47:02,782 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:9efb6d13) Add job-57 into job monitoring
2018-06-20 09:47:02,790 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Executing AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}
2018-06-20 09:47:02,791 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Run VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
2018-06-20 09:47:02,795 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Execute VM work job: com.cloud.vm.VmWorkMigrateWithStorage\{"srcHostId":1,"destHostId":4,"volumeToPool":{},"userId":2,"accountId":2,"vmId":3,"handlerName":"VirtualMachineManagerImpl"}
2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator looking for storage pool
2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Looking for pools in dc: 1 pod:1 cluster:2. Disabled pools will be ignored.
2018-06-20 09:47:02,814 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found pools matching tags: [Pool[2|PreSetup]]
2018-06-20 09:47:02,819 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking if storage pool is suitable, name: null ,poolId: 2
2018-06-20 09:47:02,823 INFO [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Storage pool null (2) does not supply IOPS capacity, assuming enough capacity
2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool 2 for storage, totalSize: 2199010672640, usedBytes: 8388608, usedPct: 3.8147190936227435E-6, disable threshold: 0.85
2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Destination pool id: 2
2018-06-20 09:47:02,835 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) pool id for the volume with id: 3 is 1
2018-06-20 09:47:02,836 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found storage pool TESTY01-C02-LUN01 of type PreSetup with overprovisioning factor 2
2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total over provisioned capacity calculated is 2 * 2199010672640
2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total capacity of the pool TESTY01-C02-LUN01 id: 2 is 4398021345280
2018-06-20 09:47:02,838 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool: 2 for volume allocation [Vol[3|vm=3|ROOT]], maxSize : 4398021345280, totalAllocatedSize : 21474836480, askingSize : 0, allocated disable threshold: 0.85
2018-06-20 09:47:02,839 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2018-06-20 09:47:02,840 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ZoneWideStoragePoolAllocator to find storage pool
2018-06-20 09:47:02,854 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Service SecurityGroup is not supported in the network id=204
2018-06-20 09:47:02,861 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Preparing 1 volumes for VM[User|i-2-3-VM]
2018-06-20 09:47:02,931 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Running to Migrating with event: MigrationRequestedvm's original host id: 1 new host id: 4 host id before state transition: 1
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) We are allocating VM, increasing the used capacity of this host:4
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used CPU: 0 , Free CPU:36176 ,Requested CPU: 1000
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used RAM: 0 , Free RAM:46665293824 ,Requested RAM: 1073741824
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) CPU STATS after allocation: for host: 4, old used: 0, old reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used:1000, reserved:0; requested cpu:1000,alloc_from_last:false
2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) RAM STATS after allocation: for host: 4, old used: 0, old reserved: 0, total: 46665293824; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2018-06-20 09:47:03,023 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Sending \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":{"hypervisortoolsversion":"xenserver56","platform":"apic:true;viridian:true;pae:true;acpi:1;nx:true","Message.ReservedCapacityFreed.Flag":"false"},"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[\{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":{"PromiscuousMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"},"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[\{"t":{"id":3,"name":"ROOT-3","path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","size":21474836480,"type":"ROOT","storagePoolType":"PreSetup","storagePoolUuid":"DELL01-TESTY01-C01-LUN01","deviceId":0},"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
2018-06-20 09:47:03,024 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":{"hypervisortoolsversion":"xenserver56","platform":"apic:true;viridian:true;pae:true;acpi:1;nx:true","Message.ReservedCapacityFreed.Flag":"false"},"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[\{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":{"PromiscuousMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"},"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[\{"t":{"id":3,"name":"ROOT-3","path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","size":21474836480,"type":"ROOT","storagePoolType":"PreSetup","storagePoolUuid":"DELL01-TESTY01-C01-LUN01","deviceId":0},"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
2018-06-20 09:47:03,026 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:098e161a) Seq 4-9149062643003165816: Executing request
2018-06-20 09:47:03,044 ERROR [c.c.h.x.r.w.x.XenServer610MigrateWithStorageReceiveCommandWrapper] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Migration of vm i-2-3-VM with storage failed due to com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
 at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
2018-06-20 09:47:03,045 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Response Received:
2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Processing: \{ Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110, [{"com.cloud.agent.api.MigrateWithStorageReceiveAnswer":{"result":false,"details":"Exception: com.cloud.utils.exception.CloudRuntimeException\nMessage: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\nStack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)\n\tat com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)\n\tat java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n","wait":0}}] }
2018-06-20 09:47:03,045 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: No more commands found
2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Received: \{ Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110, { MigrateWithStorageReceiveAnswer } }
2018-06-20 09:47:03,045 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration with storage of vm VM[User|i-2-3-VM] failed. Details: Exception: com.cloud.utils.exception.CloudRuntimeException
Message: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
Stack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
 at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
 at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
 at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)

2018-06-20 09:47:03,046 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) copy failed
com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
 at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.migrateVmWithVolumesAcrossCluster(XenServerStorageMotionStrategy.java:346)
 at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.copyAsync(XenServerStorageMotionStrategy.java:122)
 at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:90)
 at org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(VolumeServiceImpl.java:1646)
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1054)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
2018-06-20 09:47:03,073 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@7e53770d), no need to delete from object in store ref table
2018-06-20 09:47:03,074 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
2018-06-20 09:47:03,074 INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration was unsuccessful. Cleaning up: VM[User|i-2-3-VM]
2018-06-20 09:47:03,076 WARN [o.a.c.alerts] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) AlertType:: 17 | dataCenterId:: 1 | podId:: 1 | clusterId:: null | message:: Unable to migrate vm i-2-3-VM from host cloud-host026 in zone DC1 and pod DC1
2018-06-20 09:47:03,079 DEBUG [c.c.a.AlertManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Have already sent: 1 emails for alert type '17' -- skipping send email
2018-06-20 09:47:03,090 DEBUG [c.c.a.m.AgentAttache] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Routed from 226690535214883
2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Sending \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
2018-06-20 09:47:03,090 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:4160eebe) Seq 4-9149062643003165817: Executing request
2018-06-20 09:47:03,097 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Response Received:
2018-06-20 09:47:03,098 DEBUG [c.c.a.t.Request] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Processing: \{ Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2018-06-20 09:47:03,098 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Unable to find listener.
2018-06-20 09:47:03,118 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Migrating to Running with event: OperationFailedvm's original host id: 1 new host id: 1 host id before state transition: 4
2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total RAM: 46665294976 and RAM after applying overprovisioning: 46665293824
2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release cpu from host: 4, old used: 1000,reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release mem from host: 4, old used: 1073741824,reserved: 0, total: 46665293824; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2018-06-20 09:47:03,153 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
2018-06-20 09:47:03,153 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
2018-06-20 09:47:03,154 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done with run of VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
2018-06-20 09:47:03,154 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Unable to complete AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}, job origin:56
com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
2018-06-20 09:47:03,161 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Complete async job-57, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWlsZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItMy1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAQjdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzcQB-AAwAAAn5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmFnZXNxAH4ADAAAE3txAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAMAAAAPnEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAbc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAT4nEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAkV0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAwAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOHEAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAAAhFxAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAfgAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg
2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Publish async job-57 complete on message bus
2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs related to job-57
2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Update db status for job-57
2018-06-20 09:47:03,172 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs joined with job-57 and disjoin all subjobs created from job- 57
2018-06-20 09:47:03,269 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done executing com.cloud.vm.VmWorkMigrateWithStorage for job-57
2018-06-20 09:47:03,271 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Remove job-57 from job monitoring
2018-06-20 09:47:03,404 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
 at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
 at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
 at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
 at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
 at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
 at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
2018-06-20 09:47:03,405 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Complete async job-56, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/\{"uuidList":[],"errorcode":530,"errortext":"Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. "}
{quote}


> migrateVirtualMachineWithVolume - Can not see storage pool on host
> ------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-10385
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-10385
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Volumes, XenServer
>    Affects Versions: 4.11.0.0
>         Environment: cloudstack 4.11.0.0  on Centos 7 / 2 Clusters with 1 HBA LUN as primary storage / 2x XenServer 7.0 all updates /  1xNFS as Secondary storage.
>            Reporter: Pawel
>            Priority: Major
>
> Can not live migrate vm between clusters.
> No problem on offline migration.
>  
> Environment: cloudstack 4.11.0.0  on Centos 7 / 2 Clusters with 1 HBA LUN as primary storage / 2x XenServer 7.0 all updates /  1xNFS as Secondary storage.
>  
> Management log:
> ________________________________________________________________________
> {quote}2018-06-20 09:47:01,996 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3) (logid:0edb9558) ===START=== 172.16.5.138 – GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
>  2018-06-20 09:47:02,003 DEBUG [c.c.a.ApiServer] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) CIDRs from which account 'Acct[a573e024-6a61-11e8-a8cd-ce2c80d34f23-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
>  2018-06-20 09:47:02,027 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:6a548f01) Add job-56 into job monitoring
>  2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) submit async job-56, details: AsyncJobVO {id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"
> Unknown macro: \{"interface com.cloud.vm.VirtualMachine"}
> ","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>  2018-06-20 09:47:02,033 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Executing AsyncJobVO {id:56, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"
> Unknown macro: \{"interface com.cloud.vm.VirtualMachine"}
> ","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>  2018-06-20 09:47:02,035 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) ===END=== 172.16.5.138 – GET command=migrateVirtualMachineWithVolume&hostid=f05b52a1-8624-4b9c-a3fd-610e62ebe91d&virtualmachineid=d31eb0b0-9948-4c98-9264-bfa7e87d18e2&response=json&_=1529480800763
>  2018-06-20 09:47:02,124 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56 ctx-59fa1bf9) (logid:323a3c37) Sync job-57 execution on object VmWorkJobQueue.3
>  2018-06-20 09:47:02,562 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Processing Seq 2-7588: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"
> Unknown macro: \{n "connections"}
> ","wait":0}}] }
>  2018-06-20 09:47:02,567 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid:) SeqA 2-7588: Sending Seq 2-7588: { Ans: , MgmtId: 226690535214883, via: 2, Ver: v1, Flags: 100010, [\{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>  2018-06-20 09:47:02,757 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Execute sync-queue item: SyncQueueItemVO \{id:16, queueId: 3, contentType: AsyncJob, contentId: 57, lastProcessMsid: 226690535214883, lastprocessNumber: 10, lastProcessTime: Wed Jun 20 09:47:02 CEST 2018, created: Wed Jun 20 09:47:02 CEST 2018}
>  2018-06-20 09:47:02,760 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Schedule queued job-57
>  2018-06-20 09:47:02,782 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:9efb6d13) Add job-57 into job monitoring
>  2018-06-20 09:47:02,790 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Executing AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}
>  2018-06-20 09:47:02,791 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Run VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
>  2018-06-20 09:47:02,795 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Execute VM work job: com.cloud.vm.VmWorkMigrateWithStorage\{"srcHostId":1,"destHostId":4,"volumeToPool":{},"userId":2,"accountId":2,"vmId":3,"handlerName":"VirtualMachineManagerImpl"}
>  2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) LocalStoragePoolAllocator trying to find storage pool to fit the vm
>  2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator looking for storage pool
>  2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Looking for pools in dc: 1 pod:1 cluster:2. Disabled pools will be ignored.
>  2018-06-20 09:47:02,814 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found pools matching tags: [Pool[2|PreSetup]]
>  2018-06-20 09:47:02,819 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking if storage pool is suitable, name: null ,poolId: 2
>  2018-06-20 09:47:02,823 INFO [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Storage pool null (2) does not supply IOPS capacity, assuming enough capacity
>  2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool 2 for storage, totalSize: 2199010672640, usedBytes: 8388608, usedPct: 3.8147190936227435E-6, disable threshold: 0.85
>  2018-06-20 09:47:02,826 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Destination pool id: 2
>  2018-06-20 09:47:02,835 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) pool id for the volume with id: 3 is 1
>  2018-06-20 09:47:02,836 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Found storage pool TESTY01-C02-LUN01 of type PreSetup with overprovisioning factor 2
>  2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total over provisioned capacity calculated is 2 * 2199010672640
>  2018-06-20 09:47:02,837 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Total capacity of the pool TESTY01-C02-LUN01 id: 2 is 4398021345280
>  2018-06-20 09:47:02,838 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Checking pool: 2 for volume allocation [Vol[3|vm=3|ROOT]], maxSize : 4398021345280, totalAllocatedSize : 21474836480, askingSize : 0, allocated disable threshold: 0.85
>  2018-06-20 09:47:02,839 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
>  2018-06-20 09:47:02,840 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) ZoneWideStoragePoolAllocator to find storage pool
>  2018-06-20 09:47:02,854 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Service SecurityGroup is not supported in the network id=204
>  2018-06-20 09:47:02,861 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Preparing 1 volumes for VM[User|i-2-3-VM]
>  2018-06-20 09:47:02,931 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Running to Migrating with event: MigrationRequestedvm's original host id: 1 new host id: 4 host id before state transition: 1
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) We are allocating VM, increasing the used capacity of this host:4
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used CPU: 0 , Free CPU:36176 ,Requested CPU: 1000
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Current Used RAM: 0 , Free RAM:46665293824 ,Requested RAM: 1073741824
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) CPU STATS after allocation: for host: 4, old used: 0, old reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used:1000, reserved:0; requested cpu:1000,alloc_from_last:false
>  2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) RAM STATS after allocation: for host: 4, old used: 0, old reserved: 0, total: 46665293824; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
>  2018-06-20 09:47:03,023 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Sending { Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":
> Unknown macro: \{"hypervisortoolsversion"}
> ,"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":
> Unknown macro: \{"PromiscuousMode"}
> ,"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[{"t":
> Unknown macro: \{"id"}
> ,"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
>  2018-06-20 09:47:03,024 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Executing: { Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":
> Unknown macro: \{"hypervisortoolsversion"}
> ,"uuid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\\{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSetup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=Primary&STOREUUID=DELL01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","type":"ROOT","_details":\\{"storageHost":"localhost","managed":"false","storagePort":"0","volumeSize":"21474836480"}},\\{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":
> Unknown macro: \{"PromiscuousMode"}
> ,"uuid":"b43587f6-89e4-4ce3-83fd-ba1e023f03a6","ip":"10.1.1.15","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:18:b3:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamicMax":"17179869184"}},"volumeToStorageUuid":[{"t":
> Unknown macro: \{"id"}
> ,"u":"/DELL01-TESTY01-C02-LUN01"}],"wait":0}}] }
>  2018-06-20 09:47:03,026 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:098e161a) Seq 4-9149062643003165816: Executing request
>  *2018-06-20 09:47:03,044 ERROR [c.c.h.x.r.w.x.XenServer610MigrateWithStorageReceiveCommandWrapper] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Migration of vm i-2-3-VM with storage failed due to com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc*
>  *com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc*
>  *at* com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
>  at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
>  at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>  at java.lang.Thread.run(Thread.java:748)
>  2018-06-20 09:47:03,045 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Response Received:
>  2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: Processing: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110, [\{"com.cloud.agent.api.MigrateWithStorageReceiveAnswer":{"result":false,"details":"Exception: com.cloud.utils.exception.CloudRuntimeException\nMessage: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\nStack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)\n\tat com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)\n\tat com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)\n\tat com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)\n\tat org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)\n\tat java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n","wait":0}}] }
>  2018-06-20 09:47:03,045 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Seq 4-9149062643003165816: No more commands found
>  2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165816: Received: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110,
> Unknown macro: \{ MigrateWithStorageReceiveAnswer }
> }
>  2018-06-20 09:47:03,045 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration with storage of vm VM[User|i-2-3-VM] failed. Details: Exception: com.cloud.utils.exception.CloudRuntimeException
>  Message: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
>  Stack: com.cloud.utils.exception.CloudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:14c1f677-536a-4241-88a5-d466c8f354fc
>  at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:73)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiveCommandWrapper.java:48)
>  at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
>  at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)
>  at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>  at java.lang.Thread.run(Thread.java:748)
> 2018-06-20 09:47:03,046 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) copy failed
>  com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
>  at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.migrateVmWithVolumesAcrossCluster(XenServerStorageMotionStrategy.java:346)
>  at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.copyAsync(XenServerStorageMotionStrategy.java:122)
>  at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:90)
>  at org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(VolumeServiceImpl.java:1646)
>  at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1054)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
>  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>  at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
>  at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
>  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>  at java.lang.Thread.run(Thread.java:748)
>  2018-06-20 09:47:03,073 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@7e53770d), no need to delete from object in store ref table
>  2018-06-20 09:47:03,074 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm VM[User|i-2-3-VM] to host Host[-4-Routing]
>  2018-06-20 09:47:03,074 INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migration was unsuccessful. Cleaning up: VM[User|i-2-3-VM]
>  2018-06-20 09:47:03,076 WARN [o.a.c.alerts] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) AlertType:: 17 | dataCenterId:: 1 | podId:: 1 | clusterId:: null | message:: Unable to migrate vm i-2-3-VM from host cloud-host026 in zone DC1 and pod DC1
>  2018-06-20 09:47:03,079 DEBUG [c.c.a.AlertManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Have already sent: 1 emails for alert type '17' – skipping send email
>  2018-06-20 09:47:03,090 DEBUG [c.c.a.m.AgentAttache] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Routed from 226690535214883
>  2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Sending \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
>  2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165817: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-3-VM","executeInSequence":false,"wait":0}}] }
>  2018-06-20 09:47:03,090 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:4160eebe) Seq 4-9149062643003165817: Executing request
>  2018-06-20 09:47:03,097 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Response Received:
>  2018-06-20 09:47:03,098 DEBUG [c.c.a.t.Request] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Processing: { Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 10, [\{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
>  2018-06-20 09:47:03,098 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-126:ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Unable to find listener.
>  2018-06-20 09:47:03,118 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state transitted from :Migrating to Running with event: OperationFailedvm's original host id: 1 new host id: 1 host id before state transition: 4
>  2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total CPU: 36176 and CPU after applying overprovisioning: 36176
>  2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actual total RAM: 46665294976 and RAM after applying overprovisioning: 46665293824
>  2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release cpu from host: 4, old used: 1000,reserved: 0, actual total: 36176, total with overprovisioning: 36176; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
>  2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release mem from host: 4, old used: 1073741824,reserved: 0, total: 46665293824; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
>  2018-06-20 09:47:03,153 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
>  2018-06-20 09:47:03,153 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
>  2018-06-20 09:47:03,154 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done with run of VM work job: com.cloud.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56
>  2018-06-20 09:47:03,154 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Unable to complete AsyncJobVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}, job origin:56
>  com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
>  at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
>  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>  at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
>  at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
>  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>  at java.lang.Thread.run(Thread.java:748)
>  2018-06-20 09:47:03,161 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Complete async job-57, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWlsZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItMy1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAQjdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzcQB-AAwAAAn5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmFnZXNxAH4ADAAAE3txAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAMAAAAPnEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAbc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAT4nEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAkV0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAwAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOHEAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAAAhFxAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAfgAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg
>  2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Publish async job-57 complete on message bus
>  2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs related to job-57
>  2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Update db status for job-57
>  2018-06-20 09:47:03,172 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs joined with job-57 and disjoin all subjobs created from job- 57
>  2018-06-20 09:47:03,269 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Done executing com.cloud.vm.VmWorkMigrateWithStorage for job-57
>  2018-06-20 09:47:03,271 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Remove job-57 from job monitoring
>  2018-06-20 09:47:03,404 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
>  com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[User|i-2-3-VM] along with its volumes.
>  at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:1059)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2553)
>  at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4987)
>  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>  at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5090)
>  at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>  at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>  at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>  at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
>  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>  at java.lang.Thread.run(Thread.java:748)
>  2018-06-20 09:47:03,405 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-37:ctx-82373f7a job-56) (logid:323a3c37) Complete async job-56, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to migrated vm VM[User|i-2-3-VM] along with its volumes. "}
> {quote}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Mime
View raw message