I have a test method that has an inner class that extends Thread. The test method creates and runs 10 copies of the inner class and waits for them to finish. Each inner class creates some (mapped) objects and saves them. For a while (about 50 objects) this all works, but then I get a deadlock. It seems to me that this should work since I am using a ThreadLocal session via the HibernateUtil class. The HibernateUtil is the one that comes with Hibernate examples except that I modified the static initializer so that it is now a method that I can call to control the configuration.
I have tried many variations of the test and they all fail with the deadlock (DB2 SQL0911) exception. I have tried with and without c3p0, synchronizing the save() and flush() on the inner class instance and on the inner class, batch or no batch, and others.
Perhaps I have some basic misunderstanding about multithreading as it relates to Hibernate.
See the line in the code below where it says getSession().save.
Thanks in advance for any suggestions.
Hibernate version: 3.2.5
Mapping documents:
I'm not including the object mapping files since this works in a single threaded case, so I sincerely doubt they are the problem. Configuration mapping is below. The code also modifies the configuration. See further down.
Code:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration SYSTEM "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
<session-factory>
<property name="hibernate.connection.driver_class">com.ibm.db2.jcc.DB2Driver</property>
<property name="hibernate.connection.password">cfrjob</property>
<property name="hibernate.connection.url">jdbc:db2://172.16.50.110:50000/CFRDEV</property>
<property name="hibernate.connection.username">cfrjob</property>
<property name="hibernate.default_schema">TEST</property>
<property name="hibernate.dialect">org.hibernate.dialect.DB2Dialect</property>
name="hibernate.cache.use_second_level_cache">false</property>
<property name="show_sql">false</property>
<mapping resource="org/egcrc/cfr/performance/Level1a.hbm.xml"/>
<mapping resource="org/egcrc/cfr/performance/Level2a.hbm.xml"/>
<mapping resource="org/egcrc/cfr/performance/Level3a.hbm.xml"/>
</session-factory>
</hibernate-configuration>
Code:
public class PerformanceTest {
private static final Logger logger = Logger.getLogger(PerformanceTest.class);
protected int numObjects;
protected int flushLimit;
protected String configDescription;
Session getSession() {
return HibernateUtil.getSession();
}
public void setUpHibernate(Properties props, String...strings ) throws Exception {
String configFile = "performanceConfig.cfg.xml";
if (strings.length!=0) {
configFile = strings[0];
}
Properties hibProps = new Properties();
for (Enumeration e = props.keys(); e.hasMoreElements() ;) {
String name = (String) e.nextElement();
String value = props.getProperty(name);
configDescription += "," + name + "=" + value;
if (name.startsWith("hibernate"))
hibProps.setProperty(name, value);
else if (name.equals("flush_limit"))
flushLimit = Integer.parseInt(value);
else if (name.equals("num_objects"))
numObjects = Integer.parseInt(value);
}
HibernateUtil.configureFrom_with(configFile, hibProps);
}
public void tearDown() throws Exception {
flushLimit = -1;
numObjects = -1;
}
public void tearDownHibernate() throws Exception {
tearDown();
HibernateUtil.closeSession();
}
}
public class MultiSavePerformanceTest extends PerformanceTest {
private static final Logger logger = Logger.getLogger(MultiSavePerformanceTest.class);
private int numL2Objects = 2;
private int numL3Objects = 2;
public static void main(String[] args) {
Properties props = null;
props = new Properties();
props.setProperty("num_objects", ""+1000);
props.setProperty("flush_limit", "10");
props.setProperty("hibernate.connection.isolation", "2");
props.setProperty("hibernate.jdbc.batch_size", "0");
MultiSavePerformanceTest test = new MultiSavePerformanceTest();
try {
test.hibernateCreateAndSaveTest4(props);
} catch (Exception e) {
logger.error("hibernateCreateAndSaveTest", e);
}
}
// Use config that enables c3p0 connection pooling
// Multi-threaded
public long hibernateCreateAndSaveTest4(Properties props) throws Exception {
int numThreads = 10;
long totalTime = -1;
// Set up
configDescription = "hibernateCreateAndSaveTest4";
setUpHibernate(props, "performanceConfig.cfg.xml");
class HibernateInsert extends Thread {
int numObjs = 0;
HibernateInsert(int num) {
numObjs = num;
}
public void run() {
try {
Session session = getSession();
HibernateUtil.beginTransaction();
for (int i=0; i<numObjs; i++) {
Level1 l1 = Level1.createTestObject();
for (int j=0; j<numL2Objects; j++) {
Level2 l2 = Level2.createTestObject();
for (int k=0; k<numL3Objects; k++) {
Level3 l3 = Level3.createTestObject();
l2.addL3(l3);
}
l1.addL2(l2);
}
getSession().save(l1);
if ((i+1) % flushLimit == 0) {
getSession().flush();
getSession().clear();
}
}
HibernateUtil.commitTransaction();
} catch (Exception e) {
HibernateUtil.rollbackTransaction();
} finally {
// Clean up
}
}
}
GregorianCalendar beforeTime = new GregorianCalendar();
HibernateInsert[] threads = new HibernateInsert[numThreads];
for (int i=0; i<numThreads; i++) {
HibernateInsert insertThread = new HibernateInsert(numObjects/numThreads);
threads[i] = insertThread;
insertThread.start();
}
boolean done = false;
while (!done) {
done = true;
for (int i=0; i<numThreads; i++) {
done = done & !threads[i].isAlive();
}
}
GregorianCalendar afterTime = new GregorianCalendar();
totalTime = (afterTime.getTimeInMillis() - beforeTime.getTimeInMillis());
tearDownHibernate();
return totalTime;
}
}
Full stack trace of any exception that occurs:
INFO Environment.<clinit> - Hibernate 3.2.5
INFO Environment.<clinit> - hibernate.properties not found
INFO Environment.buildBytecodeProvider - Bytecode provider name : cglib
INFO Environment.<clinit> - using JDK 1.4 java.sql.Timestamp handling
INFO Configuration.configure - configuring from resource: performanceConfig.cfg.xml
INFO Configuration.getConfigurationInputStream - Configuration resource: performanceConfig.cfg.xml
DEBUG DTDEntityResolver.resolveEntity - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
DEBUG DTDEntityResolver.resolveEntity - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
DEBUG DTDEntityResolver.resolveEntity - located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
DEBUG Configuration.addProperties - hibernate.connection.driver_class=com.ibm.db2.jcc.DB2Driver
DEBUG Configuration.addProperties - hibernate.connection.password=cfrjob
DEBUG Configuration.addProperties - hibernate.connection.url=jdbc:db2://172.16.50.110:50000/CFRDEV
DEBUG Configuration.addProperties - hibernate.connection.username=cfrjob
DEBUG Configuration.addProperties - hibernate.default_schema=TEST
DEBUG Configuration.addProperties - hibernate.dialect=org.hibernate.dialect.DB2Dialect
DEBUG Configuration.addProperties - hibernate.cache.use_second_level_cache=false
DEBUG Configuration.addProperties - show_sql=false
... (lots of debugging messages but no exceptions)
DEBUG AbstractBatcher.getPreparedStatement - preparing statement
DEBUG AbstractEntityPersister.dehydrate - Dehydrating entity: [org.egcrc.cfr.performance.Level2#<null>]
DEBUG NullableType.nullSafeSet - binding 'eensy1221837687077' to parameter: 1
DEBUG NullableType.nullSafeSet - binding 'teensy1221837687077' to parameter: 2
DEBUG NullableType.nullSafeSet - binding 'spider1221837687077' to parameter: 3
DEBUG NullableType.nullSafeSet - binding '2997704' to parameter: 4
DEBUG AbstractBatcher.logClosePreparedStatement - about to close PreparedStatement (open PreparedStatements: 1, globally: 10)
DEBUG AbstractBatcher.closePreparedStatement - closing statement
DEBUG JDBCExceptionReporter.logExceptions - could not insert: [org.egcrc.cfr.performance.Level1] [insert into TEST.LEVEL1 (L1_PK, L1A, L1B, L1C) values (default, ?, ?, ?)]
com.ibm.db2.jcc.c.SqlException: DB2 SQL error:
SQLCODE: -911, SQLSTATE: 40001, SQLERRMC: 2
at com.ibm.db2.jcc.c.fg.e(fg.java:1596)
at com.ibm.db2.jcc.b.gb.o(gb.java:727)
at com.ibm.db2.jcc.b.gb.g(gb.java:143)
at com.ibm.db2.jcc.b.gb.a(gb.java:39)
at com.ibm.db2.jcc.b.w.a(w.java:34)
at com.ibm.db2.jcc.b.vb.g(vb.java:139)
at com.ibm.db2.jcc.c.fg.n(fg.java:1177)
at com.ibm.db2.jcc.c.gg.eb(gg.java:1862)
at com.ibm.db2.jcc.c.gg.d(gg.java:2295)
at com.ibm.db2.jcc.c.gg.W(gg.java:457)
at com.ibm.db2.jcc.c.gg.executeUpdate(gg.java:440)
at org.hibernate.id.IdentityGenerator$GetGeneratedKeysDelegate.executeAndExtract(IdentityGenerator.java:73)
at org.hibernate.id.insert.AbstractReturningDelegate.performInsert(AbstractReturningDelegate.java:33)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2158)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2638)
at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:48)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:298)
at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:181)
at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:107)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:187)
at org.hibernate.event.def.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:33)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:172)
at org.hibernate.event.def.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:27)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
at org.hibernate.impl.SessionImpl.fireSave(SessionImpl.java:535)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:523)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:519)
at org.egcrc.cfr.performance.MultiSavePerformanceTest$1HibernateInsert.run(MultiSavePerformanceTest.java:252)
WARN JDBCExceptionReporter.logExceptions - SQL Error: -911, SQLState: 40001
ERROR JDBCExceptionReporter.logExceptions - DB2 SQL error: SQLCODE: -911, SQLSTATE: 40001, SQLERRMC: 2
DEBUG HibernateUtil.rollbackTransaction - Tyring to rollback database transaction of this thread.
DEBUG JDBCTransaction.rollback - rollback
DEBUG JDBCTransaction.rollback - rolled back JDBC Connection
DEBUG JDBCContext.afterTransactionCompletion - after transaction completion
DEBUG ConnectionManager.aggressiveRelease - aggressively releasing JDBC connection
DEBUG ConnectionManager.closeConnection - releasing JDBC connection [ (open PreparedStatements: 0, globally: 9) (open ResultSets: 0, globally: 0)]
DEBUG DriverManagerConnectionProvider.closeConnection - returning connection to pool, pool size: 1
DEBUG SessionImpl.afterTransactionCompletion - after transaction completion
DEBUG HibernateUtil.closeSession - Closing Session of this thread.
DEBUG SessionImpl.close - closing session
DEBUG ConnectionManager.cleanup - connection already null in cleanup : no action
...
(more instances of the same exception from the other threads)
Name and version of the database you are using:
DB2 9.1
Login
FAQ
Search
