I am having a lot of problems getting Hibernate to properly lock. I have read through all of the documentation on this, and a lot of posts. However, I cannot figure out what is going on in my code. I have simplified the test down to a very basic table, and series of calls.

I am running against DB2 8.1. I am testing with two threads. Essentially I have a very simple table (with three columns: ID (NUMERIC), processNum (NUMERIC), Value(VARCHAR 255)) that maps to an object with just those three attributes.

The two threads process the same set of code. They get an object that matches a specific value for processNum using session.find. Start a transaction. Lock using session.lock(). Change the value. Call session.save(). And commit the tranaction.

Thread 1 calls
session.find

Thread 2 calls
session.find

Thread 1 calls
-->session.beginTransaction()-->session.lock()

Thread 2 calls
-->session.beginTransaction()-->session.lock()--> BLOCKS

At this point everything seems to work fine

Thread 1 calls
obj.setValue("some value");
session.save(obj);
session.commitTransaction();

At this point Thread 1 will pause, then throw a DEADLOCK exception.

We have run the exact same sequence against the same table directly using the CLI (command line interface). This gets the proper behavior. The select for update on the second process locks, until the update on the first process completes.

The isolation level has been set to serializable.

We can't seem to figure out what is going on. Something must be happening inside Hibernate that we don't understand, because the DB and tables perform properly when tested through the CLI.

The Code, exception, etc.. follow.




Hibernate version:2.x

Mapping documents:

<?xml version="1.0"?>

<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">

<hibernate-mapping>

<class name="org.jbpm.model.execution.impl.ProcessLockImpl" table="JBPM_PROCESS_LOCK">

<id name="id" type="long" unsaved-value="null">
<generator class="org.jbpm.persistence.hibernate.ConfigurableIdGenerator" />
</id>

<property name="processId" type="long" column="processid" />
<property name="value" type="string" column="value" />

</class>

</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():

[code]
String findLocksByProcess = "select p from p in class org.jbpm.model.execution.impl.ProcessLockImpl where p.processId = ?";

List locks = null;
Long pId= new Long(439091217);
ProcessLock pl; // My test class that maps to the table
locks = hs.getHibernateSession().find(findLocksByProcess, pId, Hibernate.LONG);
pl = (ProcessLock)locks.get(0);

hs.beginTransaction();
hs.lock(pl); // Thread 2 properly blocks here
pl.setValue("asdf");
hs.save(pl);
hs.flush();
hs.commitTransaction(); // Thread 1 throws deadlock exception here

[code]

Full stack trace of any exception that occurs:
[code]
COM.ibm.db2.jdbc.DB2Exception: [IBM][CLI Driver][DB2/LINUX] SQL0911N The current transaction has been rolled back because of a deadlock or timeout. Reason code "2". SQLSTATE=40001

at COM.ibm.db2.jdbc.net.SQLExceptionGenerator.throw_SQLException(SQLExceptionGenerator.java:254)
at COM.ibm.db2.jdbc.net.SQLExceptionGenerator.check_return_code(SQLExceptionGenerator.java:418)
at COM.ibm.db2.jdbc.net.SQLExceptionGenerator.check_return_code(SQLExceptionGenerator.java:396)
at COM.ibm.db2.jdbc.net.DB2ResultSet.next(DB2ResultSet.java:357)
at net.sf.hibernate.persister.AbstractEntityPersister.lock(AbstractEntityPersister.java:1191)
at net.sf.hibernate.impl.SessionImpl.upgradeLock(SessionImpl.java:1665)
at net.sf.hibernate.impl.SessionImpl.lock(SessionImpl.java:1647)
at org.jbpm.persistence.hibernate.HibernateSession.lock(HibernateSession.java:108)
at com.quickstream.workflow.jbpm.JBPMWorkflowEngineImpl.updateNextActiveState(JBPMWorkflowEngineImpl.java:533)
at com.quickstream.doccentral.api.test.WorkflowLockTests$GetNextProcessTester.run(WorkflowLockTests.java:313)
at java.lang.Thread.run(Thread.java:534)

[/code]

Name and version of the database you are using:
DB2, version 8.1

The generated SQL (show_sql=true):
10:20:19,680 debug [JbpmConfiguration] jBpm configuration:
10:20:19,700 debug [JbpmConfiguration] [hibernate.connection.driver_class] COM.ibm.db2.jdbc.net.DB2Driver
10:20:19,700 debug [JbpmConfiguration] [hibernate.connection.isolation] 4
10:20:19,700 debug [JbpmConfiguration] [hibernate.connection.password] wwmuch$
10:20:19,700 debug [JbpmConfiguration] [hibernate.connection.url] jdbc:db2:209.177.138.240/HAWKJBPM
10:20:19,710 debug [JbpmConfiguration] [hibernate.connection.username] db2inst1
10:20:19,710 debug [JbpmConfiguration] [hibernate.dialect] net.sf.hibernate.dialect.DB2Dialect
10:20:19,710 debug [JbpmConfiguration] [hibernate.query.substitutions] true 1, false 0
10:20:19,710 debug [JbpmConfiguration] [hibernate.show_sql] true
10:20:19,740 debug [JbpmConfiguration] [hibernate.transaction.factory_class] net.sf.hibernate.transaction.JDBCTransactionFactory
10:20:19,740 debug [JbpmConfiguration] [jbpm.apply.transactions] yes
10:20:19,750 debug [JbpmConfiguration] [jbpm.create.tables] never
10:20:19,750 debug [JbpmConfiguration] [jbpm.create.tables.log] false
10:20:19,750 debug [JbpmConfiguration] [jbpm.create.tables.query] SELECT ID FROM JBPM_DEFINITION WHERE ID = 1
10:20:19,750 debug [JbpmConfiguration] [jbpm.execute.actions] true
10:20:19,760 debug [JbpmConfiguration] [jbpm.file.mgr] database
10:20:19,780 debug [JbpmConfiguration] [jbpm.id.generator] default
10:20:19,780 debug [JbpmConfiguration] [jbpm.id.generator.block.size] 100
10:20:19,780 debug [JbpmConfiguration] [jbpm.id.generator.configuration] same
10:20:19,780 debug [JbpmConfiguration] [jbpm.id.generator.node.id] 0
10:20:19,790 debug [JbpmConfiguration] [jbpm.log.default] error
10:20:19,790 debug [JbpmConfiguration] [jbpm.log.package.org.jbpm] debug
10:20:19,790 debug [JbpmConfiguration] [jbpm.log.stdout] on
10:20:19,790 debug [JbpmConfiguration] [jbpm.persistence.session.factory] hibernate
10:20:19,800 debug [JbpmConfiguration] [jbpm.scheduler.wait.period] 5000
10:20:19,800 debug [JbpmConfiguration] [jbpm.service.factory] default
10:20:19,800 debug [JbpmConfiguration] [jbpm.validate.xml] true
10:20:19,820 debug [JbpmConfiguration] for key 'jbpm.file.mgr', an object of type 'org.jbpm.persistence.filemgr.DatabaseFileMgr' was instantiated
10:20:19,900 debug [HibernateSessionFactory] creating the hibernate session factory
10:21:01,880 debug [HibernateSessionFactory] created the hibernate session factory
10:21:01,880 debug [JbpmConfiguration] for key 'jbpm.persistence.session.factory', an object of type 'org.jbpm.persistence.hibernate.HibernateSessionFactory' was instantiated
10:21:03,102 debug [SequenceBlockIdGenerator] created the hibernate session factory for the id generator
10:21:03,112 debug [JbpmConfiguration] for key 'jbpm.id.generator', an object of type 'org.jbpm.persistence.hibernate.SequenceBlockIdGenerator' was instantiated
10:21:03,142 debug [JbpmConfiguration] for key 'jbpm.service.factory', an object of type 'org.jbpm.impl.DefaultServiceFactory' was instantiated
Hibernate: select p.id as id, p.processid as processid, p.value as value from JBPM_PROCESS_LOCK p where (p.processid=? )
10:21:24,513 debug [HibernateSession] beginning a jbpm transaction
Hibernate: select id from JBPM_PROCESS_LOCK where id =? for update
Hibernate: select p.id as id, p.processid as processid, p.value as value from JBPM_PROCESS_LOCK p where (p.processid=? )
10:21:31,213 debug [HibernateSession] beginning a jbpm transaction
Hibernate: select id from JBPM_PROCESS_LOCK where id =? for update
10:21:38,813 debug [HibernateSession] committing a jbpm transaction
Hibernate: update JBPM_PROCESS_LOCK set processid=?, value=? where id=?
10:21:45,563 ERROR [JDBCExceptionReporter] [IBM][CLI Driver][DB2/LINUX] SQL0911N The current transaction has been rolled back because of a deadlock or timeout. Reason code "2". SQLSTATE=40001

10:21:45,593 ERROR [JDBCExceptionReporter] [IBM][CLI Driver][DB2/LINUX] SQL0911N The current transaction has been rolled back because of a deadlock or timeout. Reason code "2". SQLSTATE=40001

10:21:45,593 ERROR [JDBCExceptionReporter] could not lock: [org.jbpm.model.execution.impl.ProcessLockImpl#439091238]
caused by exception : COM.ibm.db2.jdbc.DB2Exception

Debug level Hibernate log excerpt:

I wanted to add the property file I am using to setup the database connection. Just in case something in there is wrong.

I did notice that we are running Repeatable Read, not Serializable as stated above.

jbpm.log.stdout=on
jbpm.create.tables=never
hibernate.query.substitutions=true 1, false 0
hibernate.show_sql=true
hibernate.dialect=net.sf.hibernate.dialect.DB2Dialect
hibernate.connection.driver_class=COM.ibm.db2.jdbc.net.DB2Driver
hibernate.connection.url=jdbc:db2:210.152.128.240/HAWKJBPM
hibernate.connection.username=db2inst1
hibernate.connection.password=something
hibernate.connection.isolation=4
hibernate.transaction.factory_class=net.sf.hibernate.transaction.JDBCTransactionFactory

As I understand you just need to remove "lock" to make it work. As I understand this use case must always produce dealock and it must be something wrong if it does not .

I don't believe that is true, unless I am missing something. When we run the following SQL directly against DB2 on two different threads, we get the proper behavior.

Begin Transaction
Select for Update

** Do your work here **

Update
End Transaction

(note that we set the connection to Repeatable read and autocommit off)

However when we run the following in Hibernate

session.beginTrasaction()
session.lock (obj)

** do your work **

session.save (obj)
session.flush()
session.commitTransaction

We get a deadlock. Looking at the SQL output from Hibernate, they should be the same set of calls going against the DB.

The lock itself is essential if we wish to coordinate DB updates to shared resources between threads.

I am not sure about Db2, but as I understand " Repeatable read " will do the same as you want (serialize transactions) without "select for update", you can test "read commited" (you use custom concurrency control anyway) probably it will not deadlock.