Uploaded image for project: 'JBoss A-MQ'
  1. JBoss A-MQ
  2. ENTMQ-1119

Messages sent from qpid jms client using local transaction got lost when PFC kicks in although broker trace level log shows message commit

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • JBoss A-MQ 6.2.1
    • JBoss A-MQ 6.2
    • amqp, broker
    • None

      I have done some testing with standalone ActiveMQ distribution apache-activemq-5.11.0.redhat-620133-bin.zip from JBoss A-MQ 6.2 "extras/" folder, Qpid JMS client 0.3 and a producer provided in qpid-jms-example:
      https://github.com/apache/qpid-jms/tree/0.3.0The broker has the following configuration:
      1. Queue policy, PFC configured for 1MB:| <policyEntry queue=">" producerFlowControl="true" memoryLimit="1mb" cursorMemoryHighWaterMark="101" expireMessagesPeriod="60000"/>|

      2. Persistence configured with KahaDB and concurrent store and dispatch set to false to avoid parallel threads on the broker:| <kahaDB directory="${activemq.data}/kahadb" concurrentStoreAndDispatchQueues="false"/>|

      3. Holding the producer for 30s and then sending an exception| <systemUsage sendFailIfNoSpaceAfterTimeout="30000">|

      4. The connector with a producer credit of 60 messages and enforcing synchronous communication:| <transportConnector name="amqp" uri="amqp://0.0.0.0:63611?transport.transformer=jms&transport.producerCredit=60&sync_all=true"/>|

      I have tweaked the client code so that the session is transactional and every message gets committed after the call to the send method. Also I changed the message body so that it is approximately 10KB. I also set following env variables:| export PN_TRACE_FRM=true|

      export CLASSPATH=.:target/classes:lib/geronimo-jms_1.1_spec-1.1.1.jar:lib/netty-all-4.0.17.Final.jar:lib/proton-j-0.9.1.jar:lib/qpid-jms-client-0.3.0.jar:lib/qpid-jms-discovery-0.3.0.jar:lib/slf4j-api-1.7.12.jar

      so that I can follow the protocol exchanges in the logs and set CLASSPATH for java client call.Here is the client call with parameters:| java -Dqpid.flow_control_wait_failure=100000 -Dqpid.flow_control_wait_notify_period=1000 -cp $CLASSPATH org.apache.qpid.jms.example.Sender|

      After I let my producer creating messages in a loop (500 iterations) the producer gets blocked after ~109 messages but when I browse the queue only 94 of them are on the broker. Note: the 108 messages have been accepted by the broker, at least it is what the qpid logs pretend and the messages haven't expired. If I set the producer credit to 1000 all the messages get allegedly accepted by the broker but still only 94 of them are actually on the broker.The Qpid client did not stop after the 94th message when the PFC kicked in and the option "sendFailIfNoSpaceAfterTimeout" was still in play. It was eventually blocked on 109th message. And the messages from 94th to 108th were seen as accepted from the qpid jms client side. Furthermore, the broker's TRACE level logs also confirmed that the local transactions were committed for these messages. However, they were never persisted into the broker and after the broker was restarted only 94 messages were on the broker.I also tried to connect a qpid jms receiver to the same queue to consume some messages when the "sendFailIfNoSpaceAfterTimeout" was still in play to allow PFC to be lifted on the queue in order to allow the qpid jms sender client to continuously send in more messages:| java -Dqpid.flow_control_wait_failure=100000 -Dqpid.flow_control_wait_notify_period=1000 -cp $CLASSPATH org.apache.qpid.jms.example.Receiver|

      However, the messages from 95th to 108th were never received by the the qpid jms receiver client but only messages from 1st to 94th and then from 109th to the last message 500th were received.It could be the issue with the qpid jms client as it should stop on 94th message when PFC kicks in. But obviously broker side has an issue too. Despite the TRACE level logs showed commit for the messages (from 95th to 108th), they were never seen but lost.The bottom line is that the messages should either be seen as accepted on the client and available on broker for consumers till the producer credit has been exhausted or be rejected by the broker and the qpid client should hold the connection and stop sending further messages. The records in the qpid logs don't seem to be consistent in that sense. The broker seems on one hand to have accepted the messages (confer state=Accepted{}) and to have lost them (or rejected them) on the other hand. This conflicting information is likely to be due to the nullPointerException later in the qpid jms client logs. Here is part of the logs that I have commented. I will attach the complete logs.I'll also attach the entire test case I used to demonstrate this issue.

        1. testcase.zip
          2.52 MB
        2. activemq.xml
          6 kB

              tbish@redhat.com Timothy Bish (Inactive)
              rhn-support-qluo Joe Luo
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: