Loading...

Type: Bug
Resolution: Won't Do
Priority: Major
Fix Version/s: None
Affects Version/s: JBoss A-MQ 6.3
Component/s: camel, jms-client, JTA, RAR
Labels:
None

GSS Priority:

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

It appears that a an transacted ack rollback is not isolated, the session can still ack concurrently if nudged in that direction. The net result is two acks, one with no transaction that succeeds.
The use case is SY, jms-binding - camel-jms spring-dmlc and JTA.
Trace logging:

18:23:09,802 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:4] (ActiveMQ Transport: tcp:///x.y.z:61616@40229) RECEIVED: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338415594, brokerOutTime = 1479338597910, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@65bb1a9, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:23:09,805 TRACE [org.apache.activemq.ActiveMQMessageConsumer] (Camel (camel-4) thread #7 - JmsConsumer[queue/in]) ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38:1 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338415594, brokerOutTime = 1479338597910, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@65bb1a9, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:23:13,927 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:4] (Camel (camel-4) thread #7 - JmsConsumer[queue/in]) SENDING: MessageAck {commandId = 334, responseRequired = false, ackType = 2, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38:1, firstMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, lastMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, destination = queue://queue/in, transactionId = TX:ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38, messageCount = 1, poisonCause = null}
18:23:13,952 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:4] (Camel (camel-4) thread #7 - JmsConsumer[queue/in]) SENDING: MessageAck {commandId = 336, responseRequired = false, ackType = 1, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-13:1:38:1, firstMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, lastMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, destination = queue://queue/in, transactionId = null, messageCount = 1, poisonCause = java.lang.Throwable: Exceeded redelivery policy limit:RedeliveryPolicy {destination = null, collisionAvoidanceFactor = 0.15, maximumRedeliveries = 0, maximumRedeliveryDelay = -1, initialRedeliveryDelay = 1000, useCollisionAvoidance = false, useExponentialBackOff = false, backOffMultiplier = 5.0, redeliveryDelay = 1000}, cause:null}
18:37:47,339 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:110] (ActiveMQ Transport: tcp:///x.y.z:61616@40485) RECEIVED: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-219:1:1:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338603004, brokerOutTime = 1479339475362, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@45429ffd, marshalledProperties = org.apache.activemq.util.ByteSequence@1915be91, dataStructure = null, redeliveryCounter = 1, size = 0, properties = {scheduledJobId=ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, redeliveryDelay=1000}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:37:47,379 TRACE [org.apache.activemq.ActiveMQMessageConsumer] (Camel (camel-4) thread #3 - JmsConsumer[queue/in]) ID:dhcp181-106.boo.com-52135-1479338165120-219:1:1:1 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-219:1:1:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338603004, brokerOutTime = 1479339475362, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@45429ffd, marshalledProperties = org.apache.activemq.util.ByteSequence@1915be91, dataStructure = null, redeliveryCounter = 1, size = 0, properties = {scheduledJobId=ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, redeliveryDelay=1000}, readOnlyProperties = true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:38:32,455 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:125] (ActiveMQ Transport: tcp:///x.y.z:61616@40508) RECEIVED: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338603004, brokerOutTime = 1479339520507, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@5dcc0755, marshalledProperties = org.apache.activemq.util.ByteSequence@7df58d8e, dataStructure = null, redeliveryCounter = 2, size = 0, properties = {scheduledJobId=ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, redeliveryDelay=1000}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:38:32,651 TRACE [org.apache.activemq.ActiveMQMessageConsumer] (Camel (camel-4) thread #8 - JmsConsumer[queue/in]) ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1:1 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1:1, destination = queue://queue/in, message = ActiveMQTextMessage {commandId = 296, responseRequired = false, messageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, originalDestination = null, originalTransactionId = null, producerId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1, destination = queue://queue/in, transactionId = null, expiration = 0, timestamp = 1479338407485, arrival = 0, brokerInTime = 1479338603004, brokerOutTime = 1479339520507, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@5dcc0755, marshalledProperties = org.apache.activemq.util.ByteSequence@7df58d8e, dataStructure = null, redeliveryCounter = 2, size = 0, properties = {scheduledJobId=ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, redeliveryDelay=1000}, readOnlyProperties = true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false, text = <?xml version="1.0" encoding="UTF-8" ?>
18:39:09,779 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:125] (Camel (camel-4) thread #8 - JmsConsumer[queue/in]) SENDING: MessageAck {commandId = 7, responseRequired = false, ackType = 2, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1:1, firstMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, lastMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, destination = queue://queue/in, transactionId = TX:ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1, messageCount = 1, poisonCause = null}
18:39:09,956 DEBUG [org.apache.activemq.transport.TransportLogger.Connection:125] (pool-24-thread-1) SENDING: MessageAck {commandId = 10, responseRequired = false, ackType = 2, consumerId = ID:dhcp181-106.boo.com-52135-1479338165120-249:1:1:1, firstMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, lastMessageId = ID:dhcp181-106.boo.com-53022-1479338331536-1:1:1:1:292, destination = queue://queue/in, transactionId = null, messageCount = 1, poisonCause = null}

is related to

ENTMQ-338 Persistent message lost when java.io.InterruptedIOException happens with manual invervention

Closed

ENTMQBR-479 [ENTMQ-2009] Develop test for:: Contention with RAR localTransaction rollback, non transacted ack in the mix in error

Closed

Details

Description

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates