Failed to mark transaction as rollback only / Invalid transa

[s0d0]

Hi

Some times we get those error in MDB listening SonicMQ queue.
It looks like hibernate is having problems getting new jdbc connection.
But why message taken from queue is vanished until I restart server?
Should JBossTS take care of recovering transaction?

If someone knows why hibernate can not open new connection, that information would also be helpful.

2006-12-07 17:26:08,721 WARN [jacorb.poa.controller] rid: 2236088 opname: shouldMerge cannot process request, because object doesn't exist
2006-12-07 17:26:08,721 WARN [jacorb.poa.controller] rid: 2236088 opname: shouldMerge request rejected with exception:
2006-12-07 17:26:08,722 WARN [jacorb.poa.controller] rid: 2236090 opname: shouldReplace cannot process request, because object doesn't exist
2006-12-07 17:26:08,722 WARN [jacorb.poa.controller] rid: 2236090 opname: shouldReplace request rejected with exception:
2006-12-07 17:26:08,723 WARN [jacorb.poa.controller] rid: 2236092 opname: shouldAdd cannot process request, because object doesn't exist
2006-12-07 17:26:08,723 WARN [jacorb.poa.controller] rid: 2236092 opname: shouldAdd request rejected with exception:
2006-12-07 17:26:08,724 WARN [jacorb.poa.controller] rid: 2236094 opname: shouldAlter cannot process request, because object doesn't exist
2006-12-07 17:26:08,724 WARN [jacorb.poa.controller] rid: 2236094 opname: shouldAlter request rejected with exception:
2006-12-07 17:26:08,725 WARN [jacorb.poa.controller] rid: 2236096 opname: shouldMerge cannot process request, because object doesn't exist
2006-12-07 17:26:08,725 WARN [jacorb.poa.controller] rid: 2236096 opname: shouldMerge request rejected with exception:
2006-12-07 17:26:08,726 WARN [jacorb.poa.controller] rid: 2236098 opname: shouldReplace cannot process request, because object doesn't exist
2006-12-07 17:26:08,726 WARN [jacorb.poa.controller] rid: 2236098 opname: shouldReplace request rejected with exception:
2006-12-07 17:26:08,728 WARN [jacorb.poa.controller] rid: 2236100 opname: shouldAdd cannot process request, because object doesn't exist
2006-12-07 17:26:08,728 WARN [jacorb.poa.controller] rid: 2236100 opname: shouldAdd request rejected with exception:
2006-12-07 17:26:08,729 WARN [jacorb.poa.controller] rid: 2236102 opname: shouldAlter cannot process request, because object doesn't exist
2006-12-07 17:26:08,729 WARN [jacorb.poa.controller] rid: 2236102 opname: shouldAlter request rejected with exception:
2006-12-07 17:26:08,730 DEBUG [Sonic Resource Adapter for JCA] SonicServerSession.onMessage() WorkManager(2)-6773
2006-12-07 17:26:08,732 WARN [jacorb.poa.controller] rid: 2236108 opname: saveRecord cannot process request, because object doesn't exist
2006-12-07 17:26:08,732 WARN [jacorb.poa.controller] rid: 2236108 opname: saveRecord request rejected with exception:
2006-12-07 17:26:08,733 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.resources.errsavefail] ExtendedResourceRecord.doSave failed. Returning default value: true
2006-12-07 17:26:08,734 DEBUG [Sonic Resource Adapter for JCA] RequestProcessor-50297 XAResource=1630429486
XAResourceWrapper.leaveTransaction: GlobalId=1--3f3db8c2:8de6:4577fa84:5bb62, BranchQual=-3f3db8c2:8de6:4577fa84:5bb66
2006-12-07 17:26:08,736 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-12-07 17:26:08,736 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2006-12-07 17:26:08,759 WARN [jacorb.poa.controller] rid: 2236110 opname: commit cannot process request, because object doesn't exist
2006-12-07 17:26:08,759 WARN [jacorb.poa.controller] rid: 2236110 opname: commit request rejected with exception:
2006-12-07 17:26:08,775 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: null
2006-12-07 17:26:08,775 ERROR [org.hibernate.util.JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 >)
2006-12-07 17:26:08,782 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.jts.extensions.AtomicTransaction.rollbackOnly(AtomicTransaction.java:771)
 at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.setRollbackOnly(TransactionImple.java:387)
 at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.setRollbackOnly(BaseTransaction.java:214)
 at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.setRollbackOnly(BaseTransactionManagerDelegate.java:135)
 at org.hibernate.ejb.AbstractEntityManagerImpl.markAsRollback(AbstractEntityManagerImpl.java:432)
 at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:587)
 at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:647)
 at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:99)
 at fi.logiasoftware.messageserver.services.backend.mdbs.MessageListenerBean.getStepId(MessageListenerBean.java:163)
 at fi.logiasoftware.messageserver.services.backend.mdbs.MessageListenerBean.onMessage(MessageListenerBean.java:231)
 at sun.reflect.GeneratedMethodAccessor686.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:615)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
 at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
 at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:46)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:245)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
 at $Proxy283.onMessage(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.onMessage(SonicServerSession.java:168)
 at progress.message.jimpl.Session.eU_(Unknown Source)
 at progress.message.jimpl.Session.run(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.run(SonicServerSession.java:199)
 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:743)
 at java.lang.Thread.run(Thread.java:797)
2006-12-07 17:26:08,801 DEBUG [Sonic Resource Adapter for JCA] RequestProcessor-50297 XAResource=1387549364
XAResourceWrapper.commit: GlobalId=1--3f3db8c2:8de6:4577fa84:5bb4a, BranchQual=-3f3db8c2:8de6:4577fa84:5bb4c,false
2006-12-07 17:26:08,889 ERROR [STDERR] javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection
2006-12-07 17:26:08,871 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@6c606c60[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@6b5a6b5a handles=0 lastUse=1165505168271 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@608c608c context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@71687168 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@6c586c58 txSync=null]
2006-12-07 17:26:08,889 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@6c606c60[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@6b5a6b5a handles=0 lastUse=1165505168889 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@608c608c context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@71687168 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@6c586c58 txSync=null] [InUse/Available/Max]: [1/29/30]
2006-12-07 17:26:08,899 ERROR [STDERR] at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:647)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:99)
2006-12-07 17:26:08,900 ERROR [STDERR] at fi.logiasoftware.messageserver.services.backend.mdbs.MessageListenerBean.getStepId(MessageListenerBean.java:163)
2006-12-07 17:26:08,900 ERROR [STDERR] at fi.logiasoftware.messageserver.services.backend.mdbs.MessageListenerBean.onMessage(MessageListenerBean.java:231)
2006-12-07 17:26:08,900 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor686.invoke(Unknown Source)
2006-12-07 17:26:08,900 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2006-12-07 17:26:08,900 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:615)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
2006-12-07 17:26:08,900 ERROR [STDERR] at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:46)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:245)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
2006-12-07 17:26:08,901 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
2006-12-07 17:26:08,902 ERROR [STDERR] at $Proxy283.onMessage(Unknown Source)
2006-12-07 17:26:08,902 ERROR [STDERR] at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.onMessage(SonicServerSession.java:168)
2006-12-07 17:26:08,902 ERROR [STDERR] at progress.message.jimpl.Session.eU_(Unknown Source)
2006-12-07 17:26:08,902 ERROR [STDERR] at progress.message.jimpl.Session.run(Unknown Source)
2006-12-07 17:26:08,902 ERROR [STDERR] at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.run(SonicServerSession.java:199)
2006-12-07 17:26:08,902 ERROR [STDERR] at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
2006-12-07 17:26:08,902 ERROR [STDERR] at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
2006-12-07 17:26:08,902 ERROR [STDERR] at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:743)
2006-12-07 17:26:08,902 ERROR [STDERR] at java.lang.Thread.run(Thread.java:797)
2006-12-07 17:26:08,902 ERROR [STDERR] Caused by:
2006-12-07 17:26:08,902 ERROR [STDERR] org.hibernate.exception.GenericJDBCException: Cannot open connection
2006-12-07 17:26:08,922 DEBUG [Sonic Resource Adapter for JCA] RequestProcessor-50297 XAResource=1387549364
XAResourceWrapper.leaveTransaction: GlobalId=1--3f3db8c2:8de6:4577fa84:5bb4a, BranchQual=-3f3db8c2:8de6:4577fa84:5bb4c
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:420)
2006-12-07 17:26:08,937 ERROR [STDERR] at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.doQuery(Loader.java:661)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.doList(Loader.java:2144)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.Loader.list(Loader.java:2023)
2006-12-07 17:26:08,938 ERROR [STDERR] at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
2006-12-07 17:26:08,939 ERROR [STDERR] at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
2006-12-07 17:26:08,939 ERROR [STDERR] at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
2006-12-07 17:26:08,939 ERROR [STDERR] at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
2006-12-07 17:26:08,939 ERROR [STDERR] at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
2006-12-07 17:26:08,939 ERROR [STDERR] at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:80)
2006-12-07 17:26:08,939 ERROR [STDERR] ... 30 more
2006-12-07 17:26:08,939 ERROR [STDERR] Caused by:
2006-12-07 17:26:08,939 ERROR [STDERR] org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 >)
2006-12-07 17:26:08,940 ERROR [STDERR] at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
2006-12-07 17:26:08,940 ERROR [STDERR] at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
2006-12-07 17:26:08,940 ERROR [STDERR] at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
2006-12-07 17:26:08,940 ERROR [STDERR] ... 44 more
2006-12-07 17:26:08,940 ERROR [STDERR] Caused by:
2006-12-07 17:26:08,941 ERROR [STDERR] javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 >
2006-12-07 17:26:08,941 ERROR [STDERR] at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:290)
2006-12-07 17:26:08,941 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:396)
2006-12-07 17:26:08,941 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
2006-12-07 17:26:08,941 ERROR [STDERR] at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
2006-12-07 17:26:08,942 ERROR [STDERR] ... 46 more
2006-12-07 17:26:08,943 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.jts.extensions.AtomicTransaction.rollbackOnly(AtomicTransaction.java:771)
 at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.setRollbackOnly(TransactionImple.java:387)
 at org.jboss.aspects.tx.TxPolicy.setRollbackOnly(TxPolicy.java:212)
 at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130)
 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:245)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
 at $Proxy283.onMessage(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.onMessage(SonicServerSession.java:168)
 at progress.message.jimpl.Session.eU_(Unknown Source)
 at progress.message.jimpl.Session.run(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.run(SonicServerSession.java:199)
 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:743)
 at java.lang.Thread.run(Thread.java:797)
2006-12-07 17:26:08,949 ERROR [STDERR] Thu Dec 07 17:26:08 EET 2006 DEBUG: Executing XA statement: XA COMMIT 0x312d2d33663364623863323a386465363a34353737666138343a3562623461,0x2d33663364623863323a386465363a34353737666138343a3562623536,0x20000
2006-12-07 17:26:09,002 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.jts.extensions.AtomicTransaction.rollbackOnly(AtomicTransaction.java:771)
 at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.setRollbackOnly(TransactionImple.java:387)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:277)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
 at $Proxy283.onMessage(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.onMessage(SonicServerSession.java:168)
 at progress.message.jimpl.Session.eU_(Unknown Source)
 at progress.message.jimpl.Session.run(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.run(SonicServerSession.java:199)
 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:743)
 at java.lang.Thread.run(Thread.java:797)
2006-12-07 17:26:09,025 WARN [jacorb.poa.controller] rid: 2236142 opname: commit cannot process request, because object doesn't exist
2006-12-07 17:26:09,043 WARN [jacorb.poa.controller] rid: 2236142 opname: commit request rejected with exception:
2006-12-07 17:26:09,043 WARN [org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy] Current transaction TransactionImple < jts, -3f3db8c2:8de6:4577fa84:1a639 > is not the expected transaction.
2006-12-07 17:26:09,046 ERROR [Sonic Resource Adapter for JCA] EXCEPTION: SonicServerSession.onMessage() cannot deliver message progress.message.jimpl.TextMessage@2d782d78 javax.resource.ResourceException java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] Invalid transaction.
javax.resource.ResourceException: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] Invalid transaction.
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:232)
 at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:134)
 at $Proxy283.afterDelivery(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.onMessage(SonicServerSession.java:177)
 at progress.message.jimpl.Session.eU_(Unknown Source)
 at progress.message.jimpl.Session.run(Unknown Source)
 at com.sonicsw.sonicmq.j2ee.jmsra.impl.sonic.SonicServerSession.run(SonicServerSession.java:199)
 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:743)
 at java.lang.Thread.run(Thread.java:797)
Caused by:
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] [com.arjuna.ats.internal.jta.transaction.jts.invalidtx2] Invalid transaction.
 at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1293)
 at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:165)
 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)
 ... 10 more

Br,

Juha Moisio

[s0d0]

And what are these warnings?

2006-12-07 20:43:02,339 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.gandiva.inventory.StaticInventory_1] - cannot fin
d <ClassName:RecordType.LASTRESOURCE> implementation.
2006-12-07 20:43:02,339 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_21] - BasicAction.restore_state - c
ould not recover 2147483647
2006-12-07 20:43:02,339 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.RecoveredTransaction_2] [com.arjuna.a
ts.internal.jts.recovery.transactions.RecoveredTransaction_2] - RecoveredTransaction activate of -3f3db8c2:ab59:4577e0fa:31f failed
2006-12-07 20:43:02,341 INFO [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.TransactionRecoveryModule_6] [com.arj
una.ats.internal.jts.recovery.transactions.TransactionRecoveryModule_6] - Transaction -3f3db8c2:ce63:4577e55b:244f still in ActionStore
2006-12-07 20:43:02,343 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.gandiva.inventory.StaticInventory_1] - cannot fin
d <ClassName:RecordType.LASTRESOURCE> implementation.
2006-12-07 20:43:02,343 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_21] - BasicAction.restore_state - c
ould not recover 2147483647
2006-12-07 20:43:02,343 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.RecoveredTransaction_2] [com.arjuna.a
ts.internal.jts.recovery.transactions.RecoveredTransaction_2] - RecoveredTransaction activate of -3f3db8c2:ce63:4577e55b:244f failed
2006-12-07 20:43:02,344 INFO [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.TransactionRecoveryModule_6] [com.arj
una.ats.internal.jts.recovery.transactions.TransactionRecoveryModule_6] - Transaction -3f3db8c2:ce63:4577e55b:4063 still in ActionStore
2006-12-07 20:43:02,345 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.gandiva.inventory.StaticInventory_1] - cannot fin
d <ClassName:RecordType.LASTRESOURCE> implementation.



-Juha-

[marklittle]

The LASTRESOURCE is a special resource that JBossTS uses in the JTS implementation to support last resource commit optimisation. This error would appear to indicate that recovery is attempting to run on a transaction log that contains one such participant and it cannot locate the necessary class. Maybe a classloader/classpath issue.

[s0d0]

Which jar should contain that class?

-Juha-

[s0d0]

In jbossTS full package, jars

./lib/jbossjts.jar
 5852 Fri Nov 03 17:14:48 EET 2006 com/arjuna/ats/arjuna/coordinator/RecordType.class

and

./xts/lib/ext/jbossjts.jar
 5852 Fri Nov 03 17:14:48 EET 2006 com/arjuna/ats/arjuna/coordinator/RecordType.class

seems to contain that class.

I have all these jars

- lib/jbossjts.jar
- lib/jbossjts-jacorb.jar
- lib/jbossjts-integration.jar
- lib/ext/jbossts-common.jar

in my server/default/lib directory. Should it be enough?

Br,

Juha

[s0d0]

Could someone tell why it doesn't find this class?

RecordType.LASTRESOURCE

-Juha-

[marklittle]

Not sure why your system can't find the resource, but there is an issue for JBossTS 4.2.2 and the LRCO implementation when using JTS: it saves too much information for recovery purposes when using LRCO. We'll fix this in the next release. This may be triggering the error you see, but doesn't explain the error.

[s0d0]

as this is WARNing, it should not cause these other problem I have?

-Juha-

[marklittle]

No, you should be OK. All that is happening is that the log entry is being created when it shouldn't and the recovery system will keep trying to fix something that it shouldn't bother with. It should have no other impact.

[deanhiller]

what about those jacorb logs? I see those every 10 or 20 seconds in my productions logs....

2009-12-03 17:45:16,483 WARN [jacorb.poa.controller] (RequestController-1) rid: 430 opname: sa
veRecord cannot process request, because object doesn't exist
2009-12-03 17:45:16,483 WARN [jacorb.poa.controller] (RequestController-1) rid: 430 opname: sa
veRecord request rejected with exception:
2009-12-03 17:45:16,485 WARN [com.arjuna.ats.jts.logging.loggerI18N] (http-0.0.0.0-8080-3) [co
m.arjuna.ats.internal.jts.resources.errsavefail] ExtendedResourceRecord.doSave failed. Returnin
g default value: true
2009-12-03 17:45:16,521 WARN [jacorb.poa.controller] (RequestController-1) rid: 432 opname: co
mmit cannot process request, because object doesn't exist
2009-12-03 17:45:16,521 WARN [jacorb.poa.controller] (RequestController-1) rid: 432 opname: co
mmit request rejected with exception:
2009-12-03 17:45:16,577 INFO [net.voicelog.customLiveOperator.handler.UpdateHandler] (http-0.0
.0.0-8080-3) 2011197123:User: OP9876, UPDATE TIME: 621 ms

It is creating lots of noise where I can't search on WARN and see if we have production problems like I could before in tomcat....we have 1 Gig log files each day!!! and need to be able to search through the log on WARN and ERROR.

is this is misconfiguration on my part in jboss 5.1 though we didn't do too much to it.