Qpid
  1. Qpid
  2. QPID-3819

ExhaustiveACLTests can timeout (but still pass) during teardown [0-9-1]

    Details

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

      Description

      On the 0-9-1 test profiles we sometimes see ExhaustiveACLTest take 30 or 60 seconds then pass. On investigation I see that we are logging an error, but the test is still passing:

      main 2012-02-07 13:57:19,657 ERROR [apache.qpid.client.AMQConnection] error:
      org.apache.qpid.AMQTimeoutException: Close did not complete in timely fashion [error code 408: Request Timeout]
              at org.apache.qpid.client.AMQConnectionDelegate_8_0.closeConnection(AMQConnectionDelegate_8_0.java:91)
              at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:865)
              at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:832)
              at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:816)
              at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:807)
              at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:802)
              at org.apache.qpid.test.utils.QpidBrokerTestCase.tearDown(QpidBrokerTestCase.java:1047)
              at org.apache.qpid.server.security.acl.AbstractACLTestCase.tearDown(AbstractACLTestCase.java:105)
              at junit.framework.TestCase.runBare(TestCase.java:130)
              at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:237)
              at junit.framework.TestResult$1.protect(TestResult.java:106)
              at junit.framework.TestResult.runProtected(TestResult.java:124)
              at junit.framework.TestResult.run(TestResult.java:109)
              at junit.framework.TestCase.run(TestCase.java:118)
              at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:138)
              at junit.framework.TestSuite.runTest(TestSuite.java:208)
              at junit.framework.TestSuite.run(TestSuite.java:203)
              at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:422)
              at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:931)
              at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:785)
      Caused by: org.apache.qpid.AMQTimeoutException: Server did not respond in a timely fashion [error code 408: Request Timeout]
              at org.apache.qpid.client.util.BlockingWaiter.block(BlockingWaiter.java:178)
              at org.apache.qpid.client.state.StateWaiter.await(StateWaiter.java:111)
              at org.apache.qpid.client.AMQConnectionDelegate_8_0.closeConnection(AMQConnectionDelegate_8_0.java:87)
              ... 19 more
      
      

        Activity

        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open In Progress In Progress
        1d 22h 11m 1 Keith Wall 09/Feb/12 13:23
        In Progress In Progress Reviewable Reviewable
        1h 36m 1 Keith Wall 09/Feb/12 15:00
        Reviewable Reviewable Resolved Resolved
        4d 19h 36m 1 Robbie Gemmell 14/Feb/12 10:36
        Robbie Gemmell made changes -
        Status Ready To Review [ 10006 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Robbie Gemmell added a comment -

        Looks reasonable to me.

        Show
        Robbie Gemmell added a comment - Looks reasonable to me.
        Keith Wall made changes -
        Assignee Keith Wall [ k-wall ] Robbie Gemmell [ gemmellr ]
        Keith Wall made changes -
        Fix Version/s 0.15 [ 12319043 ]
        Keith Wall made changes -
        Status In Progress [ 3 ] Ready To Review [ 10006 ]
        Hide
        Keith Wall added a comment -

        Patch applied, Robbie can you review please?

        Show
        Keith Wall added a comment - Patch applied, Robbie can you review please?
        Keith Wall made changes -
        Affects Version/s 0.14 [ 12316855 ]
        Keith Wall made changes -
        Field Original Value New Value
        Status Open [ 1 ] In Progress [ 3 ]
        Hide
        Keith Wall added a comment -

        This problem was caused by the changes made to AMQStateManager by QPID-3512. Those changes mean the client's close call hangs awaiting the state change from CONNECTION_CLOSING => CONNECTION_CLOSED. This state change now never occurs. It is probably best to revert the change to AMQStateManager and refactor ConnectionCloseTest to avoid the sporadic test failure.

        Show
        Keith Wall added a comment - This problem was caused by the changes made to AMQStateManager by QPID-3512 . Those changes mean the client's close call hangs awaiting the state change from CONNECTION_CLOSING => CONNECTION_CLOSED. This state change now never occurs. It is probably best to revert the change to AMQStateManager and refactor ConnectionCloseTest to avoid the sporadic test failure.
        Keith Wall created issue -

          People

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

            Dates

            • Created:
              Updated:
              Resolved:

              Development