MessageInflowLocalProxy retains previous transaction
girish_n Aug 16, 2012 2:15 AMWe are using WM Broker as JMS provider with JBoss Application Server (jboss-eap-5.1).
We are using container managed MDB that is deployed in JBoss.
While JBoss receives messages from Broker we get Exception:
2012-08-16 08:50:23,197 WARN [com.arjuna.ats.jta.logging.loggerI18N] (WorkManager(2)-4) [com.arjuna.ats.internal.jta.resources.arjunacore.opcerror] [com.arjuna.ats.internal.jta.resources.arjunacore.opcerror] XAResourceRecord.commit_one_phase caught: java.util.ConcurrentModificationException
2012-08-16 08:50:23,197 SEVERE [com.sun.genericjmsra] (WorkManager(2)-4) After delivery failed javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Could not commit transaction.
javax.resource.ResourceException: javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Could not commit transaction.
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:263)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:140)
at $Proxy120.afterDelivery(Unknown Source)
at com.sun.genericra.inbound.async.InboundJmsResource.releaseEndpoint(InboundJmsResource.java:157)
at com.sun.genericra.inbound.async.WorkImpl.run(WorkImpl.java:59)
at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:205)
at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
Caused by: javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Could not commit transaction.
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1443)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:137)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:464)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:343)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:259)
... 9 more
I did some investigation and found that New Transaction is not created ( if there is a Transaction already) always in MessageInflowLocalProxy.
Traces from JBoss server logs:
Success case:
2012-08-16 10:50:47,219 INFO [com.sun.genericjmsra] (WorkManager(2)-36) Creating message endpoint : com.webmethods.jms.loadbalance.connection.WmClusterXAQueueSessionImpl[com.webmethods.jms.impl.WmXASessionImpl[state=started transacted=true acknowledgeMode=Session-Transacted messageConsumerCount=0 messageProducerCount=0]com.webmethods.jms.impl.WmXASessionImpl[state=started transacted=true acknowledgeMode=Session-Transacted messageConsumerCount=0 messageProducerCount=0]]
2012-08-16 10:50:47,219 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory] (WorkManager(2)-36) createEndpoint org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@51b343e9{ resourceAdapter=webm-jmsra.rar, messagingType=interface javax.jms.MessageListener, ejbName=TestMDB, activationConfig=[ActivationConfigProperty(ReconnectInterval=60), ActivationConfigProperty(DestinationType=javax.jms.Queue), ActivationConfigProperty(ReconnectAttempts=5), ActivationConfigProperty(RedeliveryAttempts=5), ActivationConfigProperty(ConnectionFactoryJndiName=grip-qcf), ActivationConfigProperty(RedeliveryInterval=30), ActivationConfigProperty(DestinationJndiName=ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue), ActivationConfigProperty(SupportsXA=TRUE)], activationSpec=com.sun.genericra.inbound.ActivationSpec@7ca58b69{ConnectionFactoryClassName = com.webmethods.jms.impl.WmConnectionFactoryImpl},{QueueConnectionFactoryClassName = com.webmethods.jms.impl.WmQueueConnectionFactoryImpl},{TopicConnectionFactoryClassName = com.webmethods.jms.impl.WmTopicConnectionFactoryImpl},{XAConnectionFactoryClassName = com.webmethods.jms.impl.WmXAConnectionFactoryImpl},{XAQueueConnectionFactoryClassName = com.webmethods.jms.impl.WmXAQueueConnectionFactoryImpl},{XATopicConnectionFactoryClassName = com.webmethods.jms.impl.WmXATopicConnectionFactoryImpl},{QueueClassName = com.webmethods.jms.impl.WmQueueImpl},{TopicClassName = com.webmethods.jms.impl.WmTopicImpl},{UnifiedDestinationClassName = null},{ConnectionFactoryProperties = null},{JndiProperties = java.naming.factory.initial=com.webmethods.jms.naming.WmJmsNamingCtxFactory,java.naming.provider.url=wmjmsnaming://lon-2-a@10.60.29.136:6849,com.webmethods.jms.naming.clientgroup=admin},{ProviderIntegrationMode = jndi},{CommonSetterMethodName = null},{SupportsXA = true},{DeliveryType = null},{RedeliveryInterval = 30},{RedeliveryAttempts = 5},{ClientID = null},{MessageSelector = null},{SubscriptionDurability = Non-Durable},{ConnectionFactoryJNDIName = grip-qcf},{SubscriptionName = null},{DestinationJNDIName = ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue},{DestinationType = javax.jms.Queue},{DeadMessageDestinationType = javax.jms.Destination},{MaxPoolSize = 8},{DestinationProperties = null},{DeadMessageDestinationJndiName = null},{DeadMessageConnectionFactoryJndiName = null},{DeadMessageConnectionFactoryProperties = null},{DeadMessageDestinationClassName = null},{DeadMessageDestinationProperties = null},{SendBadMessagesToDMD = false},{EndpointReleaseTimeOut = 180},{InstanceCount = 1},{LoadBalancingRequired = true},{Instance ID = 0},{CustomLoadBalancingMessageSelector = },{ShareClientID = false}{DeliveryType = null}} xaResource=com.sun.genericra.inbound.InboundXAResourceProxy@95fe6d2
2012-08-16 10:50:47,219 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory] (WorkManager(2)-36) Created endpoint jboss.j2ee:jar=jboss-seam-testmdb.jar,name=TestMDB,service=EJB3 from org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@51b343e9{ resourceAdapter=webm-jmsra.rar, messagingType=interface javax.jms.MessageListener, ejbName=TestMDB, activationConfig=[ActivationConfigProperty(ReconnectInterval=60), ActivationConfigProperty(DestinationType=javax.jms.Queue), ActivationConfigProperty(ReconnectAttempts=5), ActivationConfigProperty(RedeliveryAttempts=5), ActivationConfigProperty(ConnectionFactoryJndiName=grip-qcf), ActivationConfigProperty(RedeliveryInterval=30), ActivationConfigProperty(DestinationJndiName=ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue), ActivationConfigProperty(SupportsXA=TRUE)], activationSpec=com.sun.genericra.inbound.ActivationSpec@7ca58b69{ConnectionFactoryClassName = com.webmethods.jms.impl.WmConnectionFactoryImpl},{QueueConnectionFactoryClassName = com.webmethods.jms.impl.WmQueueConnectionFactoryImpl},{TopicConnectionFactoryClassName = com.webmethods.jms.impl.WmTopicConnectionFactoryImpl},{XAConnectionFactoryClassName = com.webmethods.jms.impl.WmXAConnectionFactoryImpl},{XAQueueConnectionFactoryClassName = com.webmethods.jms.impl.WmXAQueueConnectionFactoryImpl},{XATopicConnectionFactoryClassName = com.webmethods.jms.impl.WmXATopicConnectionFactoryImpl},{QueueClassName = com.webmethods.jms.impl.WmQueueImpl},{TopicClassName = com.webmethods.jms.impl.WmTopicImpl},{UnifiedDestinationClassName = null},{ConnectionFactoryProperties = null},{JndiProperties = java.naming.factory.initial=com.webmethods.jms.naming.WmJmsNamingCtxFactory,java.naming.provider.url=wmjmsnaming://lon-2-a@10.60.29.136:6849,com.webmethods.jms.naming.clientgroup=admin},{ProviderIntegrationMode = jndi},{CommonSetterMethodName = null},{SupportsXA = true},{DeliveryType = null},{RedeliveryInterval = 30},{RedeliveryAttempts = 5},{ClientID = null},{MessageSelector = null},{SubscriptionDurability = Non-Durable},{ConnectionFactoryJNDIName = grip-qcf},{SubscriptionName = null},{DestinationJNDIName = ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue},{DestinationType = javax.jms.Queue},{DeadMessageDestinationType = javax.jms.Destination},{MaxPoolSize = 8},{DestinationProperties = null},{DeadMessageDestinationJndiName = null},{DeadMessageConnectionFactoryJndiName = null},{DeadMessageConnectionFactoryProperties = null},{DeadMessageDestinationClassName = null},{DeadMessageDestinationProperties = null},{SendBadMessagesToDMD = false},{EndpointReleaseTimeOut = 180},{InstanceCount = 1},{LoadBalancingRequired = true},{Instance ID = 0},{CustomLoadBalancingMessageSelector = },{ShareClientID = false}{DeliveryType = null}}
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB in use by public abstract void javax.resource.spi.endpoint.MessageEndpoint.beforeDelivery(java.lang.reflect.Method) throws java.lang.NoSuchMethodException,javax.resource.ResourceException Thread[WorkManager(2)-36,5,JBoss Pooled Threads]
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB before
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB set context classloader to BaseClassLoader@72538db1{vfszip:/home/gina/jboss-eap-5.1/jboss-as/server/default/deploy/jboss-seam-testmdb.jar/}
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB beforeDelivery method=public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) xaResource=com.sun.genericra.inbound.InboundXAResourceProxy@95fe6d2 transacted=true
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB beforeDelivery currentTx=null
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB started transaction=TransactionImple < ac, BasicAction: a3c1d88:a8b5:502c82c5:722 status: ActionStatus.RUNNING >
2012-08-16 10:50:47,220 INFO [com.sun.genericjmsra] (WorkManager(2)-36) InboundXAResourceProxy::start: setting xid 613363316438383A613862353A35303263383263353A373233312D613363316438383A613862353A35303263383263353A373232
2012-08-16 10:50:47,220 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-36) MessageEndpoint TestMDB enlisted=com.sun.genericra.inbound.InboundXAResourceProxy@95fe6d2
2012-08-16 10:50:47,220 INFO [com.sun.genericjmsra] (WorkManager(2)-36) Created endpoint :
Failure case:
2012-08-16 10:50:47,233 INFO [com.sun.genericjmsra] (WorkManager(2)-40) Creating message endpoint : com.webmethods.jms.loadbalance.connection.WmClusterXAQueueSessionImpl[com.webmethods.jms.impl.WmXASessionImpl[state=started transacted=true acknowledgeMode=Session-Transacted messageConsumerCount=0 messageProducerCount=0]com.webmethods.jms.impl.WmXASessionImpl[state=started transacted=true acknowledgeMode=Session-Transacted messageConsumerCount=0 messageProducerCount=0]]
2012-08-16 10:50:47,233 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory] (WorkManager(2)-40) createEndpoint org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@51b343e9{ resourceAdapter=webm-jmsra.rar, messagingType=interface javax.jms.MessageListener, ejbName=TestMDB, activationConfig=[ActivationConfigProperty(ReconnectInterval=60), ActivationConfigProperty(DestinationType=javax.jms.Queue), ActivationConfigProperty(ReconnectAttempts=5), ActivationConfigProperty(RedeliveryAttempts=5), ActivationConfigProperty(ConnectionFactoryJndiName=grip-qcf), ActivationConfigProperty(RedeliveryInterval=30), ActivationConfigProperty(DestinationJndiName=ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue), ActivationConfigProperty(SupportsXA=TRUE)], activationSpec=com.sun.genericra.inbound.ActivationSpec@7ca58b69{ConnectionFactoryClassName = com.webmethods.jms.impl.WmConnectionFactoryImpl},{QueueConnectionFactoryClassName = com.webmethods.jms.impl.WmQueueConnectionFactoryImpl},{TopicConnectionFactoryClassName = com.webmethods.jms.impl.WmTopicConnectionFactoryImpl},{XAConnectionFactoryClassName = com.webmethods.jms.impl.WmXAConnectionFactoryImpl},{XAQueueConnectionFactoryClassName = com.webmethods.jms.impl.WmXAQueueConnectionFactoryImpl},{XATopicConnectionFactoryClassName = com.webmethods.jms.impl.WmXATopicConnectionFactoryImpl},{QueueClassName = com.webmethods.jms.impl.WmQueueImpl},{TopicClassName = com.webmethods.jms.impl.WmTopicImpl},{UnifiedDestinationClassName = null},{ConnectionFactoryProperties = null},{JndiProperties = java.naming.factory.initial=com.webmethods.jms.naming.WmJmsNamingCtxFactory,java.naming.provider.url=wmjmsnaming://lon-2-a@10.60.29.136:6849,com.webmethods.jms.naming.clientgroup=admin},{ProviderIntegrationMode = jndi},{CommonSetterMethodName = null},{SupportsXA = true},{DeliveryType = null},{RedeliveryInterval = 30},{RedeliveryAttempts = 5},{ClientID = null},{MessageSelector = null},{SubscriptionDurability = Non-Durable},{ConnectionFactoryJNDIName = grip-qcf},{SubscriptionName = null},{DestinationJNDIName = ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue},{DestinationType = javax.jms.Queue},{DeadMessageDestinationType = javax.jms.Destination},{MaxPoolSize = 8},{DestinationProperties = null},{DeadMessageDestinationJndiName = null},{DeadMessageConnectionFactoryJndiName = null},{DeadMessageConnectionFactoryProperties = null},{DeadMessageDestinationClassName = null},{DeadMessageDestinationProperties = null},{SendBadMessagesToDMD = false},{EndpointReleaseTimeOut = 180},{InstanceCount = 1},{LoadBalancingRequired = true},{Instance ID = 0},{CustomLoadBalancingMessageSelector = },{ShareClientID = false}{DeliveryType = null}} xaResource=com.sun.genericra.inbound.InboundXAResourceProxy@97e2437
2012-08-16 10:50:47,234 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory] (WorkManager(2)-40) Created endpoint jboss.j2ee:jar=jboss-seam-testmdb.jar,name=TestMDB,service=EJB3 from org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@51b343e9{ resourceAdapter=webm-jmsra.rar, messagingType=interface javax.jms.MessageListener, ejbName=TestMDB, activationConfig=[ActivationConfigProperty(ReconnectInterval=60), ActivationConfigProperty(DestinationType=javax.jms.Queue), ActivationConfigProperty(ReconnectAttempts=5), ActivationConfigProperty(RedeliveryAttempts=5), ActivationConfigProperty(ConnectionFactoryJndiName=grip-qcf), ActivationConfigProperty(RedeliveryInterval=30), ActivationConfigProperty(DestinationJndiName=ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue), ActivationConfigProperty(SupportsXA=TRUE)], activationSpec=com.sun.genericra.inbound.ActivationSpec@7ca58b69{ConnectionFactoryClassName = com.webmethods.jms.impl.WmConnectionFactoryImpl},{QueueConnectionFactoryClassName = com.webmethods.jms.impl.WmQueueConnectionFactoryImpl},{TopicConnectionFactoryClassName = com.webmethods.jms.impl.WmTopicConnectionFactoryImpl},{XAConnectionFactoryClassName = com.webmethods.jms.impl.WmXAConnectionFactoryImpl},{XAQueueConnectionFactoryClassName = com.webmethods.jms.impl.WmXAQueueConnectionFactoryImpl},{XATopicConnectionFactoryClassName = com.webmethods.jms.impl.WmXATopicConnectionFactoryImpl},{QueueClassName = com.webmethods.jms.impl.WmQueueImpl},{TopicClassName = com.webmethods.jms.impl.WmTopicImpl},{UnifiedDestinationClassName = null},{ConnectionFactoryProperties = null},{JndiProperties = java.naming.factory.initial=com.webmethods.jms.naming.WmJmsNamingCtxFactory,java.naming.provider.url=wmjmsnaming://lon-2-a@10.60.29.136:6849,com.webmethods.jms.naming.clientgroup=admin},{ProviderIntegrationMode = jndi},{CommonSetterMethodName = null},{SupportsXA = true},{DeliveryType = null},{RedeliveryInterval = 30},{RedeliveryAttempts = 5},{ClientID = null},{MessageSelector = null},{SubscriptionDurability = Non-Durable},{ConnectionFactoryJNDIName = grip-qcf},{SubscriptionName = null},{DestinationJNDIName = ReferentialsSsdProcessing_MsgConInstrument_ResubmitQueue},{DestinationType = javax.jms.Queue},{DeadMessageDestinationType = javax.jms.Destination},{MaxPoolSize = 8},{DestinationProperties = null},{DeadMessageDestinationJndiName = null},{DeadMessageConnectionFactoryJndiName = null},{DeadMessageConnectionFactoryProperties = null},{DeadMessageDestinationClassName = null},{DeadMessageDestinationProperties = null},{SendBadMessagesToDMD = false},{EndpointReleaseTimeOut = 180},{InstanceCount = 1},{LoadBalancingRequired = true},{Instance ID = 0},{CustomLoadBalancingMessageSelector = },{ShareClientID = false}{DeliveryType = null}}
2012-08-16 10:50:47,234 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB in use by public abstract void javax.resource.spi.endpoint.MessageEndpoint.beforeDelivery(java.lang.reflect.Method) throws java.lang.NoSuchMethodException,javax.resource.ResourceException Thread[WorkManager(2)-40,5,JBoss Pooled Threads]
2012-08-16 10:50:47,234 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB before
2012-08-16 10:50:47,234 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB set context classloader to BaseClassLoader@72538db1{vfszip:/home/gina/jboss-eap-5.1/jboss-as/server/default/deploy/jboss-seam-testmdb.jar/}
2012-08-16 10:50:47,234 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB beforeDelivery method=public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) xaResource=com.sun.genericra.inbound.InboundXAResourceProxy@97e2437 transacted=true
2012-08-16 10:50:47,235 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB beforeDelivery currentTx=TransactionImple < ac, BasicAction: a3c1d88:a8b5:502c82c5:5a2 status: ActionStatus.COMMITTING >
2012-08-16 10:50:47,235 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] (WorkManager(2)-40) MessageEndpoint TestMDB transaction=null already active, IGNORED=com.sun.genericra.inbound.InboundXAResourceProxy@97e2437
2012-08-16 10:50:47,235 INFO [com.sun.genericjmsra] (WorkManager(2)-40) Created endpoint :
Why the above mentioned exception is thrown? Is it related to Traces above?
Found the similar bug fix here https://issues.jboss.org/browse/EJBTHREE-1142?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel is this related?
Attached Server logs.
Let me know if you need any further information.
-
server.log.zip 14.4 MB