I am trying to initialize hibernate session factory using c3po to connect to oracle database and my unit test fails on the line when the hibernate session factory is being created at this line:
SessionFactory oracleSessionFactory = oracleConf.buildSessionFactory();
From the logs it seems to be a deadlock issue... no idea whatz causing this.
Thanks in advance.
Hibernate version: 3.2.3
c3po version: 0.9.1.1
Name and version of the database you are using:
Oracle 10g
Debug level Hibernate log excerpt:
DEBUG
Mapping documents:
Code:
hibernate.connection.driver_class = "xxx.jdbc.driver.SecureDriver";
hibernate.connection.username = "abcde";
hibernate.connection.password = "xxxxx";
hibernate.dialect = "org.hibernate.dialect.OracleDialect";
hibernate.connection.autocommit = false;
#connection pool settings:
hibernate.connection.provider_class = "org.hibernate.connection.C3P0ConnectionProvider";
hibernate.c3p0.acquire_increment = 2;
hibernate.c3p0.idle_test_period = 60;
hibernate.c3p0.min_size = 2;
hibernate.c3p0.max_size = 10;
hibernate.c3p0.max_statements = 0;
hibernate.c3p0.timeout = 5000;
hibernate.c3p0.validate = false;
hibernate.c3p0.unreturnedConnectionTimeout=120;
hibernate.c3p0.debugUnreturnedConnectionStackTraces=true;
hibernate.transaction.factory_class = "org.hibernate.transaction.JDBCTransactionFactory";
hibernate.cache.provider_class = "org.hibernate.cache.HashtableCacheProvider";
hibernate.order_updates = true;
Hibernate Initializing Code :
Code:
public static void init() {
try {
Configuration oracleConf = createConfiguration(null,HBM_ORACLE_CLASS_LIST_KEY);
readHibernateAppConfig (oracleConf, HIBERNATE_ORACLE_CONFIG_KEY);
log.info("Building Session Factory for " + HIBERNATE_ORACLE_CONFIG_KEY);
SessionFactory oracleSessionFactory = oracleConf.buildSessionFactory();
sessionFactoryMap.put(ORACLE_STRING, oracleSessionFactory);
} catch (Throwable ex) {
log.error("Initial SessionFactory creation failed." +
ex.toString());
throw new ExceptionInInitializerError(ex);
}
}
private static synchronized void readHibernateAppConfig(
Configuration config, String configKey) {
Map<String, String> hibernateProperties = AppConfig.findMap(configKey);
if (null == hibernateProperties) {
throw new ExceptionInInitializerError("Unable to find "
+ configKey + " entry in brazil configuration file");
}
if (null == config) {
throw new ExceptionInInitializerError(
"Working on a null hibernate Configuration ");
}
for (Iterator<String> iter = hibernateProperties.keySet().iterator(); iter.hasNext();) {
String key = (String) iter.next();
String value = hibernateProperties.get(key);
config.setProperty(key, value);
log.info("Setting hibernate property " + "<" + key + ", " + value + ">");
}
}
/**
* Create Configuration.
* @return a Configuration with classes loaded.
*/
@SuppressWarnings("unchecked")
private static Configuration createConfiguration(Configuration config, String key) {
Configuration cfg = config;
if(cfg ==null){
cfg = new Configuration();
}
Vector<String> classList = AppConfig.findVector(key);
if(classList != null && classList.size() > 0){
for(String resourceName : classList){
log.info("Adding resource: " + resourceName);
cfg = cfg.addResource(resourceName);
}
}else{
log.warn("No Hibernate xml file specified!");
}
return cfg;
}
Full stack trace of any exception that occurs:
No exception, just my unit test hangs doing nothing as it starts. From the junit logs:
Code:
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [INFO] (main) com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource: Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@f7ef3eac [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@f79bd4a1 [ acquireIncrement -> 2, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> true, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> z8kflt7tvydqzrr7hty9|b7b3f9, idleConnectionTestPeriod -> 60, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 5000, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 10, maxStatements -> 100, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@f5ee3895 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> z8kflt7tvydqzrr7hty9|c8376b, jdbcUrl -> jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB, properties -> {user=******, password=******, autocommit=false} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 120, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> z8kflt7tvydqzrr7hty9|b1cc87, numHelperThreads -> 3 ]
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: incremented pending_acquires: 1
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: incremented pending_acquires: 2
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: com.mchange.v2.resourcepool.BasicResourcePool@121177e config: [start -> 2; min -> 2; max -> 10; inc -> 2; num_acq_attempts -> 30; acq_attempt_delay -> 1000; check_idle_resources_delay -> 60000; mox_resource_age -> 0; max_idle_time -> 5000000; excess_max_idle_time -> 0; destroy_unreturned_resc_time -> 120000; expiration_enforcement_delay -> 30000; break_on_acquisition_failure -> false; debug_store_checkout_exceptions -> true]
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: acquire test -- pool size: 0; target_pool_size: 2; desired target? 1
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: awaitAvailable(): [unknown]
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (main) com.mchange.v2.resourcepool.BasicResourcePool: trace com.mchange.v2.resourcepool.BasicResourcePool@121177e [managed: 0, unused: 0, excluded: 0]
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) xxxx.jdbc.driver.SecureDriver: accepts url? [true] jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB (jdbc:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB)
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) xxxx.jdbc.driver.SecureDriver: accepts url? [true] jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB (jdbc:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB)
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1) xxxx.jdbc.driver.SecureDriver: accepts url? [true] jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB (jdbc:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB)
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) xxxx.jdbc.driver.SecureDriver: Connect to url [jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB]
Mon Apr 21 22:46:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1) xxxx.jdbc.driver.SecureDriver: Connect to url [jdbc:xxxx;moduleName=FionaTodoList:oracle:thin:@myDB-orasvr.db.xxxx.com:63620:myDB]
Mon Apr 21 22:46:52 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1) com.mchange.v2.resourcepool.BasicResourcePool: decremented pending_acquires: 1
Mon Apr 21 22:46:52 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) com.mchange.v2.resourcepool.BasicResourcePool: decremented pending_acquires: 0
================== have to cntrl-C my unit test here ======================
Mon Apr 21 22:47:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (Timer-0) com.mchange.v2.resourcepool.BasicResourcePool: Refurbishing idle resources - Mon Apr 21 22:47:50 UTC 2008 [com.mchange.v2.resourcepool.BasicResourcePool@121177e]
Mon Apr 21 22:47:50 2008 GMT TestCustomerNotify 17193-0@prats.desktop.xxxx.com:0 [DEBUG] (Timer-0) com.mchange.v2.resourcepool.BasicResourcePool: trace com.mchange.v2.resourcepool.BasicResourcePool@121177e [managed: 0, unused: 0, excluded: 0]
Tue Apr 22 20:31:16 2008 GMT TestCustomerNotify 21225-0@prats.desktop.xxxx.com:0 [WARN] (Timer-0) com.mchange.v2.async.ThreadPoolAsynchronousRunner: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@dada24 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
Tue Apr 22 20:31:16 2008 GMT TestCustomerNotify 21225-0@prats.desktop.xxxx.com:0 [WARN] (Timer-0) com.mchange.v2.async.ThreadPoolAsynchronousRunner: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@dada24 -- APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 3 Active Threads: 0
Active Tasks: Pending Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@1f02b85 Pool thread stack traces:
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,] Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,] Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,]
Tue Apr 22 20:31:16 2008 GMT TestCustomerNotify 21225-0@prats.desktop.xxxx.com:0 [DEBUG] (Timer-0) com.mchange.v2.async.ThreadPoolAsynchronousRunner: Apparently some threads have been replaced. Replacement thread processing enabled.