読者です 読者をやめる 読者になる 読者になる

PostgreSQLにもつないでみる。

この前の「ロック試行がタイムアウト」というエラーの切り分けをするのに、
とりあえずDBをH2からPostgreSQLに変更してみました。

設定は以下を参考にした。
ハテサテ。 - 設計と実装の狭間で。


修正した箇所は lucy-config.xml の dataSource 部分のみ。

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE lucy-config PUBLIC "-//LUCY//DTD LUCY//EN" "http://www.lucy.org/dtd/lucy-config.dtd">
<lucy-config>

	<component name="dataSource" class="com.atomikos.jdbc.AtomikosDataSourceBean">
		<inject method="setXaDataSourceClassName">"org.postgresql.xa.PGXADataSource"</inject>
		<inject method="setUniqueResourceName">"jdbc/postgreSQL/xaDatasource"</inject>
		<inject method="setPoolSize">20</inject>
		<inject method="setBorrowConnectionTimeout">60</inject>
		<inject method="setXaProperties"><![CDATA[
			p = dataSource.XaProperties;
			p["ServerName"]="localhost";
			p["PortNumber"]="5432";
			p["DatabaseName"]="t2db";
			p["User"]="postgres";
			p["Password"]="postgres";
			p;
		]]></inject>
		<destroy method="close"/>
	</component>

</lucy-config>

テストケースを作って実行。
一覧取得のみ、更新のみはできるが、PostgreSQLでも更新した後に
一覧取得しようとするとエラーが発生。

問題はDBではなくて lucy-tx か atomikos に原因がありそうだなぁ。

### worker.work()
********** =====> UPDATE *************
13:49:07 [main] INFO  atomikos - AtomikosDataSourceBean: initializing with [ xaDataSourceClassName=org.postgresql.xa.PGXADataSource, uniqueResourceName=jdbc/postgreSQL/xaDatasource, maxPoolSize=20, minPoolSize=20, borrowConnectionTimeout=60, maxIdleTime=60, reapTimeout=300, maintenanceInterval=60, testQuery=null, xaProperties={PortNumber=5432, Password=postgres, ServerName=localhost, DatabaseName=t2db, User=postgres}]
13:49:07 [main] WARN  atomikos - jdbc/postgreSQL/xaDatasource: refreshed XAResource
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - addParticipant ( 192.168.0.3.tm0000100016192.168.0.3.tm1 ) for transaction 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - XAResource.start ( 192.168.0.3.tm0000100016192.168.0.3.tm1 , XAResource.TMNOFLAGS ) called on resource jdbc/postgreSQL/xaDatasource represented by XAResource instance org.postgresql.xa.PGXAConnection@e14d81
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - XAResource.end ( 192.168.0.3.tm0000100016192.168.0.3.tm1 , XAResource.TMSUCCESS ) called on resource jdbc/postgreSQL/xaDatasource represented by XAResource instance org.postgresql.xa.PGXAConnection@e14d81
********** <===== UPDATE *************
********** =====> SELECT *************
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - addParticipant ( 192.168.0.3.tm0000100016192.168.0.3.tm1 ) for transaction 192.168.0.3.tm0000100016
13:49:10 [main] WARN  atomikos - resume for XID 192.168.0.3.tm0000100016192.168.0.3.tm1 raised -3: the XA resource detected an internal error
org.postgresql.xa.PGXAException: Transaction interleaving not implemented
	at org.postgresql.xa.PGXAConnection.start(PGXAConnection.java:146)
	at com.atomikos.datasource.xa.XAResourceTransaction.resume(Unknown Source)
	at com.atomikos.datasource.xa.session.BranchEnlistedStateHandler.<init>(Unknown Source)
	at com.atomikos.datasource.xa.session.NotInBranchStateHandler.checkEnlistBeforeUse(Unknown Source)
	at com.atomikos.datasource.xa.session.TransactionContext.checkEnlistBeforeUse(Unknown Source)
	at com.atomikos.datasource.xa.session.SessionHandleState.notifyBeforeUse(Unknown Source)
	at com.atomikos.jdbc.AtomikosConnectionProxy.enlist(Unknown Source)
	at com.atomikos.jdbc.AtomikosConnectionProxy.invoke(Unknown Source)
	at $Proxy11.prepareStatement(Unknown Source)
	at org.seasar.dbflute.s2dao.jdbc.TnStatementFactoryImpl.createPreparedStatement(TnStatementFactoryImpl.java:59)
	at org.seasar.dbflute.s2dao.sqlhandler.TnBasicHandler.prepareStatement(TnBasicHandler.java:196)
	at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.execute(TnBasicSelectHandler.java:58)
	at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.execute(TnBasicSelectHandler.java:48)
	at org.seasar.dbflute.bhv.core.execution.SelectCBExecution.execute(SelectCBExecution.java:59)
	at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.executeSql(BehaviorCommandInvoker.java:236)
	at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.doInvoke(BehaviorCommandInvoker.java:155)
	at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.invoke(BehaviorCommandInvoker.java:100)
	at org.seasar.dbflute.bhv.AbstractBehaviorReadable.invoke(AbstractBehaviorReadable.java:875)
	at org.t2framework.samples.todo.postgres.dbflute.bsbhv.BsEmployeeBhv.delegateSelectList(BsEmployeeBhv.java:473)
	at org.t2framework.samples.todo.postgres.dbflute.bsbhv.BsEmployeeBhv.selectList(BsEmployeeBhv.java:165)
	at org.t2framework.samples.lucy.service.impl.TestEmployeeServiceImpl.execute(TestEmployeeServiceImpl.java:28)
	at org.t2framework.samples.lucy.service.impl.TestEmployeeServiceImpl$$LucyAop$$10dc656.execute$$(TestEmployeeServiceImpl$$LucyAop$$10dc656.java)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.t2framework.lucy.aop.impl.InvocationImpl.proceed(InvocationImpl.java:137)
	at org.t2framework.lucy.tx.interceptor.InvocationWorker.work(InvocationWorker.java:20)
	at org.t2framework.lucy.tx.JTATransactionProcesser.required(JTATransactionProcesser.java:30)
	at org.t2framework.lucy.tx.interceptor.RequiredInterceptor.process(RequiredInterceptor.java:11)
	at org.t2framework.lucy.tx.interceptor.AbstractTxInterceptor.intercept(AbstractTxInterceptor.java:38)
	at org.t2framework.lucy.aop.impl.InvocationImpl.proceed(InvocationImpl.java:134)
	at org.t2framework.lucy.aop.impl.InvocationImpl.doProceed(InvocationImpl.java:112)
	at org.t2framework.samples.lucy.service.impl.TestEmployeeServiceImpl$$LucyAop$$10dc656.execute(TestEmployeeServiceImpl$$LucyAop$$10dc656.java)
	at org.t2framework.samples.lucy.dbflute.BehaviorTest.testService(BehaviorTest.java:36)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at junit.framework.TestCase.runTest(TestCase.java:164)
	at org.t2framework.commons.ut.BaseTestCase.runTest(BaseTestCase.java:88)
	at org.t2framework.commons.ut.DefaultUtPlugin.runTest(DefaultUtPlugin.java:46)
	at org.t2framework.commons.ut.BaseTestCase.runBare(BaseTestCase.java:34)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:120)
	at junit.framework.TestSuite.runTest(TestSuite.java:230)
	at junit.framework.TestSuite.run(TestSuite.java:225)
	at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:81)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:45)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)

13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - setRollbackOnly() called for transaction 192.168.0.3.tm0000100016
### JTATransactionProcesser#end() を実行
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:10 [main] INFO  atomikos - getCompositeTransaction()  returning instance with id 192.168.0.3.tm0000100016
13:49:11 [Atomikos:4] WARN  atomikos - rollback for XID 192.168.0.3.tm0000100016192.168.0.3.tm1 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(Unknown Source)
	at com.atomikos.icatch.imp.RollbackMessage.send(Unknown Source)
	at com.atomikos.icatch.imp.PropagationMessage.submit(Unknown Source)
	at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Unknown Source)
	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_MTkyLjE2OC4wLjMudG0wMDAwMTAwMDE2_MTkyLjE2OC4wLjMudG0x" 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

13:49:11 [main] INFO  atomikos - rollback() done of transaction 192.168.0.3.tm0000100016