Dear Vadim, can you test this issue with Xenserver pool, with at least 2 servers in it? It seems like a Xenserver pool/Cloudstack issue. Probably a bug.
Ar cieņu, Aldis Gerhards valdes loceklis GSM: (+371) 27 812 777 Fakss: (+371) 67 387 397 E-pasts: [email protected] <mailto:[email protected]> Web: http://www.hostnet.lv <http://www.hostnet.lv/> Twitter: http://www.twitter.com/hostnetlv <http://www.twitter.com/hostnetlv> Hostnet Virtuālie serveri (VPS) - Izmēģini VPS par brīvu veselu nedēļu! Pakalpojums tiek nodrošināts tikai ar jaudīgiem oriģināliem DELL serveriem > On 22 Oct 2014, at 15:37, Vadim Kimlaychuk <[email protected]> wrote: > > Mārtiņš, > > I have tried to repeat your sequence of events (created template, > created VM from template, deleted Template, stop/start VM) and have no > problems getting VM back to work. You can check my log here: > http://pastebin.com/38EhygW6 > You may try to compare it, but keep in mind that I don't have more than > 1 host, so this problem may not arise at single node installation. Don't > know what to suggest - it is not clear for me where the problem can be. > > Regards, > > Vadim. > > -----Original Message----- > From: Mārtiņš Jakubovičs [mailto:[email protected]] > Sent: Tuesday, October 21, 2014 4:32 PM > To: [email protected] > Subject: Re: Launch VM after deleting template > > Hello Vadim, > > Thanks for response, I have pool of 5 hosts. Master is with id=3. All pool > members (hosts) ar successfully connected to all primary storages. > This error only appears if I try to start instance which was turned off and > was created from deleted template. In other cases VM's starts on all hosts > successfully. > > Thanks > > On 10/21/2014 04:11 PM, Vadim Kimlaychuk wrote: >> Hi Mārtiņš, >> >> It seems your host id=2 is not configured to be a pool member. New host >> id == null is not good obviously. >> >VM state transitted from :Starting to Stopped with event: >> OperationFailedvm's original host id: 2 new host id: null host id >> before state transition: null >> >> Can you provide more information about your XS pool configuration? How >> many hosts are there and which one is master? Do all pool members connect to >> storage and have vhd-util installed ? >> >> Vadim. >> >> -----Original Message----- >> From: Mārtiņš Jakubovičs [mailto:[email protected]] >> Sent: Tuesday, October 21, 2014 3:12 PM >> To: [email protected] >> Subject: Re: Launch VM after deleting template >> >> Interesting, if I create template of VM's ROOT disk, after that I can boot >> VM successfully, after deleting template, it fails again. >> >> Steps which I use: >> >> 1.) create template >> 2.) create instance from template >> 3.) delete template >> 4.) shutdown vm, and try to start it (didn't test with reboot) >> >> System: >> CS - 4.3.0 >> XS - 62ESP1013 >> >> On 10/21/2014 12:01 PM, Mārtiņš Jakubovičs wrote: >>> Hello all, >>> >>> After deleting template in CS 4.3.0, VM's, which was created from >>> this template and if they are shut down is unable to start. >>> As described in >>> http://cloudstack-administration.readthedocs.org/en/latest/templates. >>> h tml#deleting-templates They should work well after deleting >>> template. >>> >>> Is this bug or misconfiguration? >>> >>> Thanks. >>> >>> http://pastebin.com/9Vnn8Kua >>> >>> 2014-10-21 11:58:27,155 DEBUG [c.c.a.ApiServlet] >>> (http-10285-2:ctx-cc971930) ===START=== 10.10.100.11 -- GET >>> command=startVirtualMachine&id=75c7d13a-c800-4617-a88a-af9c80055c1a&r >>> e >>> sponse=json&sessionkey=SlJqKEVrQxFIQGYXZdfcu9hMb1E%3D&_=1413881909193 >>> 2014-10-21 11:58:27,195 INFO [o.a.c.f.j.i.AsyncJobMonitor] >>> (Job-Executor-40:ctx-c5f7cb4d) Add job-1540 into job monitoring >>> 2014-10-21 11:58:27,195 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d) Executing AsyncJobVO {id:1540, userId: >>> 48, accountId: 54, instanceType: VirtualMachine, instanceId: 225, cmd: >>> org.apache.cloudstack.api.command.user.vm.StartVMCmd, cmdInfo: >>> {"id":"75c7d13a-c800-4617-a88a-af9c80055c1a","response":"json","sessi >>> o >>> nkey":"SlJqKEVrQxFIQGYXZdfcu9hMb1E\u003d","cmdEventType":"VM.START"," >>> c >>> txUserId":"48","httpmethod":"GET","_":"1413881909193","ctxAccountId":" >>> 54","ctxStartEventId":"7170"}, >>> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, >>> result: null, initMsid: 64026978978098, completeMsid: null, >>> lastUpdated: null, lastPolled: null, created: null} >>> 2014-10-21 11:58:27,196 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] >>> (http-10285-2:ctx-cc971930 ctx-01c2506a) submit async job-1540, >>> details: AsyncJobVO {id:1540, userId: 48, accountId: 54, instanceType: >>> VirtualMachine, instanceId: 225, cmd: >>> org.apache.cloudstack.api.command.user.vm.StartVMCmd, cmdInfo: >>> {"id":"75c7d13a-c800-4617-a88a-af9c80055c1a","response":"json","sessi >>> o >>> nkey":"SlJqKEVrQxFIQGYXZdfcu9hMb1E\u003d","cmdEventType":"VM.START"," >>> c >>> txUserId":"48","httpmethod":"GET","_":"1413881909193","ctxAccountId":" >>> 54","ctxStartEventId":"7170"}, >>> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, >>> result: null, initMsid: 64026978978098, completeMsid: null, >>> lastUpdated: null, lastPolled: null, created: null} >>> 2014-10-21 11:58:27,198 DEBUG [c.c.a.ApiServlet] >>> (http-10285-2:ctx-cc971930 ctx-01c2506a) ===END=== 10.10.100.11 -- >>> GET >>> command=startVirtualMachine&id=75c7d13a-c800-4617-a88a-af9c80055c1a&r >>> e >>> sponse=json&sessionkey=SlJqKEVrQxFIQGYXZdfcu9hMb1E%3D&_=1413881909193 >>> 2014-10-21 11:58:27,220 DEBUG [c.c.u.AccountManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Access to >>> VM[User|dev-martins-demo] granted to >>> Acct[e6529330-a7ab-4206-9e8d-c8a25c31faed-martinsdev] by >>> DomainChecker >>> 2014-10-21 11:58:27,248 DEBUG [c.c.n.NetworkModelImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Service SecurityGroup is >>> not supported in the network id=255 >>> 2014-10-21 11:58:27,258 DEBUG [c.c.n.NetworkModelImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Service SecurityGroup is >>> not supported in the network id=255 >>> 2014-10-21 11:58:27,296 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Deploy avoids pods: [], >>> clusters: [], hosts: [] >>> 2014-10-21 11:58:27,299 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) DeploymentPlanner >>> allocation algorithm: com.cloud.deploy.FirstFitPlanner@6bd86a2d >>> 2014-10-21 11:58:27,299 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Trying to allocate a host >>> and storage pools from dc:1, pod:1,cluster:1, requested cpu: 2400, >>> requested ram: 4294967296 >>> 2014-10-21 11:58:27,299 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Is ROOT volume READY >>> (pool already allocated)?: Yes >>> 2014-10-21 11:58:27,299 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) This VM has last host_id >>> specified, trying to choose the same host: 2 >>> 2014-10-21 11:58:27,312 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Checking if host: 2 has >>> enough capacity for requested CPU: 2400 and requested RAM: 4294967296 >>> , cpuOverprovisioningFactor: 4.0 >>> 2014-10-21 11:58:27,316 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Hosts's actual total CPU: >>> 57456 and CPU after applying overprovisioning: 229824 >>> 2014-10-21 11:58:27,316 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) We need to allocate to >>> the last host again, so checking if there is enough reserved capacity >>> 2014-10-21 11:58:27,316 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Reserved CPU: 2400 , >>> Requested CPU: 2400 >>> 2014-10-21 11:58:27,317 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Reserved RAM: 4294967296 >>> , Requested RAM: 4294967296 >>> 2014-10-21 11:58:27,317 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Host has enough CPU and >>> RAM available >>> 2014-10-21 11:58:27,317 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) STATS: Can alloc CPU from >>> host: 2, used: 2200, reserved: 2400, actual total: 57456, total with >>> overprovisioning: 229824; requested >>> cpu:2400,alloc_from_last_host?:true ,considerReservedCapacity?: true >>> 2014-10-21 11:58:27,317 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) STATS: Can alloc MEM from >>> host: 2, used: 1342177280, reserved: 4294967296, total: 198580420608; >>> requested mem: 4294967296,alloc_from_last_host?:true >>> ,considerReservedCapacity?: true >>> 2014-10-21 11:58:27,320 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Host: 2 has cpu >>> capability (cpu:24, speed:2394) to support requested CPU: 2 and requested >>> speed: >>> 1200 >>> 2014-10-21 11:58:27,320 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) The last host of this VM >>> is UP and has enough capacity >>> 2014-10-21 11:58:27,320 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Now checking for suitable >>> pools under zone: 1, pod: 1, cluster: 1 >>> 2014-10-21 11:58:27,325 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Checking suitable pools >>> for volume (Id, Type): (295,ROOT) >>> 2014-10-21 11:58:27,325 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Volume has pool already >>> allocated, checking if pool can be reused, poolId: 1 >>> 2014-10-21 11:58:27,328 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Planner need not allocate >>> a pool for this volume since its READY >>> 2014-10-21 11:58:27,328 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Trying to find a potenial >>> host and associated storage pools from the suitable host/pool lists >>> for this VM >>> 2014-10-21 11:58:27,328 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Checking if host: 2 can >>> access any suitable storage pool for volume: ROOT >>> 2014-10-21 11:58:27,330 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Host: 2 can access pool: >>> 1 >>> 2014-10-21 11:58:27,333 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Found a potential host id: >>> 2 name: cloudstack-3 and associated storage pools for this VM >>> 2014-10-21 11:58:27,333 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Returning Deployment >>> Destination: >>> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->P >>> o >>> ol(Id))] >>> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage()] >>> 2014-10-21 11:58:27,369 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) VM state transitted from >>> :Stopped to Starting with event: StartRequestedvm's original host id: >>> 2 new host id: null host id before state transition: null >>> 2014-10-21 11:58:27,370 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Successfully transitioned >>> to start state for VM[User|dev-martins-demo] reservation id = >>> c01a5cbd-fe25-406c-b6ff-22d38af3fba3 >>> 2014-10-21 11:58:27,382 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Trying to deploy VM, vm >>> has dcId: 1 and podId: 1 >>> 2014-10-21 11:58:27,382 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) advanceStart: >>> DeploymentPlan is provided, using dcId:1, podId: 1, clusterId: 1, >>> hostId: 2, poolId: null >>> 2014-10-21 11:58:27,382 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Deploy avoids pods: null, >>> clusters: null, hosts: null >>> 2014-10-21 11:58:27,404 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) VM state transitted from >>> :Starting to Stopped with event: OperationFailedvm's original host id: >>> 2 new host id: null host id before state transition: null >>> 2014-10-21 11:58:27,445 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) VM state transitted from >>> :Stopped to Starting with event: StartRequestedvm's original host id: >>> 2 new host id: null host id before state transition: null >>> 2014-10-21 11:58:27,445 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Successfully transitioned >>> to start state for VM[User|dev-martins-demo] reservation id = >>> f6f56edd-e81b-4ae4-8a91-28369f089a55 >>> 2014-10-21 11:58:27,455 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Trying to deploy VM, vm >>> has dcId: 1 and podId: 1 >>> 2014-10-21 11:58:27,455 DEBUG [c.c.v.VirtualMachineManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) Deploy avoids pods: null, >>> clusters: null, hosts: null >>> 2014-10-21 11:58:27,475 DEBUG [c.c.c.CapacityManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d ctx-01c2506a) VM state transitted from >>> :Starting to Stopped with event: OperationFailedvm's original host id: >>> 2 new host id: null host id before state transition: null >>> 2014-10-21 11:58:27,505 ERROR [c.c.a.ApiAsyncJobDispatcher] >>> (Job-Executor-40:ctx-c5f7cb4d) Unexpected exception while executing >>> org.apache.cloudstack.api.command.user.vm.StartVMCmd >>> java.lang.NullPointerException >>> at >>> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:858) >>> at >>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761) >>> at >>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:601) >>> at >>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237) >>> at >>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:207) >>> at >>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3581) >>> at >>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2043) >>> at sun.reflect.GeneratedMethodAccessor720.invoke(Unknown Source) >>> at >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >>> at java.lang.reflect.Method.invoke(Method.java:622) >>> at >>> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) >>> at >>> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) >>> at >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) >>> at >>> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50) >>> at >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) >>> at >>> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) >>> at >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) >>> at >>> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) >>> at com.sun.proxy.$Proxy169.startVirtualMachine(Unknown Source) >>> at >>> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:121) >>> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161) >>> at >>> com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109) >>> at >>> com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66) >>> 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 >>> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63) >>> at >>> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509) >>> 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:471) >>> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) >>> at java.util.concurrent.FutureTask.run(FutureTask.java:166) >>> at >>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) >>> at >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) >>> at java.lang.Thread.run(Thread.java:701) >>> 2014-10-21 11:58:27,508 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d) Complete async job-1540, jobStatus: >>> FAILED, resultCode: 530, result: >>> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList": >>> [],"errorcode":530} >>> 2014-10-21 11:58:27,522 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] >>> (Job-Executor-40:ctx-c5f7cb4d) Done executing >>> org.apache.cloudstack.api.command.user.vm.StartVMCmd for job-1540 >>> 2014-10-21 11:58:27,531 INFO [o.a.c.f.j.i.AsyncJobMonitor] >>> (Job-Executor-40:ctx-c5f7cb4d) Remove job-1540 from job monitoring >
