[
https://issues.apache.org/jira/browse/CLOUDSTACK-5324?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sheng Yang reassigned CLOUDSTACK-5324:
--------------------------------------
Assignee: Kishan Kavala (was: Sheng Yang)
Assign to Kishan who wrote router version check feature.
> 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.4.0, 4.5.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.3.4#6332)
