[jboss-jira] [JBoss JIRA] (WFWIP-15) [Artemis 2.x upgrade] Broken managed connections after suspending remote broker

[Artemis 2.x upgrade] Broken managed connections after suspending remote broker ------------------------------------------------------------------------------- Key: WFWIP-15 URL: https://issues.jboss.org/browse/WFWIP-15 Project: WildFly WIP Issue Type: Bug Components: Artemis Reporter: Miroslav Novak Assignee: Martyn Taylor Priority: Blocker Labels: activemq, feature-branch-blocker Test Scenario: * Start 2 servers in cluster with deployed InQueue and OutQueue (jms cluster) * Send 50000 messages (10KB) to InQueue * Start 2 other servers (mdb nodes) which have configured remote JCA to connect to jms cluster * Deploy MDB to each mdb node ** MDB consumes messages from InQueue and resend to OutQueue * Suspend one of JMS servers (node-3) for 5 minutes when MDBs are processing messages * Resume JMS servers and wait for MDBs to process all messages Pass Criteria: All messages sent to InQueue well get to OutQueue Actual Result: There are errors on one of the MDB servers node-4 after node-3 is resumed: {code} 21:35:05,813 ERROR [org.jboss.qa.hornetq.apps.mdb.MdbWithRemoteOutQueueWithOutQueueLookups] (Thread-168 (ActiveMQ-client-global-threads)) Could not create a session: IJ000453: Unable to get managed connection fo r java:/JmsXA: javax.jms.JMSException: Could not create a session: IJ000453: Unable to get managed connection for java:/JmsXA at org.apache.activemq.artemis.ra.ActiveMQRASessionFactoryImpl.allocateConnection(ActiveMQRASessionFactoryImpl.java:909) at org.apache.activemq.artemis.ra.ActiveMQRASessionFactoryImpl.createSession(ActiveMQRASessionFactoryImpl.java:531) at org.jboss.qa.hornetq.apps.mdb.MdbWithRemoteOutQueueWithOutQueueLookups.onMessage(MdbWithRemoteOutQueueWithOutQueueLookups.java:89) [lodhLikemdb1.jar:] at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) [:1.8.0_162] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_162] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_162] at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:253) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:332) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPS HOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:243) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNA PSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:243) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNA PSHOT] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619) [wildfly-elytron-1.2.2.Final.jar:1.2.2.Final] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198) at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185) at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81) at org.jboss.qa.hornetq.apps.mdb.MdbWithRemoteOutQueueWithOutQueueLookups$$$view1.onMessage(Unknown Source) [lodhLikemdb1.jar:] at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) [:1.8.0_162] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_162] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_162] at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:139) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [wildfly-ejb3-13.0.0.Alpha1-SNAPSHOT.jar:13.0.0.Alpha1-SNAPSHOT] at org.jboss.qa.hornetq.apps.mdb.MdbWithRemoteOutQueueWithOutQueueLookups$$$endpoint1.onMessage(Unknown Source) [lodhLikemdb1.jar:] at org.apache.activemq.artemis.ra.inflow.ActiveMQMessageHandler.onMessage(ActiveMQMessageHandler.java:302) at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1002) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.access$400(ClientConsumerImpl.java:50) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1125) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.5.0.jar:2.5.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_162] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_162] Caused by: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/JmsXA at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:690) at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:430) at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:789) at org.apache.activemq.artemis.ra.ActiveMQRASessionFactoryImpl.allocateConnection(ActiveMQRASessionFactoryImpl.java:872) ... 69 more Caused by: javax.resource.ResourceException: IJ000655: No managed connections available within configured blocking timeout (30000 [ms]) at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:570) at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:714) at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:613) at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:624) ... 72 more {code} later on there are errors: {code} 21:35:52,119 WARN [org.apache.activemq.artemis.core.client] (Thread-218 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,120 WARN [org.apache.activemq.artemis.core.client] (Thread-208 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,122 WARN [org.apache.activemq.artemis.core.client] (Thread-161 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,123 WARN [org.apache.activemq.artemis.core.client] (Thread-172 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,124 WARN [org.apache.activemq.artemis.core.client] (Thread-167 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,124 WARN [org.apache.activemq.artemis.core.client] (Thread-174 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,124 WARN [org.apache.activemq.artemis.core.client] (Thread-176 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,124 WARN [org.apache.activemq.artemis.core.client] (Thread-196 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:52,124 WARN [org.apache.activemq.artemis.core.client] (Thread-157 (ActiveMQ-client-global-threads)) AMQ212009: resetting session after failure 21:35:53,087 WARN [org.apache.activemq.artemis.core.client] (Thread-163 (ActiveMQ-client-global-threads)) AMQ212052: Packet PACKET(SessionXAResponseMessage)[type=55, channelID=10, packetObject=SessionXAResponse Message, error=false, message=null, responseCode=0] was answered out of sequence due to a previous server timeout and it's being ignored: java.lang.Exception: trace at org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:395) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:319) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.sessionStop(ActiveMQSessionContext.java:399) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.stop(ClientSessionImpl.java:1019) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.stop(ClientSessionImpl.java:1008) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.rollback(ClientSessionImpl.java:912) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.rollback(ClientSessionImpl.java:895) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.resetIfNeeded(ClientSessionImpl.java:985) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.ra.inflow.ActiveMQMessageHandler.onMessage(ActiveMQMessageHandler.java:371) at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1002) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.access$400(ClientConsumerImpl.java:50) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1125) [artemis-core-client-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.5.0.jar:2.5.0] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.5.0.jar:2.5.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_162] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_162] at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.5.0.jar:2.5.0] {code} However mdb server never recovers from this situation. It seems that all managed connections are left in broken state.