Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-3576

Test AddressBasedDestinationTest#testDeleteOptions fails against CPP broker occasionally

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Won't Fix
    • 0.13
    • None
    • Java Tests, JMS AMQP 0-x
    • None

    Description

      Test AddressBasedDestinationTest#testDeleteOptions fails against CPP broker occasionally.

      It appears that CPP broker is responding to QueueQuery request with an ExecutionException response instead of ExecutionResult QueueQueryResult.

      We ran test in a loop. Every 2-4 minutes tests failed with the following error

      Error closing session: org.apache.qpid.AMQException: timed out waiting for sync: complete = 33, point = 35 [error code 541: internal error]

      javax.jms.JMSException: Error closing session: org.apache.qpid.AMQException: timed out waiting for sync: complete = 33, point = 35 [error code 541: internal error]
at org.apache.qpid.client.AMQSession.close(AMQSession.java:766)
at org.apache.qpid.client.AMQSession.close(AMQSession.java:726)
at org.apache.qpid.client.AMQConnection.closeAllSessions(AMQConnection.java:941)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:835)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:824)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:808)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:799)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:794)
at org.apache.qpid.test.client.destination.AddressBasedDestinationTest.tearDown(AddressBasedDestinationTest.java:81)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:240)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:135)
Caused by: org.apache.qpid.AMQException: timed out waiting for sync: complete = 33, point = 35 [error code 541: internal error]
at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1041)
at org.apache.qpid.client.AMQSession_0_10.sendClose(AMQSession_0_10.java:417)
at org.apache.qpid.client.AMQSession.close(AMQSession.java:760)

      The following snippet from the test log indicates the issue:

      BROKER: 2011-11-02 13:38:51 trace RECV [127.0.0.1:15672-127.0.0.1:45043]: Frame[BEbe; channel=0; {QueueDeleteBody: queue=testQueue3; }]
BROKER: 2011-11-02 13:38:51 trace guest@QPID.201476f7-bdc6-4ba8-a37f-111c1d87ab2a: recv cmd 34: {QueueDeleteBody: queue=testQueue3; }
BROKER: 2011-11-02 13:38:51 debug Unbinding key [testQueue3] from queue testQueue3 on exchange  origin=)
BROKER: 2011-11-02 13:38:51 trace Management object marked deleted: org.apache.qpid.broker:binding:org.apache.qpid.broker:exchange:,org.apache.qpid.broker:queue:testQueue3,testQueue3
BROKER: 2011-11-02 13:38:51 debug SEND raiseEvent (v1) class=org.apache.qpid.broker.queueDelete
BROKER: 2011-11-02 13:38:51 debug SEND raiseEvent (v2) class=org.apache.qpid.broker.queueDelete
BROKER: 2011-11-02 13:38:51 debug guest@QPID.201476f7-bdc6-4ba8-a37f-111c1d87ab2a: receiver marked completed: 34 incomplete: { } unknown-completed: { [1,34] }
BROKER: 2011-11-02 13:38:51 trace RECV [127.0.0.1:15672-127.0.0.1:45043]: Frame[BEbe; channel=0; {QueueQueryBody: queue=testQueue3; }]
BROKER: 2011-11-02 13:38:51 trace guest@QPID.201476f7-bdc6-4ba8-a37f-111c1d87ab2a: recv cmd 35: {QueueQueryBody: queue=testQueue3; }
BROKER: 2011-11-02 13:38:51 debug guest@QPID.201476f7-bdc6-4ba8-a37f-111c1d87ab2a: receiver marked completed: 35 incomplete: { } unknown-completed: { [1,35] }
BROKER: 2011-11-02 13:38:51 trace guest@QPID.201476f7-bdc6-4ba8-a37f-111c1d87ab2a: sent cmd 8: {ExecutionResultBody: command-id=35; value=\x08\x01\x00\x00; }
BROKER: 2011-11-02 13:38:51 debug Exception constructed: Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415)
BROKER: 2011-11-02 13:38:51 debug Exception constructed: Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415)
BROKER: 2011-11-02 13:38:51 error Execution exception (during output): Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415)
BROKER: 2011-11-02 13:38:51 trace SENT [127.0.0.1:15672-127.0.0.1:45043]: Frame[BEbe; channel=0; {ExecutionResultBody: command-id=35; value=\x08\x01\x00\x00; }]
BROKER: 2011-11-02 13:38:51 trace SENT [127.0.0.1:15672-127.0.0.1:45043]: Frame[BEbe; channel=0; {ExecutionExceptionBody: error-code=408; command-id=0; class-code=0; command-code=0; field-index=0; description=Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415); error-info={}; }]
BROKER: 2011-11-02 13:38:51 trace SENT [127.0.0.1:15672-127.0.0.1:45043]: Frame[BEbe; channel=0; {SessionDetachBody: name=201476f7-bdc6-4ba8-a37f-111c1d87ab2a; }]
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,719 DEBUG [apache.qpid.transport.Connection] RECV: [conn:4b455d1c] ch=0 ExecutionResult(commandId=35, value=QueueQueryResult())
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,719 DEBUG [apache.qpid.transport.Session] ID: [0] 8
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,719 DEBUG [apache.qpid.transport.Session] ssn:"201476f7-bdc6-4ba8-a37f-111c1d87ab2a" processed([8, 8]) 7 7
main 2011-11-02 13:38:51,720 INFO [apache.qpid.client.AMQSession] Closing session: org.apache.qpid.client.AMQSession_0_10@69107c05
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,720 DEBUG [apache.qpid.transport.Session] {[0, 7]}
main 2011-11-02 13:38:51,720 INFO [apache.qpid.client.BasicMessageConsumer] Closing consumer:3[72177013]
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,720 DEBUG [apache.qpid.transport.Connection] RECV: [conn:4b455d1c] ch=0 ExecutionException(errorCode=RESOURCE_DELETED, commandId=0, classCode=0, commandCode=0, fieldIndex=0, description=Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415), errorInfo={})  
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,720 DEBUG [apache.qpid.transport.Session] ID: [0] 9
Dispatcher-Channel-0 2011-11-02 13:38:51,720 INFO [qpid.client.AMQSession.Dispatcher] Dispatcher-Channel-0 thread terminating for channel 0:org.apache.qpid.client.AMQSession_0_10@69107c05
IoReceiver - localhost/127.0.0.1:15672 2011-11-02 13:38:51,720 DEBUG [apache.qpid.client.AMQConnection] exceptionReceived done by:IoReceiver - localhost/127.0.0.1:15672
org.apache.qpid.AMQException: ch=0 id=9 ExecutionException(errorCode=RESOURCE_DELETED, commandId=0, classCode=0, commandCode=0, fieldIndex=0, description=Queue testQueue3 has been deleted. (qpid/broker/Queue.cpp:1415), errorInfo={}) [error code 408: Request Timeout]
        at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1066)
        at org.apache.qpid.client.AMQSession_0_10.exception(AMQSession_0_10.java:924)
        at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:160)
        at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:32)
        at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
        at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50)
        at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:32)
        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.executionException(MethodDelegate.java:110)
        at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
        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.transport.Connection.received(Connection.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.transport.network.io.IoReceiver.run(IoReceiver.java:151)
        at java.lang.Thread.run(Thread.java:662)

      Attachments

        Activity

          People

            Unassigned Unassigned
            orudyy Alex Rudyy
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: