Hi,

We are using jboss 4.2.3 and we noticed a really bizarre bug. When we enable tracing for org.jboss.ejb3 in the jboss-log4j.xml file with the following entry:

We start getting this arjuna exception every time we put a message on our topic. It seems like the transaction changes mid transaction, causing an inconsistent state which arjuna does not like :

12:10:06,247 WARN  [MessageInflowLocalProxy] Current transaction TransactionImple < ac, BasicAction: -53ec9f29:d858:4bfe44ad:ca2 status: ActionStatus.RUNNING > is not the expected transaction.

12:10:06,247 WARN  [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_34] - End called on already committed atomic action -53ec9f29:d858:4bfe44ad:434

12:10:06,247 ERROR [JmsServerSession] Unexpected error delivering message org.jboss.mq.SpyObjectMessage {

Header {

   jmsDestination  : TOPIC.XXXXXX

   jmsDeliveryMode : 1

   jmsExpiration   : 1274955064906

   jmsPriority     : 4

   jmsMessageID    : ID:2-12749550049061

   jmsTimeStamp    : 1274955004906

   jmsCorrelationID: null

   jmsReplyTo      : null

   jmsType         : null

   jmsRedelivered  : true

   jmsProperties   : {JMSXDeliveryCount=484, JMS_JBOSS_REDELIVERY_LIMIT=0, JMS_JBOSS_REDELIVERY_COUNT=483}

   jmsPropReadWrite: false

   msgReadOnly     : true

   producerClientId: ID:2

}

}

javax.resource.ResourceException: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!

at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:232)

at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:134)

at $Proxy153.afterDelivery(Unknown Source)

at org.jboss.resource.adapter.jms.inflow.JmsServerSession.onMessage(JmsServerSession.java:183)

at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:906)

at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)

at org.jboss.mq.SpySession.run(SpySession.java:323)

at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:237)

at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)

at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)

at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)

at java.lang.Thread.run(Thread.java:619)

Caused by: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!

at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1385)

at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)

at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)

at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:433)

at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:312)

at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:228)

Any ideas why this is happening (or if a jira bug has been opened for this)?

We have other classes set to TRACE in a similar fashion which work 100%. The good news is that the trace is definitely activated for org.jboss.ejb3.