Qpid
  1. Qpid
  2. QPID-3683

FailoverBehaviourTest.testPublishClientAcknowledgedWithFailoverMutex/testPublishTransactedAcknowledgedWithFailoverMutex failing regularly on Jenkins.

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.15
    • Component/s: Java Broker, Java Client
    • Labels:
      None

      Description

      We are seeing the following tests

      org.apache.qpid.client.failover.FailoverBehaviourTest.testPublishClientAcknowledgedWithFailoverMutex
      org.apache.qpid.client.failover.FailoverBehaviourTest.testPublishTransactedAcknowledgedWithFailoverMutex

      fail very regularly on Jenkins.

        Issue Links

          Activity

          Keith Wall created issue -
          Hide
          Keith Wall added a comment -

          It appears that the failing cases are suffering a ConcurrentModificationException:

          IoReceiver - /127.0.0.1:49538 2011-12-14 13:20:34,413 ERROR [qpid.server.transport.ServerSessionDelegate] Exception processing command
          java.util.ConcurrentModificationException
                  at java.util.Hashtable$Enumerator.next(Hashtable.java:1031)
                  at org.apache.commons.collections.iterators.FilterIterator.setNextObject(FilterIterator.java:183)
                  at org.apache.commons.collections.iterators.FilterIterator.hasNext(FilterIterator.java:93)
                  at org.apache.commons.configuration.CompositeConfiguration.getKeys(CompositeConfiguration.java:236)
                  at org.apache.commons.configuration.SubsetConfiguration.getKeys(SubsetConfiguration.java:200)
                  at org.apache.commons.configuration.CompositeConfiguration.getKeys(CompositeConfiguration.java:214)
                  at org.apache.qpid.server.configuration.plugins.ConfigurationPlugin.setConfiguration(ConfigurationPlugin.java:87)
                  at org.apache.qpid.server.configuration.QueueConfiguration.<init>(QueueConfiguration.java:44)
                  at org.apache.qpid.server.configuration.VirtualHostConfiguration.getQueueConfiguration(VirtualHostConfiguration.java:146)
                  at org.apache.qpid.server.queue.AMQQueueFactory.createAMQQueueImpl(AMQQueueFactory.java:256)
                  at org.apache.qpid.server.transport.ServerSessionDelegate.createQueue(ServerSessionDelegate.java:1116)
                  at org.apache.qpid.server.transport.ServerSessionDelegate.queueDeclare(ServerSessionDelegate.java:952)
                  at org.apache.qpid.server.transport.ServerSessionDelegate.queueDeclare(ServerSessionDelegate.java:99)
                  at org.apache.qpid.transport.QueueDeclare.dispatch(QueueDeclare.java:108)
                  at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50)
                  at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:122)
                  at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:99)
                  at org.apache.qpid.transport.Method.delegate(Method.java:159)
                  at org.apache.qpid.transport.Session.received(Session.java:545)
                  at org.apache.qpid.transport.Connection.dispatch(Connection.java:422)
                  at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
                  at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
                  at org.apache.qpid.transport.MethodDelegate.queueDeclare(MethodDelegate.java:206)
                  at org.apache.qpid.transport.QueueDeclare.dispatch(QueueDeclare.java:108)
                  at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
                  at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
                  at org.apache.qpid.transport.Method.delegate(Method.java:159)
                  at org.apache.qpid.transport.Connection.received(Connection.java:387)
                  at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:232)
                  at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:66)
                  at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:95)
                  at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:196)
                  at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:129)
                  at org.apache.qpid.transport.network.Frame.delegate(Frame.java:133)
                  at org.apache.qpid.transport.network.Assembler.received(Assembler.java:100)
                  at org.apache.qpid.transport.network.Assembler.received(Assembler.java:42)
                  at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:187)
                  at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:103)
                  at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:42)
                  at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:111)
                  at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:36)
                  at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:153)
                  at java.lang.Thread.run(Thread.java:662)
          
          Show
          Keith Wall added a comment - It appears that the failing cases are suffering a ConcurrentModificationException: IoReceiver - /127.0.0.1:49538 2011-12-14 13:20:34,413 ERROR [qpid.server.transport.ServerSessionDelegate] Exception processing command java.util.ConcurrentModificationException at java.util.Hashtable$Enumerator.next(Hashtable.java:1031) at org.apache.commons.collections.iterators.FilterIterator.setNextObject(FilterIterator.java:183) at org.apache.commons.collections.iterators.FilterIterator.hasNext(FilterIterator.java:93) at org.apache.commons.configuration.CompositeConfiguration.getKeys(CompositeConfiguration.java:236) at org.apache.commons.configuration.SubsetConfiguration.getKeys(SubsetConfiguration.java:200) at org.apache.commons.configuration.CompositeConfiguration.getKeys(CompositeConfiguration.java:214) at org.apache.qpid.server.configuration.plugins.ConfigurationPlugin.setConfiguration(ConfigurationPlugin.java:87) at org.apache.qpid.server.configuration.QueueConfiguration.<init>(QueueConfiguration.java:44) at org.apache.qpid.server.configuration.VirtualHostConfiguration.getQueueConfiguration(VirtualHostConfiguration.java:146) at org.apache.qpid.server.queue.AMQQueueFactory.createAMQQueueImpl(AMQQueueFactory.java:256) at org.apache.qpid.server.transport.ServerSessionDelegate.createQueue(ServerSessionDelegate.java:1116) at org.apache.qpid.server.transport.ServerSessionDelegate.queueDeclare(ServerSessionDelegate.java:952) at org.apache.qpid.server.transport.ServerSessionDelegate.queueDeclare(ServerSessionDelegate.java:99) at org.apache.qpid.transport.QueueDeclare.dispatch(QueueDeclare.java:108) at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50) at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:122) at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:99) at org.apache.qpid.transport.Method.delegate(Method.java:159) at org.apache.qpid.transport.Session.received(Session.java:545) at org.apache.qpid.transport.Connection.dispatch(Connection.java:422) at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64) at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40) at org.apache.qpid.transport.MethodDelegate.queueDeclare(MethodDelegate.java:206) at org.apache.qpid.transport.QueueDeclare.dispatch(QueueDeclare.java:108) at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54) at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40) at org.apache.qpid.transport.Method.delegate(Method.java:159) at org.apache.qpid.transport.Connection.received(Connection.java:387) at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:232) at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:66) at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:95) at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:196) at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:129) at org.apache.qpid.transport.network.Frame.delegate(Frame.java:133) at org.apache.qpid.transport.network.Assembler.received(Assembler.java:100) at org.apache.qpid.transport.network.Assembler.received(Assembler.java:42) at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:187) at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:103) at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:42) at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:111) at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:36) at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:153) at java.lang. Thread .run( Thread .java:662)
          Keith Wall made changes -
          Field Original Value New Value
          Status Open [ 1 ] In Progress [ 3 ]
          Keith Wall made changes -
          Status In Progress [ 3 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Keith Wall made changes -
          Link This issue requires QPID-3691 [ QPID-3691 ]
          Hide
          Keith Wall added a comment -

          This is a Broker side problem that only manifests itself when Broker is co-located with the testing framework.

          Investigation shows that on the occasions that fail, the QpidBrokerTestCase#tearDown is underway whilst the QueueDeclare is being processed (the QueueDeclate is part of the client's resubscribe activity after failover).

          The tearDown reverts changes to system properties. The QueueDeclare uses the Configuration object to create a QueueConfiguration for the new queue. There is an unlucky timing where thread processing the QueueDeclare can be interating the configuration keys whilst in the main thread, #tearDown is removing the test system properties. As the Configuration is formed from a composite configuration comprising config.xml + system properties, the modification to the system properties can give rise to the ConcurrentModificationException.

          The underlying problem here is QPID-3691. The client should not proceed (i.e report failover complete) until it knows the resubscribe activity is complete (i.e. synch'd).

          Show
          Keith Wall added a comment - This is a Broker side problem that only manifests itself when Broker is co-located with the testing framework. Investigation shows that on the occasions that fail, the QpidBrokerTestCase#tearDown is underway whilst the QueueDeclare is being processed (the QueueDeclate is part of the client's resubscribe activity after failover). The tearDown reverts changes to system properties. The QueueDeclare uses the Configuration object to create a QueueConfiguration for the new queue. There is an unlucky timing where thread processing the QueueDeclare can be interating the configuration keys whilst in the main thread, #tearDown is removing the test system properties. As the Configuration is formed from a composite configuration comprising config.xml + system properties, the modification to the system properties can give rise to the ConcurrentModificationException. The underlying problem here is QPID-3691 . The client should not proceed (i.e report failover complete) until it knows the resubscribe activity is complete (i.e. synch'd).
          Keith Wall made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Transition Time In Source Status Execution Times Last Executer Last Execution Date
          Open Open In Progress In Progress
          1h 27m 1 Keith Wall 14/Dec/11 13:38
          In Progress In Progress Resolved Resolved
          1d 23h 17m 1 Keith Wall 16/Dec/11 12:55
          Resolved Resolved Closed Closed
          4h 12m 1 Keith Wall 16/Dec/11 17:07

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Development