Atomikos Forum

Hi,
 
I’m currently facing a problem while trying to have my transactions working with Atomikos and Postgresql. No rollback seems to take effect when exception is thrown since the commit seems to have already been done. After searching, I think the problem is about the autoCommit mode which is set to true even during the transaction.
 
Here are the details:
 
Database version: postgresql 8.3.5
Driver version: postgresql-8.3-603.jdbc4 (tried also with postgresql-9.0-801.jdbc4 and same results)
Application server: Tomcat 6, with Atomikos 3.6.6
 
Server.xml:
<Resource
        name="jdbc/actualite_dev"
        auth="Container"
        type="com.atomikos.jdbc.AtomikosDataSourceBean"
        factory="com.atomikos.tomcat.BeanFactory"
        uniqueResourceName="jdbc/actualite_dev"
        xaDataSourceClassName="org.postgresql.xa.PGXADataSource"
        xaProperties.databaseName="actualite_dev"
        xaProperties.serverName="10.85……"
        xaProperties.portNumber="5432"
        xaProperties.user="*****"
        xaProperties.password="*****"
    />
 
Context.xml:
<Transaction factory="com.atomikos.icatch.jta.UserTransactionFactory" />
<ResourceLink name="jdbc/actualite_dev" global="jdbc/actualite_dev" type="com.atomikos.jdbc.AtomikosDataSourceBean"/>
 
I’m testing from a webapp in which the spring configuration uses JtaTransactionManager pointing to Atomikos. The transactional mode is set to my business method by spring annotations. This part seems to be ok. With breakpoints and logs, I can see the transaction is created; when I throw an exception, it does decide to rollback and seems to initiate it. Apparently no rollback error but nothing happens then in the database.
 
The problem is apparently before that: When I check the database before throwing the exception, the update has already been commited. When I check the value of the autoCommit during the transaction, it seems to be true and thus the root cause of the problem.
 
I saw this old post about a similar problem: http://archives.postgresql.org/pgsql-jdbc/2006-10/msg00043.php
When comparing the patch to the most recent driver (9-801), I saw the changes were already integrated. But the autoCommit problem is still there for me even with this version.
 
Have I missed something in the configuration with Atomikos?
Should I explicitly set the autocommit mode to false somewhere? How? (I think the driver prevent from doing that)
 
I don't know if the problem is on the driver’s side or Atomikos'. I’m a bit confused now.
I also read posts and docs about the autocommit set to true in Postgresql since any “begin” instruction has not been sent. Is there something about that? Should Atomikos send a begin instruction when starting any transaction?
 
I would really appreciate some help. I can provide more details if needed.
Thank you.
Marion.
 
Logs in debug (the transaction is set around the ActualiteBusinessImpl.modifierActualiteDto method, containing calls to ActualitoDaoImpl):
 
2011-02-09 14:24:57,498 DEBUG [ActualiteDaoImpl.java:102] : Entree dans la methode
2011-02-09 14:24:57,498 DEBUG [JakartaCommonsLoggingImpl.java:27] : {conn-100891} Connection
2011-02-09 14:24:57,498 DEBUG [JakartaCommonsLoggingImpl.java:27] : {conn-100891} Preparing Statement:    UPDATE ACTUALITE SET TITRE = ?,    CONTENU = ?,    IMPORTANTE = ?,    ETAT_ESPACE_DISCUSSION_ID = ?,    MODERATION_ID = ?,        AUTEUR_MAJ = ?,    ESPACE_DISCUSSION = ?,      DATE_PUBLICATION = ?,      DATE_EXPIRATION = ?,      DATE_MAJ = ?,      IMAGE_POSITION = ?,      IMAGE_DIMENSION = ?,      TYPE_ACTUALITE_ID = ?        WHERE ACTUALITE_ID = ?;
2011-02-09 14:24:57,498 DEBUG [DataSourceUtils.java:112] : Fetching JDBC Connection from DataSource
2011-02-09 14:24:57,513 DEBUG [DataSourceUtils.java:116] : Registering transaction synchronization for JDBC Connection
2011-02-09 14:24:57,513 DEBUG [TransactionSynchronizationManager.java:168] : Bound value [org.springframework.jdbc.datasource.ConnectionHolder@5a8d05] for key [AtomikosDataSoureBean 'jdbc/actualite_dev'] to thread [http-8080-1]
2011-02-09 14:24:57,513 DEBUG [TransactionSynchronizationManager.java:140] : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@5a8d05] for key [AtomikosDataSoureBean 'jdbc/actualite_dev'] bound to thread [http-8080-1]
2011-02-09 14:24:57,513 DEBUG [JakartaCommonsLoggingImpl.java:27] : {pstm-100892} Executing Statement:    UPDATE ACTUALITE SET TITRE = ?,    CONTENU = ?,    IMPORTANTE = ?,    ETAT_ESPACE_DISCUSSION_ID = ?,    MODERATION_ID = ?,        AUTEUR_MAJ = ?,    ESPACE_DISCUSSION = ?,      DATE_PUBLICATION = ?,      DATE_EXPIRATION = ?,      DATE_MAJ = ?,      IMAGE_POSITION = ?,      IMAGE_DIMENSION = ?,      TYPE_ACTUALITE_ID = ?        WHERE ACTUALITE_ID = ?;
2011-02-09 14:24:57,513 DEBUG [JakartaCommonsLoggingImpl.java:27] : {pstm-100892} Parameters: [transactions, <p>test transactions mmau jcomprends plus</p>, true, null, null, 110000000000007027, false, 2011-01-17 00:00:00.0, 2011-07-05 00:00:00.0, 2011-02-09 14:24:56.763, 1, 100, 0, 182]
2011-02-09 14:24:57,513 DEBUG [JakartaCommonsLoggingImpl.java:27] : {pstm-100892} Types: [java.lang.String, java.lang.String, java.lang.Boolean, null, null, java.lang.Long, java.lang.Boolean, java.sql.Timestamp, java.sql.Timestamp, java.sql.Timestamp, java.lang.Long, java.lang.Long, java.lang.Long, java.lang.Long]
2011-02-09 14:24:57,529 DEBUG [TransactionSynchronizationManager.java:140] : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@5a8d05] for key [AtomikosDataSoureBean 'jdbc/actualite_dev'] bound to thread [http-8080-1]
(the following exception is on purpose to test the rollback)
2011-02-09 14:25:07,967 ERROR [ActualitesBusinessImpl.java:161] :
java.lang.NullPointerException
                at org.lilie.services.actualite.business.impl.ActualitesBusinessImpl.modifierActualiteDto(ActualitesBusinessImpl.java:145)
                at org.lilie.services.actualite.business.impl.ActualitesBusinessImpl$$FastClassByCGLIB$$be9db12c.invoke(<generated>)
                …
                at java.lang.Thread.run(Thread.java:619)
2011-02-09 14:25:09,248 DEBUG [TransactionAspectSupport.java:327] : Completing transaction for [org.lilie.services.actualite.business.impl.ActualitesBusinessImpl.modifierActualiteDto] after exception: org.lilie.socle.core.business.exception.ServiceTechniqueException: java.lang.NullPointerException
2011-02-09 14:25:09,248 DEBUG [RuleBasedTransactionAttribute.java:130] : Applying rules to determine whether transaction should rollback on org.lilie.socle.core.business.exception.ServiceTechniqueException: java.lang.NullPointerException
2011-02-09 14:25:09,248 DEBUG [RuleBasedTransactionAttribute.java:148] : Winning rollback rule is: RollbackRuleAttribute with pattern [java.lang.Exception]
2011-02-09 14:25:09,263 DEBUG [AbstractPlatformTransactionManager.java:846] : Triggering beforeCompletion synchronization
2011-02-09 14:25:09,263 DEBUG [TransactionSynchronizationManager.java:193] : Removed value [org.springframework.jdbc.datasource.ConnectionHolder@5a8d05] for key [AtomikosDataSoureBean 'jdbc/actualite_dev'] from thread [http-8080-1]
2011-02-09 14:25:09,263 DEBUG [DataSourceUtils.java:312] : Returning JDBC Connection to DataSource
2011-02-09 14:25:09,263 DEBUG [AbstractPlatformTransactionManager.java:751] : Initiating transaction rollback
2011-02-09 14:25:09,263 DEBUG [Slf4jConsole.java:88] : getCompositeTransaction()  returning instance with id 10.84.213.150.tm0000700057
2011-02-09 14:25:09,263 DEBUG [Slf4jConsole.java:88] : getCompositeTransaction()  returning instance with id 10.84.213.150.tm0000700057
2011-02-09 14:25:09,279 DEBUG [Slf4jConsole.java:88] : getCompositeTransaction()  returning instance with id 10.84.213.150.tm0000700057
2011-02-09 14:25:09,279 DEBUG [Slf4jConsole.java:88] : getCompositeTransaction()  returning instance with id 10.84.213.150.tm0000700057
2011-02-09 14:25:09,310 DEBUG [Slf4jConsole.java:88] : Coordinator 10.84.213.150.tm0000700057 entering state: ABORTING
2011-02-09 14:25:09,310 DEBUG [Slf4jConsole.java:88] : Coordinator 10.84.213.150.tm0000700057 entering state: TERMINATED
2011-02-09 14:25:09,326 DEBUG [Slf4jConsole.java:88] : Coordinator 10.84.213.150.tm0000700057 : stopping timer...
2011-02-09 14:25:09,326 DEBUG [Slf4jConsole.java:88] : Coordinator 10.84.213.150.tm0000700057 : disposing statehandler TERMINATED...
2011-02-09 14:25:09,326 DEBUG [Slf4jConsole.java:88] : Coordinator 10.84.213.150.tm0000700057 : disposed.
2011-02-09 14:25:09,326 INFO  [Slf4jConsole.java:85] : rollback() done of transaction 10.84.213.150.tm0000700057
2011-02-09 14:25:09,326 DEBUG [AbstractPlatformTransactionManager.java:875] : Triggering afterCompletion synchronization
2011-02-09 14:25:09,326 DEBUG [TransactionSynchronizationManager.java:276] : Clearing transaction synchronization

Hi,

We don't do anything special to disable autoCommit in XA mode because it is required by the JDBC/XA specs...

We are working with PostgreSQL to tune things but it is a work in progress.

HTH

Hi, thanks for the answer.

Do you mean it's the job of Postgresql jdbc Driver to set the autocommit to false and not Atomikos'?
What do you mean by "work in progess": is it normal that I can't have tx working for the moment with Postgresql?

Thanks

Here are Atomikos's logs in the tm.out file:

11-02-17 17:04:53,175 [http-8080-6] getCompositeTransaction() returning NULL!
11-02-17 17:04:53,175 [http-8080-6] getCompositeTransaction() returning NULL!
11-02-17 17:04:53,190 [http-8080-6] getCompositeTransaction() returning NULL!
11-02-17 17:04:53,190 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entering state: ACTIVE
11-02-17 17:04:53,190 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entered state: ACTIVE
11-02-17 17:04:53,190 [http-8080-6] (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@b748dd
11-02-17 17:04:53,190 [http-8080-6] Creating composite transaction: 10.84.213.150.tm0001000081
11-02-17 17:04:53,206 [http-8080-6] createCompositeTransaction ( 300000 ): created new ROOT transaction with id 10.84.213.150.tm0001000081
11-02-17 17:05:07,019 [http-8080-6] getCompositeTransaction()  returning instance with id 10.84.213.150.tm0001000081
11-02-17 17:05:07,019 [http-8080-6] getCompositeTransaction()  returning instance with id 10.84.213.150.tm0001000081
11-02-17 17:05:07,019 [http-8080-6] getCompositeTransaction()  returning instance with id 10.84.213.150.tm0001000081
11-02-17 17:05:07,034 [http-8080-6] getCompositeTransaction()  returning instance with id 10.84.213.150.tm0001000081
11-02-17 17:05:07,034 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entering state: ABORTING
11-02-17 17:05:07,034 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entered state: ABORTING
11-02-17 17:05:07,034 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entering state: TERMINATED
11-02-17 17:05:07,034 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 : stopping timer...
11-02-17 17:05:07,034 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 : disposing statehandler TERMINATED...
11-02-17 17:05:07,050 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 : disposed.
11-02-17 17:05:07,081 [http-8080-6] Coordinator 10.84.213.150.tm0001000081 entered state: TERMINATED
11-02-17 17:05:07,081 [http-8080-6] rollback() done of transaction 10.84.213.150.tm0001000081

The tm.out suggests that you are not actually using the AtomikosDataSourceBean for you JDBC... That should explain.

What makes you think that in the tm.out?
Indeed when I put breakpoints in AtomikosDatasrouceBean, it does not seem to be called. Though I do have calls on other Atomikos classes: for example I can see AtomikosConnectionProxy.addStatement is called.

Is my configuration wrong? Is it on Atomikos's BeanFactory side?
Thanks

I do see the instantiation of AtomikosDatasourceBean in the logs when I start Tomcat:
2011-02-21 12:25:04,704 DEBUG [BeanFactory.java:50] : instanciating bean of class com.atomikos.jdbc.AtomikosDataSourceBean
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'uniqueResourceName' to 'jdbc/actualite_dev'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'maxPoolSize' to '100'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.databaseName' to 'actualite_dev'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.serverName' to '10.85.210.60'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'minPoolSize' to '10'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.user' to 'actualite'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.portNumber' to '5432'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.logLevel' to '2'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaProperties.password' to 'actualite'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:65] : setting property 'xaDataSourceClassName' to 'org.postgresql.xa.PGXADataSource'
2011-02-21 12:25:04,719 DEBUG [BeanFactory.java:71] : done setting 10 property(ies), now initializing resource AtomikosDataSoureBean 'jdbc/actualite_dev'

I would look at the Spring config instead?