Return-Path: X-Original-To: apmail-cloudstack-dev-archive@www.apache.org Delivered-To: apmail-cloudstack-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 7699F11CC0 for ; Thu, 10 Jul 2014 08:58:41 +0000 (UTC) Received: (qmail 62479 invoked by uid 500); 10 Jul 2014 08:58:40 -0000 Delivered-To: apmail-cloudstack-dev-archive@cloudstack.apache.org Received: (qmail 62433 invoked by uid 500); 10 Jul 2014 08:58:40 -0000 Mailing-List: contact dev-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 dev@cloudstack.apache.org Received: (qmail 62420 invoked by uid 99); 10 Jul 2014 08:58:40 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 10 Jul 2014 08:58:40 +0000 X-ASF-Spam-Status: No, hits=-0.7 required=5.0 tests=RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of trippie@gmail.com designates 74.125.82.175 as permitted sender) Received: from [74.125.82.175] (HELO mail-we0-f175.google.com) (74.125.82.175) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 10 Jul 2014 08:58:35 +0000 Received: by mail-we0-f175.google.com with SMTP id k48so8569638wev.20 for ; Thu, 10 Jul 2014 01:58:13 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=sender:from:content-type:mime-version:subject:in-reply-to:date :content-transfer-encoding:message-id:references:to; bh=v1yz4tSfNEYSXrv9PPVG0Y8phG1/CIhVgO9tEA2YICM=; b=DXOcuXlerHaupGYBQWDQkxfylboXS++1JBCU4FUex6+4MK4UtOVEUvNPyqfrREbn0M bAE2hvvv0Iy6IUwSlzxSbJWgnNU7T8J24HDURFTtrpPHIpgt6+hgmShzwKoI01qwdtcR OnaquD3wtiDiS9lP9RK3sGy4d1Kt0wNclMc5xb55ADcLnhbJr74hZok5xZmv5hCWBMox 6S3H0pcWQ23gBWpagSru8Ci68L+KEJOO8iOXVkSIv+iDTZaKt9d2FObsdJQAeq5sX1Ii 32Z7AdRMAgrpfbaDnMjFPjE8drL2jfbfvP+1T6GjHCa0Sf2UlbicpmgDOR+fswBI/vKh yXjg== X-Received: by 10.180.10.138 with SMTP id i10mr17137570wib.81.1404982693768; Thu, 10 Jul 2014 01:58:13 -0700 (PDT) Received: from [10.10.1.178] ([95.142.96.53]) by mx.google.com with ESMTPSA id w9sm29364503wif.12.2014.07.10.01.58.10 for (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Thu, 10 Jul 2014 01:58:11 -0700 (PDT) Sender: Trippie From: Hugo Trippaers X-Google-Original-From: Hugo Trippaers Content-Type: text/plain; charset=windows-1252 Mime-Version: 1.0 (Mac OS X Mail 7.3 \(1878.6\)) Subject: Re: "Bug" introduced by part of commit a600d8408ea86782318139c17cf346c8497943d0 In-Reply-To: Date: Thu, 10 Jul 2014 10:58:10 +0200 Content-Transfer-Encoding: quoted-printable Message-Id: <23F7F4FF-4FB3-4633-BC20-51EC99835C36@GMAIL.com> References: To: dev@cloudstack.apache.org X-Mailer: Apple Mail (2.1878.6) X-Virus-Checked: Checked by ClamAV on apache.org Doesn=92t seem related to that particular commit, the function = invalidateRunSession appears to be dead code. I=92ll do some digging. Cheers, Hugo On 10 jul. 2014, at 10:40, Funs Kessen = wrote: > Hi Devs, >=20 > I recently noticed on master that after starting, stopping and = starting the management server again I get stacktraces about every = second. > After some digging with Daan we found that part of the = a600d8408ea86782318139c17cf346c84979943d0 commit causes this. The = problem is however deeper rooted, as the code is supposed to update the = mshost table, but because another Session ID (actually _runId from = ClusterManagerImpl.java from the previous run) is already in there the = update fails. The Session ID is based on time in milliseconds, and = offcourse changes when you stop and start the management server again. > Prior to the commit it failed silently, and has done so since the = initial checkin it seems. The real question is what the original idea is = behind the _runId, and is it something that requires fixing ? >=20 > I've pasted part of the commit, sql and stacktrace below. >=20 > Cheers, >=20 > Funs >=20 > =3D=3D=3D > mysql> select * from mshost; > = +----+----------------+---------------+---------+-------+----------------+= ------------+--------------+---------------------+---------+-------------+= > | id | msid | runid | name | state | version = | service_ip | service_port | last_update | removed | = alert_count | > = +----+----------------+---------------+---------+-------+----------------+= ------------+--------------+---------------------+---------+-------------+= > | 1 | 90520734207775 | 1404924979461 | cs-mgmt | Up | = 4.5.0-SNAPSHOT | 127.0.0.1 | 9090 | 2014-07-09 16:58:07 | NULL = | 0 | > = +----+----------------+---------------+---------+-------+----------------+= ------------+--------------+---------------------+---------+-------------+= > 1 row in set (0.00 sec) >=20 > =3D=3D=3D > commit a600d8408ea86782318139c17cf346c8497943d0 > Author: Santhosh Edukulla 2014-07-02 = 10:38:16 > Committer: Santhosh Edukulla 2014-07-04 = 12:47:58 >=20 > Fixed Resource Leaks, null dereferences, few other issues reported by = coverity >=20 > - = framework/cluster/src/com/cloud/cluster/dao/ManagementServerHostDaoImpl.ja= va=20 > diff --git = a/framework/cluster/src/com/cloud/cluster/dao/ManagementServerHostDaoImpl.= java = b/framework/cluster/src/com/cloud/cluster/dao/ManagementServerHostDaoImpl.= java > index 3d0c3f5..89d7d27 100644 > --- = a/framework/cluster/src/com/cloud/cluster/dao/ManagementServerHostDaoImpl.= java > +++ = b/framework/cluster/src/com/cloud/cluster/dao/ManagementServerHostDaoImpl.= java > @@ -53,15 +53,14 @@ > @Override > public void invalidateRunSession(long id, long runid) { > TransactionLegacy txn =3D TransactionLegacy.currentTxn(); > - PreparedStatement pstmt =3D null; > - try { > - pstmt =3D txn.prepareAutoCloseStatement("update mshost = set runid=3D0, state=3D'Down' where id=3D? and runid=3D?"); > - pstmt.setLong(1, id); > - pstmt.setLong(2, runid); > - > - pstmt.executeUpdate(); > + try (PreparedStatement pstmt =3D txn.prepareStatement("update = mshost set runid=3D0, state=3D'Down' where id=3D? and runid=3D?");){ > + if(pstmt !=3D null) { > + pstmt.setLong(1, id); > + pstmt.setLong(2, runid); > + pstmt.executeUpdate(); > + } > } catch (SQLException e) { > - throw new CloudRuntimeException("DB exception on " + = pstmt.toString(), e); > + throw new = CloudRuntimeException("invalidateRunSession:Exception:"+ e.getMessage(), = e); > } > } >=20 > =3D=3D=3D > 2014-07-09 18:45:06,541 WARN [c.c.c.d.ManagementServerHostDaoImpl] = (Cluster-Heartbeat-1:ctx-5f2f8ad5) update:Exception:Invalid cluster = session detected > com.cloud.utils.exception.CloudRuntimeException: Invalid cluster = session detected > at = com.cloud.cluster.dao.ManagementServerHostDaoImpl.update(ManagementServerH= ostDaoImpl.java:147) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at = sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:= 57) > at = sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm= pl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at = org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(Ao= pUtils.java:317) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoi= nt(ReflectiveMethodInvocation.java:183) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:150) > at = com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContext= Interceptor.java:34) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:161) > at = org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(Exp= oseInvocationInterceptor.java:91) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:172) > at = org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopP= roxy.java:204) > at com.sun.proxy.$Proxy158.update(Unknown Source) > at = com.cloud.cluster.ClusterManagerImpl$4.runInContext(ClusterManagerImpl.jav= a:545) > at = org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Managed= ContextRunnable.java:49) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De= faultManagedContext.java:56) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC= ontext(DefaultManagedContext.java:103) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo= ntext(DefaultManagedContext.java:53) > at = org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedCo= ntextRunnable.java:46) > at = java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at = java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304) > at = java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acces= s$301(ScheduledThreadPoolExecutor.java:178) > at = java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(S= cheduledThreadPoolExecutor.java:293) > at = java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:= 1145) > at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java= :615) > at java.lang.Thread.run(Thread.java:744) > Caused by: com.cloud.cluster.ClusterInvalidSessionException: runid = 1404924278923 is no longer valid > at = com.cloud.cluster.dao.ManagementServerHostDaoImpl.update(ManagementServerH= ostDaoImpl.java:147) > ... 26 more > 2014-07-09 18:45:06,543 ERROR [c.c.c.ClusterManagerImpl] = (Cluster-Heartbeat-1:ctx-5f2f8ad5) Unexpected exception in cluster = heartbeat > java.lang.RuntimeException: update:Exception:Invalid cluster session = detected > at = com.cloud.cluster.dao.ManagementServerHostDaoImpl.update(ManagementServerH= ostDaoImpl.java:155) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at = sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:= 57) > at = sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm= pl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at = org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(Ao= pUtils.java:317) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoi= nt(ReflectiveMethodInvocation.java:183) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:150) > at = com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContext= Interceptor.java:34) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:161) > at = org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(Exp= oseInvocationInterceptor.java:91) > at = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle= ctiveMethodInvocation.java:172) > at = org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopP= roxy.java:204) > at com.sun.proxy.$Proxy158.update(Unknown Source) > at = com.cloud.cluster.ClusterManagerImpl$4.runInContext(ClusterManagerImpl.jav= a:545) > at = org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Managed= ContextRunnable.java:49) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De= faultManagedContext.java:56) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC= ontext(DefaultManagedContext.java:103) > at = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo= ntext(DefaultManagedContext.java:53) > at = org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedCo= ntextRunnable.java:46) > at = java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at = java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304) > at = java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acces= s$301(ScheduledThreadPoolExecutor.java:178) > at = java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(S= cheduledThreadPoolExecutor.java:293) > at = java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:= 1145) > at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java= :615) > at java.lang.Thread.run(Thread.java:744) > Caused by: com.cloud.utils.exception.CloudRuntimeException: Invalid = cluster session detected > at = com.cloud.cluster.dao.ManagementServerHostDaoImpl.update(ManagementServerH= ostDaoImpl.java:147) > ... 26 more > Caused by: com.cloud.cluster.ClusterInvalidSessionException: runid = 1404924278923 is no longer valid > at = com.cloud.cluster.dao.ManagementServerHostDaoImpl.update(ManagementServerH= ostDaoImpl.java:147) > ... 26 more >=20 >=20 >=20