Atomikos TransactionsEssentials で JTA (XA with MySQL編その２)
EntityManager#persist()を２回連続で呼び出してみた。
前回は、JPA で複数のデータソースに対して persist() できました。
さて、今度は、EntityManager#persist() を、同一のEntityManager に対して２回連続で呼び出してみることにします。
ソースはこんな感じです。
A a1 = new A(); A a2 = new A(); a1.setName("Kuma-chan"); a2.setName("Fellow-kun"); em1.persist(a1); em1.persist(a2);
今度は、こんなエラーが出ました。
Exception in thread "main" com.atomikos.datasource.ResourceException: resume for XID com.atomikos.spring.jdbc.tm0000100017com.atomikos.spring.jdbc.tm1 raised -5: invalid arguments were given for the XA operation 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 $Proxy7.prepareStatement(Unknown Source) 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.hibernate.util.GetGeneratedKeysHelper.prepareStatement(GetGeneratedKeysHelper.java:49) at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:495) at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:94) at org.hibernate.id.IdentityGenerator$GetGeneratedKeysDelegate.prepare(IdentityGenerator.java:69) at org.hibernate.id.insert.AbstractReturningDelegate.performInsert(AbstractReturningDelegate.java:30) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2163) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2643) at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:51) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:298) at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:181) at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:107) at org.hibernate.ejb.event.EJB3PersistEventListener.saveWithGeneratedId(EJB3PersistEventListener.java:49) at org.hibernate.event.def.DefaultPersistEventListener.entityIsTransient(DefaultPersistEventListener.java:131) at org.hibernate.event.def.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:87) at org.hibernate.event.def.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:38) at org.hibernate.impl.SessionImpl.firePersist(SessionImpl.java:618) at org.hibernate.impl.SessionImpl.persist(SessionImpl.java:592) at org.hibernate.impl.SessionImpl.persist(SessionImpl.java:596) at org.hibernate.ejb.AbstractEntityManagerImpl.persist(AbstractEntityManagerImpl.java:220) 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.springframework.orm.jpa.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler.invoke(ExtendedEntityManagerCreator.java:357) at $Proxy9.persist(Unknown Source) 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.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:194) at $Proxy9.persist(Unknown Source) at sample.JpaExample1.main(JpaExample1.java:45)
DBへのクエリはこんな感じです。
1108 Query SET autocommit=0
1108 Query XA START 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d
1108 Query insert into A (name) values ('Kuma-chan')
1108 Query XA END 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d
1109 Query XA START 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d JOIN
このクエリから分かるのは、以下の２点でしょうか。
- 一度目の insert の後に XA END を行い、次の insert の前準備として XA START JOIN を行っている。
- XA START JOIN は別トランザクションで行っている。
トランザクションマネージャ実装のログ
08-07-02 01:22:49,609 [main] resume for XID com.atomikos.spring.jdbc.tm0000100017com.atomikos.spring.jdbc.tm1 raised -5: invalid arguments were given for the XA operation com.mysql.jdbc.jdbc2.optional.MysqlXAException: XAER_INVAL: Invalid arguments (or unsupported command) at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:567) at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:550) at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.start(MysqlXAConnection.java:490) 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 $Proxy7.prepareStatement(Unknown Source) 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.hibernate.util.GetGeneratedKeysHelper.prepareStatement(GetGeneratedKeysHelper.java:49) at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:495) at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:94) at org.hibernate.id.IdentityGenerator$GetGeneratedKeysDelegate.prepare(IdentityGenerator.java:69) at org.hibernate.id.insert.AbstractReturningDelegate.performInsert(AbstractReturningDelegate.java:30) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2163) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2643) at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:51) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:298) at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:181) at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:107) at org.hibernate.ejb.event.EJB3PersistEventListener.saveWithGeneratedId(EJB3PersistEventListener.java:49) at org.hibernate.event.def.DefaultPersistEventListener.entityIsTransient(DefaultPersistEventListener.java:131) at org.hibernate.event.def.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:87) at org.hibernate.event.def.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:38) at org.hibernate.impl.SessionImpl.firePersist(SessionImpl.java:618) at org.hibernate.impl.SessionImpl.persist(SessionImpl.java:592) at org.hibernate.impl.SessionImpl.persist(SessionImpl.java:596) at org.hibernate.ejb.AbstractEntityManagerImpl.persist(AbstractEntityManagerImpl.java:220) 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.springframework.orm.jpa.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler.invoke(ExtendedEntityManagerCreator.java:357) at $Proxy9.persist(Unknown Source) 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.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:194) at $Proxy9.persist(Unknown Source) at sample.JpaExample1.main(JpaExample1.java:45)
こいつ、例外を摩り替えてやがる、、、。原因となる例外はネストして渡してくれよ、、、。
なにはともあれ、MySQL のドライバが以下のメッセージを吐いているようです。
com.mysql.jdbc.jdbc2.optional.MysqlXAException: XAER_INVAL: Invalid arguments (or unsupported command)
MySQL 側の問題切り分け
ドライバだけの問題なのか、それともサーバーも関係しているのかを切り分けるため、MySQL のコンソールから直接SQLを投げてみました。
mysql> SET autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> XA START 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d;
Query OK, 0 rows affected (0.00 sec)
mysql> insert into A (name) values ('Kuma-chan');
Query OK, 1 row affected (0.00 sec)
mysql> XA END 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d;
Query OK, 0 rows affected (0.00 sec)
mysql> XA START 0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d30303030313030303137,0x636f6d2e61746f6d696b6f732e737072696e672e6a6462632e746d31,0x41544f4d JOIN;
ERROR 1398 (XAE05): XAER_INVAL: Invalid arguments (or unsupported command)
MySQLのサーバ側でエラーを吐いていますね。ということで、ドライバ側のみの問題というわけではなさそうです。
さて、問題の現状の情報はそろったかな。
次は問題調査ですね。
ちなみに、関連するミドルウェアその他のバージョンは、以下のとおり。
| コンポーネント | バージョン |
|---|---|
| OS | WinXP Pro V2002 sp2 |
| MySQL Connector/J | 5.1.3 |
| MySQL | 5.0.51b |
| java | 1.6.0_05-b13 |
