Atomikos Forum |
|
We are using Atomikos 3.6.5 in combination with Spring annotation based transactions and this running on Tomcat 6. When the Spring JtaTransactionManager commits it calls commit() on the Atomikos UserTransactionImp. This eventually ends up in CoordinatorImp.terminate(). However the participants_ vector is empty. As a matter of fact, the addParticipant() method is never called on the CoordinatorImp object.
Just to avoid any misunderstanding, am I supposed to see participants when I use Spring transaction annotation? Stepping through the Spring and Atomikos source while debugging the application, I can see the Spring TransactionInterceptor create a transaction, which is done by the correct implementation, i.e. the Atomikos UserTransactionManager. Yet, when Spring does its JDBC stuff, the SQL operation is never registered as a participant in the Atomikos CompositeTransaction and as a result, a commit is never executed. This leaves us with dangling connections at the end of our business, basically blocking the record for all other applications wanting to access it. The only solution is to stop Tomcat to free up the connection. Surely there must be something simple that we are overlooking. All help is very much appreciated.
Forgot to add that this is with an XA datasource. Below is the configuration.
Tomcat context.xml <Resource auth="Container" factory="com.atomikos.tomcat.BeanFactory" maxPoolSize="150" minPoolSize="5" name="jdbc/HORA_XA_Managed" type="com.atomikos.jdbc.AtomikosDataSourceBean" uniqueResourceName="AtomikosDataSourceJDBCOracle.HORA_WS" xaDataSourceClassName="oracle.jdbc.xa.client.OracleXADataSource" xaProperties.URL="..." xaProperties.password="..." xaProperties.user="..."/> Spring config: <bean id="atomikosTransactionManager" class="com.atomikos.icatch.jta.J2eeTransactionManager" /> <bean id="atomikosUserTransaction" class="com.atomikos.icatch.jta.UserTransactionImp" /> <bean id="springTxManager" class="org.springframework.transaction.jta.JtaTransactionManager"> <property name="transactionManager" ref="atomikosTransactionManager" /> <property name="userTransaction" ref="atomikosUserTransaction" /> </bean> <tx:annotation-driven transaction-manager="springTxManager" />
Hi Guy,
Sorry for the late reply. I have been out of the office for a couple of days. Below is the tm.out log file in INFO mode. As you can see the last line is a commit(). However, since no participants are registered, the commit itself does not do anything at all. Any idea why our JDBC operations are not participating in the Atomikos transaction? Regards, Rik 10-06-07 09:56:13,312 [http-8080-2] USING core version: 3.6.5 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.console_file_name = tm.out 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.console_file_count = 1 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.automatic_resource_registration = true 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.client_demarcation = false 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.threaded_2pc = true 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.serial_jta_transactions = true 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.log_base_dir = c:\Tomcat6\logs\Atomikos 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.console_log_level = INFO 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.max_actives = 50 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.checkpoint_interval = 500 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.enable_logging = true 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.output_dir = c:\Tomcat6\logs\Atomikos 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.log_base_name = tmlog 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.console_file_limit = -1 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.max_timeout = 3000000 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.tm_unique_name = 172.16.203.64.tm 10-06-07 09:56:13,312 [http-8080-2] USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory 10-06-07 09:56:13,312 [http-8080-2] USING java.naming.provider.url = rmi://localhost:1099 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.force_shutdown_on_vm_exit = false 10-06-07 09:56:13,312 [http-8080-2] USING com.atomikos.icatch.default_jta_timeout = 3000000 10-06-07 09:56:13,327 [http-8080-2] createCompositeTransaction ( 3000000 ): created new ROOT transaction with id 172.16.203.64.tm0000100001 10-06-07 09:56:13,343 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': getConnection ( null )... 10-06-07 09:56:13,343 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': init... 10-06-07 09:56:13,343 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling toString... 10-06-07 09:56:13,343 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling toString... 10-06-07 09:56:13,343 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling getMetaData... 10-06-07 09:56:13,343 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: close()... 10-06-07 09:56:13,359 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': getConnection ( null )... 10-06-07 09:56:13,359 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': init... 10-06-07 09:56:13,359 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling toString... 10-06-07 09:56:13,359 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling toString... 10-06-07 09:56:13,359 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling getMetaData... 10-06-07 09:56:13,421 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': getConnection ( null )... 10-06-07 09:56:13,421 [http-8080-2] AtomikosDataSoureBean 'AtomikosDataSourceJDBCOracle.HORA_WS': init... 10-06-07 09:56:13,421 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling toString... 10-06-07 09:56:13,421 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling toString... 10-06-07 09:56:13,421 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling getMetaData... 10-06-07 09:56:13,421 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling getDescriptor... 10-06-07 09:56:13,421 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling physicalConnectionWithin... 10-06-07 09:56:13,452 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling putDescriptor... 10-06-07 09:56:13,452 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling physicalConnectionWithin... 10-06-07 09:56:13,452 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling physicalConnectionWithin... 10-06-07 09:56:13,452 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: calling physicalConnectionWithin... 10-06-07 09:56:13,468 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@210a0e: close()... 10-06-07 09:56:13,468 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: calling getMetaData... 10-06-07 09:56:13,889 [http-8080-2] atomikos connection proxy for oracle.jdbc.driver.LogicalConnection@8f7e20: close()... 10-06-07 09:56:13,889 [http-8080-2] commit() done (by application) of transaction 172.16.203.64.tm0000100001
Hi again Guy,
I managed to reduce our scenario to a very simple unit test, which reproduces the problem. As long as I use Spring's DataSourceTransactionManager, my JDBC operation gets enrolled in a transaction and responds to the commit/rollback at the end. As soon as I switch to the Atomikos transaction manager, the JDBC operation no longer takes part in the transaction. The unit test is quite simple. It consists of a transactionTestDao which updates one single field in one single row in an Oracle table. It gets called from the transactionTestService, which is made transactional by Spring's @Transactional(propagation = Propagation.REQUIRED, rollbackFor = Exception.class) annotation. Below is the Spring configuration for all this: <bean id="datasource" class="org.springframework.jdbc.datasource.DriverManagerDataSource"> <property name="driverClassName" value="oracle.jdbc.driver.OracleDriver" /> <property name="url" value="jdbc:oracle:thin:@..." /> <property name="username" value="..." /> <property name="password" value="..." /> </bean> <bean id="jdbcTemplate" class="org.springframework.jdbc.core.JdbcTemplate"> <property name="dataSource" ref="datasource" /> </bean> <bean id="transactionTestDao" class="be.admb.transactiontest.persistence.TransactionTestJdbcDao"> <property name="jdbcTemplate" ref="jdbcTemplate" /> </bean> <bean id="transactionTestService" class="be.admb.transactiontest.service.TransactionTestServiceImpl"> <property name="transactionTestDao" ref="transactionTestDao" /> </bean> <bean id="atomikosTransactionManager" class="com.atomikos.icatch.jta.J2eeTransactionManager" /> <bean id="atomikosUserTransaction" class="com.atomikos.icatch.jta.UserTransactionImp" /> <bean id="springTxManager" class="org.springframework.transaction.jta.JtaTransactionManager"> <property name="transactionManager" ref="atomikosTransactionManager" /> <property name="userTransaction" ref="atomikosUserTransaction" /> </bean> <tx:annotation-driven transaction-manager="springTxManager" /> Below is the tm.out in DEBUG: 0-06-07 11:26:58,938 [main] Logfile closed: c:\temp\Atomikos\tmlog-1.log 10-06-07 11:26:58,969 [main] USING core version: 3.6.5 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.console_file_name = tm.out 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.console_file_count = 1 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.automatic_resource_registration = true 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.client_demarcation = false 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.threaded_2pc = true 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.serial_jta_transactions = true 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.log_base_dir = c:\temp\Atomikos 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.console_log_level = DEBUG 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.max_actives = 50 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.checkpoint_interval = 500 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.enable_logging = true 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.output_dir = c:\temp\Atomikos 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.log_base_name = tmlog 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.console_file_limit = -1 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.max_timeout = 3000000 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.tm_unique_name = 172.16.203.64.tm 10-06-07 11:26:58,969 [main] USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory 10-06-07 11:26:58,969 [main] USING java.naming.provider.url = rmi://localhost:1099 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.force_shutdown_on_vm_exit = false 10-06-07 11:26:58,969 [main] USING com.atomikos.icatch.default_jta_timeout = 3000000 10-06-07 11:26:58,969 [main] getCompositeTransaction() returning NULL! 10-06-07 11:26:58,969 [main] getCompositeTransaction() returning NULL! 10-06-07 11:26:58,969 [main] getCompositeTransaction() returning NULL! 10-06-07 11:26:58,984 [main] Coordinator 172.16.203.64.tm0000100001 entering state: ACTIVE 10-06-07 11:26:58,984 [main] Coordinator 172.16.203.64.tm0000100001 entered state: ACTIVE 10-06-07 11:26:58,984 [main] TaskManager: initializing... 10-06-07 11:26:58,984 [main] THREADS: using JDK thread pooling... 10-06-07 11:26:58,984 [main] THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor 10-06-07 11:26:58,984 [main] (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@18e4327 10-06-07 11:26:59,000 [main] ThreadFactory: creating new thread: Atomikos:0 10-06-07 11:26:59,000 [main] Creating composite transaction: 172.16.203.64.tm0000100001 10-06-07 11:26:59,000 [main] createCompositeTransaction ( 3000000 ): created new ROOT transaction with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,000 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,000 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] getCompositeTransaction() returning instance with id 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] commit() done (by application) of transaction 172.16.203.64.tm0000100001 10-06-07 11:26:59,281 [main] Coordinator 172.16.203.64.tm0000100001 entering state: COMMITTING 10-06-07 11:26:59,375 [main] Coordinator 172.16.203.64.tm0000100001 entered state: COMMITTING 10-06-07 11:26:59,375 [main] Coordinator 172.16.203.64.tm0000100001 entering state: TERMINATED 10-06-07 11:26:59,375 [main] Coordinator 172.16.203.64.tm0000100001 : stopping timer... 10-06-07 11:26:59,375 [main] Coordinator 172.16.203.64.tm0000100001 : disposing statehandler TERMINATED... 10-06-07 11:26:59,375 [main] Coordinator 172.16.203.64.tm0000100001 : disposed. 10-06-07 11:26:59,453 [main] Coordinator 172.16.203.64.tm0000100001 entered state: TERMINATED
Hi,
The unit test's config above uses org.springframework.jdbc.datasource.DriverManagerDataSource - so it is no surprise that it does not react to JTA commit/rollback. You would have to use the Atomikos datasource. The other log shows no statements being created on the Atomikos JDBC connections. That is why there is no participation in commit either. I am not sure what it is that you are doing there, but that explains the lack of participation at least.
Guy,
I agree that the use of the DriverManagerDataSource prevents proper JTA rollback/commit. However, even when I use the AtomikosDataSource I still have the problem. The reason being that there is a flaw in the Atomikos source code which prevents the connection participating in the ongoing transaction. This only happens when the Spring JdbcTemplate is configured in a certain way. When using Spring's DataSourceTransactionManager this problem does not occur, because Spring has neatly catered for this situation. Regards, Rik |