Qpid
  1. Qpid
  2. QPID-4052

HAClusterTwoNodeTest.testSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped occasionally fails on Apache CI

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 0.17
    • Fix Version/s: 0.17
    • Component/s: Java Broker, Java Tests
    • Labels:
      None

      Description

      New HA test is showing occasionally failures on Apache CI e.g. builds 297 and 298.

      https://builds.apache.org/view/M-R/view/Qpid/job/Qpid-Java-Java-BDB-TestMatrix/297/jdk=JDK%201.6%20%28latest%29,label=Ubuntu,profile=java-bdb.0-10/testReport/junit/org.apache.qpid.server.store.berkeleydb/HAClusterTwoNodeTest/testSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped/

      https://builds.apache.org/view/M-R/view/Qpid/job/Qpid-Java-Java-BDB-TestMatrix/298/jdk=JDK%201.6%20%28latest%29,label=Ubuntu,profile=java-bdb.0-10/testReport/org.apache.qpid.server.store.berkeleydb/HAClusterTwoNodeTest/testSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped/

      javax.jms.JMSException: Error creating connection: Connection refused
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:159)
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:134)
      	at org.apache.qpid.test.utils.QpidBrokerTestCase.getConnection(QpidBrokerTestCase.java:1038)
      	at org.apache.qpid.server.store.berkeleydb.HAClusterTwoNodeTest.testSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped(HAClusterTwoNodeTest.java:189)
      	at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:237)
      	at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:139)
      Caused by: org.apache.qpid.AMQConnectionFailureException: Connection refused
      	at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:444)
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:155)
      Caused by: org.apache.qpid.transport.TransportException: Error connecting to broker
      	at org.apache.qpid.transport.network.io.IoNetworkTransport.connect(IoNetworkTransport.java:82)
      	at org.apache.qpid.transport.Connection.connect(Connection.java:235)
      	at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:219)
      	at org.apache.qpid.client.AMQConnection.makeBrokerConnection(AMQConnection.java:588)
      	at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:367)
      Caused by: java.net.ConnectException: Connection refused
      	at java.net.PlainSocketImpl.socketConnect(Native Method)
      	at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
      	at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
      	at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
      	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
      	at java.net.Socket.connect(Socket.java:529)
      	at org.apache.qpid.transport.network.io.IoNetworkTransport.connect(IoNetworkTransport.java:78)
      

        Activity

        Hide
        Keith Wall added a comment -

        This is a timing issue within the test. From the logs you are see that the client burns all its chances to connect before the node has designated primary has been made master.

        Here are the pertinent parts of the log showing the designation as primary, the client's attempts to connect, followed by the primary becoming master.
        Notice that the client burns most of its attempts to connect before the primary becomes master.

        Giving the client more chances to connect will resolve this issue.

        BROKER: RMI TCP Connection(2)-67.195.138.60 2012-06-12 17:04:02,638 INFO [server.store.berkeleydb.BDBHAMessageStore] Node nodetestSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped10003 successfully set as designated primary for group
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:02,640 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:02,641 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,750 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,764 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,764 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,765 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,777 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,789 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,790 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,790 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,801 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,813 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,814 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,815 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,826 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,848 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,849 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,849 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:07,861 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ********
        BROKER: UNKNOWN nodetestSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped10003(2) 2012-06-12 17:04:08,411 INFO [server.store.berkeleydb.BDBHAMessageStore] Received BDB event indicating transition to state MASTER
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:08,415 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:08,416 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        
        Show
        Keith Wall added a comment - This is a timing issue within the test. From the logs you are see that the client burns all its chances to connect before the node has designated primary has been made master. Here are the pertinent parts of the log showing the designation as primary, the client's attempts to connect, followed by the primary becoming master. Notice that the client burns most of its attempts to connect before the primary becomes master. Giving the client more chances to connect will resolve this issue. BROKER: RMI TCP Connection(2)-67.195.138.60 2012-06-12 17:04:02,638 INFO [server.store.berkeleydb.BDBHAMessageStore] Node nodetestSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped10003 successfully set as designated primary for group MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:02,640 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:02,641 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,750 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,764 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,764 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:03,765 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,777 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,789 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,790 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:04,790 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,801 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,813 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,814 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:05,815 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,826 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,848 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,849 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:06,849 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:07,861 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10002 vhost: test username: guest password: ******** BROKER: UNKNOWN nodetestSecondaryDesignatedAsPrimaryAfterOrginalPrimaryStopped10003(2) 2012-06-12 17:04:08,411 INFO [server.store.berkeleydb.BDBHAMessageStore] Received BDB event indicating transition to state MASTER MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:08,415 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ******** MASTER nodetestSetSystemConfiguration10000(1) 2012-06-12 17:04:08,416 DEBUG [apache.qpid.client.AMQConnectionDelegate_0_10] connecting to host: localhost port: 10000 vhost: test username: guest password: ********
        Hide
        Keith Wall added a comment -

        Patch applied.

        Show
        Keith Wall added a comment - Patch applied.
        Hide
        Robbie Gemmell added a comment -

        Resolving.

        Show
        Robbie Gemmell added a comment - Resolving.

          People

          • Assignee:
            Philip Harvey
            Reporter:
            Keith Wall
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development