Spring JdbcTemplate closes connection after update and Hikari performs a rollback before JpaTransactionManager commit

Affects: Spring Boot 3.3.5

I asked on stackoverflow and also found similar questions there:

https://stackoverflow.com/questions/78022351/spring-boot-jpa-transaction-is-committing-but-record-is-not-getting-inserted https://stackoverflow.com/questions/78863344/frequent-rollback-on-connection-close-in-spring-boot-with-hikaricp-and-mariadb

The problem:

Simple table:

CREATE TABLE table_master
(
    id       INTEGER NOT NULL,
    name     VARCHAR(200),
    CONSTRAINT t_master_pk PRIMARY KEY (id)
);

Test:

@SpringBootTest
@TestMethodOrder(MethodOrderer.OrderAnnotation.class)
@Slf4j
class JdbcTest {

    private DataSource fbDataSource;

    @Autowired
    private PlatformTransactionManager transactionManager;

    @BeforeEach
    public void setUp() {
        HikariConfig config = new HikariConfig();
        config.setJdbcUrl("jdbc:firebirdsql://localhost:3055//opt/fb/db/DBGDB");
        config.setUsername("user");
        config.setPassword("passwd");
        config.setAutoCommit(false);
        fbDataSource = new HikariDataSource(config);
    }

    private static final String insertQuery = "INSERT INTO table_master(id, name) VALUES(?, ?)";
    private static final String cntQuery = "SELECT COUNT(*) FROM table_master";

    @Test
    public void testFbLoad() throws SQLException {
        JdbcTemplate fbJdbcTemplate = new JdbcTemplate(fbDataSource);
        DefaultTransactionDefinition def = new DefaultTransactionDefinition();
        def.setPropagationBehavior(DefaultTransactionDefinition.PROPAGATION_REQUIRES_NEW);
        def.setIsolationLevel(DefaultTransactionDefinition.ISOLATION_READ_COMMITTED);
        TransactionStatus status = transactionManager.getTransaction(def);

        if (fbJdbcTemplate.update(insertQuery, 1, "Row") == 0) {
            throw new RuntimeException("Cannot insert row");
        }
        transactionManager.commit(status);

        Integer cnt = fbJdbcTemplate.queryForObject(cntQuery, Integer.class);
        log.info("Rows in table_master: {}", cnt);
    }

Log:

2024-11-30T04:10:31.534+02:00 DEBUG 15966 --- [    Test worker] o.h.e.t.internal.TransactionImpl         : On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2024-11-30T04:10:31.535+02:00 DEBUG 15966 --- [    Test worker] o.h.e.t.internal.TransactionImpl         : begin
2024-11-30T04:10:31.536+02:00 DEBUG 15966 --- [    Test worker] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@ea34dee]
2024-11-30T04:10:31.536+02:00 DEBUG 15966 --- [    Test worker] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL update
2024-11-30T04:10:31.537+02:00 DEBUG 15966 --- [    Test worker] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [INSERT INTO table_master(id, name) VALUES(?, ?)]
2024-11-30T04:10:31.537+02:00 DEBUG 15966 --- [    Test worker] o.s.jdbc.datasource.DataSourceUtils      : Fetching JDBC Connection from DataSource
2024-11-30T04:10:31.544+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.553+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.553+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.567+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.568+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.570+02:00 DEBUG 15966 --- [    Test worker] o.f.jaybird.xca.FBManagedConnection      : End called: Xid[413118226]
2024-11-30T04:10:31.573+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.573+02:00 DEBUG 15966 --- [    Test worker] o.f.gds.ng.wire.AbstractWireOperations   : readStatusVector arg:isc_arg_gds int: 0
2024-11-30T04:10:31.574+02:00 DEBUG 15966 --- [    Test worker] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Executed rollback on connection org.firebirdsql.jdbc.FBConnection@394e21b9 due to dirty commit state on close().
2024-11-30T04:10:31.574+02:00 DEBUG 15966 --- [    Test worker] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2024-11-30T04:10:31.574+02:00 DEBUG 15966 --- [    Test worker] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(865867007<open>)]
2024-11-30T04:10:31.574+02:00 DEBUG 15966 --- [    Test worker] o.h.e.t.internal.TransactionImpl         : committing
2024-11-30T04:10:31.575+02:00 DEBUG 15966 --- [    Test worker] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(865867007<open>)] after transaction

Problem:

No data inserted due to:

2024-11-30T04:10:31.574+02:00 DEBUG 15966 --- [    Test worker] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Executed rollback on connection org.firebirdsql.jdbc.FBConnection@394e21b9 due to dirty commit state on close().

Reason:

JdbcTemplate closes connection in the update method. Hikari rolls the transaction back due to the connection' dirty state then. Then JpaTransactionManager tries to commit it but it was already rolled back. So, the example from the Spring docs is not working.

Stack:

doCloseConnection:406, DataSourceUtils (org.springframework.jdbc.datasource)
doReleaseConnection:393, DataSourceUtils (org.springframework.jdbc.datasource)
releaseConnection:360, DataSourceUtils (org.springframework.jdbc.datasource)
beforeCompletion:525, DataSourceUtils$ConnectionSynchronization (org.springframework.jdbc.datasource)
triggerBeforeCompletion:108, TransactionSynchronizationUtils (org.springframework.transaction.support)
triggerBeforeCompletion:996, AbstractPlatformTransactionManager (org.springframework.transaction.support)
processCommit:776, AbstractPlatformTransactionManager (org.springframework.transaction.support)
commit:758, AbstractPlatformTransactionManager (org.springframework.transaction.support)
testFbLoad:105, JdbcTest (com.freewayfleet.dbreplicator)

Comment From: quaff

Can not be reproduced by H2.

import static org.assertj.core.api.Assertions.assertThat;

import java.sql.SQLException;

import javax.sql.DataSource;

import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.jdbc.core.JdbcTemplate;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.jdbc.Sql;
import org.springframework.transaction.PlatformTransactionManager;
import org.springframework.transaction.TransactionStatus;
import org.springframework.transaction.support.DefaultTransactionDefinition;

@org.springframework.boot.test.autoconfigure.jdbc.JdbcTest
@ContextConfiguration(classes = JdbcTest.class)
@Sql(statements = "CREATE TABLE table_master(id INTEGER NOT NULL,name VARCHAR(200),CONSTRAINT t_master_pk PRIMARY KEY (id))")
class JdbcTest {

    @Autowired
    private DataSource dataSource;

    @Autowired
    private PlatformTransactionManager transactionManager;

    private static final String insertQuery = "INSERT INTO table_master(id, name) VALUES(?, ?)";
    private static final String cntQuery = "SELECT COUNT(*) FROM table_master";

    @Test
    public void test() throws SQLException {
        JdbcTemplate fbJdbcTemplate = new JdbcTemplate(dataSource);
        DefaultTransactionDefinition def = new DefaultTransactionDefinition();
        def.setPropagationBehavior(DefaultTransactionDefinition.PROPAGATION_REQUIRES_NEW);
        def.setIsolationLevel(DefaultTransactionDefinition.ISOLATION_READ_COMMITTED);
        TransactionStatus status = transactionManager.getTransaction(def);

        if (fbJdbcTemplate.update(insertQuery, 1, "Row") == 0) {
            throw new RuntimeException("Cannot insert row");
        }
        transactionManager.commit(status);

        Integer cnt = fbJdbcTemplate.queryForObject(cntQuery, Integer.class);
        assertThat(cnt).isEqualTo(1);
    }
}

Comment From: BbIKTOP

Looks like it fails with custom datasource

Comment From: mdeinum

As mentioned in the stackoverflow issue, the datasource isnt even known to Spring and the PlatformTransactionManager in use is tied to another DataSource so won't manage the transactions. As the auto-commit is set to false you are basically running without a transaction, no transaction no persisting.

Comment From: snicoll

@BbIKTOP please do not cross post. Especially since you've accepted the StackOverflow answer which left the duplicate thread you've created here open for no reason.