Geronimo
  1. Geronimo
  2. GERONIMO-6372

RecoveryImpl completing in-progress transactions, XidFactoryImpl needs to be smarter with matching

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.2
    • Fix Version/s: None
    • Component/s: transaction manager
    • Security Level: public (Regular issues)
    • Labels:
      None
    • Environment:

      Aries, OSGI, camel, activemq

    • Patch Info:
      Patch Available

      Description

      Given a camel route with from("activemq:a").to("activemq:b") in a Geronimo managed XA transaction. On start/restart new transactions are created in parallel with recovery of the jms components.
      There are two issues:

      • The Recovery processing can match new transactions through the XidFactory.matchXX methods and rollback new work in error. (Note: a xa_recover of activemq correctly returns all prepared transactions)
      • The XidFactoryImpl(byte[] seed) can create duplicate xids which could potentially interfere with recovering transactions and makes it impossible to determine from the logs what is going on.

      Xids should be globally unique and recoverable. So they need a persistent unique seed (provided through configuration) and an ever increasing id.
      The current time provides a simple approach to an increasing id that negates the need to persist the last used id in the transaction recovery log.
      (It has the downside of regressing if the XidFactory is recreated in the same millisecond, but I think this is in practice improbable outside unit tests.)

      If the id component is keyed of the epoch, a recovering XidFactory can match only old Xids, ones created by it in a previous incarnation. In this way it can avoid completing newly created transactions.

        Issue Links

          Activity

          Hide
          Gary Tully added a comment -

          Patch that modifies XidFactoryImpl to key the sequence id from current time.
          It modifies the branch and globalid match to ignore new xids, ids created sense the start of the XidFactory.
          Additional unit test that verifies the new matching rules.
          A bunch of recovery tests that depended on an existing factory matching xids after a recovery replay were modified to reinitialize the XidFactory before recovery to simulate a restart.

          Show
          Gary Tully added a comment - Patch that modifies XidFactoryImpl to key the sequence id from current time. It modifies the branch and globalid match to ignore new xids, ids created sense the start of the XidFactory. Additional unit test that verifies the new matching rules. A bunch of recovery tests that depended on an existing factory matching xids after a recovery replay were modified to reinitialize the XidFactory before recovery to simulate a restart.
          Hide
          Gary Tully added a comment -

          Here is a snippet from the log when the problem occurs. The brokers stay alive, and the servicemix instance with aries tm and the camel route is restarted. In this example there is a partal impl of the fix such that the globalId does not match but the branchId does. With 2.2, the global id matches so it occurs a little earlier, but the outcome is the same.
          You can see a newly created tx:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000 that is prepared getting rolledback by the recovery processing. The subsequent commit fails with not found. note: Just do a search for that globalId=.. string in the log to get a handle on what is going on.

          19:40:23,421 | INFO  | rint Extender: 3 | BlueprintCamelContext            | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | Total 1 routes, of which 1 is started.
          19:40:23,421 | INFO  | rint Extender: 3 | BlueprintCamelContext            | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | Apache Camel 2.8.0-fuse-06-11 (CamelContext: 225-camel-3) started in 3.062 seconds
          19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,437 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager            | 92 - org.springframework.transaction - 3.0.5.RELEASE | Creating new transaction with name [JmsConsumer[ESB_IN]]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
          19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,437 | TRACE | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-6:1, clientId = ID:nbdubpafox-1818-1341596420578-5:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,437 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61620], from: [tcp://localhost:61620]
          19:40:23,453 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,484 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61620
          19:40:23,500 | DEBUG | ActiveMQ Task-2  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,500 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,500 | INFO  | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61620
          19:40:23,500 | TRACE | /127.0.0.1:61620 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61620 starting
          19:40:23,500 | DEBUG | /127.0.0.1:61620 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,500 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,515 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,515 | TRACE | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-8:1, clientId = ID:nbdubpafox-1818-1341596420578-7:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,515 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61620], from: [tcp://localhost:61620]
          19:40:23,515 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61620
          19:40:23,531 | DEBUG | ActiveMQ Task-1  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,531 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,531 | INFO  | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61620
          19:40:23,531 | TRACE | /127.0.0.1:61620 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61620 starting
          19:40:23,531 | DEBUG | /127.0.0.1:61620 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,546 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,546 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Start called on XAResource activemq.external1
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           flags: TMNOFLAGS
          19:40:23,546 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Start: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,562 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,562 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,562 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,562 | TRACE | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-6:2, clientId = ID:nbdubpafox-1818-1341596420578-5:2, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,562 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61620], from: [tcp://localhost:61620]
          19:40:23,562 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61620
          19:40:23,593 | DEBUG | ActiveMQ Task-2  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,593 | DEBUG | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,593 | INFO  | ActiveMQ Task-2  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61620
          19:40:23,593 | TRACE | Consumer[ESB_IN] | ActiveMQMessageConsumer          | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | ID:nbdubpafox-1818-1341596420578-8:1:1:1 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:nbdubpafox-1818-1341596420578-8:1:1:1, destination = queue://ESB_IN, message = ActiveMQTextMessage {commandId = 2199, responseRequired = false, messageId = ID:nbdubpafox-1656-1341596255125-2:1:1:1:732, originalDestination = null, originalTransactionId = null, producerId = ID:nbdubpafox-1656-1341596255125-2:1:1:1, destination = queue://ESB_IN, transactionId = TX:ID:nbdubpafox-1656-1341596255125-2:1:732, expiration = 0, timestamp = 1341596258265, arrival = 0, brokerInTime = 1341596258265, brokerOutTime = 1341596423562, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 1, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = 731}, redeliveryCounter = 1}
          19:40:23,593 | TRACE | /127.0.0.1:61620 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61620 starting
          19:40:23,593 | DEBUG | /127.0.0.1:61620 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,609 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager            | 92 - org.springframework.transaction - 3.0.5.RELEASE | Participating in existing transaction
          19:40:23,656 | INFO  | Consumer[ESB_IN] | Camel-JMS-XA-Test                | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | GOT MESSAGE ################################ 731
          19:40:23,671 | INFO  | Consumer[ESB_IN] | Camel-JMS-XA-Test                | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | REDELIVERED: true
          19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,671 | TRACE | Consumer[ESB_IN] | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-10:1, clientId = ID:nbdubpafox-1818-1341596420578-9:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,671 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61618], from: [tcp://localhost:61618]
          19:40:23,671 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61618
          19:40:23,703 | DEBUG | ActiveMQ Task-1  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,703 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,703 | INFO  | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61618
          19:40:23,703 | TRACE | /127.0.0.1:61618 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61618 starting
          19:40:23,703 | DEBUG | /127.0.0.1:61618 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,703 | DEBUG | rint Extender: 3 | ActiveMQResourceManager          | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | new namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-6:2,clientId=ID:nbdubpafox-1818-1341596420578-5:2,started=true}
          19:40:23,703 | TRACE | rint Extender: 3 | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Recover called on XAResource activemq.external1
           flags:  TMENDRSCAN TMSTARTRSCAN remaining: 25165824
          19:40:23,703 | DEBUG | rint Extender: 3 | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Recover: 25165824
          19:40:23,718 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Start called on XAResource activemq.external2
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           flags: TMNOFLAGS
          19:40:23,718 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Start: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,718 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,734 | TRACE | Consumer[ESB_IN] | ActiveMQSession                  | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | ID:nbdubpafox-1818-1341596420578-10:1:1 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:nbdubpafox-1818-1341596420578-10:1:1:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:nbdubpafox-1818-1341596420578-10:1:1:1, destination = queue://ESB_OUT, transactionId = XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000], expiration = 0, timestamp = 1341596423734, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {breadcrumbId=ID:nbdubpafox-1656-1341596255125-2:1:1:1:732, CamelJmsDeliveryMode=2}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = 731}
          19:40:23,734 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager            | 92 - org.springframework.transaction - 3.0.5.RELEASE | Initiating transaction commit
          19:40:23,734 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | End called on XAResource activemq.external2
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           flags: TMSUCCESS remaining: 67108864
          19:40:23,734 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | End: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,750 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from
           name: activemq.external1
           [Xid:class=XATransactionId:globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,750 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid was initiated from this tm but not prepared: rolling back
          19:40:23,750 | TRACE | rint Extender: 3 | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external1
           Xid: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,750 | DEBUG | rint Extender: 3 | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,750 | DEBUG | rint Extender: 3 | ActiveMQResourceManager          | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | closing returned namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-6:2,clientId=ID:nbdubpafox-1818-1341596420578-5:2,started=true}
          19:40:23,750 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopped tcp://localhost:61620
          19:40:23,750 | DEBUG | rint Extender: 3 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopping transport tcp://localhost/127.0.0.1:61620
          19:40:23,750 | TRACE | /127.0.0.1:61620 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost:61620 handleTransportFailure: java.io.EOFException
          19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,765 | TRACE | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-12:1, clientId = ID:nbdubpafox-1818-1341596420578-11:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,750 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Ended XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,765 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | End called on XAResource activemq.external1
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           flags: TMSUCCESS remaining: 67108864
          19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | End: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,750 | DEBUG | sRequestorPool-1 | ActiveMQMessageConsumer          | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | remove: ID:nbdubpafox-1818-1341596420578-4:3:1:2, lastDeliveredSequenceId:0
          19:40:23,765 | DEBUG | ActiveMQ Task-2  | AbstractRegion                   | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | default removing consumer: ID:nbdubpafox-1818-1341596420578-4:3:1:2 for destination: queue://org.apache.servicemix.jbi.cluster
          19:40:23,765 | DEBUG | ActiveMQ Task-2  | Queue                            | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | queue://org.apache.servicemix.jbi.cluster remove sub: QueueSubscription: consumer=ID:nbdubpafox-1818-1341596420578-4:3:1:2, destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0, dequeues: 0, dispatched: 0, inflight: 0
          19:40:23,765 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61618], from: [tcp://localhost:61618]
          19:40:23,765 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61618
          19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Ended XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,765 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Prepare called on XAResource activemq.external1
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Prepare: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,765 | DEBUG | ActiveMQ Task-2  | AbstractRegion                   | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | default adding consumer: ID:nbdubpafox-1818-1341596420578-4:3:1:3 for destination: queue://org.apache.servicemix.jbi.cluster
          19:40:23,781 | DEBUG | ActiveMQ Task-1  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,781 | DEBUG | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,781 | INFO  | ActiveMQ Task-1  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61618
          19:40:23,781 | DEBUG | ActiveMQ Task-2  | Queue                            | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | queue://org.apache.servicemix.jbi.cluster add sub: QueueSubscription: consumer=ID:nbdubpafox-1818-1341596420578-4:3:1:3, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0
          19:40:23,781 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Prepare called on XAResource activemq.external2
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,781 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Prepare: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,781 | TRACE | /127.0.0.1:61618 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61618 starting
          19:40:23,781 | DEBUG | /127.0.0.1:61618 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport.
          19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected
          19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task
          19:40:23,796 | TRACE | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:nbdubpafox-1818-1341596420578-12:2, clientId = ID:nbdubpafox-1818-1341596420578-11:2, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false}
          19:40:23,796 | DEBUG | ActiveMQ Task-3  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp://localhost:61618], from: [tcp://localhost:61618]
          19:40:23,796 | DEBUG | ActiveMQ Task-3  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting  0th  connect to: tcp://localhost:61618
          19:40:23,812 | DEBUG | ActiveMQ Task-3  | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,812 | DEBUG | ActiveMQ Task-3  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established
          19:40:23,812 | INFO  | ActiveMQ Task-3  | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp://localhost:61618
          19:40:23,812 | TRACE | /127.0.0.1:61618 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp://localhost/127.0.0.1:61618 starting
          19:40:23,812 | DEBUG | /127.0.0.1:61618 | InactivityMonitor                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true, MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
          19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator             | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=104857600}
          19:40:23,812 | DEBUG | rint Extender: 3 | ActiveMQResourceManager          | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | new namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-12:2,clientId=ID:nbdubpafox-1818-1341596420578-11:2,started=true}
          19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Recover called on XAResource activemq.external2
           flags:  TMENDRSCAN TMSTARTRSCAN remaining: 25165824
          19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Recover: 25165824
          19:40:23,828 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from
           name: activemq.external2
           [Xid:class=XATransactionId:globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,828 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid was initiated from this tm but not prepared: rolling back
          19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external2
           Xid: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,828 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from
           name: activemq.external2
           [Xid:class=XATransactionId:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
          19:40:23,828 | TRACE | rint Extender: 3 | Recovery                         | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid is from an external transaction and was not prepared: rolling back
          19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external2
           Xid: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]
          19:40:23,828 | DEBUG | rint Extender: 3 | ActiveMQResourceManager          | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | closing returned namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-12:2,clientId=ID:nbdubpafox-1818-1341596420578-11:2,started=true}
          19:40:23,843 | TRACE | /127.0.0.1:61618 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp://localhost:61618 handleTransportFailure: java.io.EOFException
          19:40:23,843 | DEBUG | /127.0.0.1:61618 | TcpTransport                     | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopping transport tcp://localhost/127.0.0.1:61618
          19:40:23,843 | DEBUG | rint Extender: 3 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopped tcp://localhost:61618
          19:40:23,843 | WARN  | /127.0.0.1:61618 | FailoverTransport                | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Transport (tcp://127.0.0.1:61618) failed, reason:  java.io.EOFException, not attempting to automatically reconnect
          19:40:23,843 | DEBUG | /127.0.0.1:61618 | ActiveMQConnection               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | transport interrupted, dispatchers: 0
          19:40:23,843 | DEBUG | /127.0.0.1:61618 | ActiveMQConnection               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | notified failover transport (unconnected) of pending interruption processing for: ID:nbdubpafox-1818-1341596420578-12:2
          19:40:23,937 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Commit called on XAResource activemq.external1
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           onePhase:false
          19:40:23,937 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Commit: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64], onePhase=false
          19:40:23,937 | DEBUG | Consumer[ESB_IN] | ActiveMQMessageConsumer          | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | remove: ID:nbdubpafox-1818-1341596420578-8:1:1:1, lastDeliveredSequenceId:26015
          19:40:23,937 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource           | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Commit called on XAResource activemq.external2
           Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64]
           onePhase:false
          19:40:23,937 | DEBUG | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Commit: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64], onePhase=false
          19:40:23,937 | WARN  | Consumer[ESB_IN] | TransactionContext               | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | commit of: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] failed with: javax.jms.JMSException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started.
          javax.jms.JMSException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started.
          	at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:49)
          	at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1298)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.TransactionContext.syncSendPacketWithInterruptionHandling(TransactionContext.java:748)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.TransactionContext.commit(TransactionContext.java:555)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.ra.LocalAndXATransaction.commit(LocalAndXATransaction.java:85)
          	at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.commit(WrapperNamedXAResource.java:54)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.CommitTask.run(CommitTask.java:63)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionImpl.commitResources(TransactionImpl.java:673)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:321)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1009)
          	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
          	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
          	at org.apache.aries.transaction.GeronimoPlatformTransactionManager.commit(GeronimoPlatformTransactionManager.java:76)
          	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_29]
          	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_29]
          	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_29]
          	at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_29]
          	at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:50)[8:org.apache.aries.proxy:0.3.0]
          	at org.apache.aries.proxy.impl.DefaultWrapper.invoke(DefaultWrapper.java:31)[8:org.apache.aries.proxy:0.3.0]
          	at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:78)[8:org.apache.aries.proxy:0.3.0]
          	at $Proxy60.commit(Unknown Source)[92:org.springframework.transaction:3.0.5.RELEASE]
          	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1058)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1050)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:947)[94:org.springframework.jms:3.0.5.RELEASE]
          	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)[:1.6.0_29]
          	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)[:1.6.0_29]
          	at java.lang.Thread.run(Thread.java:662)[:1.6.0_29]
          Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started.
          	at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:380)
          	at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:262)
          	at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:422)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:215)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:197)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	... 1 more
          19:40:23,937 | ERROR | Consumer[ESB_IN] | CommitTask                       | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Unexpected exception committing org.apache.geronimo.transaction.manager.WrapperNamedXAResource@161dc26; continuing to commit other RMs
          javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started.
          	at org.apache.activemq.TransactionContext.toXAException(TransactionContext.java:773)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.TransactionContext.commit(TransactionContext.java:588)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.ra.LocalAndXATransaction.commit(LocalAndXATransaction.java:85)
          	at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.commit(WrapperNamedXAResource.java:54)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.CommitTask.run(CommitTask.java:63)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionImpl.commitResources(TransactionImpl.java:673)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:321)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT]
          	at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1009)
          	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
          	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
          	at org.apache.aries.transaction.GeronimoPlatformTransactionManager.commit(GeronimoPlatformTransactionManager.java:76)
          	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_29]
          	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_29]
          	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_29]
          	at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_29]
          	at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:50)[8:org.apache.aries.proxy:0.3.0]
          	at org.apache.aries.proxy.impl.DefaultWrapper.invoke(DefaultWrapper.java:31)[8:org.apache.aries.proxy:0.3.0]
          	at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:78)[8:org.apache.aries.proxy:0.3.0]
          	at $Proxy60.commit(Unknown Source)[92:org.springframework.transaction:3.0.5.RELEASE]
          	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1058)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1050)[94:org.springframework.jms:3.0.5.RELEASE]
          	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:947)[94:org.springframework.jms:3.0.5.RELEASE]
          	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)[:1.6.0_29]
          	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)[:1.6.0_29]
          	at java.lang.Thread.run(Thread.java:662)[:1.6.0_29]
          Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started.
          	at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:380)
          	at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:262)
          	at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:422)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:215)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:197)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11]
          	... 1 more
          Show
          Gary Tully added a comment - Here is a snippet from the log when the problem occurs. The brokers stay alive, and the servicemix instance with aries tm and the camel route is restarted. In this example there is a partal impl of the fix such that the globalId does not match but the branchId does. With 2.2, the global id matches so it occurs a little earlier, but the outcome is the same. You can see a newly created tx: globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000 that is prepared getting rolledback by the recovery processing. The subsequent commit fails with not found. note: Just do a search for that globalId=.. string in the log to get a handle on what is going on. 19:40:23,421 | INFO | rint Extender: 3 | BlueprintCamelContext | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | Total 1 routes, of which 1 is started. 19:40:23,421 | INFO | rint Extender: 3 | BlueprintCamelContext | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | Apache Camel 2.8.0-fuse-06-11 (CamelContext: 225-camel-3) started in 3.062 seconds 19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,437 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager | 92 - org.springframework.transaction - 3.0.5.RELEASE | Creating new transaction with name [JmsConsumer[ESB_IN]]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,437 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,437 | TRACE | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-6:1, clientId = ID:nbdubpafox-1818-1341596420578-5:1, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,437 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61620], from: [tcp://localhost:61620] 19:40:23,453 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,484 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61620 19:40:23,500 | DEBUG | ActiveMQ Task-2 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,500 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,500 | INFO | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61620 19:40:23,500 | TRACE | /127.0.0.1:61620 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61620 starting 19:40:23,500 | DEBUG | /127.0.0.1:61620 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,500 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,500 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,515 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,515 | TRACE | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-8:1, clientId = ID:nbdubpafox-1818-1341596420578-7:1, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,515 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61620], from: [tcp://localhost:61620] 19:40:23,515 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61620 19:40:23,531 | DEBUG | ActiveMQ Task-1 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,531 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,531 | INFO | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61620 19:40:23,531 | TRACE | /127.0.0.1:61620 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61620 starting 19:40:23,531 | DEBUG | /127.0.0.1:61620 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,531 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,546 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,546 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Start called on XAResource activemq.external1 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] flags: TMNOFLAGS 19:40:23,546 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Start: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,562 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,562 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,562 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,562 | TRACE | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-6:2, clientId = ID:nbdubpafox-1818-1341596420578-5:2, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,562 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61620], from: [tcp://localhost:61620] 19:40:23,562 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61620 19:40:23,593 | DEBUG | ActiveMQ Task-2 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,593 | DEBUG | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,593 | INFO | ActiveMQ Task-2 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61620 19:40:23,593 | TRACE | Consumer[ESB_IN] | ActiveMQMessageConsumer | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | ID:nbdubpafox-1818-1341596420578-8:1:1:1 received message: MessageDispatch {commandId = 0, responseRequired = false , consumerId = ID:nbdubpafox-1818-1341596420578-8:1:1:1, destination = queue: //ESB_IN, message = ActiveMQTextMessage {commandId = 2199, responseRequired = false , messageId = ID:nbdubpafox-1656-1341596255125-2:1:1:1:732, originalDestination = null , originalTransactionId = null , producerId = ID:nbdubpafox-1656-1341596255125-2:1:1:1, destination = queue://ESB_IN, transactionId = TX:ID:nbdubpafox-1656-1341596255125-2:1:732, expiration = 0, timestamp = 1341596258265, arrival = 0, brokerInTime = 1341596258265, brokerOutTime = 1341596423562, correlationId = null , replyTo = null , persistent = true , type = null , priority = 4, groupID = null , groupSequence = 0, targetConsumerId = null , compressed = false , userID = null , content = null , marshalledProperties = null , dataStructure = null , redeliveryCounter = 1, size = 0, properties = null , readOnlyProperties = true , readOnlyBody = true , droppable = false , text = 731}, redeliveryCounter = 1} 19:40:23,593 | TRACE | /127.0.0.1:61620 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61620 starting 19:40:23,593 | DEBUG | /127.0.0.1:61620 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,593 | DEBUG | /127.0.0.1:61620 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61620 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,609 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager | 92 - org.springframework.transaction - 3.0.5.RELEASE | Participating in existing transaction 19:40:23,656 | INFO | Consumer[ESB_IN] | Camel-JMS-XA-Test | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | GOT MESSAGE ################################ 731 19:40:23,671 | INFO | Consumer[ESB_IN] | Camel-JMS-XA-Test | 89 - org.apache.camel.camel-core - 2.8.0.fuse-06-11 | REDELIVERED: true 19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,671 | DEBUG | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,671 | TRACE | Consumer[ESB_IN] | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-10:1, clientId = ID:nbdubpafox-1818-1341596420578-9:1, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,671 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61618], from: [tcp://localhost:61618] 19:40:23,671 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61618 19:40:23,703 | DEBUG | ActiveMQ Task-1 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,703 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,703 | INFO | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61618 19:40:23,703 | TRACE | /127.0.0.1:61618 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61618 starting 19:40:23,703 | DEBUG | /127.0.0.1:61618 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,703 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,703 | DEBUG | rint Extender: 3 | ActiveMQResourceManager | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | new namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-6:2,clientId=ID:nbdubpafox-1818-1341596420578-5:2,started= true } 19:40:23,703 | TRACE | rint Extender: 3 | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Recover called on XAResource activemq.external1 flags: TMENDRSCAN TMSTARTRSCAN remaining: 25165824 19:40:23,703 | DEBUG | rint Extender: 3 | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Recover: 25165824 19:40:23,718 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Start called on XAResource activemq.external2 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] flags: TMNOFLAGS 19:40:23,718 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Start: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,718 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,734 | TRACE | Consumer[ESB_IN] | ActiveMQSession | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | ID:nbdubpafox-1818-1341596420578-10:1:1 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false , messageId = ID:nbdubpafox-1818-1341596420578-10:1:1:1:1, originalDestination = null , originalTransactionId = null , producerId = ID:nbdubpafox-1818-1341596420578-10:1:1:1, destination = queue: //ESB_OUT, transactionId = XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000], expiration = 0, timestamp = 1341596423734, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null , replyTo = null , persistent = true , type = null , priority = 4, groupID = null , groupSequence = 0, targetConsumerId = null , compressed = false , userID = null , content = null , marshalledProperties = null , dataStructure = null , redeliveryCounter = 0, size = 0, properties = {breadcrumbId=ID:nbdubpafox-1656-1341596255125-2:1:1:1:732, CamelJmsDeliveryMode=2}, readOnlyProperties = true , readOnlyBody = true , droppable = false , text = 731} 19:40:23,734 | DEBUG | Consumer[ESB_IN] | JtaTransactionManager | 92 - org.springframework.transaction - 3.0.5.RELEASE | Initiating transaction commit 19:40:23,734 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | End called on XAResource activemq.external2 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] flags: TMSUCCESS remaining: 67108864 19:40:23,734 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | End: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,750 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from name: activemq.external1 [Xid:class=XATransactionId:globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,750 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid was initiated from this tm but not prepared: rolling back 19:40:23,750 | TRACE | rint Extender: 3 | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external1 Xid: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,750 | DEBUG | rint Extender: 3 | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,750 | DEBUG | rint Extender: 3 | ActiveMQResourceManager | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | closing returned namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-6:2,clientId=ID:nbdubpafox-1818-1341596420578-5:2,started= true } 19:40:23,750 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopped tcp: //localhost:61620 19:40:23,750 | DEBUG | rint Extender: 3 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopping transport tcp: //localhost/127.0.0.1:61620 19:40:23,750 | TRACE | /127.0.0.1:61620 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost:61620 handleTransportFailure: java.io.EOFException 19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,765 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,765 | TRACE | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-12:1, clientId = ID:nbdubpafox-1818-1341596420578-11:1, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,750 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Ended XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,765 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | End called on XAResource activemq.external1 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] flags: TMSUCCESS remaining: 67108864 19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | End: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,750 | DEBUG | sRequestorPool-1 | ActiveMQMessageConsumer | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | remove: ID:nbdubpafox-1818-1341596420578-4:3:1:2, lastDeliveredSequenceId:0 19:40:23,765 | DEBUG | ActiveMQ Task-2 | AbstractRegion | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | default removing consumer: ID:nbdubpafox-1818-1341596420578-4:3:1:2 for destination: queue: //org.apache.servicemix.jbi.cluster 19:40:23,765 | DEBUG | ActiveMQ Task-2 | Queue | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | queue: //org.apache.servicemix.jbi.cluster remove sub: QueueSubscription: consumer=ID:nbdubpafox-1818-1341596420578-4:3:1:2, destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0, dequeues: 0, dispatched: 0, inflight: 0 19:40:23,765 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61618], from: [tcp://localhost:61618] 19:40:23,765 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61618 19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Ended XA transaction: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,765 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Prepare called on XAResource activemq.external1 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,765 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Prepare: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,765 | DEBUG | ActiveMQ Task-2 | AbstractRegion | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | default adding consumer: ID:nbdubpafox-1818-1341596420578-4:3:1:3 for destination: queue: //org.apache.servicemix.jbi.cluster 19:40:23,781 | DEBUG | ActiveMQ Task-1 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,781 | DEBUG | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,781 | INFO | ActiveMQ Task-1 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61618 19:40:23,781 | DEBUG | ActiveMQ Task-2 | Queue | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | queue: //org.apache.servicemix.jbi.cluster add sub: QueueSubscription: consumer=ID:nbdubpafox-1818-1341596420578-4:3:1:3, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0 19:40:23,781 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Prepare called on XAResource activemq.external2 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,781 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Prepare: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,781 | TRACE | /127.0.0.1:61618 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61618 starting 19:40:23,781 | DEBUG | /127.0.0.1:61618 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,781 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Reconnect was triggered but transport is not started yet. Wait for start to connect the transport. 19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Started unconnected 19:40:23,796 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waking up reconnect task 19:40:23,796 | TRACE | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Waiting for transport to reconnect..: ConnectionInfo {commandId = 1, responseRequired = true , connectionId = ID:nbdubpafox-1818-1341596420578-12:2, clientId = ID:nbdubpafox-1818-1341596420578-11:2, clientIp = null , userName = null , password = *****, brokerPath = null , brokerMasterConnector = false , manageable = true , clientMaster = true , faultTolerant = true , failoverReconnect = false } 19:40:23,796 | DEBUG | ActiveMQ Task-3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | urlList connectionList:[tcp: //localhost:61618], from: [tcp://localhost:61618] 19:40:23,796 | DEBUG | ActiveMQ Task-3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Attempting 0th connect to: tcp: //localhost:61618 19:40:23,812 | DEBUG | ActiveMQ Task-3 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Sending: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,812 | DEBUG | ActiveMQ Task-3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Connection established 19:40:23,812 | INFO | ActiveMQ Task-3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Successfully connected to tcp: //localhost:61618 19:40:23,812 | TRACE | /127.0.0.1:61618 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | TCP consumer thread for tcp: //localhost/127.0.0.1:61618 starting 19:40:23,812 | DEBUG | /127.0.0.1:61618 | InactivityMonitor | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Using min of local: WireFormatInfo { version=8, properties={MaxFrameSize=104857600, CacheSize=1024, CacheEnabled= true , SizePrefixDisabled= false , MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled= true , MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Received WireFormat: WireFormatInfo { version=8, properties={CacheSize=1024, MaxFrameSize=104857600, CacheEnabled= true , SizePrefixDisabled= false , TcpNoDelayEnabled= true , MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000, TightEncodingEnabled= true , StackTraceEnabled= true }, magic=[A,c,t,i,v,e,M,Q]} 19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 before negotiation: OpenWireFormat{version=8, cacheEnabled= false , stackTraceEnabled= false , tightEncodingEnabled= false , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,812 | DEBUG | /127.0.0.1:61618 | WireFormatNegotiator | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost/127.0.0.1:61618 after negotiation: OpenWireFormat{version=8, cacheEnabled= true , stackTraceEnabled= true , tightEncodingEnabled= true , sizePrefixDisabled= false , maxFrameSize=104857600} 19:40:23,812 | DEBUG | rint Extender: 3 | ActiveMQResourceManager | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | new namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-12:2,clientId=ID:nbdubpafox-1818-1341596420578-11:2,started= true } 19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Recover called on XAResource activemq.external2 flags: TMENDRSCAN TMSTARTRSCAN remaining: 25165824 19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Recover: 25165824 19:40:23,828 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from name: activemq.external2 [Xid:class=XATransactionId:globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,828 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid was initiated from this tm but not prepared: rolling back 19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external2 Xid: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=6affffffce5f5d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,828 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | considering recovered xid from name: activemq.external2 [Xid:class=XATransactionId:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] 19:40:23,828 | TRACE | rint Extender: 3 | Recovery | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | this xid is from an external transaction and was not prepared: rolling back 19:40:23,828 | TRACE | rint Extender: 3 | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Rollback called on XAResource activemq.external2 Xid: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,828 | DEBUG | rint Extender: 3 | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Rollback: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] 19:40:23,828 | DEBUG | rint Extender: 3 | ActiveMQResourceManager | 53 - org.apache.activemq.activemq-pool - 5.5.1.fuse-07-11 | closing returned namedXAResource's connection: ActiveMQConnection {id=ID:nbdubpafox-1818-1341596420578-12:2,clientId=ID:nbdubpafox-1818-1341596420578-11:2,started= true } 19:40:23,843 | TRACE | /127.0.0.1:61618 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | tcp: //localhost:61618 handleTransportFailure: java.io.EOFException 19:40:23,843 | DEBUG | /127.0.0.1:61618 | TcpTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopping transport tcp: //localhost/127.0.0.1:61618 19:40:23,843 | DEBUG | rint Extender: 3 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Stopped tcp: //localhost:61618 19:40:23,843 | WARN | /127.0.0.1:61618 | FailoverTransport | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Transport (tcp: //127.0.0.1:61618) failed, reason: java.io.EOFException, not attempting to automatically reconnect 19:40:23,843 | DEBUG | /127.0.0.1:61618 | ActiveMQConnection | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | transport interrupted, dispatchers: 0 19:40:23,843 | DEBUG | /127.0.0.1:61618 | ActiveMQConnection | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | notified failover transport (unconnected) of pending interruption processing for : ID:nbdubpafox-1818-1341596420578-12:2 19:40:23,937 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Commit called on XAResource activemq.external1 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] onePhase: false 19:40:23,937 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Commit: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=100000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64], onePhase= false 19:40:23,937 | DEBUG | Consumer[ESB_IN] | ActiveMQMessageConsumer | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | remove: ID:nbdubpafox-1818-1341596420578-8:1:1:1, lastDeliveredSequenceId:26015 19:40:23,937 | TRACE | Consumer[ESB_IN] | WrapperNamedXAResource | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Commit called on XAResource activemq.external2 Xid: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64] onePhase: false 19:40:23,937 | DEBUG | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | Commit: [Xid:globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,length=64], onePhase= false 19:40:23,937 | WARN | Consumer[ESB_IN] | TransactionContext | 49 - org.apache.activemq.activemq-core - 5.5.1.fuse-07-11 | commit of: XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000] failed with: javax.jms.JMSException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started. javax.jms.JMSException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started. at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:49) at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1298)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.TransactionContext.syncSendPacketWithInterruptionHandling(TransactionContext.java:748)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.TransactionContext.commit(TransactionContext.java:555)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.ra.LocalAndXATransaction.commit(LocalAndXATransaction.java:85) at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.commit(WrapperNamedXAResource.java:54)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.CommitTask.run(CommitTask.java:63)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionImpl.commitResources(TransactionImpl.java:673)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:321)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1009) at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) at org.apache.aries.transaction.GeronimoPlatformTransactionManager.commit(GeronimoPlatformTransactionManager.java:76) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_29] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_29] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_29] at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_29] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:50)[8:org.apache.aries.proxy:0.3.0] at org.apache.aries.proxy.impl.DefaultWrapper.invoke(DefaultWrapper.java:31)[8:org.apache.aries.proxy:0.3.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:78)[8:org.apache.aries.proxy:0.3.0] at $Proxy60.commit(Unknown Source)[92:org.springframework.transaction:3.0.5.RELEASE] at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1058)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1050)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:947)[94:org.springframework.jms:3.0.5.RELEASE] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)[:1.6.0_29] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)[:1.6.0_29] at java.lang. Thread .run( Thread .java:662)[:1.6.0_29] Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started. at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:380) at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:262) at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:422)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:215)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:197)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] ... 1 more 19:40:23,937 | ERROR | Consumer[ESB_IN] | CommitTask | 226 - org.apache.aries.transaction.manager - 0.3.1.fuse-7-0-x-SNAPSHOT | Unexpected exception committing org.apache.geronimo.transaction.manager.WrapperNamedXAResource@161dc26; continuing to commit other RMs javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started. at org.apache.activemq.TransactionContext.toXAException(TransactionContext.java:773)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.TransactionContext.commit(TransactionContext.java:588)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.ra.LocalAndXATransaction.commit(LocalAndXATransaction.java:85) at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.commit(WrapperNamedXAResource.java:54)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.CommitTask.run(CommitTask.java:63)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionImpl.commitResources(TransactionImpl.java:673)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:321)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252)[226:org.apache.aries.transaction.manager:0.3.1.fuse-7-0-x-SNAPSHOT] at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1009) at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) at org.apache.aries.transaction.GeronimoPlatformTransactionManager.commit(GeronimoPlatformTransactionManager.java:76) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_29] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_29] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_29] at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_29] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:50)[8:org.apache.aries.proxy:0.3.0] at org.apache.aries.proxy.impl.DefaultWrapper.invoke(DefaultWrapper.java:31)[8:org.apache.aries.proxy:0.3.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:78)[8:org.apache.aries.proxy:0.3.0] at $Proxy60.commit(Unknown Source)[92:org.springframework.transaction:3.0.5.RELEASE] at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1058)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1050)[94:org.springframework.jms:3.0.5.RELEASE] at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:947)[94:org.springframework.jms:3.0.5.RELEASE] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)[:1.6.0_29] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)[:1.6.0_29] at java.lang. Thread .run( Thread .java:662)[:1.6.0_29] Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1197822575,globalId=67ffffffb9605d381006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000,branchId=200000006f72672e6170616368652e61726965732e7472616e73616374696f6e0000000000000000000000000000]' has not been started. at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:380) at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:262) at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:422)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:215)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:197)[49:org.apache.activemq.activemq-core:5.5.1.fuse-07-11] ... 1 more
          Hide
          Gary Tully added a comment -

          The bean in the camel context that initiates recovery is defined as:

          <bean id=".." class="org.apache.activemq.pool.ActiveMQResourceManager" init-method="recoverResource">
                    <property name="transactionManager" ref="recoverableTxManager" />
                    <property name="connectionFactory" ref="AmqXaCF" />
                    <property name="resourceName" value="activemq.external2" />
              </bean>
          Show
          Gary Tully added a comment - The bean in the camel context that initiates recovery is defined as: <bean id= ".." class= "org.apache.activemq.pool.ActiveMQResourceManager" init-method= "recoverResource" > <property name= "transactionManager" ref= "recoverableTxManager" /> <property name= "connectionFactory" ref= "AmqXaCF" /> <property name= "resourceName" value= "activemq.external2" /> </bean>
          Hide
          Guillaume Nodet added a comment -

          Not sure which version I should put. djencks ?

          Show
          Guillaume Nodet added a comment - Not sure which version I should put. djencks ?

            People

            • Assignee:
              Guillaume Nodet
              Reporter:
              Gary Tully
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development