5 Replies Latest reply on Jul 13, 2004 1:43 PM by jdefelice

    3.2.4 / JMS / Transacation is not active

    jdefelice

      We just upgraded from 3.2.3 to 3.2.4, and are now getting exceptions when trying to send JMS messages.

      We're using file-based message persistence, and a point-to-point transacted session.

      Here's a snippet of stack trace:

      2004.06.29 12:47:55.812 GMT-05:00 DEBUG [org.jboss.mq.server.JMSDestinationManager] Exception occured, rolling back transaction:
      javax.jms.JMSException: Transacation is not active.
      at org.jboss.mq.pm.Tx.addPostRollbackTask(Tx.java:228)
      at org.jboss.mq.pm.TxManager.addPostRollbackTask(TxManager.java:133)
      at org.jboss.mq.server.BasicQueue.addMessage(BasicQueue.java:344)
      at org.jboss.mq.server.PersistentQueue.addMessage(PersistentQueue.java:40)
      at org.jboss.mq.server.JMSQueue.addMessage(JMSQueue.java:131)
      at org.jboss.mq.server.JMSDestinationManager.addMessage(JMSDestinationManager.java:402)
      at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:428)
      at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
      at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
      at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
      at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
      at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
      at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
      at java.lang.Thread.run(Thread.java:534)


      Client code runs within a POJO, and looks like:

      try {

      Context context = ContextFactory.createContext();

      QueueConnectionFactory factory =
      (QueueConnectionFactory) context.lookup(ContextFactory.LMS_JMS);
      QueueConnection conn = factory.createQueueConnection();
      // since transacted_session=true (transacted mode), the 2nd arg is ignored
      // and the session.commit() is required to delete the recieved message.
      QueueSession session = conn.createQueueSession(true, Session.AUTO_ACKNOWLEDGE);
      Queue queue = (Queue) context.lookup(ContextFactory.EVENT_QUEUE_NAME);
      QueueSender sender = session.createSender(queue);
      conn.start();

      ObjectMessage objMsg = session.createObjectMessage();

      objMsg.setJMSDeliveryMode( deliveryMode );
      objMsg.setObject( this );
      log.debug("send(): Sending event " + getClass().getName() );
      sender.send( objMsg );
      session.commit(); // required to delete the message after recieved
      log.debug("send(): Sent & committed event " + this);

      conn.close();
      } catch ( Exception e ) {
      log.error("send(): Failed to send JMS Message", e);
      throw new RuntimeException("Failed to send JMS Message " + e.getMessage());
      }


      Here's what the jbossmq trace looks like before the exception:
      2004.06.29 12:47:55.718 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Starting tx with new xid=-9223372036854775806
      2004.06.29 12:47:55.718 GMT-05:00 TRACE [org.jboss.mq.SpySession] New session SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]
      2004.06.29 12:47:55.718 GMT-05:00 TRACE [org.jboss.mq.SpyMessageProducer] New message producer SpyMessageProducer@16564336[ dest=QUEUE.khubEventQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]]
      2004.06.29 12:47:55.718 GMT-05:00 TRACE [org.jboss.mq.SpySession] Adding producer SpyMessageProducer@16564336[ dest=QUEUE.khubEventQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]]
      2004.06.29 12:47:55.765 GMT-05:00 DEBUG [com.elementk.service.event.Event] send(): Sending event com.elementk.lms.khub.sys.email.GenerateEmailEvent
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@16564336[ dest=QUEUE.khubEventQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]] org.jboss.mq.SpyObjectMessage {
      Header {
      jmsDestination : QUEUE.khubEventQueue
      jmsDeliveryMode : 2
      jmsExpiration : 0
      jmsPriority : 4
      jmsMessageID : ID:5-10885312757651
      jmsTimeStamp : 1088531275765
      jmsCorrelationID: null
      jmsReplyTo : null
      jmsType : null
      jmsRedelivered : false
      jmsProperties : {}
      jmsPropReadWrite: true
      msgReadOnly : false
      producerClientId: ID:5
      }
      }
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpySession] Adding message to transaction ID:5-10885312757651 SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Adding message xid=-9223372036854775806, message=ID:5-10885312757651
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] TXState=TxState txState=0 sent=[] acks=[]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpySession] Committing transaction SpySession@15378051[tx=true txid=-9223372036854775806 RUNNING connection=Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Ending xid=-9223372036854775806, success=true
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Commiting xid=-9223372036854775806, onePhase=true
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@54be84 Connection@27308955[token=ConnectionToken:ID:5/dda5f260f66ada4628aca68dbcac1da9 rcvstate=STARTED]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg27787679[msgType: m_transact, msgID: -2147483588, error: null]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg27787679[msgType: m_transact, msgID: -2147483588, error: null]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483588
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.TransactMsg16938957[msgType: m_transact, msgID: -2147483588, error: null]
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 17
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : transact
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.TransactionRequest@10772d2
      2004.06.29 12:47:55.765 GMT-05:00 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
      Principal: guest
      Principal: Roles(members:guest)
      ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest] 2004.06.29 12:47:55.812 GMT-05:00 TRACE [org.jboss.mq.server.BasicQueue] addMessage 1 msg=0 hard NOT_STORED PERSISTENT persistData=org.jboss.mq.pm.rollinglogged.PersistenceManager$LogInfo@aa780b queue=QUEUE.khubEventQueue priority=4 lateClone=false hashCode=1222210 -9223372036854775806 org.jboss.mq.server.PersistentQueue@114069b{id=QUEUE.khubEventQueue}

      Any ideas would be helpful.

      Thanks,

      James

        • 1. Re: 3.2.4 / JMS / Transacation is not active
          genman


          If it's running in a POJO and there is no transaction, then why do this:

          // since transacted_session=true (transacted mode), the 2nd arg is ignored
          // and the session.commit() is required to delete the recieved message.
          QueueSession session = conn.createQueueSession(true, Session.AUTO_ACKNOWLEDGE);

          What you might want instead is:

          QueueSession session = conn.createQueueSession(false, Session.CLIENT_ACKNOWLEDGE);

          • 2. Re: 3.2.4 / JMS / Transacation is not active
            jdefelice

            Thank you for the quick reply - this fixed the problem for the POJO.

            I still have the "same" problem occurring in a stateless session bean. By "same" problem, I mean I still get "Transacation is not active" exceptions. It looks like the exceptions are being generated as part of the transaction attempting to commit. It appears as if there have been no other errors during the transaction, so the commit should succeed. Instead I get the exception.

            In the SSB I'm using, I'm running under "Required" semantics, using the default "java:/JmsXa" JMS connection factory. I'm still trying to use a transacted JMS session here because the logic is much more complicated than it was in the POJO - I need to rollback the JMS messages if there are any database errors.

            I'm also using an XA datasource wrapper around my oracle thin driver connection.

            Here's the stack trace:


            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.SpyXAResource] End xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=], flags=67108864 SpyXAResource[session=SpySession@25165599[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=] XA RUNNING connection=Connection@11044709[token=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 rcvstate=STARTED]]]
            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.SpySession] Unsetting current tx xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=] previous: XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=] SpySession@25165599[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=] XA RUNNING connection=Connection@11044709[token=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 rcvstate=STARTED]]
            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Ending xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=], success=true 2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.SpyXAResource] Commit xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=], onePhase=true SpyXAResource[session=SpySession@25165599[tx=true txid=null XA RUNNING connection=Connection@11044709[token=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 rcvstate=STARTED]]]
            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.SpyXAResourceManager] Commiting xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=], onePhase=true
            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@1136abc Connection@11044709[token=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 rcvstate=STARTED]
            2004.06.30 08:58:08.578 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg29651644[msgType: m_transact, msgID: -2147483571, error: null]
            2004.06.30 08:58:08.578 GMT-05:00 DEBUG [com.elementk.lms.khub.sys.email.MailSender] EmailTransportListener.messageDelivered: valid sent emails to 1 recipients
            2004.06.30 08:58:08.578 GMT-05:00 DEBUG [com.elementk.lms.khub.sys.email.MailSender] EmailTransportListener.messageDelivered: email addresses: james_defelice@elementk.com

            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg29651644[msgType: m_transact, msgID: -2147483571, error: null]
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483571
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.TransactMsg14552258[msgType: m_transact, msgID: -2147483571, error: null]
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 17
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : transact
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.TransactionRequest@17a35c
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.server.BasicQueue] acknowledge AcknowledgementRequest:ACK,QUEUE.khubEmailQueue,ID:6-10886038859681 -9223372036854775806 org.jboss.mq.server.PersistentQueue@ea4081{id=QUEUE.khubEmailQueue}
            2004.06.30 08:58:08.609 GMT-05:00 DEBUG [org.jboss.mq.server.JMSDestinationManager] Exception occured, rolling back transaction:
            javax.jms.JMSException: Transacation is not active.
            at org.jboss.mq.pm.Tx.addPostRollbackTask(Tx.java:228)
            at org.jboss.mq.pm.TxManager.addPostRollbackTask(TxManager.java:133)
            at org.jboss.mq.server.BasicQueue.acknowledge(BasicQueue.java:530)
            at org.jboss.mq.server.JMSQueue.acknowledge(JMSQueue.java:123)
            at org.jboss.mq.server.ClientConsumer.acknowledge(ClientConsumer.java:322)
            at org.jboss.mq.server.JMSDestinationManager.acknowledge(JMSDestinationManager.java:524)
            at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:436)
            at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
            at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
            at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
            at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
            at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
            at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
            at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
            at java.lang.Thread.run(Thread.java:534)
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] EXCEPTION : transact:
            javax.jms.JMSException: Transaction is not active for commit
            at org.jboss.mq.pm.Tx.commit(Tx.java:144)
            at org.jboss.mq.pm.TxManager.rollbackTx(TxManager.java:118)
            at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:446)
            at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
            at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
            at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
            at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
            at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
            at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
            at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
            at java.lang.Thread.run(Thread.java:534)
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : transact
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.TransactMsg14552258[msgType: m_transact, msgID: -2147483571, error: null]
            javax.jms.JMSException: Transaction is not active for commit
            at org.jboss.mq.pm.Tx.commit(Tx.java:144)
            at org.jboss.mq.pm.TxManager.rollbackTx(TxManager.java:118)
            at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:446)
            at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
            at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
            at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
            at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
            at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
            at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
            at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
            at java.lang.Thread.run(Thread.java:534)
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.TransactMsg14552258[msgType: m_transact, msgID: -2147483571, error: javax.jms.JMSException: Transaction is not active for commit]
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg14552258[msgType: m_transact, msgID: -2147483571, error: javax.jms.JMSException: Transaction is not active for commit]
            2004.06.30 08:58:08.609 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg14552258[msgType: m_transact, msgID: -2147483571, error: javax.jms.JMSException: Transaction is not active for commit]
            2004.06.30 08:58:08.625 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483571
            2004.06.30 08:58:08.625 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.TransactMsg29651644[msgType: m_transact, msgID: -2147483571, error: null]
            2004.06.30 08:58:08.625 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.TransactMsg29651644[msgType: m_transact, msgID: -2147483571, error: javax.jms.JMSException: Transaction is not active for commit]
            2004.06.30 08:58:08.625 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg29651644[msgType: m_transact, msgID: -2147483571, error: javax.jms.JMSException: Transaction is not active for commit]
            2004.06.30 08:58:08.625 GMT-05:00 TRACE [org.jboss.mq.il.uil2.SocketManager] sendMessage will throw error
            javax.jms.JMSException: Transaction is not active for commit
            at org.jboss.mq.pm.Tx.commit(Tx.java:144)
            at org.jboss.mq.pm.TxManager.rollbackTx(TxManager.java:118)
            at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:446)
            at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
            at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
            at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
            at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
            at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
            at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
            at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
            at java.lang.Thread.run(Thread.java:534)
            2004.06.30 08:58:08.625 GMT-05:00 ERROR [org.jboss.jms.asf.StdServerSession] failed to commit/rollback
            org.jboss.mq.SpyXAException: - nested throwable: (javax.jms.JMSException: Transaction is not active for commit)
            at org.jboss.mq.SpyXAResource.commit(SpyXAResource.java:88)
            at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:327)
            at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:871)
            at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:159)
            at org.jboss.mq.SpySession.run(SpySession.java:347)
            at org.jboss.jms.asf.StdServerSession.run0(StdServerSession.java:200)
            at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:743)
            at java.lang.Thread.run(Thread.java:534)
            Caused by: javax.jms.JMSException: Transaction is not active for commit
            at org.jboss.mq.pm.Tx.commit(Tx.java:144)
            at org.jboss.mq.pm.TxManager.rollbackTx(TxManager.java:118)
            at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:446)
            at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
            at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
            at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
            at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
            at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
            at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
            at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
            at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
            ... 1 more
            2004.06.30 08:58:08.640 GMT-05:00 TRACE [org.jboss.mq.SpyMessageConsumer] consumer() after onMessage=ID:6-10886038859681 SpyMessageConsumer@20076805[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 destination=QUEUE.khubEmailQueue messageSelector=null Local Create] listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@46638f session=SpySession@25165599[tx=true txid=null XA RUNNING connection=Connection@11044709[token=ConnectionToken:ID:4/062d5ce3759294ec70cb3dc12f8327b6 rcvstate=STARTED]]]
            2004.06.30 08:58:13.312 GMT-05:00 DEBUG [org.jgroups.protocols.PING] FIND_INITIAL_MBRS
            2004.06.30 08:58:13.312 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] sending message to 237.5.61.16:40011 (src=local:3094 (additional data: 18 bytes)), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=DefaultPartition]}
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] received (mcast) 122 bytes from /172.16.16.61:3094 (size=122 bytes)
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] message is [dst: 237.5.61.16:40011, src: local:3094 (additional data: 18 bytes) (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=DefaultPartition]}
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.PING] waiting for initial members: time_to_wait=2000, got 0 rsps
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.PING] received GET_MBRS_REQ from local:3094 (additional data: 18 bytes), returning [PING: type=GET_MBRS_RSP, arg=[own_addr=local:3094 (additional data: 18 bytes), coord_addr=local:3094 (additional data: 18 bytes)]]
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] sending message to local:3094 (additional data: 18 bytes) (src=local:3094 (additional data: 18 bytes)), headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=local:3094 (additional data: 18 bytes), coord_addr=local:3094 (additional data: 18 bytes)]], UDP=[UDP:group_addr=DefaultPartition]}
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] received (ucast) 320 bytes from /172.16.16.61:3094
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.UDP] message is [dst: local:3094 (additional data: 18 bytes), src: local:3094 (additional data: 18 bytes) (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=local:3094 (additional data: 18 bytes), coord_addr=local:3094 (additional data: 18 bytes)]], UDP=[UDP:group_addr=DefaultPartition]}
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.PING] received FIND_INITAL_MBRS_RSP, rsp=[own_addr=local:3094 (additional data: 18 bytes), coord_addr=local:3094 (additional data: 18 bytes)]
            2004.06.30 08:58:13.328 GMT-05:00 DEBUG [org.jgroups.protocols.PING] waiting for initial members: time_to_wait=2000, got 1 rsps


            • 3. Re: 3.2.4 / JMS / Transacation is not active

              Looks to me like you are misusing it.

              If you are using the resource adapter (java:/JmsXA), you don't do an explicit commit,
              the transaction manager does it for you when the JTA transaction completes,
              or rollsback when required.

              Another possibility would be trying to use the connection across two transactions/threads
              at the same time?
              e.g. you holding the connection in a static field or something which will totally break
              any pooling/ejb semantics.

              • 4. Re: 3.2.4 / JMS / Transacation is not active
                jdefelice

                Thanks for the tip. I added the thread ID to my server log files - it looks like all of the work in the transaction is being coordinated from a single thread. I'm not sharing the connection that I create across transactions (my connection is a local variable in my method).

                Here's a code snippet that outlines my use of the connection (different than the POJO code above):

                 public void sendMail( final long sinceWhen ) {
                
                 final Email[] emails = // determine the emails that i need to send
                 if ( emails.length > 0 ) {
                
                 Context nonFinalContext = null;
                 QueueConnection nonFinalConnection = null;
                
                 try {
                
                 final Context context = nonFinalContext = ContextFactory.createContext();
                 final QueueConnection conn = nonFinalConnection = createQueueConnection(context);
                
                 // force code in run(TxContext) to execute in SSB...
                 new AbstractTxCommand() {
                 public Object run(TxContext ctx) {
                 try {
                 QueueSession session = createSession(conn);
                 QueueSender sender = createSender(context,conn,session);
                 for ( int j = 0; j < emails.length; j++){
                 for ( int i = 0; i < recipients.length; i++){
                 sendSingle( emails[j], session, sender );
                 }
                 // log email as sent in the database
                 }
                 } catch (MailDeliveryException e ) {
                 throw new RuntimeException(...);
                 } catch (NamingException e ) {
                 throw new RuntimeException(...);
                 } catch (JMSException e ) {
                 throw new RuntimeException(...);
                 }
                 return null;// unused
                 }
                 }.run();
                 }
                 catch(NamingException ne) {
                 throw new RuntimeException("error accessing JNDI -- see logs for more detail");
                 }
                 catch(JMSException je) {
                 throw new RuntimeException("error accessing JMS -- see logs for more detail");
                 }
                 finally {
                 closeResources(nonFinalContext,nonFinalConnection);
                 }
                 }
                 }
                
                 QueueConnection createQueueConnection(Context context) throws NamingException, JMSException {
                 QueueConnectionFactory factory = (QueueConnectionFactory) context.lookup("java:/JmsXA");
                 return factory.createQueueConnection();
                 }
                
                 QueueSession createSession(QueueConnection conn) throws JMSException {
                 return conn.createQueueSession(true, Session.CLIENT_ACKNOWLEDGE);
                 }
                
                 QueueSender createSender(Context context, QueueConnection conn, QueueSession session) throws NamingException, JMSException {
                 Queue queue = (Queue)context.lookup(ContextFactory.EMAIL_QUEUE_NAME);
                 return session.createSender(queue);
                 }
                
                


                Here's what the server logs are giving me (my apologies for the length... but I thought it would be helpful to have all this info):


                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [DownHandler (PING)] [org.jgroups.protocols.PING] FIND_INITIAL_MBRS
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [DownHandler (PING)] [org.jgroups.protocols.PING] waiting for initial members: time_to_wait=2000, got 0 rsps
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [DownHandler (UDP)] [org.jgroups.protocols.UDP] sending message to 237.5.61.16:40011 (src=local:4804 (additional data: 18 bytes)), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=DefaultPartition]}
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UDP mcast receiver] [org.jgroups.protocols.UDP] received (mcast) 122 bytes from /172.16.16.61:4804 (size=122 bytes)
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UDP mcast receiver] [org.jgroups.protocols.UDP] message is [dst: 237.5.61.16:40011, src: local:4804 (additional data: 18 bytes) (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=DefaultPartition]}
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UpHandler (PING)] [org.jgroups.protocols.PING] received GET_MBRS_REQ from local:4804 (additional data: 18 bytes), returning [PING: type=GET_MBRS_RSP, arg=[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]]
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [DownHandler (UDP)] [org.jgroups.protocols.UDP] sending message to local:4804 (additional data: 18 bytes) (src=local:4804 (additional data: 18 bytes)), headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]], UDP=[UDP:group_addr=DefaultPartition]}
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UDP.UcastReceiverThread] [org.jgroups.protocols.UDP] received (ucast) 320 bytes from /172.16.16.61:4804
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UDP.UcastReceiverThread] [org.jgroups.protocols.UDP] message is [dst: local:4804 (additional data: 18 bytes), src: local:4804 (additional data: 18 bytes) (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]], UDP=[UDP:group_addr=DefaultPartition]}
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [UpHandler (PING)] [org.jgroups.protocols.PING] received FIND_INITAL_MBRS_RSP, rsp=[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]
                2004.07.01 08:54:56.437 GMT-05:00 DEBUG [DownHandler (PING)] [org.jgroups.protocols.PING] waiting for initial members: time_to_wait=2000, got 1 rsps
                2004.07.01 08:54:58.437 GMT-05:00 DEBUG [DownHandler (PING)] [org.jgroups.protocols.PING] initial mbrs are [[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]]
                2004.07.01 08:54:58.437 GMT-05:00 DEBUG [MERGE2.FindSubgroups thread] [org.jgroups.protocols.MERGE2] initial_mbrs=[[own_addr=local:4804 (additional data: 18 bytes), coord_addr=local:4804 (additional data: 18 bytes)]]
                2004.07.01 08:55:07.140 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.dao.EmailDao] sending [1008199,]
                2004.07.01 08:55:07.203 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [org.jboss.mq.referenceable.SpyConnectionFactoryObjectFactory] Extracting SpyConnectionFactory from reference
                2004.07.01 08:55:07.203 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [org.jboss.mq.referenceable.SpyConnectionFactoryObjectFactory] The GenericConnectionFactory is: GenericConnectionFactory[server=org.jboss.mq.il.uil2.UILServerIL@1bbdc80 connectionProperties={UIL_ADDRESS_KEY=172.16.16.61, UIL_CHUNKSIZE_KEY=1000000, UIL_TCPNODELAY_KEY=yes, ClientILService=org.jboss.mq.il.uil2.UILClientILService, UIL_PORT_KEY=22014, UIL_BUFFERSIZE_KEY=2048, PingPeriod=60000}]
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Connection Initializing userName=guest Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Getting the serverIL Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] serverIL=org.jboss.mq.il.uil2.UILServerIL@124be4f Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Authenticating user guest Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.UILServerIL] Connecting to : JDefelice1/172.16.16.61:22014
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.UILServerIL] Connecting with addr=172.16.16.61, port=22014, localAddr=null, localPort=0, socketFactory=javax.net.DefaultSocketFactory@341db1, enableTcpNoDelay=true, bufferSize=2048, chunkSize=1000000
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [UILServerILService Accept Thread] [org.jboss.mq.server.TracingInterceptor] CALLED : getThreadGroup
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [UILServerILService Accept Thread] [org.jboss.mq.server.TracingInterceptor] RETURN : getThreadGroup
                2004.07.01 08:55:07.203 GMT-05:00 TRACE [UILServerILService Accept Thread] [org.jboss.mq.il.uil2.SocketManager] start called
                java.lang.Exception: Start stack trace
                at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:94)
                at org.jboss.mq.il.uil2.UILServerILService.run(UILServerILService.java:127)
                at java.lang.Thread.run(Thread.java:534)
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] start called
                java.lang.Exception: Start stack trace
                at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:94)
                at org.jboss.mq.il.uil2.UILServerIL.createConnection(UILServerIL.java:626)
                at org.jboss.mq.il.uil2.UILServerIL.getSocketMgr(UILServerIL.java:505)
                at org.jboss.mq.il.uil2.UILServerIL.authenticate(UILServerIL.java:307)
                at org.jboss.mq.Connection.authenticate(Connection.java:1153)
                at org.jboss.mq.Connection.<init>(Connection.java:248)
                at org.jboss.mq.SpyConnection.<init>(SpyConnection.java:55)
                at org.jboss.mq.SpyXAConnection.<init>(SpyXAConnection.java:52)
                at org.jboss.mq.SpyXAConnectionFactory.createXAConnection(SpyXAConnectionFactory.java:98)
                at org.jboss.mq.SpyXAConnectionFactory.createXAQueueConnection(SpyXAConnectionFactory.java:119)
                at org.jboss.jms.ConnectionFactoryHelper.createQueueConnection(ConnectionFactoryHelper.java:67)
                at org.jboss.resource.adapter.jms.JmsManagedConnection.setup(JmsManagedConnection.java:683)
                at org.jboss.resource.adapter.jms.JmsManagedConnection.<init>(JmsManagedConnection.java:172)
                at org.jboss.resource.adapter.jms.JmsManagedConnectionFactory.createManagedConnection(JmsManagedConnectionFactory.java:101)
                at org.jboss.resource.connectionmanager.InternalManagedConnectionPool.createConnectionEventListener(InternalManagedConnectionPool.java:504)
                at org.jboss.resource.connectionmanager.InternalManagedConnectionPool.getConnection(InternalManagedConnectionPool.java:214)
                at org.jboss.resource.connectionmanager.JBossManagedConnectionPool$BasePool.getConnection(JBossManagedConnectionPool.java:534)
                at org.jboss.resource.connectionmanager.BaseConnectionManager2.getManagedConnection(BaseConnectionManager2.java:444)
                at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:312)
                at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:496)
                at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:887)
                at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.allocateConnection(JmsSessionFactoryImpl.java:369)
                at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.createQueueSession(JmsSessionFactoryImpl.java:137)
                at com.elementk.lms.khub.sys.email.MailSystem.createSession(MailSystem.java:233)
                at com.elementk.lms.khub.sys.email.MailSystem$2.run(MailSystem.java:102)
                at com.elementk.util.transaction.command.DefaultTxCommandProcessor.runAsRequired(DefaultTxCommandProcessor.java:24)
                at com.elementk.util.transaction.command.TxCommandProcessorBean.runAsRequired(TxCommandProcessorBean.java:94)
                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                at java.lang.reflect.Method.invoke(Method.java:324)
                at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
                at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
                at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
                at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
                at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:315)
                at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:148)
                at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:120)
                at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
                at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
                at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
                at org.jboss.ejb.Container.invoke(Container.java:723)
                at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:359)
                at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
                at $Proxy868.runAsRequired(Unknown Source)
                at com.elementk.util.transaction.command.TxCommandRunner$3.execute(TxCommandRunner.java:177)
                at com.elementk.util.transaction.command.TxCommandRunner$1.execute(TxCommandRunner.java:108)
                at com.elementk.util.transaction.command.TxCommandRunner.run(TxCommandRunner.java:66)
                at com.elementk.util.transaction.command.AbstractTxCommand.run(AbstractTxCommand.java:23)
                at com.elementk.lms.khub.sys.email.MailSystem.sendMail(MailSystem.java:99)
                at com.elementk.lms.khub.sys.email.EmailDaemon.wakeUpAndSendMail(EmailDaemon.java:84)
                at com.elementk.lms.khub.sys.email.EmailDaemon.process(EmailDaemon.java:68)
                at com.elementk.service.scheduler.ProcessSchedulerAdapter.runIfEnabled(ProcessSchedulerAdapter.java:65)
                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                at java.lang.reflect.Method.invoke(Method.java:324)
                at org.jboss.mx.server.ReflectedDispatcher.dispatch(ReflectedDispatcher.java:60)
                at org.jboss.mx.server.Invocation.dispatch(Invocation.java:61)
                at org.jboss.mx.server.Invocation.dispatch(Invocation.java:53)
                at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
                at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:185)
                at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:473)
                at org.jboss.jmx.adaptor.control.Server.invokeOpByName(Server.java:234)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.invokeOpByName(HtmlAdaptorServlet.java:266)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.processRequest(HtmlAdaptorServlet.java:81)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.doGet(HtmlAdaptorServlet.java:56)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
                at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
                at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
                at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
                at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:72)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:275)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at com.elementk.util.valve.RequestCollectorValve.invoke(RequestCollectorValve.java:96)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at com.elementk.util.valve.RequestEncodingValve.invoke(RequestEncodingValve.java:73)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
                at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
                at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
                at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
                at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
                at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
                at java.lang.Thread.run(Thread.java:534)
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg21643367[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg21643367[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_authenticate, msgID: -2147483581
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg23809882[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 22
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] CALLED : authenticate
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.security.ServerSecurityInterceptor] Autenticating user guest/guest
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.sm.file.DynamicLoginModule] initialize
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.sm.file.DynamicLoginModule] Saw unauthenticatedIdentity=guest
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.sm.file.DynamicLoginModule] login
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.sm.file.DynamicLoginModule] User 'guest' authenticated, loginOk=true
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.sm.file.DynamicLoginModule] commit, loginOk=true
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.security.SecurityManager] Username: guest is authenticated
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.security.SecurityManager] Adding group : class org.jboss.security.NestableGroup Roles(members:guest)
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] RETURN : authenticate
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg23809882[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg23809882[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 DEBUG [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_authenticate, msgID: -2147483581
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg21643367[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.CheckUserMsg21643367[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg23809882[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 22
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg21643367[msgType: m_authenticate, msgID: -2147483581, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Ask for an id user=guest Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg25604810[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.218 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg25604810[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_checkUser, msgID: -2147483580
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg4454359[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 20
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] CALLED : checkUser
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] ARG : guest
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] ARG : (password not shown)
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] RETURN : checkUser
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg4454359[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg4454359[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 20
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg4454359[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_checkUser, msgID: -2147483580
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg25604810[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.CheckUserMsg25604810[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg25604810[msgType: m_checkUser, msgID: -2147483580, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Starting the client il Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.GenericConnectionFactory] Handing out ClientIL: org.jboss.mq.il.uil2.UILClientILService
                2004.07.01 08:55:07.234 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.UILClientILService] Starting
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Using client id org.jboss.mq.il.uil2.UILClientILService@17a0daa Connection@9003160[clientID=null rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg1514716[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg1514716[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_setSpyDistributedConnection, msgID: -2147483579
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg10032989[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 15
                2004.07.01 08:55:07.234 GMT-05:00 DEBUG [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Setting up the UILClientIL Connection
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg10032989[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg10032989[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 DEBUG [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] The UILClientIL Connection is set up
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 15
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg10032989[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_setSpyDistributedConnection, msgID: -2147483579
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg1514716[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg1514716[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg1514716[msgType: m_setSpyDistributedConnection, msgID: -2147483579, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Creating XAResourceManager Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Starting the ping thread Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Connection establishment successful Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Checking clientID=null Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Ask for an id Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.GetIDMsg13439845[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Connection Monitor Thread] [org.jboss.mq.Connection] PING 1088690107234 Connection@9003160[token=ConnectionToken:null/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Connection Monitor Thread] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg28593753[msgType: m_ping, msgID: -2147483577, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Connection Monitor Thread] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg28593753[msgType: m_ping, msgID: -2147483577, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg13439845[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_getID, msgID: -2147483578
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.GetIDMsg8638356[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg28593753[msgType: m_ping, msgID: -2147483577, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_ping, msgID: -2147483577
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg28376790[msgType: m_ping, msgID: -2147483577, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 9
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] CALLED : getID
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] RETURN : getID
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.GetIDMsg8638356[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.GetIDMsg8638356[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 9
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg8638356[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.234 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_getID, msgID: -2147483578
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.GetIDMsg13439845[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.GetIDMsg13439845[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.GetIDMsg13439845[msgType: m_getID, msgID: -2147483578, error: null]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] ClientID established Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResource] Created SpyXAResource[session=SpySession@2508535[tx=true txid=null connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpySession] New session SpySession@2508535[tx=true txid=null XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResource] Start xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1], flags=0 SpyXAResource[session=SpySession@2508535[tx=true txid=null XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] Starting tx xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpySession] Setting current tx xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] previous: null SpySession@2508535[tx=true txid=null XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]
                2004.07.01 08:55:07.250 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyMessageProducer] New message producer SpyMessageProducer@13424221[ dest=QUEUE.khubEmailQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpySession] Adding producer SpyMessageProducer@13424221[ dest=QUEUE.khubEmailQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.250 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendMail(Wed Dec 31 00:00:00 GMT 1969)
                sending 1 email messages
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] CALLED : ping
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] ARG : 1088690107234
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg23659532[msgType: m_pong, msgID: -2147483576, error: null]
                2004.07.01 08:55:07.250 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg23659532[msgType: m_pong, msgID: -2147483576, error: null]
                2004.07.01 08:55:07.265 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_pong, msgID: -2147483576
                2004.07.01 08:55:07.265 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg25749752[msgType: m_pong, msgID: -2147483576, error: null]
                2004.07.01 08:55:07.265 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg23659532[msgType: m_pong, msgID: -2147483576, error: null]
                2004.07.01 08:55:07.265 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] RETURN : ping
                2004.07.01 08:55:07.265 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
                2004.07.01 08:55:07.281 GMT-05:00 TRACE [Thread-106] [org.jboss.mq.il.uil2.UILClientILService] Begin handleMsg, msgType: 24
                2004.07.01 08:55:07.281 GMT-05:00 TRACE [Thread-106] [org.jboss.mq.Connection] PONG serverTime=1088690107250 Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.281 GMT-05:00 TRACE [Thread-106] [org.jboss.mq.il.uil2.UILClientILService] End handleMsg
                2004.07.01 08:55:07.343 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendMail() recipients 1
                2004.07.01 08:55:07.343 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendMail: sending queued email: # to send = 1
                2004.07.01 08:55:07.343 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendMail(): sending to [Lcom.elementk.lms.khub.sys.email.IndividualRecipient;@53d4bf
                2004.07.01 08:55:07.343 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendSingle(): sending email [test one email] to to=james_defelice@elementk.com recipientId=0
                2004.07.01 08:55:07.359 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] sendSingle(): Sending email com.elementk.lms.khub.sys.email.Email subject=test one email; # of recipients=1
                2004.07.01 08:55:07.359 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@13424221[ dest=QUEUE.khubEmailQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                org.jboss.mq.SpyObjectMessage {
                Header {
                jmsDestination : QUEUE.khubEmailQueue
                jmsDeliveryMode : 2
                jmsExpiration : 0
                jmsPriority : 4
                jmsMessageID : ID:6-10886901073591
                jmsTimeStamp : 1088690107359
                jmsCorrelationID: null
                jmsReplyTo : null
                jmsType : null
                jmsRedelivered : false
                jmsProperties : {}
                jmsPropReadWrite: true
                msgReadOnly : false
                producerClientId: ID:6
                }
                }
                2004.07.01 08:55:07.359 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpySession] Adding message to transaction ID:6-10886901073591 SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]
                2004.07.01 08:55:07.359 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] Adding message xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1], message=ID:6-10886901073591
                2004.07.01 08:55:07.359 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] TXState=TxState txState=0 sent=[] acks=[]
                2004.07.01 08:55:07.359 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.MailSystem] marking email(1008199) as sent
                2004.07.01 08:55:07.359 GMT-05:00 DEBUG [http-0.0.0.0-8443-Processor5] [com.elementk.lms.khub.sys.email.dao.EmailDao] marking email(1008199) as SENT
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResource] End xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1], flags=67108864 SpyXAResource[session=SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpySession] Unsetting current tx xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] previous: XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] SpySession@2508535[tx=true txid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] Ending xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1], success=true
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResource] Prepare xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] SpyXAResource[session=SpySession@2508535[tx=true txid=null XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] Preparing xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1]
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@756b37 Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.375 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg13757758[msgType: m_transact, msgID: -2147483575, error: null]
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg13757758[msgType: m_transact, msgID: -2147483575, error: null]
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483575
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.TransactMsg6173652[msgType: m_transact, msgID: -2147483575, error: null]
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 17
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] CALLED : transact
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.TransactionRequest@11bedb0
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
                Principal: guest
                Principal: Roles(members:guest)
                ;principal=guest;roles=Roles(members:guest) for rolePrincipals [guest]
                2004.07.01 08:55:07.390 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] EXCEPTION : transact:
                javax.jms.JMSException: Transacation is not active.
                at org.jboss.mq.pm.Tx.addPostCommitTask(Tx.java:177)
                at org.jboss.mq.pm.TxManager.createTx(TxManager.java:157)
                at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:453)
                at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
                at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
                at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
                at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
                at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
                at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
                at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
                at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
                at java.lang.Thread.run(Thread.java:534)
                2004.07.01 08:55:07.406 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.server.TracingInterceptor] RETURN : transact
                2004.07.01 08:55:07.406 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.TransactMsg6173652[msgType: m_transact, msgID: -2147483575, error: null]
                javax.jms.JMSException: Transacation is not active.
                at org.jboss.mq.pm.Tx.addPostCommitTask(Tx.java:177)
                at org.jboss.mq.pm.TxManager.createTx(TxManager.java:157)
                at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:453)
                at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
                at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
                at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
                at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
                at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
                at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
                at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
                at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
                at java.lang.Thread.run(Thread.java:534)
                2004.07.01 08:55:07.406 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.TransactMsg6173652[msgType: m_transact, msgID: -2147483575, error: javax.jms.JMSException: Transacation is not active.]
                2004.07.01 08:55:07.406 GMT-05:00 TRACE [Thread-104] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg6173652[msgType: m_transact, msgID: -2147483575, error: javax.jms.JMSException: Transacation is not active.]
                2004.07.01 08:55:07.406 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg6173652[msgType: m_transact, msgID: -2147483575, error: javax.jms.JMSException: Transacation is not active.]
                2004.07.01 08:55:07.421 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483575
                2004.07.01 08:55:07.421 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.TransactMsg13757758[msgType: m_transact, msgID: -2147483575, error: null]
                2004.07.01 08:55:07.421 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.TransactMsg13757758[msgType: m_transact, msgID: -2147483575, error: javax.jms.JMSException: Transacation is not active.]
                2004.07.01 08:55:07.421 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg13757758[msgType: m_transact, msgID: -2147483575, error: javax.jms.JMSException: Transacation is not active.]
                2004.07.01 08:55:07.421 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] sendMessage will throw error
                javax.jms.JMSException: Transacation is not active.
                at org.jboss.mq.pm.Tx.addPostCommitTask(Tx.java:177)
                at org.jboss.mq.pm.TxManager.createTx(TxManager.java:157)
                at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:453)
                at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
                at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
                at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
                at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
                at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
                at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
                at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
                at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
                at java.lang.Thread.run(Thread.java:534)
                2004.07.01 08:55:07.421 GMT-05:00 WARN [http-0.0.0.0-8443-Processor5] [org.jboss.tm.TransactionImpl] XAException: tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=] errorCode=XAER_RMERR
                org.jboss.mq.SpyXAException: - nested throwable: (javax.jms.JMSException: Transacation is not active.)
                at org.jboss.mq.SpyXAResource.prepare(SpyXAResource.java:135)
                at org.jboss.tm.TransactionImpl.prepareResources(TransactionImpl.java:1556)
                at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:385)
                at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:456)
                at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:324)
                at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:148)
                at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:120)
                at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
                at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
                at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
                at org.jboss.ejb.Container.invoke(Container.java:723)
                at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:359)
                at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
                at $Proxy868.runAsRequired(Unknown Source)
                at com.elementk.util.transaction.command.TxCommandRunner$3.execute(TxCommandRunner.java:177)
                at com.elementk.util.transaction.command.TxCommandRunner$1.execute(TxCommandRunner.java:108)
                at com.elementk.util.transaction.command.TxCommandRunner.run(TxCommandRunner.java:66)
                at com.elementk.util.transaction.command.AbstractTxCommand.run(AbstractTxCommand.java:23)
                at com.elementk.lms.khub.sys.email.MailSystem.sendMail(MailSystem.java:99)
                at com.elementk.lms.khub.sys.email.EmailDaemon.wakeUpAndSendMail(EmailDaemon.java:84)
                at com.elementk.lms.khub.sys.email.EmailDaemon.process(EmailDaemon.java:68)
                at com.elementk.service.scheduler.ProcessSchedulerAdapter.runIfEnabled(ProcessSchedulerAdapter.java:65)
                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                at java.lang.reflect.Method.invoke(Method.java:324)
                at org.jboss.mx.server.ReflectedDispatcher.dispatch(ReflectedDispatcher.java:60)
                at org.jboss.mx.server.Invocation.dispatch(Invocation.java:61)
                at org.jboss.mx.server.Invocation.dispatch(Invocation.java:53)
                at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
                at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:185)
                at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:473)
                at org.jboss.jmx.adaptor.control.Server.invokeOpByName(Server.java:234)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.invokeOpByName(HtmlAdaptorServlet.java:266)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.processRequest(HtmlAdaptorServlet.java:81)
                at org.jboss.jmx.adaptor.html.HtmlAdaptorServlet.doGet(HtmlAdaptorServlet.java:56)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
                at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
                at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
                at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
                at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:72)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:275)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
                at com.elementk.util.valve.RequestCollectorValve.invoke(RequestCollectorValve.java:96)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at com.elementk.util.valve.RequestEncodingValve.invoke(RequestEncodingValve.java:73)
                at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
                at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
                at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
                at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
                at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
                at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
                at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
                at java.lang.Thread.run(Thread.java:534)
                Caused by: javax.jms.JMSException: Transacation is not active.
                at org.jboss.mq.pm.Tx.addPostCommitTask(Tx.java:177)
                at org.jboss.mq.pm.TxManager.createTx(TxManager.java:157)
                at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:453)
                at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:186)
                at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:182)
                at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:447)
                at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186)
                at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:166)
                at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:356)
                at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377)
                at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
                ... 1 more
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResource] Rollback xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1] SpyXAResource[session=SpySession@2508535[tx=true txid=null XA RUNNING connection=Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]]]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.SpyXAResourceManager] Rolling back xid=XidImpl [FormatId=257, GlobalId=JDefelice1//6, BranchQual=1]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@24f2f2 Connection@9003160[token=ConnectionToken:ID:6/46367633bd2f616b4c6d6078f77f59f4 rcvstate=STOPPED]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg30010864[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#40 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg30010864[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483574
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#37 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.TransactMsg10364428[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 17
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] CALLED : transact
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.TransactionRequest@d40c4e
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.server.TracingInterceptor] RETURN : transact
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.TransactMsg10364428[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg10364428[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [Thread-105] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 17
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.WriteTask#38 client=172.16.16.61:4830] [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg10364428[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: -2147483574
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.TransactMsg30010864[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [UIL2.SocketManager.ReadTask#39 client=172.16.16.61:22014] [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.TransactMsg30010864[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.437 GMT-05:00 TRACE [http-0.0.0.0-8443-Processor5] [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg30010864[msgType: m_transact, msgID: -2147483574, error: null]
                2004.07.01 08:55:07.484 GMT-05:00 INFO [http-0.0.0.0-8443-Processor5] [org.jboss.resource.connectionmanager.CachedConnectionManager] Closing a connection for you. Please close them yourself: org.jboss.resource.adapter.jms.JmsSession@5d868f
                java.lang.Exception: STACKTRACE
                at org.jboss.resource.connectionmanager.CachedConnectionManager.registerConnection(CachedConnectionManager.java:285)
                at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:525)
                at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:887)
                at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.allocateConnection(JmsSessionFactoryImpl.java:369)
                at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.createQueueSession(JmsSessionFactoryImpl.java:137)
                at com.elementk.lms.khub.sys.email.MailSystem.createSession(MailSyst


                • 5. Re: 3.2.4 / JMS / Transacation is not active
                  jdefelice

                  Thanks for the help Adrian.

                  I figured out what the problem was - it's a bug in the org.jboss.mq.pm.rollinglogged.PersistenceManager class.

                  I filed a bug report #990315 in sourceforce - along with some changes that I made locally to fix it.

                  It would be nice to see this fixed in the upcoming 3.2.6 release.