Uploaded image for project: 'Qpid JMS'
  1. Qpid JMS
  2. QPIDJMS-154

Failover mechanism does not handle connection URLs in a predictable way

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 0.8.0
    • Fix Version/s: 0.9.0
    • Component/s: qpid-jms-client
    • Labels:
      None

      Description

      As discussed in this link, if the links provided in the failover URL are ordered in a way to have the Replicate first and then the Master. Then the connection will fail and an error will be thrown client-side.

      This is because the multi-threading behavior in the FailoverProvider is not correct. The main thread will not wait for the connection trial thread to try and find the active Master node. If we add a Sleep or debug the main thread to give the connection trial thread enough time to find the Master URL then the test works

      Log in case of failure:

      2016-03-11 10:46:31 DEBUG FailoverProvider:160 - Initiating initial connection attempt task
      2016-03-11 10:46:33 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:10352?amqp.vhost=weather in-progress
      2016-03-11 10:46:34 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
      2016-03-11 10:46:34 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Received error from remote peer without description [condition = amqp:not-found]
      2016-03-11 10:46:34 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found]
      2016-03-11 10:46:34 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:5672?amqp.vhost=weather in-progress
      2016-03-11 10:46:31 DEBUG FailoverProvider:160 - Initiating initial connection attempt task
      2016-03-11 10:46:33 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:10352?amqp.vhost=weather in-progress
      2016-03-11 10:46:34 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
      2016-03-11 10:46:34 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Received error from remote peer without description [condition = amqp:not-found]
      2016-03-11 10:46:34 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found]
      2016-03-11 10:46:34 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:5672?amqp.vhost=weather in-progress
      

      Logs in case we debug the main thread to allow the connection thread to finish:

      2016-03-11 11:03:37 DEBUG FailoverProvider:160 - Initiating initial connection attempt task
      2016-03-11 11:04:05 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:10352?amqp.vhost=weather in-progress
      2016-03-11 11:04:18 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
      2016-03-11 11:04:18 DEBUG FailoverProvider:985 - Request received error: Cannot send to a non-connected transport.
      2016-03-11 11:04:18 DEBUG FailoverProvider:519 - handling Provider failure: Cannot send to a non-connected transport.
      2016-03-11 11:04:18 DEBUG FailoverProvider:985 - Request received error: Cannot send to a non-connected transport.
      2016-03-11 11:04:18 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Cannot send to a non-connected transport.
      2016-03-11 11:04:18 DEBUG FailoverProvider:519 - handling Provider failure: Cannot send to a non-connected transport.
      2016-03-11 11:04:18 DEBUG FailoverProvider:519 - handling Provider failure: Cannot send to a non-connected transport.
      2016-03-11 11:04:40 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:5672?amqp.vhost=weather in-progress
      2016-03-11 11:04:41 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
      2016-03-11 11:04:42 INFO  JmsConnection:1114 - Connection ID::af28891b-adbe-47f1-9da2-ad03f124a215:1 connected to remote Broker: amqp://localhost:5672
      2016-03-11 11:04:42 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsSessionInfo {} (2)
      

      Test code:

      @Test
      public void testScalabilityReversedOrder() throws JMSException {
          String brokerUrl = "failover:(amqp://localhost:10352,amqp://localhost:5672)?failover.nested.amqp.vhost=weather";
          ConnectionFactory connectionFactory = new JmsConnectionFactory(brokerUrl);
          Connection connection = connectionFactory.createConnection();
          Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
      }
      
      1. broker2.png
        278 kB
        Adel Boutros
      2. Broker1.png
        273 kB
        Adel Boutros
      There are no Sub-Tasks for this issue.

        Activity

        Hide
        tabish121 Timothy Bish added a comment -

        Great, just glad it's all working now.

        Show
        tabish121 Timothy Bish added a comment - Great, just glad it's all working now.
        Hide
        sta191919@gmail.com Adel Boutros added a comment -

        You were absolutely right. When I closed the connection properly after each test, they are all run successfully. So for me the issue is fixed.

        I really apologize for missing out on the connection closing stuff.

        Show
        sta191919@gmail.com Adel Boutros added a comment - You were absolutely right. When I closed the connection properly after each test, they are all run successfully. So for me the issue is fixed. I really apologize for missing out on the connection closing stuff.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit 274fff802dfae00f5722ceebbc952362fcbe4e54 in qpid-jms's branch refs/heads/master from Timothy Bish
        [ https://git-wip-us.apache.org/repos/asf?p=qpid-jms.git;h=274fff8 ]

        https://issues.apache.org/jira/browse/QPIDJMS-154

        Add more testing for connection state after failure to connect when the
        peer sends error info.

        Show
        jira-bot ASF subversion and git services added a comment - Commit 274fff802dfae00f5722ceebbc952362fcbe4e54 in qpid-jms's branch refs/heads/master from Timothy Bish [ https://git-wip-us.apache.org/repos/asf?p=qpid-jms.git;h=274fff8 ] https://issues.apache.org/jira/browse/QPIDJMS-154 Add more testing for connection state after failure to connect when the peer sends error info.
        Hide
        tabish121 Timothy Bish added a comment -

        I tried reproducing this in an client side integration test and could not. One thing I don't see in the test you have posted is clean-up code for the previously opened connections / consumers, is there such code? Don't want to chase something if there is just a rogue consumer still running in the background given that both calls run consumers on the same Queue.

        Show
        tabish121 Timothy Bish added a comment - I tried reproducing this in an client side integration test and could not. One thing I don't see in the test you have posted is clean-up code for the previously opened connections / consumers, is there such code? Don't want to chase something if there is just a rogue consumer still running in the background given that both calls run consumers on the same Queue.
        Hide
        tabish121 Timothy Bish added a comment -

        So this looks like it is a different issue from the original which means it might be best to open a new one to track it.

        Show
        tabish121 Timothy Bish added a comment - So this looks like it is a different issue from the original which means it might be best to open a new one to track it.
        Hide
        sta191919@gmail.com Adel Boutros added a comment - - edited

        I have spoken too soon. Actually, the session is being created but the consumer cannot receive any message. Its call to receive is timeouting. In the below code, the 2nd test is failing.

        PS: The Master node is the one listening on 5672. The other 2 nodes are REPLICA

        Successful test Log:

        2016-03-15 17:29:35 DEBUG FailoverProvider:160 - Initiating initial connection attempt task
        2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:5672?amqp.vhost=weather in-progress
        2016-03-15 17:29:35 DEBUG InternalLoggerFactory:71 - Using SLF4J as the default logging framework
        2016-03-15 17:29:35 DEBUG MultithreadEventLoopGroup:76 - -Dio.netty.eventLoopThreads: 24
        2016-03-15 17:29:35 DEBUG PlatformDependent:71 - Platform: Windows
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - Java version: 7
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noUnsafe: false
        2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.ByteBuffer.cleaner: available
        2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.Buffer.address: available
        2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - sun.misc.Unsafe.theUnsafe: available
        2016-03-15 17:29:35 DEBUG PlatformDependent0:71 - sun.misc.Unsafe.copyMemory: available
        2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.Bits.unaligned: true
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - sun.misc.Unsafe: available
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noJavassist: false
        2016-03-15 17:29:35 DEBUG PlatformDependent:71 - Javassist: available
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.tmpdir: C:\Users\aboutros\AppData\Local\Temp (java.io.tmpdir)
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.bitMode: 64 (sun.arch.data.model)
        2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noPreferDirect: false
        2016-03-15 17:29:35 DEBUG NioEventLoop:76 - -Dio.netty.noKeySetOptimization: false
        2016-03-15 17:29:35 DEBUG NioEventLoop:76 - -Dio.netty.selectorAutoRebuildThreshold: 512
        2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.numHeapArenas: 12
        2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.numDirectArenas: 12
        2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.pageSize: 8192
        2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.maxOrder: 11
        2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.chunkSize: 16777216
        2016-03-15 17:29:35 DEBUG ThreadLocalRandom:71 - -Dio.netty.initialSeedUniquifier: 0xfef29df1ac8a8913
        2016-03-15 17:29:35 DEBUG ChannelOutboundBuffer:76 - -Dio.netty.threadLocalDirectBufferSize: 65536
        2016-03-15 17:29:35 DEBUG ByteBufUtil:76 - -Dio.netty.allocator.type: unpooled
        2016-03-15 17:29:35 DEBUG JavassistTypeParameterMatcherGenerator:76 - Generated: io.netty.util.internal.__matchers__.io.netty.buffer.ByteBufMatcher
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
        2016-03-15 17:29:35 DEBUG ResourceLeakDetector:81 - -Dio.netty.leakDetectionLevel: simple
        2016-03-15 17:29:35 INFO  SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS
        2016-03-15 17:29:35 DEBUG AmqpConnectionBuilder:71 - AmqpConnection { ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1 } is now open: 
        2016-03-15 17:29:35 INFO  JmsConnection:1114 - Connection ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1 connected to remote Broker: amqp://localhost:5672
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsSessionInfo {} (2)
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConsumerInfo {} (3)
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (4)
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 2, messageId = ID::0f3b2678-1251-4481-b1d5-930f787eec8b:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 3, messageId = ID::c64f2b79-f126-4ed1-8822-8d9c8f6e784b:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsProducerInfo {} (5)
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 4, messageId = ID::f47b9f24-f740-4b76-b981-de25b91e87df:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 5, messageId = ID::e8c5f733-7382-4b29-a217-b8f3b5bc4617:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 6, messageId = ID::666cf19b-9b9e-4d2b-bea8-6572cef030e6:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 7, messageId = ID::f92beb52-b724-47a7-b3b9-80aa68a37d5d:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 8, messageId = ID::eed9e416-3a6c-4980-8eb3-dc29ebfeafd4:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG AmqpSession:98 - Creating AmqpFixedProducer for: scalabilityQueue
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: send -> JmsOutboundMessageDispatch {dispatchId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1-1 (6)
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 9, messageId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: message acknowledge -> JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} ackType: ACCEPTED (7)
        2016-03-15 17:29:35 DEBUG AmqpConsumer:241 - Accepted Ack of message: JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        

        Failing test Log:

        2016-03-15 17:29:35 DEBUG FailoverProvider:160 - Initiating initial connection attempt task
        2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:10354?amqp.vhost=weather in-progress
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
        2016-03-15 17:29:35 INFO  SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS
        2016-03-15 17:29:35 INFO  AmqpAbstractResource:127 - Resource JmsConnectionInfo {} was remotely closed
        2016-03-15 17:29:35 DEBUG FailoverProvider:1078 - Request received error: Received error from remote peer without description [condition = amqp:not-found]
        2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found]
        2016-03-15 17:29:35 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Received error from remote peer without description [condition = amqp:not-found]
        2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found]
        2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:10352?amqp.vhost=weather in-progress
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
        2016-03-15 17:29:35 DEBUG AmqpProvider:746 - Transport connection remotely closed
        2016-03-15 17:29:35 DEBUG FailoverProvider:1078 - Request received error: Transport connection remotely closed.
        2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Transport connection remotely closed.
        2016-03-15 17:29:35 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Transport connection remotely closed.
        2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp://localhost:5672?amqp.vhost=weather in-progress
        2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Transport connection remotely closed.
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1)
        2016-03-15 17:29:35 INFO  SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS
        2016-03-15 17:29:35 DEBUG AmqpConnectionBuilder:71 - AmqpConnection { ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1 } is now open: 
        2016-03-15 17:29:35 INFO  JmsConnection:1114 - Connection ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1 connected to remote Broker: amqp://localhost:5672
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsSessionInfo {} (2)
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConsumerInfo {} (3)
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (4)
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsProducerInfo {} (5)
        2016-03-15 17:29:35 DEBUG AmqpSession:98 - Creating AmqpFixedProducer for: scalabilityQueue
        2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: send -> JmsOutboundMessageDispatch {dispatchId = ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1-1 (6)
        2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 10, messageId = ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1}
        2016-03-15 17:29:40 DEBUG FailoverProvider:963 - Executing Failover Task: message pull -> ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1 (7)
        2016-03-15 17:29:40 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (8)
        
        java.lang.AssertionError: expecting actual value not to be null
        
        	at org.fest.assertions.Fail.failure(Fail.java:228)
        	at org.fest.assertions.Fail.fail(Fail.java:167)
        	at org.fest.assertions.Fail.failIfActualIsNull(Fail.java:100)
        	at org.fest.assertions.GenericAssert.isNotNull(GenericAssert.java:238)
        	at test.ScalabilityTest.exchangeMessages(ScalabilityTest.java:50)
        	at test.ScalabilityTest.testScalabilityReversedOrder(ScalabilityTest.java:33)
        	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:606)
        	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
        	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
        	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
        	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
        	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
        	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
        	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
        	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
        	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
        	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
        	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
        	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
        	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
        	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
        	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
        	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:606)
        	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
        
        import javax.jms.*;
        
        import org.apache.qpid.jms.JmsConnectionFactory;
        
        import static org.fest.assertions.Assertions.assertThat;
        
        import org.junit.Test;
        
        
        public class ScalabilityTest {
        
            //~ ----------------------------------------------------------------------------------------------------------------
            //~ Methods 
            //~ ----------------------------------------------------------------------------------------------------------------
        
            @Test
            public void testScalability() throws JMSException {
                String brokerUrl = "failover:(amqp://localhost:5672,amqp://localhost:10354,amqp://localhost:10352)?failover.nested.amqp.vhost=weather";
                exchangeMessages(brokerUrl);
            }
        
            @Test
            public void testScalabilityReversedOrder() throws JMSException {
                String brokerUrl = "failover:(amqp://localhost:10354,amqp://localhost:10352,amqp://localhost:5672)?failover.nested.amqp.vhost=weather";
                exchangeMessages(brokerUrl);
            }
        
            private void exchangeMessages(String brokerUrl) throws JMSException {
                ConnectionFactory connectionFactory = new JmsConnectionFactory(brokerUrl);
                Connection connection = connectionFactory.createConnection();
                Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
                connection.start();
                Queue queue = session.createQueue("scalabilityQueue");
        
                MessageConsumer consumer = session.createConsumer(queue);
                TextMessage message = session.createTextMessage("Hello world!");
                MessageProducer producer = session.createProducer(queue);
                producer.send(message);
        
                TextMessage receivedMessage = (TextMessage) consumer.receive(5000);
        
                assertThat(receivedMessage).isNotNull();
                assertThat(receivedMessage.getText()).isEqualTo(message.getText());
            }
        }
        
        Show
        sta191919@gmail.com Adel Boutros added a comment - - edited I have spoken too soon. Actually, the session is being created but the consumer cannot receive any message. Its call to receive is timeouting. In the below code, the 2nd test is failing. PS: The Master node is the one listening on 5672. The other 2 nodes are REPLICA Successful test Log: 2016-03-15 17:29:35 DEBUG FailoverProvider:160 - Initiating initial connection attempt task 2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp: //localhost:5672?amqp.vhost=weather in-progress 2016-03-15 17:29:35 DEBUG InternalLoggerFactory:71 - Using SLF4J as the default logging framework 2016-03-15 17:29:35 DEBUG MultithreadEventLoopGroup:76 - -Dio.netty.eventLoopThreads: 24 2016-03-15 17:29:35 DEBUG PlatformDependent:71 - Platform: Windows 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - Java version: 7 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noUnsafe: false 2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.ByteBuffer.cleaner: available 2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.Buffer.address: available 2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - sun.misc.Unsafe.theUnsafe: available 2016-03-15 17:29:35 DEBUG PlatformDependent0:71 - sun.misc.Unsafe.copyMemory: available 2016-03-15 17:29:35 DEBUG PlatformDependent0:76 - java.nio.Bits.unaligned: true 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - sun.misc.Unsafe: available 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noJavassist: false 2016-03-15 17:29:35 DEBUG PlatformDependent:71 - Javassist: available 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.tmpdir: C:\Users\aboutros\AppData\Local\Temp (java.io.tmpdir) 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.bitMode: 64 (sun.arch.data.model) 2016-03-15 17:29:35 DEBUG PlatformDependent:76 - -Dio.netty.noPreferDirect: false 2016-03-15 17:29:35 DEBUG NioEventLoop:76 - -Dio.netty.noKeySetOptimization: false 2016-03-15 17:29:35 DEBUG NioEventLoop:76 - -Dio.netty.selectorAutoRebuildThreshold: 512 2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.numHeapArenas: 12 2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.numDirectArenas: 12 2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.pageSize: 8192 2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.maxOrder: 11 2016-03-15 17:29:35 DEBUG PooledByteBufAllocator:76 - -Dio.netty.allocator.chunkSize: 16777216 2016-03-15 17:29:35 DEBUG ThreadLocalRandom:71 - -Dio.netty.initialSeedUniquifier: 0xfef29df1ac8a8913 2016-03-15 17:29:35 DEBUG ChannelOutboundBuffer:76 - -Dio.netty.threadLocalDirectBufferSize: 65536 2016-03-15 17:29:35 DEBUG ByteBufUtil:76 - -Dio.netty.allocator.type: unpooled 2016-03-15 17:29:35 DEBUG JavassistTypeParameterMatcherGenerator:76 - Generated: io.netty.util.internal.__matchers__.io.netty.buffer.ByteBufMatcher 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1) 2016-03-15 17:29:35 DEBUG ResourceLeakDetector:81 - -Dio.netty.leakDetectionLevel: simple 2016-03-15 17:29:35 INFO SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS 2016-03-15 17:29:35 DEBUG AmqpConnectionBuilder:71 - AmqpConnection { ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1 } is now open: 2016-03-15 17:29:35 INFO JmsConnection:1114 - Connection ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1 connected to remote Broker: amqp: //localhost:5672 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsSessionInfo {} (2) 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConsumerInfo {} (3) 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (4) 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 2, messageId = ID::0f3b2678-1251-4481-b1d5-930f787eec8b:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 3, messageId = ID::c64f2b79-f126-4ed1-8822-8d9c8f6e784b:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsProducerInfo {} (5) 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 4, messageId = ID::f47b9f24-f740-4b76-b981-de25b91e87df:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 5, messageId = ID::e8c5f733-7382-4b29-a217-b8f3b5bc4617:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 6, messageId = ID::666cf19b-9b9e-4d2b-bea8-6572cef030e6:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 7, messageId = ID::f92beb52-b724-47a7-b3b9-80aa68a37d5d:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 8, messageId = ID::eed9e416-3a6c-4980-8eb3-dc29ebfeafd4:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG AmqpSession:98 - Creating AmqpFixedProducer for : scalabilityQueue 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: send -> JmsOutboundMessageDispatch {dispatchId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1-1 (6) 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 9, messageId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: message acknowledge -> JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} ackType: ACCEPTED (7) 2016-03-15 17:29:35 DEBUG AmqpConsumer:241 - Accepted Ack of message: JmsInboundMessageDispatch {sequence = 1, messageId = ID::d1b9561b-d32f-4a0b-a083-70dda07d6675:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} Failing test Log: 2016-03-15 17:29:35 DEBUG FailoverProvider:160 - Initiating initial connection attempt task 2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp: //localhost:10354?amqp.vhost=weather in-progress 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1) 2016-03-15 17:29:35 INFO SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS 2016-03-15 17:29:35 INFO AmqpAbstractResource:127 - Resource JmsConnectionInfo {} was remotely closed 2016-03-15 17:29:35 DEBUG FailoverProvider:1078 - Request received error: Received error from remote peer without description [condition = amqp:not-found] 2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found] 2016-03-15 17:29:35 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Received error from remote peer without description [condition = amqp:not-found] 2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Received error from remote peer without description [condition = amqp:not-found] 2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp: //localhost:10352?amqp.vhost=weather in-progress 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1) 2016-03-15 17:29:35 DEBUG AmqpProvider:746 - Transport connection remotely closed 2016-03-15 17:29:35 DEBUG FailoverProvider:1078 - Request received error: Transport connection remotely closed. 2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Transport connection remotely closed. 2016-03-15 17:29:35 DEBUG FailoverProvider:761 - Failover: the provider reports failure: Transport connection remotely closed. 2016-03-15 17:29:35 DEBUG FailoverProvider:653 - Connection attempt:[1] to: amqp: //localhost:5672?amqp.vhost=weather in-progress 2016-03-15 17:29:35 DEBUG FailoverProvider:519 - handling Provider failure: Transport connection remotely closed. 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConnectionInfo {} (1) 2016-03-15 17:29:35 INFO SaslMechanismFinder:93 - Best match for SASL auth was: SASL-ANONYMOUS 2016-03-15 17:29:35 DEBUG AmqpConnectionBuilder:71 - AmqpConnection { ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1 } is now open: 2016-03-15 17:29:35 INFO JmsConnection:1114 - Connection ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1 connected to remote Broker: amqp: //localhost:5672 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsSessionInfo {} (2) 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsConsumerInfo {} (3) 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (4) 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: create -> JmsProducerInfo {} (5) 2016-03-15 17:29:35 DEBUG AmqpSession:98 - Creating AmqpFixedProducer for : scalabilityQueue 2016-03-15 17:29:35 DEBUG FailoverProvider:963 - Executing Failover Task: send -> JmsOutboundMessageDispatch {dispatchId = ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1-1 (6) 2016-03-15 17:29:35 DEBUG AmqpConsumer:520 - Dispatching received message: JmsInboundMessageDispatch {sequence = 10, messageId = ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1-1, consumerId = ID::37eae8b1-14ce-4809-ba78-35ccddcc8b82:1:1:1} 2016-03-15 17:29:40 DEBUG FailoverProvider:963 - Executing Failover Task: message pull -> ID::5f6b0685-5b06-4a24-ae75-8b3bccdc2b1e:1:1:1 (7) 2016-03-15 17:29:40 DEBUG FailoverProvider:963 - Executing Failover Task: start -> JmsConsumerInfo {} (8) java.lang.AssertionError: expecting actual value not to be null at org.fest.assertions.Fail.failure(Fail.java:228) at org.fest.assertions.Fail.fail(Fail.java:167) at org.fest.assertions.Fail.failIfActualIsNull(Fail.java:100) at org.fest.assertions.GenericAssert.isNotNull(GenericAssert.java:238) at test.ScalabilityTest.exchangeMessages(ScalabilityTest.java:50) at test.ScalabilityTest.testScalabilityReversedOrder(ScalabilityTest.java:33) 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:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.junit.runner.JUnitCore.run(JUnitCore.java:160) at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69) at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234) at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74) 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:606) at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144) import javax.jms.*; import org.apache.qpid.jms.JmsConnectionFactory; import static org.fest.assertions.Assertions.assertThat; import org.junit.Test; public class ScalabilityTest { //~ ---------------------------------------------------------------------------------------------------------------- //~ Methods //~ ---------------------------------------------------------------------------------------------------------------- @Test public void testScalability() throws JMSException { String brokerUrl = "failover:(amqp: //localhost:5672,amqp://localhost:10354,amqp://localhost:10352)?failover.nested.amqp.vhost=weather" ; exchangeMessages(brokerUrl); } @Test public void testScalabilityReversedOrder() throws JMSException { String brokerUrl = "failover:(amqp: //localhost:10354,amqp://localhost:10352,amqp://localhost:5672)?failover.nested.amqp.vhost=weather" ; exchangeMessages(brokerUrl); } private void exchangeMessages( String brokerUrl) throws JMSException { ConnectionFactory connectionFactory = new JmsConnectionFactory(brokerUrl); Connection connection = connectionFactory.createConnection(); Session session = connection.createSession( false , Session.AUTO_ACKNOWLEDGE); connection.start(); Queue queue = session.createQueue( "scalabilityQueue" ); MessageConsumer consumer = session.createConsumer(queue); TextMessage message = session.createTextMessage( "Hello world!" ); MessageProducer producer = session.createProducer(queue); producer.send(message); TextMessage receivedMessage = (TextMessage) consumer.receive(5000); assertThat(receivedMessage).isNotNull(); assertThat(receivedMessage.getText()).isEqualTo(message.getText()); } }
        Hide
        tabish121 Timothy Bish added a comment -

        You should be able to build your own snapshot now and it should retry against the alternate host.

        Show
        tabish121 Timothy Bish added a comment - You should be able to build your own snapshot now and it should retry against the alternate host.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit 15f6446ac0bda96230c9dbe0f54b7495911363b6 in qpid-jms's branch refs/heads/master from Timothy Bish
        [ https://git-wip-us.apache.org/repos/asf?p=qpid-jms.git;h=15f6446 ]

        QPIDJMS-154 Don't pass along a JMSException on connect so that attempts
        to connect can continue until stopped by user or by configuration.

        Show
        jira-bot ASF subversion and git services added a comment - Commit 15f6446ac0bda96230c9dbe0f54b7495911363b6 in qpid-jms's branch refs/heads/master from Timothy Bish [ https://git-wip-us.apache.org/repos/asf?p=qpid-jms.git;h=15f6446 ] QPIDJMS-154 Don't pass along a JMSException on connect so that attempts to connect can continue until stopped by user or by configuration.
        Hide
        tabish121 Timothy Bish added a comment -

        When possble it is also helpful to capture a trace of the frames so we can see what is going on under the covers, there's a bit on that in the docs in the logging section at the end here: https://qpid.apache.org/releases/qpid-jms-0.8.0/docs/index.html

        Show
        tabish121 Timothy Bish added a comment - When possble it is also helpful to capture a trace of the frames so we can see what is going on under the covers, there's a bit on that in the docs in the logging section at the end here: https://qpid.apache.org/releases/qpid-jms-0.8.0/docs/index.html
        Hide
        sta191919@gmail.com Adel Boutros added a comment -

        Broker's configuration

        Show
        sta191919@gmail.com Adel Boutros added a comment - Broker's configuration

          People

          • Assignee:
            tabish121 Timothy Bish
            Reporter:
            sta191919@gmail.com Adel Boutros
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development