Atomikos Forum |
|
I get the following exception when doing stress tests with JMeter , ( 5 users ) , sometimes the exception does not occur, sometimes it happens allready after a few minutes.
I can't seem the find any cause for this problem. Some more info: Database : SQL Server JDBC Driver : Merlia 7.03 TransactionEssentials : 3.2.3 Hibernate : 3.2.3 Stacktrace: com.atomikos.datasource.ResourceException: resume for XID 192.168.100.39.tm0018100086192.168.100.39.tm25 raised -2147168242: unknown com.atomikos.datasource.xa.XAResourceTransaction.resume(Unknown Source) com.atomikos.jdbc.ConnectionProxy.invoke(Unknown Source) $Proxy36.prepareStatement(Unknown Source) org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:505) org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:423) org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139) org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547) org.hibernate.loader.Loader.doQuery(Loader.java:673) org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236) org.hibernate.loader.Loader.doList(Loader.java:2220) org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104) org.hibernate.loader.Loader.list(Loader.java:2099) org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378) org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338) org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172) org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121) org.hibernate.impl.QueryImpl.list(QueryImpl.java:79) org.springframework.orm.hibernate3.HibernateTemplate$29.doInHibernate(HibernateTemplate.java:849) org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:372) org.springframework.orm.hibernate3.HibernateTemplate.find(HibernateTemplate.java:840) org.springframework.orm.hibernate3.HibernateTemplate.find(HibernateTemplate.java:836) ***.***.dao.hibernate.OurDao.find(OurDao.java:80)
This is the stacktrace that was thrown at that given time.
com.atomikos.datasource.ResourceException: resume for XID 192.168.100.39.tm2018900001192.168.100.39.tm13285 raised -2147168242: unknown com.atomikos.datasource.xa.XAResourceTransaction.resume(Unknown Source) com.atomikos.jdbc.ConnectionProxy.invoke(Unknown Source) $Proxy36.prepareStatement(Unknown Source) org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:505) org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:423) org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139) org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547) org.hibernate.loader.Loader.doQuery(Loader.java:673)
Guy,
The following lines come from tm.out after I enabled debug logging: 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL! 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL! 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@c4dc35 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Creating composite transaction: 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] createCompositeTransaction ( 120000 ): created new ROOT transaction with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] JDBC ConnectionPool: using connection: ExternalXAPooledConnectionImp1210267443078com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@de89e9 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] addParticipant ( 192.168.100.39.tm2018900001192.168.100.39.tm13285 ) for transaction 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] XAResourceTransaction 192.168.100.39.tm2018900001192.168.100.39.tm13285: about to switch to XAResource com.inet.tds.ab@11ca066 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] XAResourceTransaction 192.168.100.39.tm2018900001192.168.100.39.tm13285: switched to XAResource com.inet.tds.ab@11ca066 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001
Second part of the log :
5-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: ACTIVE 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] resume for XID 192.168.100.39.tm2018900001192.168.100.39.tm13285 raised -2147168242: unknown 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning instance with id 192.168.100.39.tm2018900001 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: ABORTING 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: ABORTING 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@165076e 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@1cb060c 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entering state: TERMINATED 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 : stopping timer... 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 : disposing statehandler TERMINATED... 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 : disposed. 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Putting connection back in pool: ExternalXAPooledConnectionImp1210267443078com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@de89e9 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL!
last part of the log :
08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] JDBC ConnectionProxy: delegating isClosed to connection com.inet.pool.k@1fa1136 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL! 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] JDBC ConnectionProxy: delegating clearWarnings to connection com.inet.pool.k@1fa1136 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL! 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] JDBC ConnectionProxy: delegating close to connection com.inet.pool.k@1fa1136 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] afterCompletion ( STATUS_ROLLEDBACK ) called on Synchronization: org.hibernate.transaction.CacheSynchronization 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] Coordinator 192.168.100.39.tm2018900001 entered state: TERMINATED 08-05-08 19:25:19,515 [resin-tcp-connection-192.168.100.39:6187-37] rollback() done of transaction 192.168.100.39.tm2018900001 08-05-08 19:25:19,531 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL! 08-05-08 19:25:19,531 [resin-tcp-connection-192.168.100.39:6187-37] getCompositeTransaction() returning NULL!
I did not find anything in the logs of sql server, but when looking at the event viewer, there was an error of DTCProxy : "getCookie 7: The calling thread is not associated with any transaction. : -2147168242"
As you can see that number is the same as in the stacktrace.
Hi,
Did you try this: "Make sure that your SQLServer is configured for authentication: open the SQLServer Enterprise Manager ap- plication, right-click your SQLServer and choose properties from the pop-up menu. Click the Security tab, and make sure to select 'SQL Server and Windows' for the 'Authentication' setting." |