Spring transactions in unit tests and annotation based configuration

Question

I have trouble getting transactions working in this unit test. The TransactionTest class contains all the necessary Spring configuration. It starts up, initializes the database and executes two Runnables in parallel (Inserter and Selector). From the logged output it is visible that the test executes, records are inserted and selected from the database in correct order, but there is no transaction isolation.

What I would expect to see in the log is something like:

2016-01-16 00:29:32,447 [main] DEBUG  TransactionTest - Starting test
2016-01-16 00:29:32,619 [pool-2-thread-2] DEBUG  Selector - Select 1 returned: 0
2016-01-16 00:29:33,121 [pool-2-thread-1] DEBUG  Inserter - inserting record: 1
2016-01-16 00:29:33,621 [pool-2-thread-2] DEBUG  Selector - Select 2 returned: 0
2016-01-16 00:29:34,151 [pool-2-thread-1] DEBUG  Inserter - inserting record: 2
2016-01-16 00:29:34,624 [pool-2-thread-2] DEBUG  Selector - Select 3 returned: 2
2016-01-16 00:29:34,624 [main] DEBUG  TransactionTest - Terminated

However, what I see is:

2016-01-16 00:29:32,447 [main] DEBUG  TransactionTest - Starting test
2016-01-16 00:29:32,619 [pool-2-thread-2] DEBUG  Selector - Select 1 returned: 0
2016-01-16 00:29:33,121 [pool-2-thread-1] DEBUG  Inserter - inserting record: 1
2016-01-16 00:29:33,621 [pool-2-thread-2] DEBUG  Selector - Select 2 returned: 1
2016-01-16 00:29:34,151 [pool-2-thread-1] DEBUG  Inserter - inserting record: 2
2016-01-16 00:29:34,624 [pool-2-thread-2] DEBUG  Selector - Select 3 returned: 2
2016-01-16 00:29:34,624 [main] DEBUG  TransactionTest - Terminated

Please consider the test code below. In TransactionTest.java there are a few annotations commented out ahead of the class body itself. When I include these annotations, I can see from the log that Spring executes the entire test itself in a separate transaction. However my aim is to get it to execute the method Inserter.insertSeveralRecords() in a separate transaction. There are sadly no indications in the log that Spring even sees the @Transactional annotation there.

I have tried to add the @EnableTransactionManagement annotation also to the TransactionTest class itself, instead of the Configuration section, but it makes no difference.

TransactionTest.java

package program.test.db.transaction;

import java.util.concurrent.Executors;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

import org.apache.commons.dbcp2.BasicDataSource;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.flywaydb.core.Flyway;
import org.flywaydb.test.annotation.FlywayTest;
import org.flywaydb.test.junit.FlywayTestExecutionListener;
import org.jooq.DSLContext;
import org.jooq.SQLDialect;
import org.jooq.impl.DataSourceConnectionProvider;
import org.jooq.impl.DefaultConfiguration;
import org.jooq.impl.DefaultDSLContext;
import org.jooq.impl.DefaultExecuteListenerProvider;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.PropertySource;
import org.springframework.core.env.Environment;
import org.springframework.jdbc.datasource.DataSourceTransactionManager;
import org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.TestExecutionListeners;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;
import org.springframework.test.context.support.AnnotationConfigContextLoader;
import org.springframework.test.context.support.DependencyInjectionTestExecutionListener;
import org.springframework.test.context.transaction.TransactionConfiguration;
import org.springframework.test.context.transaction.TransactionalTestExecutionListener;
import org.springframework.transaction.annotation.EnableTransactionManagement;
import org.springframework.transaction.annotation.Transactional;

import program.db.JooqExceptionTranslator;
import static org.junit.Assert.assertTrue;
import static program.db.Tables.SYSTEM_LOG;

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(loader=AnnotationConfigContextLoader.class)
@TestExecutionListeners({DependencyInjectionTestExecutionListener.class, FlywayTestExecutionListener.class})//, TransactionalTestExecutionListener.class})
//@Transactional
//@TransactionConfiguration(transactionManager="transactionManager", defaultRollback=false)
public class TransactionTest {

    private static Logger log = LogManager.getLogger(TransactionTest.class);

    @Configuration
    @PropertySource("classpath:program.properties")
    @EnableTransactionManagement
    static class ContextConfiguration {
        @Autowired
        private Environment env;
        @Bean
        public Flyway flyway(){
            Flyway flyway = new Flyway();
            flyway.setDataSource(dataSource());
            flyway.setSchemas("program_x");
            flyway.setLocations("db/migration");
            return flyway;
        }
        @Bean
        public BasicDataSource dataSource() {
            BasicDataSource result = new BasicDataSource();
            result.setDriverClassName(env.getRequiredProperty("program.database.driver"));
            result.setUrl(env.getRequiredProperty("program.database.url"));
            result.setUsername(env.getRequiredProperty("program.database.username"));
            result.setPassword(env.getRequiredProperty("program.database.password"));
            return result;
        }
        @Bean
        public DataSourceTransactionManager transactionManager() {
            return new DataSourceTransactionManager(dataSource());
        }
        @Bean
        public TransactionAwareDataSourceProxy transactionAwareDataSource(){
            return new TransactionAwareDataSourceProxy(dataSource());
        }
        @Bean
        public DataSourceConnectionProvider connectionProvider(){
            return new DataSourceConnectionProvider(transactionAwareDataSource());
        }
        @Bean
        public JooqExceptionTranslator jooqExceptionTranslator(){
            return new JooqExceptionTranslator();
        }
        @Bean
        public DefaultConfiguration config(){
            DefaultConfiguration result = new DefaultConfiguration();
            result.set(connectionProvider());
            result.set(new DefaultExecuteListenerProvider(jooqExceptionTranslator()));
            result.set(SQLDialect.POSTGRES);
            return result;
        }
        @Bean
        public DefaultDSLContext db(){
            return new DefaultDSLContext(config());
        }
        @Bean
        public Inserter inserter(){
            return new Inserter();
        }
        @Bean
        public Selector selector(){
            return new Selector();
        }
    }

    @Autowired
    private DSLContext db;
    @Autowired
    private Selector selector;
    @Autowired
    private Inserter inserter;

    private final ThreadPoolExecutor THREAD_POOL = (ThreadPoolExecutor) Executors.newCachedThreadPool();

    @Test
    @FlywayTest
    public void runTest() throws InterruptedException {
        log.debug("Starting test");
        int count0 = db.selectCount().from(SYSTEM_LOG).fetchOne(0, int.class);
        assertTrue(count0 == 0);

        THREAD_POOL.execute(inserter);
        THREAD_POOL.execute(selector);

        THREAD_POOL.shutdown();
        THREAD_POOL.awaitTermination(5, TimeUnit.SECONDS);
        log.debug("Terminated");
    }

}

Selector.java

package program.test.db.transaction;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.jooq.DSLContext;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;

import static program.db.Tables.SYSTEM_LOG;

@Component
public class Selector implements Runnable {

    private static Logger log = LogManager.getLogger(Selector.class);

    @Autowired
    private DSLContext db;

    @Override
    public void run() {
        try {
            int count1 = db.selectCount().from(SYSTEM_LOG).fetchOne(0, int.class);
            log.debug("Select 1 returned: " + count1);
            Thread.sleep(1000);
            int count2 = db.selectCount().from(SYSTEM_LOG).fetchOne(0, int.class);
            log.debug("Select 2 returned: " + count2);
            Thread.sleep(1000);
            int count3 = db.selectCount().from(SYSTEM_LOG).fetchOne(0, int.class);
            log.debug("Select 3 returned: " + count3);
        } catch (InterruptedException e) {
            log.error("Selects were interrupted", e);
        }
    }

}

Inserter.java

package program.test.db.transaction;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.joda.time.DateTime;
import org.jooq.DSLContext;
import org.jooq.InsertQuery;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;
import org.springframework.transaction.annotation.Transactional;

import program.db.tables.records.SystemLogRecord;
import static org.junit.Assert.assertTrue;
import static program.db.Tables.SYSTEM_LOG;

@Component
public class Inserter implements Runnable {

    private static Logger log = LogManager.getLogger(Inserter.class);

    @Autowired
    private DSLContext db;

    @Override
    public void run() {
        insertSeveralRecords();
    }

    @Transactional
    private void insertSeveralRecords(){
        try {
            Thread.sleep(500);
            insertRecord(1);
            Thread.sleep(1000);
            insertRecord(2);
        } catch (InterruptedException e) {
            log.error("Inserts were interrupted", e);
        }
    }

    private void insertRecord(int i){
        log.debug("inserting record: " + i);
        InsertQuery insertQuery = db.insertQuery(SYSTEM_LOG);
        insertQuery.addValue(SYSTEM_LOG.SERVICE, "Service " + i);
        insertQuery.addValue(SYSTEM_LOG.MESSAGE, "Message " + i);
        insertQuery.addValue(SYSTEM_LOG.SYS_INSERT_TIME, DateTime.now());
        int result = insertQuery.execute();
        assertTrue(result == 1);
    }
}

I am probably missing something rather basic here - what am I doing wrong?

Tarmo · Accepted Answer

The problem in the question was caused by:

The method Inserter.insertSeveralRecords() which was annotated with @Transactional was a private method.
- Only public methods should be annotated with @Transactional
Making the method Inserter.insertSeveralRecords() public still did not start up the transaction. That is because the method is called internally from the method Inserter.run() (as opposed to externally from some other class).
- When adding support for @Transactional, Spring uses proxies to add code before and after the invocation of the annotated method. In case of classes which implement an interface, these will be dynamic proxies. This means that only external method calls that come in through the proxy will be intercepted
- The class Inserter implements the Runnable interface - thus @Transactional is only picked up if the annotated method is called directly from outside
Moving the @Transactional annotation to the method Inserter.run() fixes THAT class but is still not enough to successfully run the test. When starting up, it now throw an error:

"Could not autowire field: TransactionTest.inserter; NoSuchBeanDefinitionException: No qualifying bean of type [program.test.db.transaction.Inserter] found for dependency"

This is caused by the fact that TransactionTest.inserter field is of type Inserter and not Runnable, whereas the @Transactional annotation is added to the method of the Runnable interface. I could not find any reference as to why this works like this, but changing the @Autowired field type from Inserter to Runnable allows Spring to start up correctly and use transactions when the executer calls Inserter.run(). (Probably because the dynamic proxy is created on the interface also?)

Here are the relevant code sections for the 3 changes described above:

Inserter.java

@Override
@Transactional
public void run() {
    insertSeveralRecords();
}

private void insertSeveralRecords(){
    try {
        Thread.sleep(500);
        insertRecord(1);
        Thread.sleep(1000);
        insertRecord(2);
    } catch (InterruptedException e) {
        log.error("Inserts were interrupted", e);
    }
}

TransactionTest.java

@Autowired
private DSLContext db;
@Autowired
private Runnable selector;
@Autowired
private Runnable inserter;

private final ThreadPoolExecutor THREAD_POOL = (ThreadPoolExecutor) Executors.newCachedThreadPool();

@Test
@FlywayTest
public void runTest() throws InterruptedException {
    log.debug("Starting test");
    int count0 = db.selectCount().from(SYSTEM_LOG).fetchOne(0, int.class);
    assertTrue(count0 == 0);

    THREAD_POOL.execute(inserter);
    THREAD_POOL.execute(selector);

    THREAD_POOL.shutdown();
    THREAD_POOL.awaitTermination(5, TimeUnit.SECONDS);
    log.debug("Terminated");
}

The test now executes correctly with transactional isolation, producing the log output desired in the original question.

Used resources:

Spring transactions in unit tests and annotation based configuration

Answers (1)

Related Questions