I have written a small example program that is a highly-concurrent money (5 threads executing as many transfers as quickly as possible) transfer application (transferring amounts between different bank accounts).
Unfortunately, even though I am using optimistic locking, and have annotated my entity, the database deadlocks. The database is an MS SQL 2000 database, and it is a JSE app, thus everything is resource local.
I have looked and looked for what the problem might be, and would appreciate any help. The details:
Hibernate version:
EntityManager 3.3.2.GA
Annotations 3.3.1.GA
Core 3.2
Mapping documents:
Code:
<?xml version="1.0" encoding="UTF-8"?>
<persistence version="1.0" xmlns="http://java.sun.com/xml/ns/persistence">
<persistence-unit name="hibernatejpatest" transaction-type="RESOURCE_LOCAL">
<provider>org.hibernate.ejb.HibernatePersistence</provider>
<class>hibernatejpatest.Account</class>
<exclude-unlisted-classes>true</exclude-unlisted-classes>
<properties>
<property name="hibernate.dialect" value="org.hibernate.dialect.SQLServerDialect"/>
<property name="hibernate.connection.driver_class" value="com.microsoft.jdbc.sqlserver.SQLServerDriver"/>
<property name="hibernate.connection.username" value="hibernatejpatest"/>
<property name="hibernate.connection.password" value="hibernatejpatest"/>
<property name="hibernate.connection.url" value="jdbc:sqlserver://someserver;databaseName=HIBERNATEJPATEST;"/>
<property name="hibernate.max_fetch_depth" value="3"/>
<property name="hibernate.connection.autocommit" value="false"/>
<property name="hibernate.order_updates" value="true"/>
<property name="hibernate.connection.isolation" value="2"/>
<property name="hibernate.cache.use_second_level_cache" value="false"/>
<!-- Show SQL -->
<property name="hibernate.show_sql" value="false"/>
<!-- Java2DB properties, creates the tables -->
<property name="hibernate.hbm2ddl.auto" value="create"/>
</properties>
</persistence-unit>
</persistence>
The persistence happens in the doTransfer method of the TransferApp class.
This method is called by multiple threads as fast as possible, with random to and from accounts and random amounts. OptimisticLockExceptions are expected and hence the re-try logic.
Here is the main snippet:
Code:
public void doTransfer(String fromAct, String toAct, double amount) {
EntityManager em = null;
EntityTransaction tx = null;
boolean committed = false;
System.out.println("From " + fromAct + " to " + toAct + " : " + amount);
while (!committed) {
try {
// Thread-local entity manager pattern
em = ((Client) Thread.currentThread()).createEntityManager();
tx = em.getTransaction();
tx.begin();
Account fromAccount = em.find(Account.class, fromAct);
Account toAccount = em.find(Account.class, toAct);
if (fromAccount.getBalance() >= amount) {
fromAccount.debitCredit(-amount);
toAccount.debitCredit(amount);
}
// OptimisticLockException is not thrown regularly unless
// a flush is called before the commit.
em.flush();
tx.commit();
committed = true;
} catch (OptimisticLockException e) {
committed = false;
System.out.println("-----------------------");
System.out.println("OptimisticLockException: " + e.getMessage());
System.out.println("Caused by: " + e.getCause());
e.printStackTrace();
System.out.println("-----------------------");
} finally {
em.close();
}
}
Full stack trace of any exception that occurs:Hibernate logs the StaleObjectStateExceptions and then re-throws (I believe) the wrapped OptimisticLockException all as expected:
78 [Thread-8] ERROR org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [hibernatejpatest.Account#Acct 2]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:304)
at hibernatejpatest.TransferApp.doTransfer(TransferApp.java:37)
at hibernatejpatest.Client.run(Client.java:37)
javax.persistence.OptimisticLockException
at org.hibernate.ejb.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:650)
at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:607)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:307)
at hibernatejpatest.TransferApp.doTransfer(TransferApp.java:37)
at hibernatejpatest.Client.run(Client.java:37)
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [hibernatejpatest.Account#Acct 3]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:304)
... 2 more
However, the database deadlocks, because MS SQL reports it (and the app hangs), and selects a victim:
16 [Thread-3] ERROR org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
org.hibernate.exception.LockAcquisitionException: could not update: [hibernatejpatest.Account#Acct 2]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:82)
Exception in thread "Thread-3" javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not update: [hibernatejpatest.Account#Acct 2]
at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:637)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:307)
at hibernatejpatest.TransferApp.doTransfer(TransferApp.java:37)
at hibernatejpatest.Client.run(Client.java:37)
Caused by: org.hibernate.exception.LockAcquisitionException: could not update: [hibernatejpatest.Account#Acct 2]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:82)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2430)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2430)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:304)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:304)
... 2 more
Caused by: java.sql.SQLException: [Microsoft][SQLServer 2000 Driver for JDBC][SQLServer]Transaction (Process ID 57) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at com.microsoft.jdbc.base.BaseExceptions.createException(Unknown Source)
at com.microsoft.jdbc.base.BaseExceptions.getException(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processErrorToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processReplyToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRPCRequest.processReplyToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processReply(Unknown Source)
at com.microsoft.jdbc.sqlserver.SQLServerImplStatement.getNextResultType(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.commonTransitionToState(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.postImplExecute(Unknown Source)
at com.microsoft.jdbc.base.BasePreparedStatement.postImplExecute(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.commonExecute(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.executeUpdateInternal(Unknown Source)
at com.microsoft.jdbc.base.BasePreparedStatement.executeUpdate(Unknown Source)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412)
... 12 more
at hibernatejpatest.TransferApp.doTransfer(TransferApp.java:37)
at hibernatejpatest.Client.run(Client.java:37)
Caused by: java.sql.SQLException: [Microsoft][SQLServer 2000 Driver for JDBC][SQLServer]Transaction (Process ID 57) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at com.microsoft.jdbc.base.BaseExceptions.createException(Unknown Source)
at com.microsoft.jdbc.base.BaseExceptions.getException(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processErrorToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processReplyToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRPCRequest.processReplyToken(Unknown Source)
at com.microsoft.jdbc.sqlserver.tds.TDSRequest.processReply(Unknown Source)
at com.microsoft.jdbc.sqlserver.SQLServerImplStatement.getNextResultType(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.commonTransitionToState(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.postImplExecute(Unknown Source)
at com.microsoft.jdbc.base.BasePreparedStatement.postImplExecute(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.commonExecute(Unknown Source)
at com.microsoft.jdbc.base.BaseStatement.executeUpdateInternal(Unknown Source)
at com.microsoft.jdbc.base.BasePreparedStatement.executeUpdate(Unknown Source)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412)
... 12 more
Other Code Snippets Here is a snippet of the @Entity Account. The names of the accounts
ARE unique. The rest of the methods are just getters and setters:
Code:
@Entity
public class Account implements java.io.Serializable {
@Id
private String name;
private double balance;
@Version
private int version;
... Constructor + getters and setters
}
Full Source: The full source is available here:
http://www.harvsnews.com/hibernatejpatest/Name and version of the database you are using:Microsoft SQL Server 2000
The generated SQL (show_sql=true):There is tons of SQL, I will link to the full source, the problem is reproduce able with the application provided.
Debug level Hibernate log excerpt: BasicConfigurator.configure();
Logger.getRootLogger().setLevel(Level.ERROR);
Code:
Login
FAQ
Search
