1 Reply Latest reply on Jul 20, 2016 9:22 AM by Jeremy Whiting

    Indefinute wait on count down latch during createSessionFactory.

    Jeremy Whiting Expert

      Hi,

      I am testing running EAP7 with the Shenandoah jvm option. Which at the moment causes the jvm to not operate not quickly at the moment.

       

      This slowdown is causing an installed application with does operate normally (without the Shenandoah flag) to cease processing requests.

      A stack dump shows all but one of the threads processing jms requests to be blocked waiting on a lock. The one thread that has the lock is waiting on a count down latch. But this latch is never counted down.

       

      Has this been seen before ?

       

      1. "httpWorker task-10" #547 prio=5 os_prio=0 tid=0x00002acc1c044000
      2. nid=0xf422 waiting on condition [0x00002ac9a7ffc000]
      3.     java.lang.Thread.State: TIMED_WAITING (parking)
      4.      at sun.misc.Unsafe.park(Native Method)
      5.      - parking to wait for  <0x00002ac2d0f072d0> (a
      6. java.util.concurrent.CountDownLatch$Sync)
      7.      at
      8. java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
      9.      at
      10. java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
      11.      at
      12. java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
      13.      at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
      14.      at
      15. org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.waitForTopology(ClientSessionFactoryImpl.java:453)
      16.      at
      17. org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.createSessionFactory(ServerLocatorImpl.java:790)
      18.      at
      19. org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createConnectionInternal(ActiveMQConnectionFactory.java:724)
      20.      - locked <0x00002ac31e7b69b8> (a
      21. org.apache.activemq.artemis.jms.client.ActiveMQXAConnectionFactory)
      22.      at
      23. org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createXAQueueConnection(ActiveMQConnectionFactory.java:333)
      24.      at
      25. org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createXAQueueConnection(ActiveMQConnectionFactory.java:329)
      26.      at
      27. org.apache.activemq.artemis.ra.ActiveMQRAManagedConnection.setup(ActiveMQRAManagedConnection.java:771)
      28.      at
      29. org.apache.activemq.artemis.ra.ActiveMQRAManagedConnection.<init>(ActiveMQRAManagedConnection.java:163)
      30.      at
      31. org.apache.activemq.artemis.ra.ActiveMQRAManagedConnectionFactory.createManagedConnection(ActiveMQRAManagedConnectionFactory.java:149)
      32.      at
      33. org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.createConnectionEventListener(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1320)
      34.      at
      35. org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:496)
      36.      at
      37. org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:699)
      38.      at
      39. org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:598)
      40.      at
      41. org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:590)
      42.      at
      43. org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:429)
      44.      at
      45. org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:747)
      46.      at
      47. org.apache.activemq.artemis.ra.ActiveMQRASessionFactoryImpl.allocateConnection(ActiveMQRASessionFactoryImpl.java:853)
      48.      - locked <0x00002ac2d342c260> (a java.util.HashSet)
      49.      at
      50. org.apache.activemq.artemis.ra.ActiveMQRASessionFactoryImpl.createQueueSession(ActiveMQRASessionFactoryImpl.java:296)
      51.      at
      52. org.spec.jent.ejb.orders.session.LargeOrderSenderSession.sendOrdersToManufacturing(LargeOrderSenderSession.java:50)
      53.      at sun.reflect.GeneratedMethodAccessor450.invoke(Unknown Source)
      54.      at
      55. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      56.      at java.lang.reflect.Method.invoke(Method.java:498)
      57.      at
      58. org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
      59.      at
      60. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      61.      at
      62. org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
      63.      at
      64. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      65.      at
      66. org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)
      67.      at
      68. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      69.      at
      70. org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
      71.      at
      72. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      73.      at
      74. org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
      75.      at
      76. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      77.      at
      78. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      79.      at
      80. org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
      81.      at
      82. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      83.      at
      84. org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)
      85.      at
      86. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      87.      at
      88. org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:254)
      89.      at
      90. org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:329)
      91.      at
      92. org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
      93.      at
      94. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      95.      at
      96. org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      97.      at
      98. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      99.      at
      100. org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
      101.      at
      102. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      103.      at
      104. org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      105.      at
      106. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      107.      at
      108. org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
      109.      at
      110. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      111.      at
      112. org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      113.      at
      114. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      115.      at
      116. org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
      117.      at
      118. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      119.      at
      120. org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
      121.      at
      122. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      123.      at
      124. org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      125.      at
      126. org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
      127.      at
      128. org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
      129.      at
      130. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      131.      at
      132. org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      133.      at
      134. org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
      135.      at
      136. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      137.      at
      138. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      139.      at
      140. org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
      141.      at
      142. org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
      143.      at
      144. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      145.      at
      146. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      147.      at
      148. org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
      149.      at
      150. org.spec.jent.ejb.orders.session.LargeOrderSenderSessionLocal$$$view11.sendOrdersToManufacturing(Unknown
      151. Source)
      152.      at
      153. org.spec.jent.ejb.orders.session.OrderSession.newOrder(OrderSession.java:165)
      154.      at sun.reflect.GeneratedMethodAccessor219.invoke(Unknown Source)
      155.      at
      156. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      157.      at java.lang.reflect.Method.invoke(Method.java:498)
      158.      at
      159. org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
      160.      at
      161. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      162.      at
      163. org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
      164.      at
      165. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      166.      at
      167. org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)
      168.      at
      169. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      170.      at
      171. org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
      172.      at
      173. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      174.      at
      175. org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
      176.      at
      177. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      178.      at
      179. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      180.      at
      181. org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
      182.      at
      183. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      184.      at
      185. org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)
      186.      at
      187. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      188.      at
      189. org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:275)
      190.      at
      191. org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
      192.      at
      193. org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
      194.      at
      195. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      196.      at
      197. org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      198.      at
      199. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      200.      at
      201. org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
      202.      at
      203. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      204.      at
      205. org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      206.      at
      207. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      208.      at
      209. org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
      210.      at
      211. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      212.      at
      213. org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      214.      at
      215. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      216.      at
      217. org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
      218.      at
      219. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      220.      at
      221. org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
      222.      at
      223. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      224.      at
      225. org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      226.      at
      227. org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
      228.      at
      229. org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
      230.      at
      231. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      232.      at
      233. org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      234.      at
      235. org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
      236.      at
      237. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      238.      at
      239. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      240.      at
      241. org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
      242.      at
      243. org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
      244.      at
      245. org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      246.      at
      247. org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      248.      at
      249. org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
      250.      at
      251. org.spec.jent.ejb.orders.session.OrderSessionLocal$$$view3.newOrder(Unknown
      252. Source)
      253.      at
      254. org.spec.jent.servlet.helper.SpecAction.doPurchase(SpecAction.java:340)
      255.      at
      256. org.spec.jent.servlet.helper.SpecServletAction.doPurchase(SpecServletAction.java:502)
      257.      at
      258. org.spec.jent.servlet.SpecAppServlet.performTask(SpecAppServlet.java:199)
      259.      at org.spec.jent.servlet.SpecAppServlet.doGet(SpecAppServlet.java:78)
      260.      at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
      261.      at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
      262.      at
      263. io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
      264.      at
      265. io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
      266.      at
      267. io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
      268.      at
      269. io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
      270.      at
      271. io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
      272.      at
      273. io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      274.      at
      275. io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
      276.      at
      277. io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
      278.      at
      279. io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
      280.      at
      281. io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
      282.      at
      283. io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
      284.      at
      285. io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      286.      at
      287. io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      288.      at
      289. io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:285)
      290.      at
      291. io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:264)
      292.      at
      293. io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
      294.      at
      295. io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:175)
      296.      at
      297. io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
      298.      at
      299. io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:792)
      300.      at
      301. java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      302.      at
      303. java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      304.      at java.lang.Thread.run(Thread.java:745)


      Regards,

      Jeremy

        • 1. Re: Indefinute wait on count down latch during createSessionFactory.
          Jeremy Whiting Expert

          These were the options passed to the JVM for EAP7 in standalone mode.

           

          -Xmx20g -Xmx20g -Xss256m -XX:-UseCompressedOops -XX:+UseShenandoahGC -XX:+PrintGCDetails

           

          To investigate this further I added some useful logging messages. At the point where the topology update messages are dispatched and received.

           

          Initially when the server starts up the count of dispatched and received match.

           

          Then load is pushed at the server. Using a benchmark.

          After 12 seconds the ability of the server to process messages collapses.

           

          Doing a subsequent count of the dispatched at 118 and received 116. A discrepancy of 2.

          This indicates messages dispatched on the channel are being lost.

           

          I'll continue investigating where the packets go missing.