When doing small transactions, the java client times out waiting for a response from the c++ broker. Using qpid-queue-stats tool I could see that the client does consume a few messages transactionally and then at one point when it does a sync after sending a commit, the broker fails to respond in a timely manner. [java] java.lang.RuntimeException: timed out waiting for sync [java] at org.apache.qpidity.transport.Session.sync(Session.java:334) [java] at org.apache.qpidity.transport.Session.sync(Session.java:293) [java] at org.apache.qpidity.nclient.impl.ClientSession.sync(ClientSession.java:107) [java] at org.apache.qpid.client.AMQSession_0_10.sendCommit(AMQSession_0_10.java:225) [java] at org.apache.qpid.client.AMQSession_0_10.commit(AMQSession_0_10.java:770) [java] at org.jboss.jms.example.PerfExample$PerfListener.checkCommit(PerfExample.java:344) [java] at org.jboss.jms.example.PerfExample$PerfListener.onMessage(PerfExample.java:317) [java] at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:688) [java] at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:151) [java] at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:647) [java] at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:259) [java] at org.apache.qpid.client.AMQSession$Dispatcher.dispatchMessage(AMQSession.java:2848) [java] at org.apache.qpid.client.AMQSession$Dispatcher.run(AMQSession.java:2770)
The following extract from amd-38.coe.lga.redhat.com:/home/rajith/qpid/cpp/broker.log suggests that the broker did respond with a completed: 63868:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[BEbe; channel=1; {SessionCompletedBody: commands={ [0,1348] }; }] 64517:2008-jun-06 12:58:43 trace RECV [10.15.60.33:55383]: Frame[BEbe; channel=1; {SessionCompletedBody: commands={ [780,1334] }; }] 64518:2008-jun-06 12:58:43 trace RECV [10.15.60.33:55383]: Frame[BEbe; channel=1; {MessageAcceptBody: transfers={ [1333,1334] }; }] 64519:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[Bbe; channel=1; {MessageTransferBody: destination=1; accept-mode=0; acquire-mode=0; }] 64520:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[be; channel=1; header (110 bytes); properties={{MessageProperties: content-length=1024; message-id=5c783b76-ec0a-4ece-97e5-fdebe2bd36cc; content-type=application/octet-stream; application-headers={}; }{DeliveryProperties: priority=0; delivery-mode=2; timestamp=1212771506401; expiration=0; exchange=amq.direct; routing-key=MyQueue; }}] 64521:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[Ebe; channel=1; content (1024 bytes) \00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00...] 64522:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[Bbe; channel=1; {MessageTransferBody: destination=1; accept-mode=0; acquire-mode=0; }] 64523:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[be; channel=1; header (110 bytes); properties={{MessageProperties: content-length=1024; message-id=aea20ee6-4da2-42f5-9fa0-f58084ea56ab; content-type=application/octet-stream; application-headers={}; }{DeliveryProperties: priority=0; delivery-mode=2; timestamp=1212771506404; expiration=0; exchange=amq.direct; routing-key=MyQueue; }}] 64524:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[Ebe; channel=1; content (1024 bytes) \00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00...] 64525:2008-jun-06 12:58:43 trace RECV [10.15.60.33:55383]: Frame[BEbe; channel=1; {TxCommitBody: }] 64527:2008-jun-06 12:58:43 trace SENT [10.15.60.33:55383]: Frame[BEbe; channel=1; {SessionCompletedBody: commands={ [0,1350] }; }] 251804:2008-jun-06 12:59:43 trace RECV [10.15.60.33:55383]: Frame[BEbe; channel=1; {SessionCompletedBody: commands={ [780,1336] }; }] 251805:2008-jun-06 12:59:43 trace SENT [10.15.60.33:55383]: Frame[Bbe; channel=1; {MessageTransferBody: destination=1; accept-mode=0; acquire-mode=0; }]
This turned out to be due to an OOM error on the java client that was being swallowed and prevented the IO thread from continuing. That in turn was due to a very large buffer being created for each message (2M even though only 1k was used). This meant the incoming, unprocessed message queue was very large (up to 1000 messages of 2M each!). The issue has been resolved by setting a lower default maximum size which can still be overridden.
qpidc-0.2.667603-1.el5, qpidc-perftest-0.2.667603-1.el5, qpidd-0.2.667603-1.el5, and rhm-0.2.2153-1.el5 have been pushed to the staging repo for testing