Atomikos Forum |
|
hello everybody,
i'm trying to get XA transactions running with PostgreSQL and ActiveMQ. i am using Spring Framework 3.0.0 (declarative transactions), Hibernate 3.3.2, PostgreSQL 8.4 + JDBC4 Driver 8.4-701 (also tested with PostgreSQL 8.3 + JDBC3 Driver 8.3-603), ActiveMQ 5.3.0, Atomikos TransactionEssentials 3.6.5 (AtomikosDataSourceBean) the application selects the current transaction timestamp from the database and sends a JMS message with ActiveMQ every 5 seconds. the application is running and i force a shutdown of the database system after BEGIN but before PREPARE (to simulate a failure). when i restart the database system a ROLLBACK PREPARED 'xid' is executed on the new connection. the ROLLBACK PREPARED statement is executed over and over again. is there a way to limit the retry count? why is ROLLBACK PREPARED executed when PREPARE was never executed for the transaction? thanks, tscho Atomikos Log: 2010-05-28 14:25:14,946 [Atomikos:9] DEBUG atomikos - XA resource 'dataSourceJTA': prepare for XID '31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837' raised -3: the XA resource detected an internal error org.postgresql.xa.PGXAException: Error preparing transaction at org.postgresql.xa.PGXAConnection.prepare(PGXAConnection.java:254) at com.atomikos.datasource.xa.XAResourceTransaction.prepare(XAResourceTransaction.java:591) at com.atomikos.icatch.imp.PrepareMessage.send(PrepareMessage.java:63) at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:114) at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:90) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: org.postgresql.util.PSQLException: FATAL: terminating connection due to administrator command at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1592) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1327) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:451) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:336) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:282) at org.postgresql.xa.PGXAConnection.prepare(PGXAConnection.java:242) ... 7 more 2010-05-28 14:25:14,947 [DefaultMessageListenerContainer-1] DEBUG atomikos - Coordinator 10.10.1.3.tm0004500001 entering state: ABORTING 2010-05-28 14:25:14,947 [DefaultMessageListenerContainer-1] DEBUG atomikos - (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@8e683a 2010-05-28 14:25:14,948 [Atomikos:9] INFO atomikos - XAResource.rollback ( 31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837 ) on resource dataSourceJTA represented by XAResource instance org.postgresql.xa.PGXAConnection@da1c9f 2010-05-28 14:25:14,949 [Atomikos:9] WARN atomikos - XA resource 'dataSourceJTA': rollback for XID '31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837' raised -3: the XA resource detected an internal error org.postgresql.xa.PGXAException: Error rolling back prepared transaction at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:357) at com.atomikos.datasource.xa.XAResourceTransaction.rollback(XAResourceTransaction.java:659) at com.atomikos.icatch.imp.RollbackMessage.send(RollbackMessage.java:74) at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:114) at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:90) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: org.postgresql.util.PSQLException: An I/O error occured while sending to the backend. at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:218) at org.postgresql.jdbc2.AbstractJdbc2Connection.executeTransactionCommand(AbstractJdbc2Connection.java:650) at org.postgresql.jdbc2.AbstractJdbc2Connection.commit(AbstractJdbc2Connection.java:670) at org.postgresql.jdbc2.AbstractJdbc2Connection.setAutoCommit(AbstractJdbc2Connection.java:633) at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:343) ... 7 more Caused by: java.net.SocketException: Broken pipe at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92) at java.net.SocketOutputStream.write(SocketOutputStream.java:136) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123) at org.postgresql.core.PGStream.flush(PGStream.java:508) at org.postgresql.core.v3.QueryExecutorImpl.sendSync(QueryExecutorImpl.java:676) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191) ... 11 more === shutdown/restart === 2010-05-28 14:25:24,949 [Atomikos:9] DEBUG atomikos - Propagator: retrying message: RollbackMessage to XAResourceTransaction: 31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837 2010-05-28 14:25:24,949 [Atomikos:9] DEBUG atomikos - dataSourceJTA: forcing refresh of XAConnection... 2010-05-28 14:25:24,972 [Atomikos:9] INFO atomikos - XAResource.rollback ( 31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837 ) on resource dataSourceJTA represented by XAResource instance org.postgresql.xa.PGXAConnection@f1036f 2010-05-28 14:25:24,973 [Atomikos:9] WARN atomikos - XA resource 'dataSourceJTA': rollback for XID '31302E31302E312E332E746D30303034353030303031:31302E31302E312E332E746D3837' raised -3: the XA resource detected an internal error org.postgresql.xa.PGXAException: Error rolling back prepared transaction at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:357) at com.atomikos.datasource.xa.XAResourceTransaction.rollback(XAResourceTransaction.java:659) at com.atomikos.icatch.imp.RollbackMessage.send(RollbackMessage.java:74) at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:114) at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:90) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: org.postgresql.util.PSQLException: ERROR: prepared transaction with identifier "1096044365_MTAuMTAuMS4zLnRtMDAwNDUwMDAwMQ==_MTAuMTAuMS4zLnRtODc=" does not exist at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1592) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1327) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:451) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:336) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:282) at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:347) ... 7 more Database Log: 2010-05-28 14:25:05.216 CEST - postgres@10.10.1.3 testdb [4bffb5e5.214b|1/1409] LOG: duration: 0.016 ms bind S_1: BEGIN 2010-05-28 14:25:05.216 CEST - postgres@10.10.1.3 testdb [4bffb5e5.214b|1/1409] LOG: duration: 0.004 ms execute S_1: BEGIN 2010-05-28 14:25:05.216 CEST - postgres@10.10.1.3 testdb [4bffb5e5.214b|1/1409] LOG: duration: 0.074 ms parse <unnamed>: select cast(now() as timestamptz(3)) 2010-05-28 14:25:05.216 CEST - postgres@10.10.1.3 testdb [4bffb5e5.214b|1/1409] LOG: duration: 0.018 ms bind <unnamed>: select cast(now() as timestamptz(3)) 2010-05-28 14:25:05.216 CEST - postgres@10.10.1.3 testdb [4bffb5e5.214b|1/1409] LOG: duration: 0.011 ms execute <unnamed>: select cast(now() as timestamptz(3)) 2010-05-28 14:25:06.213 CEST - @ [4bffae25.e61|] LOG: received fast shutdown request 2010-05-28 14:25:06.213 CEST - @ [4bffae25.e61|] LOG: aborting any active transactions 2010-05-28 14:25:06.213 CEST - postgres@10.10.1.3 testdb [4bffb5f3.216b|12/0] FATAL: terminating connection due to administrator command 2010-05-28 14:25:06.213 CEST - postgres@10.10.1.3 testdb [4bffb5e5.2152|8/0] FATAL: terminating connection due to administrator command 2010-05-28 14:25:06.213 CEST - postgres@10.10.1.3 testdb [4bffb5f2.2162|11/0] FATAL: terminating connection due to administrator command 2010-05-28 14:25:06.213 CEST - postgres@10.10.1.3 testdb [4bffb5e5.2154|10/0] FATAL: terminating connection due to administrator command === shutdown/restart === 2010-05-28 14:25:16.554 CEST - [unknown]@ [unknown] [4bffb62c.222b|] LOG: connection received: host=10.10.1.3 port=49073 2010-05-28 14:25:16.554 CEST - postgres@10.10.1.3 testdb [4bffb62c.222b|] LOG: connection authorized: user=postgres database=testdb 2010-05-28 14:25:16.559 CEST - postgres@10.10.1.3 testdb [4bffb62c.222b|1/8] LOG: duration: 0.185 ms parse <unnamed>: ROLLBACK PREPARED '1096044365_MTAuMTAuMS4zLnRtMDAwNDUwMDAwMQ==_MTAuMTAuMS4zLnRtODc=' 2010-05-28 14:25:16.559 CEST - postgres@10.10.1.3 testdb [4bffb62c.222b|1/8] LOG: duration: 0.008 ms bind <unnamed>: ROLLBACK PREPARED '1096044365_MTAuMTAuMS4zLnRtMDAwNDUwMDAwMQ==_MTAuMTAuMS4zLnRtODc=' 2010-05-28 14:25:16.559 CEST - postgres@10.10.1.3 testdb [4bffb62c.222b|1/8] ERROR: prepared transaction with identifier "1096044365_MTAuMTAuMS4zLnRtMDAwNDUwMDAwMQ==_MTAuMTAuMS4zLnRtODc=" does not exist 2010-05-28 14:25:16.559 CEST - postgres@10.10.1.3 testdb [4bffb62c.222b|1/8] STATEMENT: ROLLBACK PREPARED '1096044365_MTAuMTAuMS4zLnRtMDAwNDUwMDAwMQ==_MTAuMTAuMS4zLnRtODc=' |