You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "ASF GitHub Bot (JIRA)" <ji...@apache.org> on 2017/03/09 04:09:37 UTC

[jira] [Commented] (CLOUDSTACK-9708) Router deployment failed due to two threads start VR simultaneosuly

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-9708?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15902445#comment-15902445 ] 

ASF GitHub Bot commented on CLOUDSTACK-9708:
--------------------------------------------

Github user nitin-maharana commented on the issue:

    https://github.com/apache/cloudstack/pull/1870
  
    @remibergsma : Can you please review it again. Fixed the test failures.
    
    ping @jayapalu @rajesh-battala 


> Router deployment failed due to two threads start VR simultaneosuly
> -------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-9708
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9708
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>            Reporter: Nitin Kumar Maharana
>
> This is some race condition observed with HyperV host.
> The issue is produced when two or more threads try to start Router VMs simultaneously.
> This is a race condition between two threads trying to start Router VMs simultaneosuly, see the two threads below:
> 2015-01-08 17:10:03,750 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-11:ctx-5eb09ffd) (logid:b22fde6c) Sending cmd to https://10.81.56.130:8250/api/HypervResource/com.cloud.agent.api.GetStorageStatsCommand cmd data:{"id":"6e95644b-967e-3b15-a9f5-029e814252b1","localPath":"/storage/primary","pooltype":"SMB","contextMap":{"logid":"b22fde6c"},"wait":0}
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 static nat(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 static nat(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 firewall Ingress rule(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 firewall Ingress rule(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 port forwarding rule(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 port forwarding rule(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 static nat rule(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 static nat rule(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 vpn(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,782 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 vpn(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,784 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Found 0 load balancing rule(s) to apply as a part of domR VM[DomainRouter|r-7-VM] start.
> 2015-01-08 17:10:03,784 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Found 0 load balancing rule(s) to apply as a part of domR VM[DomainRouter|r-8-VM] start.
> 2015-01-08 17:10:03,787 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Creating  monitoring services on VM[DomainRouter|r-7-VM] start...
> 2015-01-08 17:10:03,787 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Creating  monitoring services on VM[DomainRouter|r-8-VM] start...
> Then VR failed with NPE 
> 2015-01-08 17:10:03,787 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Creating  monitoring services on VM[DomainRouter|r-8-VM] start...
> 2015-01-08 17:10:03,818 DEBUG [c.c.a.ApiServlet] (catalina-exec-13:ctx-8415f9bc) (logid:5aed5be9) ===START===  10.81.29.157 -- GET  jobid=44af1f9a-1439-4f45-a9a0-7927c59adb55&apiKey=NWeDoUSCyhxhKBIg-xv1Zp51EogNguY99pnnA2qpqEb1WPeKDnBFIXHUGJ8WovPR4j78TkJtYpBxu-6wK_0fRA&command=queryAsyncJobResult&response=json&signature=kDKgsual1Q0sKW83aXbP7l7j5y8%3D
> 2015-01-08 17:10:03,834 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-4:ctx-7d37a603 job-21/job-25 ctx-d4e904bb) (logid:d5036c46) Reapplying dhcp entries as a part of domR VM[DomainRouter|r-8-VM] start...
> 2015-01-08 17:10:03,832 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-11:ctx-5eb09ffd) (logid:b22fde6c) POST response is [{"com.cloud.agent.api.GetStorageStatsAnswer":{"result":true,"details":null,"capacity":1000202039296,"used":25881972736,"contextMap":{}}}]
> 2015-01-08 17:10:03,834 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Reapplying dhcp entries as a part of domR VM[DomainRouter|r-7-VM] start...
> 2015-01-08 17:10:03,846 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-3:ctx-333f41a7 job-20/job-24 ctx-8c682986) (logid:44af1f9a) Allocating the VR i=10 in datacenter com.cloud.dc.DataCenterVO$$EnhancerByCGLIB$$cb043236@1with the hypervisor type Hyperv
> 2015-01-08 17:10:03,852 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-11:ctx-5eb09ffd) (logid:b22fde6c) executeRequest received response [{"com.cloud.agent.api.GetStorageStatsAnswer":{"used":25881972736,"capacity":1000202039296,"result":true,"contextMap":{},"wait":0}}]
> 2015-01-08 17:10:03,852 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-5eb09ffd) (logid:b22fde6c) Seq 2-5957980832034455573: Response Received: 
> 2015-01-08 17:10:03,852 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-4a1ac475) (logid:b22fde6c) Seq 2-5957980832034455573: Received:  { Ans: , MgmtId: 231090496990904, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2015-01-08 17:10:03,857 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-5:ctx-16557d57 job-22/job-26 ctx-f19c2085) (logid:1d478d14) Failed to start instance VM[DomainRouter|r-7-VM]
> java.lang.NullPointerException
> 	at com.cloud.vm.dao.UserVmDaoImpl.listByNetworkIdAndStates(UserVmDaoImpl.java:311)
> 	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: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 com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
> 	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 $Proxy74.listByNetworkIdAndStates(Unknown Source)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.createDhcpEntryCommandsForVMs(VirtualNetworkApplianceManagerImpl.java:3772)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.finalizeUserDataAndDhcpOnStart(VirtualNetworkApplianceManagerImpl.java:2646)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.finalizeCommandsOnStart(VirtualNetworkApplianceManagerImpl.java:2543)
> 	at com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl.finalizeCommandsOnStart(VpcVirtualNetworkApplianceManagerImpl.java:701)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.finalizeDeployment(VirtualNetworkApplianceManagerImpl.java:2488)
> 	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1004)
> 	at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:775)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:3021)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:2064)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:2164)
> 	at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:2146)
> 	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: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 $Proxy192.deployVirtualRouterInGuestNetwork(Unknown Source)
> 	at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:194)
> 	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetworkElementsAndResources(NetworkOrchestrator.java:1102)
> 	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:1009)
> 	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:939)
> 	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1299)
> 	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:983)
> 	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4475)
> 	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:601)
> 	at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> 	at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4631)
> 	at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:103)
> 	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:547)
> 	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:498)
> 	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)



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)