[ 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)