[ https://issues.apache.org/jira/browse/CAMEL-12971?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Alexey Kachalov updated CAMEL-12971: ------------------------------------ Description: We use Apache ActiveMQ 5.15.2 and Camel 2.20.2. When we switched to use camel-sjms instead of camel-jms we sometimes get this error: {code:java} 2018-11-30 20:39:33,264 +0300 INFO 19 [TransactionContext] commit failed for transaction TX:ID:a-kachalov-61507-1543599563462-1:1:2 javax.jms.JMSException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1399) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1428) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.BatchSynchronizationReproduceTest$2.answer(BatchSynchronizationReproduceTest.java:66) ~[classes/:?] at org.apache.activemq.TransactionContext.commit(TransactionContext.java:330) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.ActiveMQSession.commit(ActiveMQSession.java:582) [activemq-client-5.15.2.jar:?] at org.apache.camel.component.sjms.tx.SessionBatchTransactionSynchronization$TimeoutTask.run(SessionBatchTransactionSynchronization.java:135) [camel-sjms-2.20.2.jar:2.20.2] at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_73] at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_73] Caused by: javax.transaction.xa.XAException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.transaction.Transaction.newXAException(Transaction.java:213) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:115) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] Caused by: javax.jms.TransactionRolledBackException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:116) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] Caused by: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 9, responseRequired = false, ackType = 2, consumerId = ID:a-kachalov-61507-1543599563462-1:1:1:1, firstMessageId = ID:a-kachalov-61507-1543599563462-1:2:1:1:1, lastMessageId = ID:a-kachalov-61507-1543599563462-1:2:1:1:2, destination = queue://TEST.QUEUE, transactionId = TX:ID:a-kachalov-61507-1543599563462-1:1:2, messageCount = 2, poisonCause = null}; Could not find Message-ID ID:a-kachalov-61507-1543599563462-1:2:1:1:1 in dispatched-list (start of ack) at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:473) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:213) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:528) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:475) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:581) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.MessageAck.visit(MessageAck.java:245) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] {code} This happens because Batch Transaction Timer expires and commit is done in it own thread. We use a route such as {code:java} sjms:queue:TEST.QUEUE?transacted=true&transactionBatchCount=30&transactionBatchTimeout=1000 {code} Steps of reproducing: * The first message is dispatched to consumer * Consumer waits the next message, but Timer expired and SessionBatchTransactionSynchronization.TimeoutTask executes in another thread and invokes commit() method * Commit consist of 3 operations: beforeEnd(), asyncSendPacket(...) and afterCommit() methods * When beforeEnd() finishes, transactionId is set to NULL, and consumer sends an acknowledgement to ActiveMQ via method ActiveMQConnection.asyncSendPacket. * While asyncSendPacket() is executing, new message can be dispatched to consumer * Because transactionId = null method TransactionContext.begin() produces new TransactionId in TransactionContext and set synchronizations list to NULL (but we remember that asyncSendPacket is executing yet) * After asyncSendPacket() method finished afterCommit() method does nothing, because synchronizations = NULL, that means deliveredMessages collection of ActiveMQMessageConsumer can not be cleared * when Consumer sends the next acknowledgement, it sends acknowledgement for it message again, but ActimeMQ removed it before. I wrote a test reproducing the error. Real case is more complex in production and now we can't use batch transactions with SJMS. was: We use Apache ActiveMQ 5.15.2 and Camel 2.20.2. When we switched to use camel-sjms instead of camel-jms we sometimes get this error: {code:java} 2018-11-30 20:39:33,264 +0300 INFO 19 [TransactionContext] commit failed for transaction TX:ID:a-kachalov-61507-1543599563462-1:1:2 javax.jms.JMSException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1399) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1428) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.BatchSynchronizationReproduceTest$2.answer(BatchSynchronizationReproduceTest.java:66) ~[classes/:?] at org.apache.activemq.TransactionContext.commit(TransactionContext.java:330) ~[activemq-client-5.15.2.jar:?] at org.apache.activemq.ActiveMQSession.commit(ActiveMQSession.java:582) [activemq-client-5.15.2.jar:?] at org.apache.camel.component.sjms.tx.SessionBatchTransactionSynchronization$TimeoutTask.run(SessionBatchTransactionSynchronization.java:135) [camel-sjms-2.20.2.jar:2.20.2] at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_73] at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_73] Caused by: javax.transaction.xa.XAException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.transaction.Transaction.newXAException(Transaction.java:213) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:115) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] Caused by: javax.jms.TransactionRolledBackException: COMMIT FAILED: Transaction marked rollback only xaErrorCode:100 at org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:116) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] Caused by: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 9, responseRequired = false, ackType = 2, consumerId = ID:a-kachalov-61507-1543599563462-1:1:1:1, firstMessageId = ID:a-kachalov-61507-1543599563462-1:2:1:1:1, lastMessageId = ID:a-kachalov-61507-1543599563462-1:2:1:1:2, destination = queue://TEST.QUEUE, transactionId = TX:ID:a-kachalov-61507-1543599563462-1:1:2, messageCount = 2, poisonCause = null}; Could not find Message-ID ID:a-kachalov-61507-1543599563462-1:2:1:1:1 in dispatched-list (start of ack) at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:473) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:213) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:528) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:475) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:581) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.command.MessageAck.visit(MessageAck.java:245) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) ~[activemq-broker-5.15.2.jar:5.15.2] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) ~[activemq-client-5.15.2.jar:5.15.2] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) ~[activemq-client-5.15.2.jar:5.15.2] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] {code} This happens because Batch Transaction Timer expires and commit is done in it own thread. We use a route such as {code:java} sjms:queue:TEST.QUEUE?transacted=true&transactionBatchCount=30&transactionBatchTimeout=1000 {code} Steps of reproducing: * The first message is dispatched to consumer * Consumer waits the next message, but Timer expired and SessionBatchTransactionSynchronization.TimeoutTask executes in another thread and invokes commit() method * Commit consist of 3 operations: beforeEnd(), asyncSendPacket(...) and afterCommit() methods * When beforeEnd() finishes, transactionId is set to NULL, and consumer sends an acknowledgement to ActiveMQ via method ActiveMQConnection.asyncSendPacket. * While asyncSendPacket() is executing, new message can be dispatched to consumer * Because transactionId = null method TransactionContext.begin() produces new TransactionId in TransactionContext and set synchronizations list to NULL (but we remember that asyncSendPacket is executing yet) * After asyncSendPacket() method finished afterCommit() method does nothing, because synchronizations = NULL, that means deliveredMessages collection of ActiveMQMessageConsumer can not be cleared * when Consumer sends the next acknowledgement, it sends acknowledgement for it message again, but ActimeMQ removed it. I wrote a test reproducing the error. Real case is more complex in production and now we can't use batch transactions with SJMS. > SJMS Component javax.jms.JMSException: Unmatched acknowledge: MessageAck when > transactionBatchTimeout expired > ------------------------------------------------------------------------------------------------------------- > > Key: CAMEL-12971 > URL: https://issues.apache.org/jira/browse/CAMEL-12971 > Project: Camel > Issue Type: Bug > Components: camel-sjms > Affects Versions: 2.20.2 > Reporter: Alexey Kachalov > Priority: Major > Attachments: BatchSynchronizationReproduceTest.java, test-result.log > > > We use Apache ActiveMQ 5.15.2 and Camel 2.20.2. > When we switched to use camel-sjms instead of camel-jms we sometimes get > this error: > {code:java} > 2018-11-30 20:39:33,264 +0300 INFO 19 [TransactionContext] commit failed for > transaction TX:ID:a-kachalov-61507-1543599563462-1:1:2 > javax.jms.JMSException: COMMIT FAILED: Transaction marked rollback only > xaErrorCode:100 > at > org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1399) > ~[activemq-client-5.15.2.jar:?] > at > org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1428) > ~[activemq-client-5.15.2.jar:?] > at > org.apache.activemq.BatchSynchronizationReproduceTest$2.answer(BatchSynchronizationReproduceTest.java:66) > ~[classes/:?] > at > org.apache.activemq.TransactionContext.commit(TransactionContext.java:330) > ~[activemq-client-5.15.2.jar:?] > at org.apache.activemq.ActiveMQSession.commit(ActiveMQSession.java:582) > [activemq-client-5.15.2.jar:?] > at > org.apache.camel.component.sjms.tx.SessionBatchTransactionSynchronization$TimeoutTask.run(SessionBatchTransactionSynchronization.java:135) > [camel-sjms-2.20.2.jar:2.20.2] > at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_73] > at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_73] > Caused by: javax.transaction.xa.XAException: COMMIT FAILED: Transaction > marked rollback only xaErrorCode:100 > at > org.apache.activemq.transaction.Transaction.newXAException(Transaction.java:213) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:115) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) > ~[activemq-client-5.15.2.jar:5.15.2] > at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] > Caused by: javax.jms.TransactionRolledBackException: COMMIT FAILED: > Transaction marked rollback only xaErrorCode:100 > at > org.apache.activemq.transaction.Transaction.prePrepare(Transaction.java:116) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:54) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:529) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) > ~[activemq-client-5.15.2.jar:5.15.2] > at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] > Caused by: javax.jms.JMSException: Unmatched acknowledge: MessageAck > {commandId = 9, responseRequired = false, ackType = 2, consumerId = > ID:a-kachalov-61507-1543599563462-1:1:1:1, firstMessageId = > ID:a-kachalov-61507-1543599563462-1:2:1:1:1, lastMessageId = > ID:a-kachalov-61507-1543599563462-1:2:1:1:2, destination = > queue://TEST.QUEUE, transactionId = > TX:ID:a-kachalov-61507-1543599563462-1:1:2, messageCount = 2, poisonCause = > null}; Could not find Message-ID ID:a-kachalov-61507-1543599563462-1:2:1:1:1 > in dispatched-list (start of ack) > at > org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:473) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:213) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:528) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:475) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:581) > ~[activemq-broker-5.15.2.jar:5.15.2] > at org.apache.activemq.command.MessageAck.visit(MessageAck.java:245) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194) > ~[activemq-broker-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:235) > ~[activemq-client-5.15.2.jar:5.15.2] > at > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:216) > ~[activemq-client-5.15.2.jar:5.15.2] > at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_73] > {code} > This happens because Batch Transaction Timer expires and commit is done in it > own thread. > We use a route such as > {code:java} > sjms:queue:TEST.QUEUE?transacted=true&transactionBatchCount=30&transactionBatchTimeout=1000 > {code} > > Steps of reproducing: > * The first message is dispatched to consumer > * Consumer waits the next message, but Timer expired and > SessionBatchTransactionSynchronization.TimeoutTask executes in another thread > and invokes commit() method > * Commit consist of 3 operations: beforeEnd(), asyncSendPacket(...) and > afterCommit() methods > * When beforeEnd() finishes, transactionId is set to NULL, and consumer > sends an acknowledgement to ActiveMQ via method > ActiveMQConnection.asyncSendPacket. > * While asyncSendPacket() is executing, new message can be dispatched to > consumer > * Because transactionId = null method TransactionContext.begin() produces > new TransactionId in TransactionContext and set synchronizations list to NULL > (but we remember that asyncSendPacket is executing yet) > * After asyncSendPacket() method finished afterCommit() method does nothing, > because synchronizations = NULL, that means deliveredMessages collection of > ActiveMQMessageConsumer can not be cleared > * when Consumer sends the next acknowledgement, it sends acknowledgement for > it message again, but ActimeMQ removed it before. > I wrote a test reproducing the error. Real case is more complex in production > and now we can't use batch transactions with SJMS. > -- This message was sent by Atlassian JIRA (v7.6.3#76005)