Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

JUnit testing a call to @transactional @Async method causes Lock wait timeout exceeded

I'm trying to test a service method that runs asynchronously (@Async).

Here is the async method :

@Async
@Transactional(propagation=Propagation.SUPPORTS, isolation = Isolation.READ_UNCOMMITTED)
public Future<UserPrefs> checkLanguagePreference(long id) {

    UserPrefs prefs = prefsDao.retrieveUserPreferences(id);
    if(prefs == null || !StringUtils.hasLength(prefs.getLanguage())) {
        //Save a new sms-command object
        SmsBean command = SmsHelper.buildSmsCommand();
        if(! smsDao.checkSameCommandExists(id, command)) {

            smsDao.saveSms(id, new SmsBean[] {command}); //Will wait until Lock wait timeout
        }
    }
    return new AsyncResult<UserPrefs>(prefs);
}

And here is The test method calling the async one :

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(location = "...")
@TransactionConfiguration(transactionManager = "txManager", defaultRollback = false)
@Transactional(isolation = Isolation.READ_UNCOMMITTED)
@TestExecutionListeners( {  DependencyInjectionTestExecutionListener.class,
  DirtiesContextTestExecutionListener.class,
  TransactionalTestExecutionListener.class })
public class MessagingServiceTest {

   @Before
   public void setUp() {        
     //Avant tout mettre tout les sms en lu 
     smsDao.deleteAllSms(1);
     sessionFactory.getCurrentSession().flush();

     //On vérifie bien qu'il n y a plus de sms
     List<SmsBean> list = smsDao.getNewSmsList(1);
     assertEquals(0,list.size());
   }

   @Test
   public void checkLanguagePreferenceTest() throws InterruptedException, ExecutionException {
     User user = (User) sessionFactory.getCurrentSession().load(User.class, new Long(1));//idUser = 1
     // We explicitly blank the preference from db
     prefsDao.saveLanguagePref(new UserPrefs("",user));

     Future<UserPrefs> prefs =  messagingService.checkLanguagePreference(user.getId()); 
     System.out.println("wait completion of async task");           
     prefs.get();
     System.out.println("Async task has finished");
   }
}

When prefs.get() is executed, i have this error:

Caused by: org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [insert into SmsBean (destination, message, origin, sens, status, USER_ID) values (?, ?, ?, ?, ?, ?)]; SQL state [41000]; error code [1205]; could not insert:

Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1075)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3562)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3494)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1960)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2114)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2696)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2105)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2398)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2316)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2301)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:101)
    at org.hibernate.id.IdentityGenerator$GetGeneratedKeysDelegate.executeAndExtract(IdentityGenerator.java:94)
    at org.hibernate.id.insert.AbstractReturningDelegate.performInsert(AbstractReturningDelegate.java:57)
    ... 39 more

This happens because smsDao.deleteAllSms in the setup Method is holding a lock on the sms table.

How can I correctly avoid this lock timeout and be able to run my test successfully?

Thanks for your help.

FYI, here is some console output :

DEBUG - Adding transactional method 'checkLanguagePreferenceTest' with attribute: PROPAGATION_REQUIRED,ISOLATION_READ_COMMITTED; ''
DEBUG - Explicit transaction definition [PROPAGATION_REQUIRED,ISOLATION_READ_COMMITTED; ''] found for test context [[TestContext@b76fa testClass = MessagingServiceTest, locations = array['file:src/main/resources/myapp-context.xml', 'file:src/main/resources/myapp-data.xml', 'file:src/main/resources/myapp-services.xml'], testInstance = fr.myapp.service.MessagingServiceTest@b01d43, testMethod = checkLanguagePreferenceTest@MessagingServiceTest, testException = [null]]]
DEBUG - Retrieved @TransactionConfiguration [@org.springframework.test.context.transaction.Tran sactionConfiguration(defaultRollback=false, transactionManager=txManager)] for test class [class fr.myapp.service.MessagingServiceTest]
DEBUG - Retrieved TransactionConfigurationAttributes [[TransactionConfigurationAttributes@5f7d3f transactionManagerName = 'txManager', defaultRollback = false]] for class [class fr.myapp.service.MessagingServiceTest]
DEBUG - Returning cached instance of singleton bean 'txManager'
DEBUG - Creating new transaction with name [checkLanguagePreferenceTest]: PROPAGATION_REQUIRED,ISOLATION_READ_COMMITTED; ''
DEBUG - Opened new Session [org.hibernate.impl.SessionImpl@666a53] for Hibernate transaction
DEBUG - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@666a53]
DEBUG - Changing isolation level of JDBC Connection [org.apache.commons.dbcp.PoolableConnection@1bde3d2] to 2
DEBUG - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@1bde3d2]
DEBUG - No method-level @Rollback override: using default rollback [false] for test context [[TestContext@b76fa testClass = MessagingServiceTest, locations = array['file:src/main/resources/myapp-context.xml', 'file:src/main/resources/myapp-data.xml', 'file:src/main/resources/myapp-services.xml'], testInstance = fr.myapp.service.MessagingServiceTest@b01d43, testMethod = checkLanguagePreferenceTest@MessagingServiceTest, testException = [null]]]
INFO - Began transaction (1): transaction manager [org.springframework.orm.hibernate3.HibernateTransa ctionManager@17753a8]; rollback [false]
Hibernate: delete from SmsBean where USER_ID=?
Hibernate: select user0_.id as id3_1_, user0_.email as email3_1_, user0_.login as login3_1_, user0_.passwd as passwd3_1_, smsbeans1_.USER_ID as USER7_3_3_, smsbeans1_.id as id3_, smsbeans1_.id as id0_0_, smsbeans1_.destination as destinat2_0_0_, smsbeans1_.message as message0_0_, smsbeans1_.origin as origin0_0_, smsbeans1_.sens as sens0_0_, smsbeans1_.status as status0_0_, smsbeans1_.USER_ID as USER7_0_0_ from User user0_ left outer join SmsBean smsbeans1_ on user0_.id=smsbeans1_.USER_ID where user0_.id=?
Hibernate: select user0_.id as id3_, user0_.email as email3_, user0_.login as login3_, user0_.passwd as passwd3_ from User user0_ where user0_.login=?
Hibernate: select userprefs0_.id as id2_, userprefs0_.language as language2_, userprefs0_.USER_ID as USER3_2_ from user_prefs userprefs0_ where userprefs0_.USER_ID=?
wait completion of async task
DEBUG - Returning cached instance of singleton bean 'txManager'
INFO - Ener dans checkLanguagePreference(1)
DEBUG - Opening Hibernate Session
DEBUG - Registering Spring transaction synchronization for new Hibernate Session
Hibernate: select userprefs0_.id as id2_, userprefs0_.language as language2_, userprefs0_.USER_ID as USER3_2_ from user_prefs userprefs0_ where userprefs0_.USER_ID=?
Hibernate: select user0_.id as id3_1_, user0_.email as email3_1_, user0_.login as login3_1_, user0_.passwd as passwd3_1_, smsbeans1_.USER_ID as USER7_3_3_, smsbeans1_.id as id3_, smsbeans1_.id as id0_0_, smsbeans1_.destination as destinat2_0_0_, smsbeans1_.message as message0_0_, smsbeans1_.origin as origin0_0_, smsbeans1_.sens as sens0_0_, smsbeans1_.status as status0_0_, smsbeans1_.USER_ID as USER7_0_0_ from User user0_ left outer join SmsBean smsbeans1_ on user0_.id=smsbeans1_.USER_ID where user0_.id=?
INFO - Checking if same sms command already exist
Hibernate: select * from smsbean S where S.USER_ID=? and S.status=? and S.message=?
DEBUG - Flushing Hibernate Session on transaction synchronization

//Deadlock here :
Hibernate: insert into SmsBean (destination, message, origin, sens, status, USER_ID) values (?, ?, ?, ?, ?, ?)
DEBUG - Closing Hibernate Session
58799 [SimpleAsyncTaskExecutor-1] WARN org.hibernate.util.JDBCExceptionReporter - SQL Error: 1205, SQLState: 41000
58799 [SimpleAsyncTaskExecutor-1] ERROR org.hibernate.util.JDBCExceptionReporter - Lock wait timeout exceeded; try restarting transaction

Resolved, but FYI, I've created before, a thread on MySQL's forum about why I was getting this deadlock from the DBMS point of view. Here is the link (Well explained also):

http://forums.mysql.com/read.php?97,409237,409237#msg-409237

like image 857
redochka Avatar asked Feb 25 '11 09:02

redochka


2 Answers

Since your test is declared as @Transactional, you have one big transaction that spreads over execution of setUp method and your test method. This transaction deadlocks with another transaction started in async action (async action waits for release of locks acquired by main transaction, main transaction waits for completion of async action).

You can solve it by breaking main transaction into several separate transactions:

@Before
@Transactional // separate transaction for setUp
public void setUp() {        
    //Avant tout mettre tout les sms en lu 
    smsDao.deleteAllSms(1);
    sessionFactory.getCurrentSession().flush();

    //On vérifie bien qu'il n y a plus de sms
    List<SmsBean> list = smsDao.getNewSmsList(1);
    assertEquals(0,list.size());
}

@Test
@Transactional(propagation = NEVER) // Disable main transaction
public void checkLanguagePreferenceTest() throws InterruptedException, ExecutionException {

    // Programmatic transaction for test preparation
    User user = tx.execute(new TransactionCallback<User>() {
        public User doInTransaction(TransactionStatus status) {
            User user = (User) sessionFactory.getCurrentSession().load(User.class, new Long(1));//idUser = 1
            // We explicitly blank the preference from db
            prefsDao.saveLanguagePref(new UserPrefs("",user));    
            return user;
        }
    });

    Future<UserPrefs> prefs = messagingService.checkLanguagePreference(user.getId()); 
    System.out.println("wait completion of async task");            
    prefs.get();
    System.out.println("Async task has finished");
}

private TransactionTemplate tx;

@Autowired
public void setPtm(PlatformTransactionManager ptm) {
    tx = new TransactionTemplate(ptm);
}
like image 113
axtavt Avatar answered Oct 15 '22 06:10

axtavt


If you can tolerate synchronous execution for your tests you can also configure a testing context that uses a SyncTaskExecutor instead of one its threaded peers.

In other words:

<bean id="myExecutor" class="org.springframework.core.task.SyncTaskExecutor"/>

instead of:

<task:executor id="myExecutor" pool-size="5"/>

Then everything runs in the same thread and you don't have to deal with database locking issues caused by competing transactions.

like image 45
JerryF Avatar answered Oct 15 '22 04:10

JerryF