From issues-return-92888-archive-asf-public=cust-asf.ponee.io@cloudstack.apache.org Wed Jun 20 10:00:15 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id 9D022180648 for ; Wed, 20 Jun 2018 10:00:13 +0200 (CEST) Received: (qmail 93851 invoked by uid 500); 20 Jun 2018 08:00:12 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 93842 invoked by uid 500); 20 Jun 2018 08:00:12 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 93839 invoked by uid 99); 20 Jun 2018 08:00:12 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 20 Jun 2018 08:00:12 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id D9310C7593 for ; Wed, 20 Jun 2018 08:00:11 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -109.501 X-Spam-Level: X-Spam-Status: No, score=-109.501 tagged_above=-999 required=6.31 tests=[ENV_AND_HDR_SPF_MATCH=-0.5, KAM_ASCII_DIVIDERS=0.8, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, USER_IN_DEF_SPF_WL=-7.5, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id AZ2B6sm8aVkJ for ; Wed, 20 Jun 2018 08:00:08 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id 700775F4A0 for ; Wed, 20 Jun 2018 08:00:08 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id E43CCE03A4 for ; Wed, 20 Jun 2018 08:00:07 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 8BF262183F for ; Wed, 20 Jun 2018 08:00:07 +0000 (UTC) Date: Wed, 20 Jun 2018 08:00:07 +0000 (UTC) From: "Pawel (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (CLOUDSTACK-10385) migrateVirtualMachineWithVolume - Can not see storage pool on host MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 Pawel created CLOUDSTACK-10385: ---------------------------------- Summary: migrateVirtualMachineWithVolume - Can not see storage= pool on host Key: CLOUDSTACK-10385 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1038= 5 Project: CloudStack Issue Type: Bug Security Level: Public (Anyone can view this level - this is the defa= ult.) 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 Secon= dary storage. Reporter: Pawel Can not live migrate vm between clusters. No problem on offline migration. =C2=A0 Environment: cloudstack 4.11.0.0=C2=A0 on Centos 7 / 2 Clusters with 1 HBA = LUN as primary storage / 2x XenServer 7.0 all updates /=C2=A0 1xNFS as Seco= ndary storage. =C2=A0 Management log: ________________________________________________________________________ {quote}2018-06-20 09:47:01,996 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ct= x-348d72b3) (logid:0edb9558) =3D=3D=3DSTART=3D=3D=3D 172.16.5.138 -- GET co= mmand=3DmigrateVirtualMachineWithVolume&hostid=3Df05b52a1-8624-4b9c-a3fd-61= 0e62ebe91d&virtualmachineid=3Dd31eb0b0-9948-4c98-9264-bfa7e87d18e2&response= =3Djson&_=3D1529480800763 2018-06-20 09:47:02,003 DEBUG [c.c.a.ApiServer] (qtp510113906-17:ctx-348d72= b3 ctx-e323bae9) (logid:0edb9558) CIDRs from which account 'Acct[a573e024-6= a61-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-Executo= r-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] (qtp5101139= 06-17:ctx-348d72b3 ctx-e323bae9) (logid:0edb9558) submit async job-56, deta= ils: AsyncJobVO \{id:56, userId: 2, accountId: 2, instanceType: None, insta= nceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVirtual= MachineWithVolumeCmd, cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264= -bfa7e87d18e2","response":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b= 9c-a3fd-610e62ebe91d","httpmethod":"GET","ctxStartEventId":"121","ctxDetail= s":"{\"interface com.cloud.vm.VirtualMachine\":\"d31eb0b0-9948-4c98-9264-bf= a7e87d18e2\",\"interface com.cloud.host.Host\":\"f05b52a1-8624-4b9c-a3fd-61= 0e62ebe91d\"}","ctxAccountId":"2","cmdEventType":"VM.MIGRATE","_":"15294808= 00763"}, 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-Ex= ecutor-37:ctx-82373f7a job-56) (logid:323a3c37) Executing AsyncJobVO \{id:5= 6, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.= apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd, = cmdInfo: {"virtualmachineid":"d31eb0b0-9948-4c98-9264-bfa7e87d18e2","respon= se":"json","ctxUserId":"2","hostid":"f05b52a1-8624-4b9c-a3fd-610e62ebe91d",= "httpmethod":"GET","ctxStartEventId":"121","ctxDetails":"{\"interface com.c= loud.vm.VirtualMachine\":\"d31eb0b0-9948-4c98-9264-bfa7e87d18e2\",\"interfa= ce com.cloud.host.Host\":\"f05b52a1-8624-4b9c-a3fd-610e62ebe91d\"}","ctxAcc= ountId":"2","cmdEventType":"VM.MIGRATE","_":"1529480800763"}, cmdVersion: 0= , status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initM= sid: 226690535214883, completeMsid: null, lastUpdated: null, lastPolled: nu= ll, created: null} 2018-06-20 09:47:02,035 DEBUG [c.c.a.ApiServlet] (qtp510113906-17:ctx-348d7= 2b3 ctx-e323bae9) (logid:0edb9558) =3D=3D=3DEND=3D=3D=3D 172.16.5.138 -- GE= T command=3DmigrateVirtualMachineWithVolume&hostid=3Df05b52a1-8624-4b9c-a3f= d-610e62ebe91d&virtualmachineid=3Dd31eb0b0-9948-4c98-9264-bfa7e87d18e2&resp= onse=3Djson&_=3D1529480800763 2018-06-20 09:47:02,124 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Ex= ecutor-37:ctx-82373f7a job-56 ctx-59fa1bf9) (logid:323a3c37) Sync job-57 ex= ecution on object VmWorkJobQueue.3 2018-06-20 09:47:02,562 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Hand= ler-9:null) (logid:) SeqA 2-7588: Processing Seq 2-7588: \{ Cmd , MgmtId: -= 1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadRepor= tCommand":{"_proxyVmId":1,"_loadInfo":"{\n \"connections\": []\n}","wait":0= }}] } 2018-06-20 09:47:02,567 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Hand= ler-9:null) (logid:) SeqA 2-7588: Sending Seq 2-7588: \{ Ans: , MgmtId: 226= 690535214883, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentC= ontrolAnswer":{"result":true,"wait":0}}] } 2018-06-20 09:47:02,757 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMg= r-Heartbeat-1:ctx-125acb18) (logid:f6b1f25c) Execute sync-queue item: SyncQ= ueueItemVO \{id:16, queueId: 3, contentType: AsyncJob, contentId: 57, lastP= rocessMsid: 226690535214883, lastprocessNumber: 10, lastProcessTime: Wed Ju= n 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] (AsyncJobMg= r-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-Execut= or-16:ctx-6a234c30 job-56/job-57) (logid:9efb6d13) Add job-57 into job moni= toring 2018-06-20 09:47:02,790 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-E= xecutor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Executing AsyncJobV= O \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null, c= md: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xvdWQ= udm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3= JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52b= S5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVy= TmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZVml= ydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2= hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAAAQA= AAAAHg, 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-Executo= r-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Run VM work job: com.clou= d.vm.VmWorkMigrateWithStorage for VM 3, job origin: 56 2018-06-20 09:47:02,795 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Execu= tor-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":"Virt= ualMachineManagerImpl"} 2018-06-20 09:47:02,812 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-J= ob-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Lo= calStoragePoolAllocator 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:323a3= c37) 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:323a3= c37) Looking for pools in dc: 1 pod:1 cluster:2. Disabled pools will be ign= ored. 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:323a3= c37) Found pools matching tags: [Pool[2|PreSetup]] 2018-06-20 09:47:02,819 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Wor= k-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 n= ull (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.81= 47190936227435E-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 p= ool 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 t= he 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 pr= ovisioned 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 capacit= y 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=3D3|ROOT]], maxSize : 4398021345280, to= talAllocatedSize : 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:323a3= c37) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools 2018-06-20 09:47:02,840 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Wor= k-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-1= 6:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Service Securit= yGroup is not supported in the network id=3D204 2018-06-20 09:47:02,861 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Exec= utor-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-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state tra= nsitted from :Running to Migrating with event: MigrationRequestedvm's origi= nal 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-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actu= al total CPU: 36176 and CPU after applying overprovisioning: 36176 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) We are alloc= ating VM, increasing the used capacity of this host:4 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-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-Executo= r-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-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) CPU STATS af= ter allocation: for host: 4, old used: 0, old reserved: 0, actual total: 36= 176, total with overprovisioning: 36176; new used:1000, reserved:0; request= ed cpu:1000,alloc_from_last:false 2018-06-20 09:47:02,942 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) RAM STATS af= ter allocation: for host: 4, old used: 0, old reserved: 0, total: 466652938= 24; 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-6= a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165= 816: 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,"enableDynamicall= yScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":{"hyperviso= rtoolsversion":"xenserver56","platform":"apic:true;viridian:true;pae:true;a= cpi:1;nx:true","Message.ReservedCapacityFreed.Flag":"false"},"uuid":"d31eb0= b0-9948-4c98-9264-bfa7e87d18e2","disks":[\{"data":{"org.apache.cloudstack.s= torage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3","v= olumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDat= aStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup","= host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"PreSet= up://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=3DPrimary&STOREUUID=3DDELL01-= TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":21474836480,"= path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-3-V= M","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.apa= che.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","account= Id":0,"hvm":false,"bootable":false}},"diskSeq":3,"type":"ISO"}],"nics":[\{"= deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nic= Uuid":"15c76db8-9bc1-44bb-9f13-d0e221ad9fa6","details":{"PromiscuousMode":"= false","MacAddressChanges":"true","ForgedTransmits":"true"},"uuid":"b43587f= 6-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","broadcastTy= pe":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"vlan= ://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimit":= 16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dynamic= Max":"17179869184"}},"volumeToStorageUuid":[\{"t":{"id":3,"name":"ROOT-3","= path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","size":21474836480,"type":"ROO= T","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-6= a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165= 816: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ve= r: v1, Flags: 100111, [{"com.cloud.agent.api.MigrateWithStorageReceiveComma= nd":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cp= us":1,"minSpeed":1000,"maxSpeed":1000,"minRam":1073741824,"maxRam":10737418= 24,"arch":"x86_64","os":"CentOS 5.6 (64-bit)","platformEmulator":"CentOS 5 = (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamic= allyScaleVm":false,"vncPassword":"JVNf6tig6ZGWrOK9F6JeQg","params":{"hyperv= isortoolsversion":"xenserver56","platform":"apic:true;viridian:true;pae:tru= e;acpi:1;nx:true","Message.ReservedCapacityFreed.Flag":"false"},"uuid":"d31= eb0b0-9948-4c98-9264-bfa7e87d18e2","disks":[\{"data":{"org.apache.cloudstac= k.storage.to.VolumeObjectTO":{"uuid":"1c45e783-6d0b-4657-98ce-d5dc1c8de8c3"= ,"volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.Primary= DataStoreTO":{"uuid":"DELL01-TESTY01-C01-LUN01","id":1,"poolType":"PreSetup= ","host":"localhost","path":"/DELL01-TESTY01-C01-LUN01","port":0,"url":"Pre= Setup://localhost/DELL01-TESTY01-C01-LUN01/?ROLE=3DPrimary&STOREUUID=3DDELL= 01-TESTY01-C01-LUN01","isManaged":false}},"name":"ROOT-3","size":2147483648= 0,"path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","volumeId":3,"vmName":"i-2-= 3-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":3,"device= Id":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate"= :0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"0e7ae90d-f28d-4e9d-b9= 3f-08ac12bc5b0f","type":"ROOT","_details":\{"storageHost":"localhost","mana= ged":"false","storagePort":"0","volumeSize":"21474836480"}},\{"data":{"org.= apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","acco= untId":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":"b435= 87f6-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","broadcas= tType":"Vlan","type":"Guest","broadcastUri":"vlan://1454","isolationUri":"v= lan://1454","isSecurityGroupEnabled":false,"name":"networks"}],"vcpuMaxLimi= t":16,"guestOsDetails":\{"xenserver.dynamicMin":"536870912","xenserver.dyna= micMax":"17179869184"}},"volumeToStorageUuid":[\{"t":{"id":3,"name":"ROOT-3= ","path":"0e7ae90d-f28d-4e9d-b93f-08ac12bc5b0f","size":21474836480,"type":"= ROOT","storagePoolType":"PreSetup","storagePoolUuid":"DELL01-TESTY01-C01-LU= N01","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 reques= t 2018-06-20 09:47:03,044 ERROR [c.c.h.x.r.w.x.XenServer610MigrateWithStorage= ReceiveCommandWrapper] (DirectAgent-125:ctx-18c5b853) (logid:323a3c37) Migr= ation of vm i-2-3-VM with storage failed due to com.cloud.utils.exception.C= loudRuntimeException: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 f= rom 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.getStorageRe= pository(CitrixResourceBase.java:3240) at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610Migr= ateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageR= eceiveCommandWrapper.java:73) at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610Migr= ateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageR= eceiveCommandWrapper.java:48) at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWr= apper.execute(CitrixRequestWrapper.java:122) at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeReque= st(CitrixResourceBase.java:1728) at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgen= tAttache.java:315) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana= gedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call= (DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi= thContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit= hContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage= dContextRunnable.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.ac= cess$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru= n(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.ja= va:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j= ava: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 Receive= d: 2018-06-20 09:47:03,045 DEBUG [c.c.a.t.Request] (DirectAgent-125:ctx-18c5b8= 53) (logid:323a3c37) Seq 4-9149062643003165816: Processing: \{ Ans: , MgmtI= d: 226690535214883, via: 4(cloud-host027), Ver: v1, Flags: 110, [{"com.clou= d.agent.api.MigrateWithStorageReceiveAnswer":{"result":false,"details":"Exc= eption: com.cloud.utils.exception.CloudRuntimeException\nMessage: Can not s= ee 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-5= 36a-4241-88a5-d466c8f354fc\n\tat com.cloud.hypervisor.xenserver.resource.Ci= trixResourceBase.getStorageRepository(CitrixResourceBase.java:3240)\n\tat c= om.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610MigrateWi= thStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageReceiv= eCommandWrapper.java:73)\n\tat com.cloud.hypervisor.xenserver.resource.wrap= per.xen610.XenServer610MigrateWithStorageReceiveCommandWrapper.execute(XenS= erver610MigrateWithStorageReceiveCommandWrapper.java:48)\n\tat com.cloud.hy= pervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(Ci= trixRequestWrapper.java:122)\n\tat com.cloud.hypervisor.xenserver.resource.= CitrixResourceBase.executeRequest(CitrixResourceBase.java:1728)\n\tat com.c= loud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.= java:315)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnabl= e$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.callW= ithContext(DefaultManagedContext.java:103)\n\tat org.apache.cloudstack.mana= ged.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext= .java:53)\n\tat org.apache.cloudstack.managed.context.ManagedContextRunnabl= e.run(ManagedContextRunnable.java:46)\n\tat java.util.concurrent.Executors$= RunnableAdapter.call(Executors.java:511)\n\tat java.util.concurrent.FutureT= ask.run(FutureTask.java:266)\n\tat java.util.concurrent.ScheduledThreadPool= Executor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:18= 0)\n\tat java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTa= sk.run(ScheduledThreadPoolExecutor.java:293)\n\tat java.util.concurrent.Thr= eadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.con= current.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat ja= va.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-1= 8c5b853) (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-6= a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165= 816: Received: \{ Ans: , MgmtId: 226690535214883, via: 4(cloud-host027), Ve= r: v1, Flags: 110, { MigrateWithStorageReceiveAnswer } } 2018-06-20 09:47:03,045 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (W= ork-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c3= 7) Migration with storage of vm VM[User|i-2-3-VM] failed. Details: Exceptio= n: com.cloud.utils.exception.CloudRuntimeException Message: Can not see storage pool: /DELL01-TESTY01-C02-LUN01 from on host:1= 4c1f677-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-d466c= 8f354fc at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.getStorageRe= pository(CitrixResourceBase.java:3240) at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610Migr= ateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageR= eceiveCommandWrapper.java:73) at com.cloud.hypervisor.xenserver.resource.wrapper.xen610.XenServer610Migr= ateWithStorageReceiveCommandWrapper.execute(XenServer610MigrateWithStorageR= eceiveCommandWrapper.java:48) at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWr= apper.execute(CitrixRequestWrapper.java:122) at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeReque= st(CitrixResourceBase.java:1728) at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgen= tAttache.java:315) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana= gedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call= (DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi= thContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit= hContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage= dContextRunnable.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.ac= cess$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.ru= n(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.ja= va:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j= ava:624) at java.lang.Thread.run(Thread.java:748) 2018-06-20 09:47:03,046 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy] (W= ork-Job-Executor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c3= 7) 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.mig= rateVmWithVolumesAcrossCluster(XenServerStorageMotionStrategy.java:346) at org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.cop= yAsync(XenServerStorageMotionStrategy.java:122) at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(Da= taMotionServiceImpl.java:90) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(V= olumeServiceImpl.java:1646) at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVo= lumes(VolumeOrchestrator.java:1054) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:2553) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:4987) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.ja= va:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccesso= rImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProx= y.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineMa= nagerImpl.java:5090) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInCo= ntext(AsyncJobManagerImpl.java:581) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana= gedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call= (DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi= thContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit= hContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage= dContextRunnable.java:46) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(Asy= ncJobManagerImpl.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.ja= va:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j= ava: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.Pr= imaryDataStoreImpl@7e53770d), no need to delete from object in store ref ta= ble 2018-06-20 09:47:03,074 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Exec= utor-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.exce= ption.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-Ex= ecutor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Migrati= on 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-6a234= c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) AlertType:: 17 | dataCente= rId:: 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-1= 6:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Have already se= nt: 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-91490626430= 03165817: Routed from 226690535214883 2018-06-20 09:47:03,090 DEBUG [c.c.a.t.Request] (Work-Job-Executor-16:ctx-6= a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165= 817: Sending \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ver: = v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"ch= eckBeforeCleanup":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-6= a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Seq 4-9149062643003165= 817: Executing: \{ Cmd , MgmtId: 226690535214883, via: 4(cloud-host027), Ve= r: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,= "checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmNa= me":"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 reques= t 2018-06-20 09:47:03,097 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-126= :ctx-e0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Response Receive= d: 2018-06-20 09:47:03,098 DEBUG [c.c.a.t.Request] (DirectAgent-126:ctx-e0734e= bb) (logid:323a3c37) Seq 4-9149062643003165817: Processing: \{ Ans: , MgmtI= d: 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-e= 0734ebb) (logid:323a3c37) Seq 4-9149062643003165817: Unable to find listene= r. 2018-06-20 09:47:03,118 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) VM state tra= nsitted 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-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actu= al total CPU: 36176 and CPU after applying overprovisioning: 36176 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Hosts's actu= al total RAM: 46665294976 and RAM after applying overprovisioning: 46665293= 824 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-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 o= verprovisioning: 36176; new used: 0,reserved:0; movedfromreserved: false,mo= veToReserveredfalse 2018-06-20 09:47:03,127 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executo= r-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) release mem = from host: 4, old used: 1073741824,reserved: 0, total: 46665293824; new use= d: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse 2018-06-20 09:47:03,153 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Execu= tor-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Invocation= exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Fai= led 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-Execut= or-16:ctx-6a234c30 job-56/job-57 ctx-1be10f50) (logid:323a3c37) Rethrow exc= eption 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-Executo= r-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-Executo= r-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Unable to complete AsyncJ= obVO \{id:57, userId: 2, accountId: 2, instanceType: null, instanceId: null= , cmd: com.cloud.vm.VmWorkMigrateWithStorage, cmdInfo: rO0ABXNyACVjb20uY2xv= dWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgA= Jc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC= 52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kb= GVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAADdAAZ= VmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkh= hc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAAdwgAAA= AQAAAAAHg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode= : 0, result: null, initMsid: 226690535214883, completeMsid: null, lastUpdat= ed: null, lastPolled: null, created: Wed Jun 20 09:47:02 CEST 2018}, job or= igin:56 com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[U= ser|i-2-3-VM] along with its volumes. at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVo= lumes(VolumeOrchestrator.java:1059) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:2553) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:4987) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.ja= va:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccesso= rImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProx= y.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineMa= nagerImpl.java:5090) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInCo= ntext(AsyncJobManagerImpl.java:581) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana= gedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call= (DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi= thContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit= hContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage= dContextRunnable.java:46) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(Asy= ncJobManagerImpl.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.ja= va:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j= ava: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-E= xecutor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Complete async job-= 57, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpb= HMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNv= ZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmc= uRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETA= AFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvb= GFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50= O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWl= sZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItMy1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW= 1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc= 3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwA= DmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHA= AAAQjdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU= 9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzc= QB-AAwAAAn5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0= dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmF= nZXNxAH4ADAAAE3txAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aX= ZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpb= nZva2Uwc3EAfgAMAAAAPnEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxl= Y3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3N= vckltcGwuamF2YXEAfgAbc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC0= 1ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZ= XJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EA= fgAMAAAT4nEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9= iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAk= V0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hb= mFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-= AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29= udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AA= wAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1b= HRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EA= fgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZ= hdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOH= EAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrL= m1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAA= AhFxAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V= 0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEKdAAfam= F2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAf= gAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVh= ZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25= jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC7HQAEG= phdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0a= W9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGls= LkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF= 2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQ= AEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-E= xecutor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Publish async job-5= 7 complete on message bus 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-E= xecutor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Wake up jobs relate= d to job-57 2018-06-20 09:47:03,169 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-E= xecutor-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Update db status fo= r job-57 2018-06-20 09:47:03,172 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-E= xecutor-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-E= xecutor-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-Execut= or-16:ctx-6a234c30 job-56/job-57) (logid:323a3c37) Remove job-57 from job m= onitoring 2018-06-20 09:47:03,404 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Execut= or-37:ctx-82373f7a job-56) (logid:323a3c37) Unexpected exception while exec= uting org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithV= olumeCmd com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm VM[U= ser|i-2-3-VM] along with its volumes. at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVo= lumes(VolumeOrchestrator.java:1059) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:2553) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(Vi= rtualMachineManagerImpl.java:4987) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.ja= va:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccesso= rImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProx= y.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineMa= nagerImpl.java:5090) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInCo= ntext(AsyncJobManagerImpl.java:581) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana= gedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call= (DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi= thContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit= hContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage= dContextRunnable.java:46) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(Asy= ncJobManagerImpl.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.ja= va:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j= ava: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-Ex= ecutor-37:ctx-82373f7a job-56) (logid:323a3c37) Complete async job-56, jobS= tatus: 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)