10 Replies Latest reply on Aug 17, 2007 8:51 AM by jhalliday

XA_RBROLLBACK on XAResource.end

traffic Aug 14, 2007 10:50 PM

Conducting some testing I noticed that when a XAResource throws a XAException with errorCode set to XA_RBROLLBACK on XAResource.end, the JBoss transaction manager (TM) assumes that the resource manager has rolled back the transaction and never calls XAResource.rollback.

The XA specification states that XA_RBROLLBACK indicates that the RM has marked its work on the transaction as rollback-only. The JTA specification doesn?t really state what XA_RBROLLBACK means with respect to XAResource.end. I would expect the TM to follow up with a XAResoure.rollback call. JBoss does throw a TransactionRolledbackException back to the caller, and logs the following exception:


javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state
 at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:243)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:361)
 at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
 at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
 at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
 at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
 at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
 at org.jboss.ejb.Container.invoke(Container.java:960)
...

I could be missing something... Thanks, for any help.

1. Re: XA_RBROLLBACK on XAResource.end

jhalliday Aug 15, 2007 5:37 AM (in response to traffic)

Hmm, interesting corner case. Which resource manager are you using? I don't recall ever coming across one that returns XA_RBROLLBACK on XAResource.end, although clearly it is allowed. In what circumstances is it doing so?
Actions
2. Re: XA_RBROLLBACK on XAResource.end

marklittle Aug 15, 2007 10:08 AM (in response to traffic)

"traffic" wrote:
Conducting some testing I noticed that when a XAResource throws a XAException with errorCode set to XA_RBROLLBACK on XAResource.end, the JBoss transaction manager (TM) assumes that the resource manager has rolled back the transaction and never calls XAResource.rollback.

That's not the case: if any participant causes the transaction to have to roll back during commit, then we'll call roll back on that participant as well. If you're not seeing that happen then there's definitely something wrong. What makes you think that rollback has not been called?

I think the error message you're seeing could do with rephrasing though. What has happened here is that you've tried to commit a transaction and it hasn't, so it's been aborted. That's prefectly valid. But the text doesn't really convey that.
Actions
3. Re: XA_RBROLLBACK on XAResource.end

traffic Aug 15, 2007 7:07 PM (in response to traffic)

Hmm, interesting corner case. Which resource manager are you using? I don't recall ever coming across one that returns XA_RBROLLBACK on XAResource.end, although clearly it is allowed. In what circumstances is it doing so?

We?re using our own XAResource ? it?s used in our resource adapter implementation.

Here?s what leads to the XA_RBROLLBACK on XAResource.end
This test involves a SLSB, a single resource manager, and CMT.

While in transaction state, the caller suffers an exception accessing a program in an EIS environment, which causes our resource adapter to flag the transaction as rollback-only. When XAResource.end is eventually called by the transaction manager, we throw a XAException with errorCode set to XA_RBROLLBACK, which is done to simply notify the TM to not bother with going through the 2pc phase (if multiple resource managers were involved), but to immediately roll back the transaction. (We could simply wait for the Prepare -if multiple resource managers were involved - or the XAResource.commit and then send the XA_RBROLLBACK).

Thanks for your help.
Actions

4. Re: XA_RBROLLBACK on XAResource.end

traffic Aug 15, 2007 8:04 PM (in response to traffic)

That's not the case: if any participant causes the transaction to have to roll back during commit, then we'll call roll back on that participant as well. If you're not seeing that happen then there's definitely something wrong. What makes you think that rollback has not been called?

Here's what we are seeing:

While in transaction state the caller executes the following:

1)Caller (a SLSB) gets a connection
2)Creates an interaction (javax.resource.cci.Connection.createInteraction)
3)The Interaction fails with an exception
4)Resource adapter flags the transaction as rollback-only due to the Interaction exception
5)TM calls XAResource.end
6)XAResource throws XAException with errorCode set to XA_RBROLLBACK

Other than my logs showing that XAResource.rollback was never called and an outstanding transaction in the EIS environment, I would have to say the transaction was not rolled back. But again, I could be missing something?

The test was conducted using JBoss 4.2.0 and JBoss 4.0.3.

The test passed when I tried using the old standard JBoss transaction manager on JBoss 4.0.2.

I think the error message you're seeing could do with rephrasing though. What has happened here is that you've tried to commit a transaction and it hasn't, so it's been aborted. That's prefectly valid. But the text doesn't really convey that.

We aren't doing anything to the transaction. We're simply waiting for the TM.

Here are parts of two server logs from 4.0.3 (4.2.0 is similar). I can forward the logs to you if you like. The log differ in that one lists TransactionImple.rollback and the other lists TransactionImple.commit. In the TransactionImple.commit case, the application was redeploy. Im not sure if that means anything at all.

2007-08-15 13:50:53,503 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0503][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] --->TIPXAResource.start
2007-08-15 13:50:53,503 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0503][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] xid = 01000200031e196a7261632d2d33666334303739313a3633393a34366333363666363a36302d33666334303739313a3633393a34366333363666363a3633
2007-08-15 13:50:53,503 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0503][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] flags = 0
2007-08-15 13:50:53,503 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0503][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] COMSManagedConnection uid = 7f509a7a:1146b4a33a3:07fb3
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] --->COMSManagedConnection.transactionStarted
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] transactionType = 0
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] transactionIdentifier = 01000200031e196a7261632d2d33666334303739313a3633393a34366333363666363a36302d33666334303739313a3633393a34366333363666363a3633
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] xaFlags = 0
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Current transaction state: TX_NONE_STATE (0)
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] <---COMSManagedConnection.transactionStarted
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] new transactionState = TX_ACTIVE_STATE (1)
2007-08-15 13:50:53,847 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0847][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] <---TIPXAResource.start
2007-08-15 13:50:53,847 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
2007-08-15 13:50:53,847 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3fc40791:639:46c366f6:64, 1)
2007-08-15 13:50:53,862 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 30, 25, jrac--3fc40791:639:46c366f6:60-3fc40791:639:46c366f6:63 > )
2007-08-15 13:50:53,862 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:639:46c366f6:64
2007-08-15 13:50:53,862 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0862][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Entering getConnection
2007-08-15 13:50:53,862 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0862][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Created COMSConnection with uid 7f509a7a:1146b4a33a3:07fac
2007-08-15 13:50:53,862 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0862][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Exiting getConnection
2007-08-15 13:50:53,862 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0862][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fdc][CON ] Exiting getConnection
2007-08-15 13:50:53,862 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0862][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Entering createInteraction
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Created COMSInteraction with uid 7f509a7a:1146b4a33a3:07fab
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Added COMSInteraction [7f509a7a:1146b4a33a3:07fab], connection has 1 active interaction(s)
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Exiting createInteraction
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] --->COMSInteraction.execute(InteractionSpec, Record, Record)
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] Interaction Verb = SYNC_SEND_RECEIVE
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] In Record Name = InputRecord
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] Out Record Name = OutputRecord
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] Starting Java -> MCP data conversion from record InputRecord
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fbb][INT ] --->InputRecord.toByteArray
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fbb][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fbc][INT ] --->COMSMappedRecord.toByteArray
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fbc][INT ] Converting 1 item(s) in record
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fba][INT ] --->COMSEbcdic.toByteArray
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fba][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fba][INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] >>>>>>>>>>>>>>>>>> Starting Stack Trace <<<<<<<<<<<<<<<<<<
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ]
2007-08-15 13:50:53,878 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0878][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fab][INT ] javax.resource.ResourceException: [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Entering close
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Closing 1 active Interaction(s)
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Closing Interaction 7f509a7a:1146b4a33a3:07fab
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Closed Interaction 7f509a7a:1146b4a33a3:07fab
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Closed 1 Interaction(s)
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Connection is no longer active
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Entering fireConnectionClosedEvent
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Firing Connection closed event; 1 listener(s) are registered
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Exiting fireConnectionClosedEvent
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fac][CON ] Exiting close
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.rollback
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Abort() for action-id -3fc40791:639:46c366f6:60
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::doAbort (com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@fe2509)
2007-08-15 13:50:53,894 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelAbort for < 131075, 30, 25, jrac--3fc40791:639:46c366f6:60-3fc40791:639:46c366f6:63 >
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] --->TIPXAResource.end
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] xid = 01000200031e196a7261632d2d33666334303739313a3633393a34366333363666363a36302d33666334303739313a3633393a34366333363666363a3633
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] flags = 4000000
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] local = false
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb1][TX ] COMSManagedConnection uid = 7f509a7a:1146b4a33a3:07fb3
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] --->COMSManagedConnection.transactionCompleted
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] xaFlags = 4000000
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Current transaction state: TX_ACTIVE_STATE (1)
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Transaction failed: id = 01000200031e196a7261632d2d33666334303739313a3633393a34366333363666363a36302d33666334303739313a3633393a34366333363666363a3633
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] <---COMSManagedConnection.transactionCompleted - return value = false
2007-08-15 13:50:53,894 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0894][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] new transactionState = TX_NONE_STATE (0)
2007-08-15 13:50:53,909 WARN [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.rollbackxaerror] [com.arjuna.ats.internal.jta.resources.arjunacore.rollbackxaerror] XAResourceRecord.rollback - xa error XAException.XA_RBROLLBACK
2007-08-15 13:50:53,909 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Entering cleanup
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Clean Up Request: 0 connection(s) active
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] ManagedConnection cleanup successful
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] --->COMSManagedConnection.setMCState
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] current state = READY [2]
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] new state = READY [2]
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] <---COMSManagedConnection.setMCState
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] new MC State = READY [2]
2007-08-15 13:50:53,909 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 13:50:53.0909][ http-0.0.0.0-8080-1][7f509a7a:1146b4a33a3:07fb3][MC ] Exiting cleanup
2007-08-15 13:50:53,909 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-15 13:50:53,909 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
2007-08-15 13:50:53,909 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action -3fc40791:639:46c366f6:60 removing 1721a26
2007-08-15 13:50:53,909 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action -3fc40791:639:46c366f6:60 removing 1721a26 result = true

2007-08-15 14:46:42,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:42.0845][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] --->TIPXAResource.start
2007-08-15 14:46:42,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:42.0845][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6131623a34366333373363303a36322d33666334303739313a6131623a34366333373363303a3635
2007-08-15 14:46:42,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:42.0845][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] flags = 0
2007-08-15 14:46:42,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:42.0845][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] COMSManagedConnection uid = 66a4a638:1146b7c2a97:07f7b
2007-08-15 14:46:42,939 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:42.0939][ JCA PoolFiller][66a4a638:1146b7c2a97:07f78][MC ] >>>>>>>>>>>>>>>>>> Dumping contents of byte array outbound framing header <<<<<<<<<<<<<<<<<<
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] --->COMSManagedConnection.transactionStarted
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] transactionType = 0
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] transactionIdentifier = 01000200031e196a7261632d2d33666334303739313a6131623a34366333373363303a36322d33666334303739313a6131623a34366333373363303a3635
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] xaFlags = 0
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Current transaction state: TX_NONE_STATE (0)
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] <---COMSManagedConnection.transactionStarted
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] new transactionState = TX_ACTIVE_STATE (1)
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] <---TIPXAResource.start
2007-08-15 14:46:43,204 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
2007-08-15 14:46:43,204 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3fc40791:a1b:46c373c0:66, 1)
2007-08-15 14:46:43,204 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 30, 25, jrac--3fc40791:a1b:46c373c0:62-3fc40791:a1b:46c373c0:65
2007-08-15 14:46:43,204 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:a1b:46c373c0:66
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Entering getConnection
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Created COMSConnection with uid 66a4a638:1146b7c2a97:07f74
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Exiting getConnection
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f8c][CON ] Exiting getConnection
2007-08-15 14:46:43,204 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0204][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Entering createInteraction
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Created COMSInteraction with uid 66a4a638:1146b7c2a97:07f73
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Added COMSInteraction [66a4a638:1146b7c2a97:07f73], connection has 1 active interaction(s)
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Exiting createInteraction
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] --->COMSInteraction.execute(InteractionSpec, Record, Record)
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] Interaction Verb = SYNC_SEND_RECEIVE
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] In Record Name = InputRecord
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] Out Record Name = OutputRecord
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] Starting Java -> MCP data conversion from record InputRecord
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f83][INT ] --->InputRecord.toByteArray
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f83][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f84][INT ] --->COMSMappedRecord.toByteArray
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f84][INT ] Converting 1 item(s) in record
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f82][INT ] --->COMSEbcdic.toByteArray
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f82][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f82][INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] >>>>>>>>>>>>>>>>>> Starting Stack Trace <<<<<<<<<<<<<<<<<<
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-15 14:46:43,220 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ]
2007-08-15 14:46:43,235 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0220][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f73][INT ] javax.resource.ResourceException: [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-15 14:46:43,235 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0235][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Entering close
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Closing 1 active Interaction(s)
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Closing Interaction 66a4a638:1146b7c2a97:07f73
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Closed Interaction 66a4a638:1146b7c2a97:07f73
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Closed 1 Interaction(s)
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Connection is no longer active
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Entering fireConnectionClosedEvent
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Firing Connection closed event; 1 listener(s) are registered
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Exiting fireConnectionClosedEvent
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f74][CON ] Exiting close
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commit
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id -3fc40791:a1b:46c373c0:62
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::onePhaseCommit() for action-id -3fc40791:a1b:46c373c0:62
2007-08-15 14:46:43,251 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelOnePhaseCommit for < 131075, 30, 25, jrac--3fc40791:a1b:46c373c0:62-3fc40791:a1b:46c373c0:65
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] --->TIPXAResource.end
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6131623a34366333373363303a36322d33666334303739313a6131623a34366333373363303a3635
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] flags = 4000000
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] local = false
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f79][TX ] COMSManagedConnection uid = 66a4a638:1146b7c2a97:07f7b
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] --->COMSManagedConnection.transactionCompleted
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] xaFlags = 4000000
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Current transaction state: TX_ACTIVE_STATE (1)
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Transaction failed: id = 01000200031e196a7261632d2d33666334303739313a6131623a34366333373363303a36322d33666334303739313a6131623a34366333373363303a3635
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] <---COMSManagedConnection.transactionCompleted - return value = false
2007-08-15 14:46:43,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0251][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] new transactionState = TX_NONE_STATE (0)
2007-08-15 14:46:43,251 INFO [STDOUT] javax.transaction.xa.XAException
2007-08-15 14:46:43,251 INFO [STDOUT] at com.unisys.tip.TIPXAResource.end(TIPXAResource.java:403)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.unisys.tip.TIPXAResource.end(TIPXAResource.java:417)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:601)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2620)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1780)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:87)
2007-08-15 14:46:43,251 INFO [STDOUT] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:208)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:486)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:346)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.ejb.Container.invoke(Container.java:873)
2007-08-15 14:46:43,251 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2007-08-15 14:46:43,251 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2007-08-15 14:46:43,251 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2007-08-15 14:46:43,251 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:585)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.mx.server.Invocation.invoke(Invocation.java:72)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:245)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:644)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:155)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:104)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.invocation.InvokerInterceptor.invokeLocal(InvokerInterceptor.java:179)
2007-08-15 14:46:43,251 INFO [STDOUT] at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:165)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:55)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:97)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:86)
2007-08-15 14:46:43,267 INFO [STDOUT] at $Proxy65.method(Unknown Source)
2007-08-15 14:46:43,267 INFO [STDOUT] at methodBean.submit(methodBean.java:84)
2007-08-15 14:46:43,267 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2007-08-15 14:46:43,267 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2007-08-15 14:46:43,267 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2007-08-15 14:46:43,267 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:585)
2007-08-15 14:46:43,267 INFO [STDOUT] at com.sun.faces.el.MethodBindingImpl.invoke(MethodBindingImpl.java:126)
2007-08-15 14:46:43,267 INFO [STDOUT] at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:72)
2007-08-15 14:46:43,267 INFO [STDOUT] at javax.faces.component.UICommand.broadcast(UICommand.java:312)
2007-08-15 14:46:43,267 INFO [STDOUT] at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:267)
2007-08-15 14:46:43,267 INFO [STDOUT] at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:381)
2007-08-15 14:46:43,267 INFO [STDOUT] at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:75)
2007-08-15 14:46:43,267 INFO [STDOUT] at com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:248)
2007-08-15 14:46:43,267 INFO [STDOUT] at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:90)
2007-08-15 14:46:43,267 INFO [STDOUT] at javax.faces.webapp.FacesServlet.service(FacesServlet.java:193)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
2007-08-15 14:46:43,267 INFO [STDOUT] at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
2007-08-15 14:46:43,267 INFO [STDOUT] at java.lang.Thread.run(Thread.java:595)
2007-08-15 14:46:43,267 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Entering cleanup
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Clean Up Request: 0 connection(s) active
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] ManagedConnection cleanup successful
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] --->COMSManagedConnection.setMCState
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] current state = READY [2]
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] new state = READY [2]
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] <---COMSManagedConnection.setMCState
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] new MC State = READY [2]
2007-08-15 14:46:43,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 15, 2007 14:46:43.0267][ http-0.0.0.0-8080-3][66a4a638:1146b7c2a97:07f7b][MC ] Exiting cleanup
2007-08-15 14:46:43,267 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-15 14:46:43,267 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
2007-08-15 14:46:43,267 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action -3fc40791:a1b:46c373c0:62 removing 1d1964d
2007-08-15 14:46:43,267 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action -3fc40791:a1b:46c373c0:62 removing 1d1964d result = true

Maybe there's someting I'm overlooking. Anyways, thanks for your help.

5. Re: XA_RBROLLBACK on XAResource.end

marklittle Aug 16, 2007 7:10 AM (in response to traffic)

Hold on ... you've only got one resource in your transaction?
Actions
6. Re: XA_RBROLLBACK on XAResource.end

jhalliday Aug 16, 2007 8:14 AM (in response to traffic)

OK, that's an error in our code. I've queued it up for fixing the in the next version. Thanks for bringing this to our attention.

http://jira.jboss.com/jira/browse/JBTM-278
Actions
7. Re: XA_RBROLLBACK on XAResource.end

marklittle Aug 16, 2007 8:48 AM (in response to traffic)

For now, turn off one-phase commit optimization.
Actions

8. Re: XA_RBROLLBACK on XAResource.end

traffic Aug 16, 2007 11:41 PM (in response to traffic)

Hold on ... you've only got one resource in your transaction?

The test didn't work with 2 resource managers, but for a different reason. It seems that the TM is trying to roll back the transaction after receiving the XA_RBROLLBACK on XAResourece.end; however, in the process the TM calls XAResource.end on the same RM that threw the XAException/XA_RBROLLBACK on a previous call to XAResource.end, which causes that RM to throw a XAException with errorCode set to XAER_PROTO. The XAER_PROTO is returned since the first call to XAResource.end dissociated the RM from the transaction (the XAException/XA_RBROLLBACK was thrown to inform the TM that the transaction has been marked rollback-only and is no longer associated with the RM).

I guess this goes back to my original post: Does throwing XAException with errorCode set to XA_RBROLLBACK on XAResource.end mean that the transaction has been marked rollback-only and the RM is no longer associated with the transaction or does it simply mean that an exception has happened and the TM should call XAResource.end again at some point? I believe the former.

I was able to get the transaction (using 2 RMs) to successfully roll back using JBoss 4.0.2 and the old JBoss transaction manager.

Anyhow, here's what we?re seeing:
While in transaction state the caller executes the following:

1) Caller (a SLSB) gets a connection ? connection is associated with RM-1 (XAResource)

2) Creates an interaction (javax.resource.cci.Connection.createInteraction)

3) Successfully executes the interaction (javax.resource.cci.Interaction.execute)

4) Caller get a second connection - c2 ? connection is associated with RM-2

5) Creates an interaction on connection c2

6) The Interaction associated with c2 fails with an exception

7) Resource adapter flags the transaction as rollback-only for connection c2 due to the Interaction exception

8) TM calls XAResource.end for RM-1, which returns successfully

9) TM calls XAResource.prepare for RM-1, which returns successfully

10) TM calls XAResource.end for RM-2, which throws an XAException with errorCode set to XA_RBROLLBACK

11) TM calls XAResource.rollback for RM-1, which returns successfully

12) TM calls XAResource.end for RM-2, which throws a XAException with errorCode set XAER_PROTO because the RM has previously been disassociated from the transaction at step 10.

I was wondering if there's a setting to have XAResource.end called first for all RMs involved in the transaction followed by the transaction completion phase(s)?

Here's part of the server log from the test...

2007-08-16 18:55:25,063 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0063][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] --->TIPXAResource.start
2007-08-16 18:55:25,063 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0063][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:25,063 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0063][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] flags = 0
2007-08-16 18:55:25,063 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0063][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07faf
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] --->COMSManagedConnection.transactionStarted
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] transactionType = 0
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] transactionIdentifier = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] xaFlags = 0
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Current transaction state: TX_NONE_STATE (0)
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] <---COMSManagedConnection.transactionStarted
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] new transactionState = TX_ACTIVE_STATE (1)
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] <---TIPXAResource.start
2007-08-16 18:55:25,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
2007-08-16 18:55:25,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3fc40791:f5e:46c4ffd7:64, 1)
2007-08-16 18:55:25,157 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:63
2007-08-16 18:55:25,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:f5e:46c4ffd7:64
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Entering getConnection
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Created COMSConnection with uid 3b477e4f:1147187618d:07fa8
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Exiting getConnection
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fdc][CON ] Exiting getConnection
2007-08-16 18:55:25,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Entering createInteraction
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Created COMSInteraction with uid 3b477e4f:1147187618d:07fa7
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Added COMSInteraction [3b477e4f:1147187618d:07fa7], connection has 1 active interaction(s)
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Exiting createInteraction
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] --->COMSInteraction.execute(InteractionSpec, Record, Record)
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] Interaction Verb = SYNC_SEND_RECEIVE
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] In Record Name = InputRecord
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] Out Record Name = OutputRecord
2007-08-16 18:55:25,173 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0173][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] Starting Java -> MCP data conversion from record InputRecord
2007-08-16 18:55:25,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0845][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] Starting MCP -> Java data conversion, inserting 20 bytes into record OutputRecord
2007-08-16 18:55:25,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0845][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] MCP -> Java data conversion complete
2007-08-16 18:55:25,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:25.0845][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa7][INT ] <---COMSInteraction.execute(InteractionSpec, Record, Record) - return value = true
2007-08-16 18:55:25,845 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:25.0845][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fd9][CON ] Entering getConnection
2007-08-16 18:55:25,845 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:25,845 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:25,845 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( com.unisys.tip.TIPXAResource@1feae0f )
2007-08-16 18:55:26,142 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,142 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] --->TIPXAResource.isSameRM
2007-08-16 18:55:26,142 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] xares = uid = 3b477e4f:1147187618d:07fa3
2007-08-16 18:55:26,142 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07faf
2007-08-16 18:55:26,142 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] <---TIPXAResource.isSameRM - return value = false
2007-08-16 18:55:26,142 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] --->TIPXAResource.setTransactionTimeout
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] seconds = 300
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0142][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07fa5
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] XAResource transaction timeout set to 300 second(s)
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] <---TIPXAResource.setTransactionTimeout - return value = true
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] --->TIPXAResource.start
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] flags = 0
2007-08-16 18:55:26,157 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0157][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07fa5
2007-08-16 18:55:26,235 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0235][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] --->COMSManagedConnection.transactionStarted
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0235][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] transactionType = 0
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0235][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] transactionIdentifier = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0235][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] xaFlags = 0
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Current transaction state: TX_NONE_STATE (0)
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] <---COMSManagedConnection.transactionStarted
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] new transactionState = TX_ACTIVE_STATE (1)
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] <---TIPXAResource.start
2007-08-16 18:55:26,251 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
2007-08-16 18:55:26,251 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3fc40791:f5e:46c4ffd7:67, 1)
2007-08-16 18:55:26,251 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:66
2007-08-16 18:55:26,251 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: -3fc40791:f5e:46c4ffd7:64) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:f5e:46c4ffd7:67
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Entering getConnection
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Created COMSConnection with uid 3b477e4f:1147187618d:07f9f
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Exiting getConnection
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fd9][CON ] Exiting getConnection
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Entering createInteraction
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Created COMSInteraction with uid 3b477e4f:1147187618d:07f9e
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Added COMSInteraction [3b477e4f:1147187618d:07f9e], connection has 1 active interaction(s)
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Exiting createInteraction
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] --->COMSInteraction.execute(InteractionSpec, Record, Record)
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] Interaction Verb = SYNC_SEND_RECEIVE
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] In Record Name = InputRecord2
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] Out Record Name = OutputRecord2
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] Starting Java -> MCP data conversion from record InputRecord2
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9c][INT ] --->InputRecord2.toByteArray
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9c][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9d][INT ] --->COMSMappedRecord.toByteArray
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9d][INT ] Converting 1 item(s) in record
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9b][INT ] --->COMSEbcdic.toByteArray
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9b][INT ] encoding = com.unisys.coms.connector.COMSAseriesEbcdic
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9b][INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] >>>>>>>>>>>>>>>>>> Starting Stack Trace <<<<<<<<<<<<<<<<<<
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ]
2007-08-16 18:55:26,251 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0251][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9e][INT ] javax.resource.ResourceException: [INT ] Null Data Value:[COMSEbcdic.toByteArray] - object to be sent to a COMS program is null, error code: ERROR-INT-011
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Entering close
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Closing 1 active Interaction(s)
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Closing Interaction 3b477e4f:1147187618d:07fa7
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Closed Interaction 3b477e4f:1147187618d:07fa7
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Closed 1 Interaction(s)
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Connection is no longer active
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Entering fireConnectionClosedEvent
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Firing Connection closed event; 1 listener(s) are registered
2007-08-16 18:55:26,267 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,267 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Exiting fireConnectionClosedEvent
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa8][CON ] Exiting close
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Entering close
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Closing 1 active Interaction(s)
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Closing Interaction 3b477e4f:1147187618d:07f9e
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Closed Interaction 3b477e4f:1147187618d:07f9e
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Closed 1 Interaction(s)
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Connection is no longer active
2007-08-16 18:55:26,267 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0267][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Entering fireConnectionClosedEvent
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Firing Connection closed event; 1 listener(s) are registered
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Exiting fireConnectionClosedEvent
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07f9f][CON ] Exiting close
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commit
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id -3fc40791:f5e:46c4ffd7:60
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::prepare () for action-id -3fc40791:f5e:46c4ffd7:60
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ShadowingStore.ShadowingStore( 14 )
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ShadowNoFileLockStore.ShadowNoFileLockStore( 14 )
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] HashedStore.HashedStore( 14 )
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] HashedStore.HashedActionStore()
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] FileSystemStore.setupStore()
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] FileSystemStore.createHierarchy(PutObjectStoreDirHere\HashedActionStore\defaultStore\)
2007-08-16 18:55:26,282 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelPrepare for < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:63
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] --->TIPXAResource.end
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] flags = 4000000
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] local = false
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07faf
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] --->COMSManagedConnection.transactionCompleted
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] xaFlags = 4000000
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Current transaction state: TX_ACTIVE_STATE (1)
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Transaction completed: id = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] <---COMSManagedConnection.transactionCompleted - return value = true
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] new transactionState = TX_NONE_STATE (0)
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] <---TIPXAResource.end
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] --->TIPXAResource.prepare
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:26,282 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0282][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07faf
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] <---TIPXAResource.prepare - return value = 0
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:f5e:46c4ffd7:64
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelPrepare for < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:66
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] --->TIPXAResource.end
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] flags = 4000000
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] local = false
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07fa5
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] --->COMSManagedConnection.transactionCompleted
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] xaFlags = 4000000
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Current transaction state: TX_ACTIVE_STATE (1)
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Transaction failed: id = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] <---COMSManagedConnection.transactionCompleted - return value = false
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] new transactionState = TX_NONE_STATE (0)
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3fc40791:f5e:46c4ffd7:67
2007-08-16 18:55:26,501 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id -3fc40791:f5e:46c4ffd7:60 failed.
2007-08-16 18:55:26,501 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::phase2Abort() for action-id -3fc40791:f5e:46c4ffd7:60
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::doAbort (com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@d79c75)
2007-08-16 18:55:26,501 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelAbort for < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:63
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] --->TIPXAResource.rollback
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3633
2007-08-16 18:55:26,501 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0501][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07faf
2007-08-16 18:55:26,751 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fac][TX ] <---TIPXAResource.rollback
2007-08-16 18:55:26,751 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::doAbort (com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@1013985)
2007-08-16 18:55:26,751 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelAbort for < 131075, 30, 25, jrac--3fc40791:f5e:46c4ffd7:60-3fc40791:f5e:46c4ffd7:66
2007-08-16 18:55:26,751 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] --->TIPXAResource.end
2007-08-16 18:55:26,751 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] xid = 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] flags = 4000000
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] local = false
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0751][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] COMSManagedConnection uid = 3b477e4f:1147187618d:07fa5
2007-08-16 18:55:26,767 INFO [STDOUT] [Aug 16, 2007 18:55:26.0767][TX ] In end, no transaction started on XAResource, xid passed: 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] >>>>>>>>>>>>>>>>>> Starting Stack Trace <<<<<<<<<<<<<<<<<<
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] In end, no transaction started on XAResource, xid passed: 01000200031e196a7261632d2d33666334303739313a6635653a34366334666664373a36302d33666334303739313a6635653a34366334666664373a3636
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ]
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] javax.transaction.xa.XAException
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.unisys.tip.TIPXAResource.displayXAException(TIPXAResource.java:1096)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.unisys.tip.TIPXAResource.end(TIPXAResource.java:312)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.unisys.tip.TIPXAResource.end(TIPXAResource.java:417)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:353)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3219)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3197)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:2212)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1810)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:87)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:208)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:486)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:346)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.ejb.Container.invoke(Container.java:873)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at java.lang.reflect.Method.invoke(Method.java:585)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.mx.server.Invocation.invoke(Invocation.java:72)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:245)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:644)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:155)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:104)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.invocation.InvokerInterceptor.invokeLocal(InvokerInterceptor.java:179)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:165)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:55)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:97)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:86)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at $Proxy57.method(Unknown Source)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at methodBean.submit(methodBean.java:84)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at java.lang.reflect.Method.invoke(Method.java:585)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.sun.faces.el.MethodBindingImpl.invoke(MethodBindingImpl.java:126)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:72)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at javax.faces.component.UICommand.broadcast(UICommand.java:312)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:267)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:381)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:75)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:248)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:90)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at javax.faces.webapp.FacesServlet.service(FacesServlet.java:193)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] at java.lang.Thread.run(Thread.java:595)
2007-08-16 18:55:26,767 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0767][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa3][TX ] >>>>>>>>>>>>>>>>>> Stack Trace Complete <<<<<<<<<<<<<<<<<<
2007-08-16 18:55:26,782 WARN [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.rollbackxaerror] [com.arjuna.ats.internal.jta.resources.arjunacore.rollbackxaerror] XAResourceRecord.rollback - xa error XAException.XAER_PROTO
2007-08-16 18:55:26,782 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_54] - Top-level abort of action -3fc40791:f5e:46c4ffd7:60 received TwoPhaseOutcome.FINISH_ERROR from <ClassName:RecordType.JTA_RECORD>
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::updateState() for action-id -3fc40791:f5e:46c4ffd7:60
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Entering cleanup
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Clean Up Request: 0 connection(s) active
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] ManagedConnection cleanup successful
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] --->COMSManagedConnection.setMCState
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] current state = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] new state = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] <---COMSManagedConnection.setMCState
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] new MC State = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07faf][MC ] Exiting cleanup
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Entering cleanup
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Clean Up Request: 0 connection(s) active
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] ManagedConnection cleanup successful
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] --->COMSManagedConnection.setMCState
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] current state = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] new state = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] <---COMSManagedConnection.setMCState
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] new MC State = READY [2]
2007-08-16 18:55:26,782 INFO [com.unisys.coms.connector.COMSManagedConnectionFactory.jrac/basic2] [Aug 16, 2007 18:55:26.0782][ http-0.0.0.0-8080-1][3b477e4f:1147187618d:07fa5][MC ] Exiting cleanup
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action -3fc40791:f5e:46c4ffd7:60 removing 176b9ea
2007-08-16 18:55:26,782 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action -3fc40791:f5e:46c4ffd7:60 removing 176b9ea result = true
2007-08-16 18:55:26,782 ERROR [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract p1.p2.p3.OutputRecord p1.p2.p3.testBasic.method(p1.p2.p3.InputRecord) throws java.rmi.RemoteException, causedBy:
javax.transaction.RollbackException
 at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:223)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:486)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:346)
 at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
 at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
 at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
 at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
 at org.jboss.ejb.SessionContainer.internalInvoke(SessionContai

9. Re: XA_RBROLLBACK on XAResource.end

marklittle Aug 17, 2007 4:49 AM (in response to traffic)

Check out the issue Jonathan raised.
Actions
10. Re: XA_RBROLLBACK on XAResource.end

jhalliday Aug 17, 2007 8:51 AM (in response to traffic)

> Does throwing XAException with errorCode set to XA_RBROLLBACK on XAResource.end mean that the transaction has been marked rollback-only and the RM is no longer associated with the transaction or does it simply mean that an exception has happened and the TM should call XAResource.end again at some point? I believe the former.

I agree end should be called exactly once, as should rollback if end throws an exception. Indeed we do have code in place to make the abort (rollback) skip calling end again if it was called during prepare and threw an exception. Unfortunately it's broken, which is why you are seeing the above behavior.
Actions

Go to original post