[ https://issues.apache.org/jira/browse/CLOUDSTACK-7600?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14208884#comment-14208884 ]
Prachi Damle edited comment on CLOUDSTACK-7600 at 11/12/14 11:38 PM: --------------------------------------------------------------------- There is a StopRouter API called by Admin simultaneous to the userVm deployment API. The StopRouter has already processed and put the router in stopping state: 2014-09-21 14:38:15,627 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949) Executing AsyncJobVO {id:1949, userId: 2, accountId: 2, instanceType: DomainRouter, instanceId: 271, cmd: org.apache.cloudstack.api.command.admin.router.StopRouterCmd, cmdInfo: {"id":"c731662f-d109-4295-8d07-383f84f93d31","response":"json","ctxDetails":"{\"com.cloud.vm.VirtualMachine\":\"c731662f-d109-4295-8d07-383f84f93d31\"}","cmdEventType":"ROUTER.STOP","ctxUserId":"2","httpmethod":"GET","uuid":"c731662f-d109-4295-8d07-383f84f93d31","ctxAccountId":"2","ctxStartEventId":"6330","apiKey":"mLrTCdYRf3-d4xO7DnO-QXw1Uqrdae1uxenHTEPj_ulDpIYTaujsXwkNzARz222s6M4xChsTAE2W-TUur5bKNQ","signature":"bGbFrU0IuNAt0/Z0jzShaop19Ts\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 16226561876200, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2014-09-21 14:38:15,649 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Stopping router VM[DomainRouter|r-271-VM] 2014-09-21 14:38:15,654 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Sync job-1950 execution on object VmWorkJobQueue.271 2014-09-21 14:38:15,654 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Sync job-1950 execution on object VmWorkJobQueue.271 2014-09-21 14:38:16,507 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) VM state transitted from :Running to Stopping with event: StopRequestedvm's original host id: 1 new host id: 1 host id before state transition: 1 2014-09-21 14:38:29,785 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Asking VirtualRouter to release NicProfile[551-271-6596e782-c753-4d66-ae70-4828b0e7a03e-10.1.1.1-null 2014-09-21 14:38:29,815 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Successfully released network resources for the vm VM[DomainRouter|r-271-VM] 2014-09-21 14:38:29,815 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Successfully released storage resources for the vm VM[DomainRouter|r-271-VM] 2014-09-21 14:38:29,824 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) VM state transitted from :Stopping to Stopped with event: OperationSucceededvm's original host id: 1 new host id: null host id before state transition: 1 2014-09-21 14:38:29,845 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":271,"handlerName":"VirtualMachineManagerImpl"} was (Author: prachidamle): There is a StopRouter API called by Admin simultaneous to the userVm deployment API. The StopRouter has already processed and put the router in stopping state: 2014-09-21 14:38:15,627 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949) Executing AsyncJobVO {id:1949, userId: 2, accountId: 2, instanceType: DomainRouter, instanceId: 271, cmd: org.apache.cloudstack.api.command.admin.router.StopRouterCmd, cmdInfo: {"id":"c731662f-d109-4295-8d07-383f84f93d31","response":"json","ctxDetails":"{\"com.cloud.vm.VirtualMachine\":\"c731662f-d109-4295-8d07-383f84f93d31\"}","cmdEventType":"ROUTER.STOP","ctxUserId":"2","httpmethod":"GET","uuid":"c731662f-d109-4295-8d07-383f84f93d31","ctxAccountId":"2","ctxStartEventId":"6330","apiKey":"mLrTCdYRf3-d4xO7DnO-QXw1Uqrdae1uxenHTEPj_ulDpIYTaujsXwkNzARz222s6M4xChsTAE2W-TUur5bKNQ","signature":"bGbFrU0IuNAt0/Z0jzShaop19Ts\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 16226561876200, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2014-09-21 14:38:15,649 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Stopping router VM[DomainRouter|r-271-VM] 2014-09-21 14:38:15,654 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Sync job-1950 execution on object VmWorkJobQueue.271 2014-09-21 14:38:15,654 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-86:ctx-a051db6f job-1949 ctx-d59b1c33) Sync job-1950 execution on object VmWorkJobQueue.271 2014-09-21 14:38:29,785 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Asking VirtualRouter to release NicProfile[551-271-6596e782-c753-4d66-ae70-4828b0e7a03e-10.1.1.1-null 2014-09-21 14:38:29,815 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Successfully released network resources for the vm VM[DomainRouter|r-271-VM] 2014-09-21 14:38:29,815 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Successfully released storage resources for the vm VM[DomainRouter|r-271-VM] 2014-09-21 14:38:29,824 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) VM state transitted from :Stopping to Stopped with event: OperationSucceededvm's original host id: 1 new host id: null host id before state transition: 1 2014-09-21 14:38:29,845 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-52:ctx-303ddf98 job-1949/job-1950 ctx-e9802705) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":271,"handlerName":"VirtualMachineManagerImpl"} > [Automation] VM Failed to Start due to ConcurrentOperationException - Unable > to change the state of Virtual Router > ------------------------------------------------------------------------------------------------------------------ > > Key: CLOUDSTACK-7600 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7600 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Automation, Test, Virtual Router > Affects Versions: 4.5.0 > Reporter: Chandan Purushothama > Assignee: Prachi Damle > Priority: Critical > Fix For: 4.5.0 > > Attachments: management-server.zip > > > *ConcurrentOperationException: Unable to change the state of VM* > {noformat} > 2014-09-21 14:38:20,648 ERROR [c.c.v.VirtualMachineManagerImpl] > (Work-Job-Executor-65:ctx-cfa1f316 job-1953/job-1954 ctx-6fd40296) Failed to > start instance VM[User|i-115-279-VM] > com.cloud.exception.ConcurrentOperationException: Unable to change the state > of VM[DomainRouter|r-271-VM] > at > com.cloud.vm.VirtualMachineManagerImpl.changeToStartState(VirtualMachineManagerImpl.java:717) > at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:808) > at > com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:762) > at > com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2981) > at > com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:2055) > at > com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:2155) > at > com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:2137) > at sun.reflect.GeneratedMethodAccessor335.invoke(Unknown Source) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > 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 > 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 $Proxy190.deployVirtualRouterInGuestNetwork(Unknown Source) > at > com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:234) > at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1239) > at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:1373) > at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1309) > at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:970) > at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4590) > at sun.reflect.GeneratedMethodAccessor379.invoke(Unknown Source) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > at > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > at > com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4746) > at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) > at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:516) > 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:473) > 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:1110) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > 2014-09-21 14:38:20,651 DEBUG [c.c.v.VirtualMachineManagerImpl] > (Work-Job-Executor-65:ctx-cfa1f316 job-1953/job-1954 ctx-6fd40296) Cleaning > up resources for the vm VM[User|i-115-279-VM] in Starting state > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)