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

    XA_RBROLLBACK on XAResource.end

    Stan Brown Newbie

      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
          Jonathan Halliday Master

          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?

          • 2. Re: XA_RBROLLBACK on XAResource.end
            Mark Little Master

             

            "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.

            • 3. Re: XA_RBROLLBACK on XAResource.end
              Stan Brown Newbie

               


              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.

              • 4. Re: XA_RBROLLBACK on XAResource.end
                Stan Brown Newbie

                 


                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
                  Mark Little Master

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

                  • 6. Re: XA_RBROLLBACK on XAResource.end
                    Jonathan Halliday Master

                    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

                    • 7. Re: XA_RBROLLBACK on XAResource.end
                      Mark Little Master

                      For now, turn off one-phase commit optimization.

                      • 8. Re: XA_RBROLLBACK on XAResource.end
                        Stan Brown Newbie

                         


                        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
                          Mark Little Master

                          Check out the issue Jonathan raised.

                          • 10. Re: XA_RBROLLBACK on XAResource.end
                            Jonathan Halliday Master

                            > 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.