SourceForge.net Logo
Main Overview Wiki Issues Forum Build Fisheye
Issue Details (XML | Word | Printable)

Key: CMP-542
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Blocker Blocker
Assignee: Shay Banon
Reporter: Lukasz Frankowski
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
Compass

Transactions in non managed environment are not managed properly

Created: 15/Feb/08 09:07 AM   Updated: 19/Feb/08 03:42 PM
Component/s: Compass::Core
Affects Version/s: 1.1.1, 1.2 M1, 1.2 M2, 1.2 M3, 1.2 RC1, 1.2 GA, 1.2.1, 2.0 M1
Fix Version/s: 1.2.2, 2.0.0 M2

Environment: Ubuntu linux, Hibernate 3.2.5.ga, MySQL 5.0.22


 Description  « Hide
We use Compass in non-managed environment, where connection is got from LocalCompassBean and is wrapped by TransactionAwareDataSourceProxy. We encountered some critical problems in our application, resulting in neccessity of restarting the server and mysql daemon in our deployment environment. The problem is that Compass doesn't rollback transaction is some cases and the tables are locked after exception.

After some digging I think I found the bug in LuceneSearchEngine.commit():

public void commit(boolean onePhase) throws SearchEngineException {
verifyWithinTransaction();
try {
if (transaction != null) { transaction.commit(onePhase); eventManager.afterCommit(onePhase); }
} finally { transaction = null; transactionState = COMMIT; }
}

Where the exception was:
org.compass.gps.device.hibernate.HibernateGpsDeviceException: {hibernate}: Failed while updating [RCP/3825]; nested exception is org.compass.core.engine.SearchEngineException: Failed in second phase commit from sub-index [basemodel]; nested exception is org.apache.lucene.store.jdbc.JdbcStoreException: Failed to execute sql [insert into index_basemodel (name_, value_, size_, lf_, deleted_) values ( ?, ?, ?, current_timestamp, ? )]; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
org.compass.core.engine.SearchEngineException: Failed in second phase commit from sub-index [basemodel]; nested exception is org.apache.lucene.store.jdbc.JdbcStoreException: Failed to execute sql [insert into index_basemodel (name_, value_, size_, lf_, deleted_) values ( ?, ?, ?, current_timestamp, ? )]; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
org.apache.lucene.store.jdbc.JdbcStoreException: Failed to execute sql [insert into index_basemodel (name_, value_, size_, lf_, deleted_) values ( ?, ?, ?, current_timestamp, ? )]; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
at com.mysql.jdbc.Util.getInstance(Util.java:381)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1046)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:957)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3376)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3308)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1837)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1961)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2543)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1737)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2022)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1940)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1925)
at org.apache.lucene.store.jdbc.support.JdbcTemplate.executeUpdate(JdbcTemplate.java:159)
at org.apache.lucene.store.jdbc.index.AbstractJdbcIndexOutput.close(AbstractJdbcIndexOutput.java:47)
at org.apache.lucene.index.SegmentInfos.write(SegmentInfos.java:91)
at org.apache.lucene.index.TransIndex$2.doBody(TransIndex.java:352)
at org.apache.lucene.store.Lock$With.run(Lock.java:99)
at org.apache.lucene.index.TransIndex.secondPhase(TransIndex.java:339)
at org.compass.core.lucene.engine.transaction.ReadCommittedTransaction$TransIndexManager.secondPhase(ReadCommittedTransaction.java:168)
at org.compass.core.lucene.engine.transaction.ReadCommittedTransaction.doCommit(ReadCommittedTransaction.java:269)
at org.compass.core.lucene.engine.transaction.AbstractTransaction.commit(AbstractTransaction.java:85)
at org.compass.core.lucene.engine.LuceneSearchEngine.commit(LuceneSearchEngine.java:244)
at org.compass.core.transaction.LocalTransaction.doCommit(LocalTransaction.java:93)
at org.compass.core.transaction.AbstractTransaction.commit(AbstractTransaction.java:38)
...

And further:
14:45:07,552 ERROR org.compass.core.CompassTemplate - Failed to rollback transaction, ignoring
org.compass.core.engine.SearchEngineException: Search engine transaction not successfully started or already committed/rolledback
at org.compass.core.lucene.engine.LuceneSearchEngine.verifyWithinTransaction(LuceneSearchEngine.java:223)
at org.compass.core.lucene.engine.LuceneSearchEngine.rollback(LuceneSearchEngine.java:254)
at org.compass.core.transaction.LocalTransaction.doRollback(LocalTransaction.java:119)
at org.compass.core.transaction.AbstractTransaction.rollback(AbstractTransaction.java:46)
...

As we can see, the exception in transaction.commit(onePhase) results with the method return, having set before the state to COMMIT, but when commit wasn't performed properly, and more - when the afterCommit() closing connection wasn't invoked. Moreover, the rollback() is performed after exception has been thrown, but it thinks (because transactionState=COMMIT) that it's not required to do the rollback. In result after such flow we have a locked table in MySQL.

We use compass 1.1.1 for now, but I indicated the newest release in this bug, because as I see these codes were not changed since.



 All   Comments   Change History      Sort Order: Ascending order - Click to sort in descending order
Shay Banon added a comment - 15/Feb/08 02:38 PM
I have fixed it so the rollback called after a failed commit will actually process. I am still not sure about a certain aspect, but for now, can you give it a go and see if it is better? I have fixed it on 1.2 branch, here is a link to the nightly build: http://build.compass-project.org/browse/CMP12-NIGHTLY-22/artifact

Lukasz Frankowski added a comment - 18/Feb/08 03:03 AM
We will check this release in one-two days. But, what aspect exactly are you not sure?

Shay Banon added a comment - 18/Feb/08 05:00 AM
I was not sure exactly on how to handle a certain failure scenario in the rollback, and should the afterRollback be called. I have updated it to be called every time, even if the rollback failed. When you give it a try, get the latest 1.2 nightly.

Stachu Klunder added a comment - 19/Feb/08 01:59 PM
Hi.

I've simulated runtime exception when transation is commited and with your changes Shay transaction is successfuly rolled back, what in our unmanaged enviroment means that underlaying connection is properly closed.

So I expect no more hangging connections after runtime exception when commit fails (what was caused by transactions deadlock in our case).

Also in my opinion the change in code is OK - I don't think that transaction should be marked as commited always (in finally block) but only if it was really successfuly commited in implementation layer.


Shay Banon added a comment - 19/Feb/08 03:42 PM
Great. I will close this issue then.