[jboss-jira] [JBoss JIRA] Updated: (EJBTHREE-1142) MessageInflowLocalProxy is retaining previous transaction

[ http://jira.jboss.com/jira/browse/EJBTHREE-1142?page=all ] Carlo de Wolf updated EJBTHREE-1142: ------------------------------------ Description: 2007-12-03 14:30:29,240 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:362] MessageEndpoint CallbackBean started transaction=TransactionImple < ac, BasicAction: 7f000101:843b:475404ae:d2 status: ActionStatus.RUNNING > 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:369] MessageEndpoint CallbackBean enlisted=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:116] Get instance org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#1#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:123] Acquired(true) strictMaxSize semaphore, remaining=29 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:198] 0/30 Free instance:org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:431] MessageEndpoint CallbackBean commit 2007-12-03 14:30:29,242 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:492] MessageEndpoint CallbackBean no longer in use by Thread[WorkManager(3)-1,5,JBoss Pooled Threads] 2007-12-03 14:30:29,242 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory:137] Created endpoint com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean@79826b7a from org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@2960f0e{ resourceAdapter=jms-ra.rar, messagingType=interface javax.jms.MessageListener, ejbName=CallbackBean, activationConfig=[ActivationConfigProperty(destination=MDB_QUEUE), ActivationConfigProperty(destinationType=javax.jms.Queue), ActivationConfigProperty(subscriptionDurability=false)], activationSpec=org.jboss.resource.adapter.jms.inflow.JmsActivationSpec@615ece16(ra=org.jboss.resource.adapter.jms.JmsResourceAdapter(a)6807299a destination=MDB_QUEUE isTopic=false tx=true durable=false reconnect=10 provider=java:/DefaultJMSProvider user=null maxMessages=1 minSession=1 maxSession=15 keepAlive=60000 useDLQ=true DLQHandler=org.jboss.resource.adapter.jms.inflow.dlq.GenericDLQHandler DLQJndiName=queue/DLQ DLQUser=null DLQMaxResent=5)} 2007-12-03 14:30:31,389 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean 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(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,389 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:188] MessageEndpoint CallbackBean before 2007-12-03 14:30:31,404 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:194] MessageEndpoint CallbackBean set context classloader to org.jboss.mx.loading.UnifiedClassLoader3@674e5e21{ url=vfsfile:/home/carlo/work/jboss-head/build/output/jboss-5.0.0.Beta3/server/cts/tmp/jsr88/mdb_callback_listener_annotated.ear ,addedOrder=44} 2007-12-03 14:30:31,408 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:344] MessageEndpoint CallbackBean beforeDelivery method=public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) xaResource=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] transacted=true2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:351] MessageEndpoint CallbackBean beforeDelivery currentTx=TransactionImple < ac, BasicAction: 7f000101:843b:475404ae:da status: ActionStatus.RUNNING >2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:383] MessageEndpoint CallbackBean transaction=null already active, IGNORED=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] 2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean in use by public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) Thread[WorkManager(3)-2,5,JBoss Pooled Threads]2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:249] MessageEndpoint CallbackBean delivering2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.pool.StrictMaxPool:116] Get instance org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#1#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean2007-12-03 14:30:31,410 TRACE [org.jboss.ejb3.pool.StrictMaxPool:123] Acquired(true) strictMaxSize semaphore, remaining=29 2007-12-03 14:30:31,410 INFO [STDOUT:151] isInjectionDone() in onMessage returns: true 2007-12-03 14:30:31,875 INFO [STDOUT:151] Status message (true) sent for test isInjectionDoneTest. Reason:isInjectionDone() in onMessage returns: true 2007-12-03 14:30:31,877 TRACE [org.jboss.ejb3.pool.StrictMaxPool:198] 0/30 Free instance:org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:31,877 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean in use by public abstract void javax.resource.spi.endpoint.MessageEndpoint.afterDelivery() throws javax.resource.ResourceException Thread[WorkManager(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,878 WARN [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:411] Current transaction TransactionImple < ac, BasicAction: 7f000101:843b:475404ae:da status: ActionStatus.RUNNING > is not the expected transaction. 2007-12-03 14:30:31,878 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:431] MessageEndpoint CallbackBean commit 2007-12-03 14:30:31,878 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N:1746] [com.arjuna.ats.arjuna.coordinator.BasicAction_34] - End called on already committed atomic action 7f000101:843b:475404ae:d2 2007-12-03 14:30:31,878 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:479] MessageEndpoint CallbackBean reset classloader org.jboss.mx.loading.UnifiedClassLoader3@76e5f3d2{ url=vfsfile:/home/carlo/work/jboss-head/build/output/jboss-5.0.0.Beta3/server/cts/deploy/jms-ra.rar ,addedOrder=39} 2007-12-03 14:30:31,879 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:492] MessageEndpoint CallbackBean no longer in use by Thread[WorkManager(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,879 ERROR [org.jboss.resource.adapter.jms.inflow.JmsServerSession:191] Unexpected error delivering message delegator->JBossMessage[24576]:PERSISTENT, deliveryId=1 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:231) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:133) at $Proxy77.afterDelivery(Unknown Source) at org.jboss.resource.adapter.jms.inflow.JmsServerSession.onMessage(JmsServerSession.java:182) at org.jboss.jms.client.container.ClientConsumer.callOnMessage(ClientConsumer.java:157) at org.jboss.jms.client.container.SessionAspect.handleRun(SessionAspect.java:802) at org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect_z_handleRun_1418002208.invoke(SessionAspect_z_handleRun_1418002208.java) at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java) at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170) at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:106) at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java) at org.jboss.jms.client.delegate.ClientSessionDelegate.run(ClientSessionDelegate.java) at org.jboss.jms.client.JBossSession.run(JBossSession.java:199) at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:234) at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204) at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:595) 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:1378) 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:432) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:311) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:227) ... 18 more was: 2007-12-03 14:30:29,240 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:362] MessageEndpoint CallbackBean started transaction=TransactionImple < ac, BasicAction: <b>7f000101:843b:475404ae:d2</b> status: ActionStatus.RUNNING > 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:369] MessageEndpoint CallbackBean enlisted=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:116] Get instance org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#1#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:123] Acquired(true) strictMaxSize semaphore, remaining=29 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.pool.StrictMaxPool:198] 0/30 Free instance:org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:29,241 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:431] MessageEndpoint CallbackBean commit 2007-12-03 14:30:29,242 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:492] MessageEndpoint CallbackBean no longer in use by Thread[WorkManager(3)-1,5,JBoss Pooled Threads] 2007-12-03 14:30:29,242 TRACE [org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory:137] Created endpoint com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean@79826b7a from org.jboss.ejb3.mdb.inflow.JBossMessageEndpointFactory@2960f0e{ resourceAdapter=jms-ra.rar, messagingType=interface javax.jms.MessageListener, ejbName=CallbackBean, activationConfig=[ActivationConfigProperty(destination=MDB_QUEUE), ActivationConfigProperty(destinationType=javax.jms.Queue), ActivationConfigProperty(subscriptionDurability=false)], activationSpec=org.jboss.resource.adapter.jms.inflow.JmsActivationSpec@615ece16(ra=org.jboss.resource.adapter.jms.JmsResourceAdapter(a)6807299a destination=MDB_QUEUE isTopic=false tx=true durable=false reconnect=10 provider=java:/DefaultJMSProvider user=null maxMessages=1 minSession=1 maxSession=15 keepAlive=60000 useDLQ=true DLQHandler=org.jboss.resource.adapter.jms.inflow.dlq.GenericDLQHandler DLQJndiName=queue/DLQ DLQUser=null DLQMaxResent=5)} 2007-12-03 14:30:31,389 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean 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(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,389 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:188] MessageEndpoint CallbackBean before 2007-12-03 14:30:31,404 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:194] MessageEndpoint CallbackBean set context classloader to org.jboss.mx.loading.UnifiedClassLoader3@674e5e21{ url=vfsfile:/home/carlo/work/jboss-head/build/output/jboss-5.0.0.Beta3/server/cts/tmp/jsr88/mdb_callback_listener_annotated.ear ,addedOrder=44} 2007-12-03 14:30:31,408 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:344] MessageEndpoint CallbackBean beforeDelivery method=public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) xaResource=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] transacted=true2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:351] MessageEndpoint CallbackBean beforeDelivery currentTx=TransactionImple < ac, BasicAction: 7f000101:843b:475404ae:da status: ActionStatus.RUNNING >2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:383] MessageEndpoint CallbackBean transaction=null already active, IGNORED=MessagingXAResource[r1-7wfi1r9f-1-7nxg1r9f-fmwhy2-110j3] 2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean in use by public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message) Thread[WorkManager(3)-2,5,JBoss Pooled Threads]2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:249] MessageEndpoint CallbackBean delivering2007-12-03 14:30:31,409 TRACE [org.jboss.ejb3.pool.StrictMaxPool:116] Get instance org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#1#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean2007-12-03 14:30:31,410 TRACE [org.jboss.ejb3.pool.StrictMaxPool:123] Acquired(true) strictMaxSize semaphore, remaining=29 2007-12-03 14:30:31,410 INFO [STDOUT:151] isInjectionDone() in onMessage returns: true 2007-12-03 14:30:31,875 INFO [STDOUT:151] Status message (true) sent for test isInjectionDoneTest. Reason:isInjectionDone() in onMessage returns: true 2007-12-03 14:30:31,877 TRACE [org.jboss.ejb3.pool.StrictMaxPool:198] 0/30 Free instance:org.jboss.ejb3.pool.StrictMaxPool@7c6b1066#class com.sun.ts.tests.ejb30.bb.mdb.callback.listener.annotated.CallbackBean 2007-12-03 14:30:31,877 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:118] MessageEndpoint CallbackBean in use by public abstract void javax.resource.spi.endpoint.MessageEndpoint.afterDelivery() throws javax.resource.ResourceException Thread[WorkManager(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,878 WARN [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:411] Current transaction TransactionImple < ac, BasicAction: 7f000101:843b:475404ae:da status: ActionStatus.RUNNING > is not the expected transaction. 2007-12-03 14:30:31,878 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:431] MessageEndpoint CallbackBean commit 2007-12-03 14:30:31,878 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N:1746] [com.arjuna.ats.arjuna.coordinator.BasicAction_34] - End called on already committed atomic action 7f000101:843b:475404ae:d2 2007-12-03 14:30:31,878 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:479] MessageEndpoint CallbackBean reset classloader org.jboss.mx.loading.UnifiedClassLoader3@76e5f3d2{ url=vfsfile:/home/carlo/work/jboss-head/build/output/jboss-5.0.0.Beta3/server/cts/deploy/jms-ra.rar ,addedOrder=39} 2007-12-03 14:30:31,879 TRACE [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy:492] MessageEndpoint CallbackBean no longer in use by Thread[WorkManager(3)-2,5,JBoss Pooled Threads] 2007-12-03 14:30:31,879 ERROR [org.jboss.resource.adapter.jms.inflow.JmsServerSession:191] Unexpected error delivering message delegator->JBossMessage[24576]:PERSISTENT, deliveryId=1 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:231) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:133) at $Proxy77.afterDelivery(Unknown Source) at org.jboss.resource.adapter.jms.inflow.JmsServerSession.onMessage(JmsServerSession.java:182) at org.jboss.jms.client.container.ClientConsumer.callOnMessage(ClientConsumer.java:157) at org.jboss.jms.client.container.SessionAspect.handleRun(SessionAspect.java:802) at org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect_z_handleRun_1418002208.invoke(SessionAspect_z_handleRun_1418002208.java) at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java) at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170) at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:106) at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java) at org.jboss.jms.client.delegate.ClientSessionDelegate.run(ClientSessionDelegate.java) at org.jboss.jms.client.JBossSession.run(JBossSession.java:199) at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:234) at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204) at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:595) 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:1378) 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:432) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:311) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:227) ... 18 more -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira