Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 17281200C7D for ; Tue, 16 May 2017 09:26:17 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 15BDD160BAC; Tue, 16 May 2017 07:26:17 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 0E1E9160B9D for ; Tue, 16 May 2017 09:26:15 +0200 (CEST) Received: (qmail 49115 invoked by uid 500); 16 May 2017 07:26:15 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 49106 invoked by uid 500); 16 May 2017 07:26:15 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 49103 invoked by uid 99); 16 May 2017 07:26:15 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 16 May 2017 07:26:15 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id AA7431A0568 for ; Tue, 16 May 2017 07:26:09 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -99.201 X-Spam-Level: X-Spam-Status: No, score=-99.201 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, RP_MATCHES_RCVD=-0.001, SPF_PASS=-0.001, USER_IN_WHITELIST=-100, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id ylteVhupu4LN for ; Tue, 16 May 2017 07:26:07 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id B7CB05FDD8 for ; Tue, 16 May 2017 07:26:05 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id D0EECE0D50 for ; Tue, 16 May 2017 07:26:04 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 3E15021946 for ; Tue, 16 May 2017 07:26:04 +0000 (UTC) Date: Tue, 16 May 2017 07:26:04 +0000 (UTC) From: "ASF subversion and git services (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-9708) Router deployment failed due to two threads start VR simultaneosuly MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Tue, 16 May 2017 07:26:17 -0000 [ https://issues.apache.org/jira/browse/CLOUDSTACK-9708?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16011891#comment-16011891 ] ASF subversion and git services commented on CLOUDSTACK-9708: ------------------------------------------------------------- Commit bafac742c483f1f47732973214d43528deba7b94 in cloudstack's branch refs/heads/master from [~rajanik] [ https://gitbox.apache.org/repos/asf?p=cloudstack.git;h=bafac74 ] Merge pull request #1870 from Accelerite/CLOUDSTACK-9708 CLOUDSTACK-9708: Router deployment failed due to two threads start VR simultaneously. > 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)