Vanilla Spring Batch Admin и JTA — почему коммиты внезапно перестают происходить?

У меня есть небольшое приложение, построенное на базе spring-batch и spring-batch-admim, которое в основном работало, но затем у меня случился момент, когда мне пришлось добавить к нему транзакцию XA. Ничего страшного, это достаточно распространенная схема. Как только я это сделал, коммиты перестали происходить в любом менеджере транзакций.

Средство запуска spring-batch выполняет свою работу, в логах написано, что работа была зафиксирована, но фиксации так и не произошло.

Я проследил код весны до драйвера JDBC. В отладчике я подтвердил, что методы фиксации вызываются полностью в драйвере, но состояние протокола соединения уже находится в состоянии бездействия до вызова метода фиксации драйвера, поэтому фиксация не выполняется. Похоже, что соединение возвращается в пул перед фиксацией в триггере beforeCommit.

Я подтвердил, что одинаковое поведение проявляется как в org.springframework.jdbc.datasource.DataSourceTransactionManager с org.apache.commons.dbcp.BasicDataSource, так и в BitronixTransactionManager с bitronix.tm.resource.jdbc.PoolingDataSource.

Я убежден, что упускаю что-то очевидное, но я не вижу, что это такое. Если бы это было нормальным поведением, то продукт никогда бы не заработал. У кого-нибудь есть идеи?

Псевдокод для фиксации из драйвера

if (protocolstate != IDLE) {
    sendCommand(COMMIT);
}

Окружающая среда:

OS: Windows 7
Java: 1.8.0_25
Spring: 3.2.13-RELEASE
Spring-Batch: 3.0.2-RELEASE
Spring-batch-admin: 1.3.1-RELEASE
JDBC: postgresql 9.3-1102-jdbc41
Database: postgresql 9.4

Конфигурация диспетчера транзакций (XML):

<tx:annotation-driven transaction-manager="jtaTransactionManager" />

<!--  Bitronix Transaction Manager embedded configuration -->
<bean id="btmConfig" factory-method="getConfiguration" class="bitronix.tm.TransactionManagerServices">
    <property name="serverId" value="spring-btm" />
    <property name="logPart1Filename" value="C:\TEMP\bit-btm1.tlog}" />
    <property name="logPart2Filename" value="C:\TEMP\bit-btm2.tlog}" />
</bean>

<!-- create BTM transaction manager -->
<bean id="BitronixTransactionManager" factory-method="getTransactionManager"
    class="bitronix.tm.TransactionManagerServices" depends-on="btmConfig" destroy-method="shutdown" />

<bean id="jtaTransactionManager" class="org.springframework.transaction.jta.JtaTransactionManager"
    depends-on="BitronixTransactionManager">
    <property name="transactionManager" ref="BitronixTransactionManager" />
    <property name="userTransaction" ref="BitronixTransactionManager" />
</bean>  

<alias alias="transactionManager" name="jtaTransactionManager"/>
<alias alias="dataSource" name="myDataSource"/>

<bean id="myDataSource" class="bitronix.tm.resource.jdbc.PoolingDataSource"
    init-method="init" destroy-method="close" depends-on="jtaTransactionManager">
    <property name="className" value="org.postgresql.xa.PGXADataSource" />
    <property name="uniqueName" value="maxisIlmDataSource" />
    <property name="maxPoolSize" value="30" />

    <property name="allowLocalTransactions" value="true"/>

    <property name="driverProperties">
        <props>
            <prop key="user">me</prop>
            <prop key="password">mypass</prop>
            <prop key="url">jdbc:postgresql://localhost:5432/mydb</prop>
            <prop key="serverName">localhost</prop>
            <prop key="portNumber">5432</prop>
            <prop key="databaseName">mydb</prop>
        </props>
    </property>
</bean>

Выдержка из журнала выполнения:

21:48:45.929 [tomcat-http--10] DEBUG b.tm.BitronixTransactionManager - begun new transaction at Wed Dec 31 22:50:41 CST 1969
21:48:45.929 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL query
21:48:45.929 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
21:48:45.929 [tomcat-http--10] DEBUG o.s.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
21:48:45.929 [tomcat-http--10] DEBUG o.s.jdbc.datasource.DataSourceUtils - Registering transaction synchronization for JDBC Connection
21:48:45.930 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL query
21:48:45.930 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
21:48:45.933 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL update
21:48:45.935 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]
21:48:45.938 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - SQL update affected 1 rows
21:48:45.940 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL update
21:48:45.941 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_EXECUTION(JOB_EXECUTION_ID, JOB_INSTANCE_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, VERSION, CREATE_TIME, LAST_UPDATED, JOB_CONFIGURATION_LOCATION) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
21:48:45.942 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - SQL update affected 1 rows
21:48:45.977 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL update
21:48:45.977 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO BATCH_JOB_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, JOB_EXECUTION_ID) VALUES(?, ?, ?)]
21:48:45.980 [tomcat-http--10] DEBUG o.s.jdbc.core.JdbcTemplate - SQL update affected 1 rows
21:48:45.980 [tomcat-http--10] DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
21:48:45.980 [tomcat-http--10] DEBUG b.tm.BitronixTransactionManager - committing transaction a Bitronix Transaction with GTRID [737072696E672D62746D00000000010A22560000000F], status=ACTIVE, 0 resource(s) enlisted (started Wed Dec 31 22:50:41 CST 1969)
21:48:45.980 [tomcat-http--10] DEBUG bitronix.tm.timer.TaskScheduler - cancelling transaction timeout task on a Bitronix Transaction with GTRID [737072696E672D62746D00000000010A22560000000F], status=ACTIVE, 0 resource(s) enlisted (started Wed Dec 31 22:50:41 CST 1969)
...
21:48:45.981 [tomcat-http--10] DEBUG b.tm.journal.TransactionLogAppender - between 52346 and 52405, writing a Bitronix TransactionLogRecord with status=COMMITTED, recordLength=51, headerLength=28, time=17441418, sequenceNumber=45, crc32=-367977821, gtrid=737072696E672D62746D00000000010A22560000000F, uniqueNames=
21:48:45.981 [tomcat-http--10] DEBUG b.tm.journal.TransactionLogAppender - disk journal appender now at position 52405
21:48:45.981 [tomcat-http--10] DEBUG bitronix.tm.BitronixTransaction - transaction status is changing from COMMITTING to COMMITTED - executing 0 listener(s)
21:48:45.981 [tomcat-http--10] DEBUG bitronix.tm.twopc.Committer - phase 2 commit succeeded with no interested resource
21:48:45.981 [tomcat-http--10] DEBUG bitronix.tm.BitronixTransaction - successfully committed a Bitronix Transaction with GTRID [737072696E672D62746D00000000010A22560000000F], status=COMMITTED, 0 resource(s) enlisted (started Wed Dec 31 22:50:41 CST 1969)

person pojo-guy    schedule 05.02.2015    source источник


Ответы (1)


Что на самом деле было не так В другом файле конфигурации был компонент класса BasicDataSource. Некоторые созданные bean-компоненты использовали этот источник данных вместо того, который находится в диспетчере транзакций.

Как я решил эту проблему

Шаг 1: Хороший ночной сон

Шаг 2: больше кофеина

Шаг 3. Я отследил это, проследив код инициализации и определив, что создается JDBCTemplate, который был прикреплен к неправильному типу источника данных. Я удалил библиотеку, и вуаля, Spring пожаловался, что не может инициализировать bean-компоненты, указывающие на неправильный источник данных.

Я переопределил эти bean-компоненты источника данных с правильными классами, и все снова хорошо.

person pojo-guy    schedule 05.02.2015