users@glassfish.java.net

Re: JMS and transaction issue

From: Theodor Richard <theodor.richard_at_googlemail.com>
Date: Thu, 6 Jan 2011 18:50:47 +0100

After executing this one more time, I see the following exception (I've
restarted the server before doing this):

SEVERE: prepareTransaction (XA) on JMSService:jmsdirect failed for
connectionId:6227683734675645440 due to Unknown JMSService server error
ERROR: com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad transaction
state transition. Cannot perform operation PREPARE_TRANSACTION(56)
(XAFlag=null) on a transaction in state STARTED(1).

WARNING: JTS5031: Exception [java.lang.RuntimeException:
javax.transaction.xa.XAException] on Resource [prepare] operation.
SEVERE: rollbackTransaction (XA) on JMSService:jmsdirect failed for
connectionId:6227683734675645440:transactionId=6227683734740783360 due to
Unknown JMSService server error ERROR:
com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad transaction state
transition. Cannot perform operation ROLLBACK_TRANSACTION(48) (XAFlag=null)
on a transaction in state STARTED(1).

WARNING: JTS5068: Unexpected error occurred in rollback
javax.transaction.xa.XAException
        at
com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:703)
        at
com.sun.jts.jta.TransactionState.rollback(TransactionState.java:193)
        at
com.sun.jts.jtsxa.OTSResourceImpl.rollback(OTSResourceImpl.java:333)
        at
com.sun.jts.CosTransactions.RegisteredResources.distributeRollback(RegisteredResources.java:1063)
        at
com.sun.jts.CosTransactions.TopCoordinator.rollback(TopCoordinator.java:2299)
        at
com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:420)
        at
com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:250)
        at
com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:623)
        at
com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:319)
        at
com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:173)
        at
com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:873)
        at
com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115)
        at
com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4880)
        at
com.sun.ejb.containers.MessageBeanContainer.afterMessageDeliveryInternal(MessageBeanContainer.java:1207)
        at
com.sun.ejb.containers.MessageBeanContainer.afterMessageDelivery(MessageBeanContainer.java:1180)
        at
com.sun.ejb.containers.MessageBeanListenerImpl.afterMessageDelivery(MessageBeanListenerImpl.java:86)
        at
com.sun.enterprise.connectors.inbound.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:143)
        at $Proxy260.afterDelivery(Unknown Source)
        at
com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:328)
        at
com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:114)
        at
com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:496)
        at
com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:537)
Caused by: com.sun.messaging.jmq.jmsservice.JMSServiceException:
rollbackTransaction: rollback transaction failed. Connection ID:
6227683734675645440, Transaction ID: 6227683734740783360, XID: null
        at
com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1827)
        at
com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:672)
        ... 21 more
Caused by: com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad
transaction state transition. Cannot perform operation
ROLLBACK_TRANSACTION(48) (XAFlag=null) on a transaction in state STARTED(1).
        at
com.sun.messaging.jmq.jmsserver.data.TransactionState.nextState(TransactionState.java:449)
        at
com.sun.messaging.jmq.jmsserver.data.handlers.TransactionHandler.preRollback(TransactionHandler.java:1586)
        at
com.sun.messaging.jmq.jmsserver.data.protocol.ProtocolImpl.rollbackTransaction(ProtocolImpl.java:777)
        at
com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1816)
        ... 22 more



Regards,
Theodor



On Thu, Jan 6, 2011 at 6:48 PM, Theodor Richard <
theodor.richard_at_googlemail.com> wrote:

> I have an issue with JMS and transactions which I do not completely
> understand. My application has one JDBC resource and two JMS queues. The
> message producers for the queues are created within the same stateless
> session bean from the the same jms session object. The way I use the queues
> is as follows: An entitiy is created and its id is saved as a property in
> the JMS message and sent to the queue. The creation of the entity and the
> submission to the queue happen in the same transaction. My message driven
> bean then retrieves the entity from the database via the ID in the JMS
> message and processes it.
>
> The code looks roughly like this:
>
> public long doSomething(String message) {
> SomeObject obj = new SomeObject(message);
> entityManager.persist(obj)
>
> // submit to JMS queue
> try {
> Message jmsMessage = session.createMessage();
> jmsMessage.setLongProperty("id", obj.getId());
> messageProducer.send(jmsMessage);
> } catch (JMSException ex) {
>
> Logger.getLogger(NotificationQueue.class.getName()).log(Level.SEVERE, null,
> ex);
> }
>
> return obj.getId();
> }
>
> the MDB's onMessage method:
>
> public void onMessage(Message message) {
> Long id;
> try {
> id = message.getLongProperty("id");
> } catch (Exception ex) {
>
> Logger.getLogger(AlertMessageListener.class.getName()).log(Level.SEVERE,
> null, ex);
> throw new EJBException(ex);
> }
>
> SomeObject obj = entityManager.find(SomeObject.class, id);
> obj.process();
> }
>
> When the entity is retrieved from the database in the onMessage() method,
> the following exception is in the log file:
>
> FINE: ENTRY com.test.app.alert.control.AlertMessageListener onMessage
> FINE: ENTRY com.test.app.alert.control.MessageDao find
> FINER: client acquired: 2104888816
> FINER: TX binding to tx mgr, status=STATUS_ACTIVE
> FINER: acquire unit of work: 1368213481
> FINEST: Execute query ReadObjectQuery(name="readObject"
> referenceClass=Message sql="SELECT ID, DTYPE, MESSAGE, REPORTTIME,
> SENDER_USERNAME, ALERTSTATE, TIMERHANDLE, CATEGORY_ID, PRIORITY_PRIOLEVEL
> FROM MESSAGE WHERE (ID = ?)")
> SEVERE: prepareTransaction (XA) on JMSService:jmsdirect failed for
> connectionId:7979865462417759232 due to Unknown JMSService server error
> ERROR: com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad transaction
> state transition. Cannot perform operation PREPARE_TRANSACTION(56)
> (XAFlag=null) on a transaction in state STARTED(1).
> WARNING: JTS5031: Exception [java.lang.RuntimeException:
> javax.transaction.xa.XAException] on Resource [prepare] operation.
> SEVERE: rollbackTransaction (XA) on JMSService:jmsdirect failed for
> connectionId:7979865462417759232:transactionId=7979865462479908608 due to
> Unknown JMSService server error ERROR:
> com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad transaction state
> transition. Cannot perform operation ROLLBACK_TRANSACTION(48) (XAFlag=null)
> on a transaction in state STARTED(1).
> WARNING: JTS5068: Unexpected error occurred in rollback
> javax.transaction.xa.XAException
> at
> com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:703)
> at
> com.sun.jts.jta.TransactionState.rollback(TransactionState.java:193)
> at
> com.sun.jts.jtsxa.OTSResourceImpl.rollback(OTSResourceImpl.java:333)
> at
> com.sun.jts.CosTransactions.RegisteredResources.distributeRollback(RegisteredResources.java:1063)
> at
> com.sun.jts.CosTransactions.TopCoordinator.rollback(TopCoordinator.java:2299)
> at
> com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:420)
> at
> com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:250)
> at
> com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:623)
> at
> com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:319)
> at
> com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:173)
> at
> com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:873)
> at
> com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115)
> at
> com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4880)
> at
> com.sun.ejb.containers.MessageBeanContainer.afterMessageDeliveryInternal(MessageBeanContainer.java:1207)
> at
> com.sun.ejb.containers.MessageBeanContainer.afterMessageDelivery(MessageBeanContainer.java:1180)
> at
> com.sun.ejb.containers.MessageBeanListenerImpl.afterMessageDelivery(MessageBeanListenerImpl.java:86)
> at
> com.sun.enterprise.connectors.inbound.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:143)
> at $Proxy260.afterDelivery(Unknown Source)
> at
> com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:328)
> at
> com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:114)
> at
> com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:496)
> at
> com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:537)
> Caused by: com.sun.messaging.jmq.jmsservice.JMSServiceException:
> rollbackTransaction: rollback transaction failed. Connection ID:
> 7979865462417759232, Transaction ID: 7979865462479908608, XID: null
> at
> com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1827)
> at
> com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:672)
> ... 21 more
> Caused by: com.sun.messaging.jmq.jmsserver.util.BrokerException: Bad
> transaction state transition. Cannot perform operation
> ROLLBACK_TRANSACTION(48) (XAFlag=null) on a transaction in state STARTED(1).
> at
> com.sun.messaging.jmq.jmsserver.data.TransactionState.nextState(TransactionState.java:449)
> at
> com.sun.messaging.jmq.jmsserver.data.handlers.TransactionHandler.preRollback(TransactionHandler.java:1586)
> at
> com.sun.messaging.jmq.jmsserver.data.protocol.ProtocolImpl.rollbackTransaction(ProtocolImpl.java:777)
> at
> com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1816)
> ... 22 more
>
> FINER: TX afterCompletion callback, status=ROLLEDBACK
> FINER: release unit of work
> FINER: client released
> FINEST: Register the existing object
> com.test.app.alert.entity.AlertMessage_at_7981d22
> FINER: end unit of work commit
> FINEST: Register the existing object Mailserver
> FINEST: Register the existing object Low
> FINEST: Register the existing object u0 u0 (u0)
> FINEST: Register the existing object Sankt Augustin
> FINE: RETURN com.test.app.alert.control.MessageDao find
> ...
> WARNING: javax.ejb.EJBException
> javax.ejb.EJBException: Transaction aborted
> at
> com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5121)
> at
> com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4880)
> at
> com.sun.ejb.containers.MessageBeanContainer.afterMessageDeliveryInternal(MessageBeanContainer.java:1207)
> at
> com.sun.ejb.containers.MessageBeanContainer.afterMessageDelivery(MessageBeanContainer.java:1180)
> at
> com.sun.ejb.containers.MessageBeanListenerImpl.afterMessageDelivery(MessageBeanListenerImpl.java:86)
> at
> com.sun.enterprise.connectors.inbound.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:143)
> at $Proxy260.afterDelivery(Unknown Source)
> at
> com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:328)
> at
> com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:114)
> at
> com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:496)
> at
> com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:537)
> Caused by: javax.transaction.RollbackException
> at
> com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:321)
> at
> com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:173)
> at
> com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:873)
> at
> com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115)
> ... 10 more
>
> The following INFO was in the log file a little bit before (after the
> entity was created):
>
> INFO: DXAR:start():Warning:Received diff Xid for open txnId:switching
> transactionId:
> DXAR Xid=(GlobalTransactionID=[B_at_4eec2030, BranchQualifier=[B_at_703557ca)
> DXAR TXid=7979865462479908608
> got Xid=(GlobalTransactionID=[B_at_3e16c853, BranchQualifier=[B_at_49b9e0fd)
> got TXid=7979865462480472064
>
> What exactly does this exception mean:
>
> Bad transaction state transition. Cannot perform operation
> ROLLBACK_TRANSACTION(48) (XAFlag=null) on a transaction in state STARTED(1).
>
> I'm using Glassfish v3.1-b35 with JPA 2.0 (and Apache Derby) and the
> standard JMS provider shipped with GF. Transactions settings are default as
> well as the JMS resources (EMBEDDED mode). Transactions are
> container-managed. Any ideas what is going wrong here? The exception happens
> pretty often.
>
> Regards,
> Theodor
>
>