You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "shweta agarwal (JIRA)" <ji...@apache.org> on 2013/12/02 08:11:36 UTC
[jira] [Created] (CLOUDSTACK-5324) error message not proper when
start VM fails because router reuires upgrade
shweta agarwal created CLOUDSTACK-5324:
------------------------------------------
Summary: error message not proper when start VM fails because router reuires upgrade
Key: CLOUDSTACK-5324
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5324
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Upgrade
Affects Versions: 4.3.0
Reporter: shweta agarwal
Assignee: Kishan Kavala
Fix For: 4.3.0
Repro steps:
Create a VM on 3.07 setup
Upgrade to 4.3.0 but dont upgrade routers
Stop user VM
Start user VM
Bug:
Error message shows "Unable to start a VM due to concurrent operation
Expectation :
Error message should show " router requires upgrade "
MS log snippet :
2013-12-02 12:28:09,029 ERROR [c.c.v.VirtualMachineManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Failed to start instance VM[User|f01ae0d5-23b3-44c4-9e8d-9df9245874be]
com.cloud.utils.exception.CloudRuntimeException: Router requires upgrade. Unable to send command to router:4
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.sendCommandsToRouter(VirtualNetworkApplianceManagerImpl.java:3437)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl$7.execute(VirtualNetworkApplianceManagerImpl.java:2873)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3722)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
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 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.$Proxy239.applyDhcpEntry(Unknown Source)
at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:914)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1171)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:1293)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1229)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:899)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:706)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:552)
at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:236)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3465)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1921)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
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:520)
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)
2013-12-02 12:28:09,097 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Cleaning up resources for the vm VM[User|f01ae0d5-23b3-44c4-9e8d-9df9245874be] in Starting state
2013-12-02 12:28:09,099 DEBUG [c.c.a.t.Request] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Seq 1-1690925677: Sending { Cmd , MgmtId: 233845177509765, via: 1(Rack1Pod1Host24), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-3-VM","wait":0}}] }
2013-12-02 12:28:09,099 DEBUG [c.c.a.t.Request] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Seq 1-1690925677: Executing: { Cmd , MgmtId: 233845177509765, via: 1(Rack1Pod1Host24), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-3-VM","wait":0}}] }
2013-12-02 12:28:09,100 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-183:ctx-e0a9d3bb) Seq 1-1690925677: Executing request
2013-12-02 12:28:09,186 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-183:ctx-e0a9d3bb) VM does not exist on XenServerceca7304-b915-4623-8975-e07f4093f416
2013-12-02 12:28:09,186 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-183:ctx-e0a9d3bb) Seq 1-1690925677: Response Received:
2013-12-02 12:28:09,186 DEBUG [c.c.a.t.Request] (DirectAgent-183:ctx-e0a9d3bb) Seq 1-1690925677: Processing: { Ans: , MgmtId: 233845177509765, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2013-12-02 12:28:09,186 DEBUG [c.c.a.t.Request] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Seq 1-1690925677: Received: { Ans: , MgmtId: 233845177509765, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
2013-12-02 12:28:09,194 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Service SecurityGroup is not supported in the network id=204
2013-12-02 12:28:09,197 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Changing active number of nics for network id=204 on -1
2013-12-02 12:28:09,268 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Asking VirtualRouter to release NicProfile[8-3-e1ae98d3-8718-439b-87d2-97fc0bf0ff68-10.1.1.143-null
2013-12-02 12:28:09,268 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Successfully released network resources for the vm VM[User|f01ae0d5-23b3-44c4-9e8d-9df9245874be]
2013-12-02 12:28:09,268 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Successfully cleanued up resources for the vm VM[User|f01ae0d5-23b3-44c4-9e8d-9df9245874be] in Starting state
2013-12-02 12:28:09,397 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: 5 new host id: null host id before state transition: 1
2013-12-02 12:28:09,403 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Hosts's actual total CPU: 12372 and CPU after applying overprovisioning: 12372
2013-12-02 12:28:09,403 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) Hosts's actual total RAM: 7907453568 and RAM after applying overprovisioning: 7907453440
2013-12-02 12:28:09,403 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) release cpu from host: 1, old used: 4896,reserved: 0, actual total: 12372, total with overprovisioning: 12372; new used: 4768,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-02 12:28:09,403 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-9:ctx-1bf286cd ctx-4cabd091) release mem from host: 1, old used: 2147483648,reserved: 0, total: 7907453440; new used: 2013265920,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-02 12:28:09,616 ERROR [c.c.a.ApiAsyncJobDispatcher] (Job-Executor-9:ctx-1bf286cd) Unexpected exception while executing org.apache.cloudstack.api.command.user.vm.StartVMCmd
com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due to concurrent operation
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:558)
at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:236)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3465)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1921)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
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:520)
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)
Caused by: com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Router requires upgrade. Unable to send command to router:4
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1011)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:706)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:552)
... 37 more
Caused by: com.cloud.utils.exception.CloudRuntimeException: Router requires upgrade. Unable to send command to router:4
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.sendCommandsToRouter(VirtualNetworkApplianceManagerImpl.java:3437)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl$7.execute(VirtualNetworkApplianceManagerImpl.java:2873)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3722)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
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 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.$Proxy239.applyDhcpEntry(Unknown Source)
at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:914)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1171)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:1293)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1229)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:899)
... 39 more
2013-12-02 12:28:09,619 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-9:ctx-1bf286cd) Complete async job-182, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable to start a VM due to concurrent operation"}
2013-12-02 12:28:09,674 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-9:ctx-1bf286cd) Done executing org.apache.cloudstack.api.command.user.vm.StartVMCmd for job-182
2013-12-02 12:28:09,699 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-9:ctx-1bf286cd) Remove job-
--
This message was sent by Atlassian JIRA
(v6.1#6144)