Hibernate db2 dealock case1

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: