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:
<category name="org.jboss.ejb3">
<priority value="TRACE"/>
</category>
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.