You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@servicemix.apache.org by moraleslos <mo...@hotmail.com> on 2006/12/07 17:29:22 UTC

issues with deadlocking upon deployment onto SMX w/ hibernate, c3p0

I'm running into an issue where I deploy a JBI unit onto SMX, it analyzes my
hibernate-annotated POJOs and starts (or wants) to create tables in the
database, and then runs into an "APPARENT DEADLOCK" issue with c3p0.  The
funny thing is that when I unit test this, I get no such issues.  Table
creation is just fine and I'm able to persist data.  Its when I package it
into a JBI unit and deploy it on SMX is when I get the deadlock issue.  Due
to the deadlocks, no tables were created.  Is SMX doing something in
particular that hogs up all of the connections in the c3p0 pool upon
initialization?  Below is a stacktrace:

#########################
......
10:00:01,684 | INFO  | Thread-7   | PoolBackedDataSource     |
e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
com.mchange.v2.c3p0.PoolBackedDataSource@1516490 [ connectionPoolDataSource
-> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1636731 [
acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1636731,
idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300,
maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0,
minPoolSize -> 5, nestedDataSource ->
com.mchange.v2.c3p0.DriverManagerDataSource@1128ee5 [ description -> null,
driverClass -> null, factoryClassLocation -> null, identityToken -> 1128ee5,
jdbcUrl -> jdbc:mysql://localhost:3306/test, properties -> {user=******,
password=******, release_mode=on_close} ], preferredTestQuery -> null,
propertyCycle -> 300, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies ->
false; userOverrides: {} ], dataSourceName -> 1516490, factoryClassLocation
-> null, identityToken -> 1516490, numHelperThreads -> 3 ]
10:00:01,700 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   81 | RDBMS: MySQL, version:
5.0.27-community-nt
10:00:01,700 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   82 | JDBC driver: MySQL-AB JDBC Driver,
version: mysql-connector-java-5.0.4 ( $Date: 2006-10-19 17:47:48 +0200 (Thu,
19 Oct 2006) $, $Revision: 5908 $ )
10:00:01,715 | INFO  | Thread-7   | Dialect                  |
org.hibernate.dialect.Dialect   151 | Using dialect:
org.hibernate.dialect.MySQLDialect
10:00:01,715 | INFO  | Thread-7   | ransactionFactoryFactory |
tion.TransactionFactoryFactory   31 | Using default transaction strategy
(direct JDBC transactions)
10:00:01,715 | INFO  | Thread-7   | tionManagerLookupFactory |
ransactionManagerLookupFactory   33 | No TransactionManagerLookup configured
(in JTA environment, use of read-write or transactional second-level cache
is not recommended)
10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  134 | Automatic flush during
beforeCompletion(): disabled
10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  138 | Automatic session close at end of
transaction: disabled
10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  145 | JDBC batch size: 20
10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  148 | JDBC batch updates for versioned data:
disabled
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  153 | Scrollable result sets: enabled
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  161 | JDBC3 getGeneratedKeys(): enabled
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  169 | Connection release mode: on_close
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  193 | Maximum outer join fetch depth: 2
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  196 | Default batch fetch size: 1
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  200 | Generate SQL with comments: disabled
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  204 | Order SQL updates by primary key:
disabled
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  369 | Query translator:
org.hibernate.hql.ast.ASTQueryTranslatorFactory
10:00:01,731 | INFO  | Thread-7   | STQueryTranslatorFactory |
.ast.ASTQueryTranslatorFactory   24 | Using ASTQueryTranslatorFactory
10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  212 | Query language substitutions:
{false='F', true='T'}
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  217 | JPA-QL strict compliance: disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  222 | Second-level cache: enabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  226 | Query cache: disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  356 | Cache provider:
org.hibernate.cache.NoCacheProvider
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  241 | Optimize cache for minimal puts:
disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  250 | Structured second-level cache entries:
disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  270 | Echoing all SQL to stdout
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  277 | Statistics: disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  281 | Deleted entity synthetic identifier
rollback: disabled
10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  296 | Default entity-mode: pojo
10:00:01,762 | INFO  | Thread-7   | DatabaseMetadata         |
.tool.hbm2ddl.DatabaseMetadata   96 | table not found: Customer_Relationship
10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   50 | C3P0 using driver:
com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/test
10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   51 | Connection properties: {user=root,
password=****, release_mode=on_close}
10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   54 | autocommit mode: false
10:00:01,825 | INFO  | Thread-7   | PoolBackedDataSource     |
e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
com.mchange.v2.c3p0.PoolBackedDataSource@1fccfe3 [ connectionPoolDataSource
-> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@a53e68 [
acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken -> a53e68,
idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300,
maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0,
minPoolSize -> 5, nestedDataSource ->
com.mchange.v2.c3p0.DriverManagerDataSource@e2cf81 [ description -> null,
driverClass -> null, factoryClassLocation -> null, identityToken -> e2cf81,
jdbcUrl -> jdbc:mysql://localhost:3306/test, properties -> {user=******,
password=******, release_mode=on_close} ], preferredTestQuery -> null,
propertyCycle -> 300, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies ->
false; userOverrides: {} ], dataSourceName -> 1fccfe3, factoryClassLocation
-> null, identityToken -> 1fccfe3, numHelperThreads -> 3 ]
10:00:21,840 | WARN  | Timer-123  | adPoolAsynchronousRunner |
hronousRunner$DeadlockDetector  429 |
com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1cb4a6a
-- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending
tasks!
10:00:21,840 | WARN  | Timer-123  | adPoolAsynchronousRunner |
hronousRunner$DeadlockDetector  435 |
com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1cb4a6a
-- APPARENT DEADLOCK!!! Complete Status: [num_managed_threads: 3,
num_active: 3; activeTasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@182815a
(com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1),
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@fa4dec
(com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0),
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@111e86f
(com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2);
pendingTasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@b2f2d6,
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@64cd4b]
10:00:31,167 | WARN  |
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0 |
BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@fa4dec --
Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
acquire a needed new resource, we failed to succeed more than the maximum
number of allowed acquisition attempts (30). Last acquisition attempt
exception: 
com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data source
rejected establishment of connection,  message from server: "Too many
connections"
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
	at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
	at
com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
	at
com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
	at
com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
	at
com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
	at
com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
	at
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
	at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
10:00:31,230 | WARN  |
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2 |
BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@111e86f --
Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
acquire a needed new resource, we failed to succeed more than the maximum
number of allowed acquisition attempts (30). Last acquisition attempt
exception: 
com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data source
rejected establishment of connection,  message from server: "Too many
connections"
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
	at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
	at
com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
	at
com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
	at
com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
	at
com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
	at
com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
	at
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
	at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
10:00:31,167 | WARN  |
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1 |
BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@182815a --
Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
acquire a needed new resource, we failed to succeed more than the maximum
number of allowed acquisition attempts (30). Last acquisition attempt
exception: 
com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data source
rejected establishment of connection,  message from server: "Too many
connections"
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
	at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
	at
com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
	at
com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
	at
com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
	at
com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
	at
com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
	at
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
	at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
#############################

FYI, before this exception occurs, the above situation is repeated about 20+
times for the different tables (POJOs) before coming into a deadlock.  I
guess each table *creation* gets a connection from c3p0 and holds on while
the others are doing the same, causing the deadlock.  Thanks in advance.

Using:  hibernate-3.2.1.ga, c3p0-0.9.1-pre6, mysql-connector-java-5.0.4, smx
3.0.1

-los
-- 
View this message in context: http://www.nabble.com/issues-with-deadlocking-upon-deployment-onto-SMX-w--hibernate%2C-c3p0-tf2775487s12049.html#a7742513
Sent from the ServiceMix - User mailing list archive at Nabble.com.


Re: issues with deadlocking upon deployment onto SMX w/ hibernate, c3p0

Posted by moraleslos <mo...@hotmail.com>.
UPDATE:  Seems like the reason for deadlocking is that SMX tries to
initialize the c3p0 pool atleast 2 dozen times, holding the connection to
the database without ever releasing.  Below is the output of SMX when
initializing the pool:

#############################
11:04:20,055 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   50 | C3P0 using driver:
com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/test
11:04:20,055 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   51 | Connection properties: {user=root,
password=****, release_mode=on_close}
11:04:20,055 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   54 | autocommit mode: false
11:04:20,180 | INFO  | Thread-5   | MLog                     |
com.mchange.v2.log.MLog          80 | MLog clients using log4j logging.
11:04:20,306 | INFO  | Thread-5   | C3P0Registry             |
m.mchange.v2.c3p0.C3P0Registry   87 | Initializing c3p0-0.9.1-pre6 [built
23-March-2006 16:11:59 +0200; debug? true; trace: 10]
11:04:20,493 | INFO  | Thread-5   | PoolBackedDataSource     |
e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
com.mchange.v2.c3p0.PoolBackedDataSource@3a586d [ connectionPoolDataSource
-> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@6e7127 [
acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 6e7127,
idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300,
maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0,
minPoolSize -> 5, nestedDataSource ->
com.mchange.v2.c3p0.DriverManagerDataSource@12438f1 [ description -> null,
driverClass -> null, factoryClassLocation -> null, identityToken -> 12438f1,
jdbcUrl -> jdbc:mysql://localhost:3306/test, properties -> {user=******,
password=******, release_mode=on_close} ], preferredTestQuery -> null,
propertyCycle -> 300, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies ->
false; userOverrides: {} ], dataSourceName -> 3a586d, factoryClassLocation
-> null, identityToken -> 3a586d, numHelperThreads -> 3 ]
11:04:21,057 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   81 | RDBMS: MySQL, version:
5.0.27-community-nt
11:04:21,057 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   82 | JDBC driver: MySQL-AB JDBC Driver,
version: mysql-connector-java-5.0.4 ( $Date: 2006-10-19 17:47:48 +0200 (Thu,
19 Oct 2006) $, $Revision: 5908 $ )
11:04:21,104 | INFO  | Thread-5   | Dialect                  |
org.hibernate.dialect.Dialect   151 | Using dialect:
org.hibernate.dialect.MySQLDialect
11:04:21,119 | INFO  | Thread-5   | ransactionFactoryFactory |
tion.TransactionFactoryFactory   31 | Using default transaction strategy
(direct JDBC transactions)
11:04:21,119 | INFO  | Thread-5   | tionManagerLookupFactory |
ransactionManagerLookupFactory   33 | No TransactionManagerLookup configured
(in JTA environment, use of read-write or transactional second-level cache
is not recommended)
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  134 | Automatic flush during
beforeCompletion(): disabled
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  138 | Automatic session close at end of
transaction: disabled
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  145 | JDBC batch size: 20
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  148 | JDBC batch updates for versioned data:
disabled
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  153 | Scrollable result sets: enabled
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  161 | JDBC3 getGeneratedKeys(): enabled
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  169 | Connection release mode: on_close
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  193 | Maximum outer join fetch depth: 2
11:04:21,135 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  196 | Default batch fetch size: 1
11:04:21,151 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  200 | Generate SQL with comments: disabled
11:04:21,151 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  204 | Order SQL updates by primary key:
disabled
11:04:21,151 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  369 | Query translator:
org.hibernate.hql.ast.ASTQueryTranslatorFactory
11:04:21,323 | INFO  | Thread-5   | STQueryTranslatorFactory |
.ast.ASTQueryTranslatorFactory   24 | Using ASTQueryTranslatorFactory
11:04:21,323 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  212 | Query language substitutions:
{false='F', true='T'}
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  217 | JPA-QL strict compliance: disabled
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  222 | Second-level cache: enabled
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  226 | Query cache: disabled
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  356 | Cache provider:
org.hibernate.cache.NoCacheProvider
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  241 | Optimize cache for minimal puts:
disabled
11:04:21,338 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  250 | Structured second-level cache entries:
disabled
11:04:21,370 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  270 | Echoing all SQL to stdout
11:04:21,370 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  277 | Statistics: disabled
11:04:21,370 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  281 | Deleted entity synthetic identifier
rollback: disabled
11:04:21,370 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  296 | Default entity-mode: pojo
11:04:22,089 | INFO  | Thread-5   | SessionFactoryImpl       |
ernate.impl.SessionFactoryImpl  161 | building session factory
11:04:23,153 | INFO  | Thread-5   | sionFactoryObjectFactory |
pl.SessionFactoryObjectFactory   82 | Not binding factory to JNDI, no JNDI
name configured
11:04:23,153 | INFO  | Thread-5   | SchemaUpdate             |
nate.tool.hbm2ddl.SchemaUpdate  115 | Running hbm2ddl schema update
11:04:23,153 | INFO  | Thread-5   | SchemaUpdate             |
nate.tool.hbm2ddl.SchemaUpdate  126 | fetching database metadata
11:04:23,185 | INFO  | Thread-5   | SchemaUpdate             |
nate.tool.hbm2ddl.SchemaUpdate  138 | updating schema
11:04:23,247 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   50 | C3P0 using driver:
com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/test
11:04:23,247 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   51 | Connection properties: {user=root,
password=****, release_mode=on_close}
11:04:23,263 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   54 | autocommit mode: false
11:04:23,372 | INFO  | Thread-5   | PoolBackedDataSource     |
e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
com.mchange.v2.c3p0.PoolBackedDataSource@14f79cb [ connectionPoolDataSource
-> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1578426 [
acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1578426,
idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300,
maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0,
minPoolSize -> 5, nestedDataSource ->
com.mchange.v2.c3p0.DriverManagerDataSource@d9973a [ description -> null,
driverClass -> null, factoryClassLocation -> null, identityToken -> d9973a,
jdbcUrl -> jdbc:mysql://localhost:3306/test, properties -> {user=******,
password=******, release_mode=on_close} ], preferredTestQuery -> null,
propertyCycle -> 300, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies ->
false; userOverrides: {} ], dataSourceName -> 14f79cb, factoryClassLocation
-> null, identityToken -> 14f79cb, numHelperThreads -> 3 ]
11:04:23,466 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   81 | RDBMS: MySQL, version:
5.0.27-community-nt
11:04:23,466 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory   82 | JDBC driver: MySQL-AB JDBC Driver,
version: mysql-connector-java-5.0.4 ( $Date: 2006-10-19 17:47:48 +0200 (Thu,
19 Oct 2006) $, $Revision: 5908 $ )
11:04:23,482 | INFO  | Thread-5   | Dialect                  |
org.hibernate.dialect.Dialect   151 | Using dialect:
org.hibernate.dialect.MySQLDialect
11:04:23,482 | INFO  | Thread-5   | ransactionFactoryFactory |
tion.TransactionFactoryFactory   31 | Using default transaction strategy
(direct JDBC transactions)
11:04:23,498 | INFO  | Thread-5   | tionManagerLookupFactory |
ransactionManagerLookupFactory   33 | No TransactionManagerLookup configured
(in JTA environment, use of read-write or transactional second-level cache
is not recommended)
11:04:23,498 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  134 | Automatic flush during
beforeCompletion(): disabled
11:04:23,498 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  138 | Automatic session close at end of
transaction: disabled
11:04:23,498 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  145 | JDBC batch size: 20
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  148 | JDBC batch updates for versioned data:
disabled
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  153 | Scrollable result sets: enabled
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  161 | JDBC3 getGeneratedKeys(): enabled
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  169 | Connection release mode: on_close
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  193 | Maximum outer join fetch depth: 2
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  196 | Default batch fetch size: 1
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  200 | Generate SQL with comments: disabled
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  204 | Order SQL updates by primary key:
disabled
11:04:23,513 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  369 | Query translator:
org.hibernate.hql.ast.ASTQueryTranslatorFactory
11:04:23,529 | INFO  | Thread-5   | STQueryTranslatorFactory |
.ast.ASTQueryTranslatorFactory   24 | Using ASTQueryTranslatorFactory
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  212 | Query language substitutions:
{false='F', true='T'}
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  217 | JPA-QL strict compliance: disabled
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  222 | Second-level cache: enabled
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  226 | Query cache: disabled
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  356 | Cache provider:
org.hibernate.cache.NoCacheProvider
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  241 | Optimize cache for minimal puts:
disabled
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  250 | Structured second-level cache entries:
disabled
11:04:23,529 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  270 | Echoing all SQL to stdout
11:04:23,545 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  277 | Statistics: disabled
11:04:23,545 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  281 | Deleted entity synthetic identifier
rollback: disabled
11:04:23,545 | INFO  | Thread-5   | SettingsFactory          |
.hibernate.cfg.SettingsFactory  296 | Default entity-mode: pojo
11:04:23,592 | INFO  | Thread-5   | DatabaseMetadata         |
.tool.hbm2ddl.DatabaseMetadata   96 | table not found: Consumer
11:04:23,592 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   50 | C3P0 using driver:
com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/test
11:04:23,592 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   51 | Connection properties: {user=root,
password=****, release_mode=on_close}
11:04:23,592 | INFO  | Thread-5   | C3P0ConnectionProvider   |
nection.C3P0ConnectionProvider   54 | autocommit mode: false
11:04:23,717 | INFO  | Thread-5   | PoolBackedDataSource     |
e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
com.mchange.v2.c3p0.PoolBackedDataSource@1aabc29 [ connectionPoolDataSource
-> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1e06b12 [
acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1e06b12,
idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300,
maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0,
minPoolSize -> 5, nestedDataSource ->
com.mchange.v2.c3p0.DriverManagerDataSource@1b0d2d0 [ description -> null,
driverClass -> null, factoryClassLocation -> null, identityToken -> 1b0d2d0,
jdbcUrl -> jdbc:mysql://localhost:3306/test, properties -> {user=******,
password=******, release_mode=on_close} ], preferredTestQuery -> null,
propertyCycle -> 300, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies ->
false; userOverrides: {} ], dataSourceName -> 1aabc29, factoryClassLocation
-> null, identityToken -> 1aabc29, numHelperThreads -> 3 ]
##############################



moraleslos wrote:
> 
> I'm running into an issue where I deploy a JBI unit onto SMX, it analyzes
> my hibernate-annotated POJOs and starts (or wants) to create tables in the
> database, and then runs into an "APPARENT DEADLOCK" issue with c3p0.  The
> funny thing is that when I unit test this, I get no such issues.  Table
> creation is just fine and I'm able to persist data.  Its when I package it
> into a JBI unit and deploy it on SMX is when I get the deadlock issue. 
> Due to the deadlocks, no tables were created.  Is SMX doing something in
> particular that hogs up all of the connections in the c3p0 pool upon
> initialization?  Below is a stacktrace:
> 
> #########################
> ......
> 10:00:01,684 | INFO  | Thread-7   | PoolBackedDataSource     |
> e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
> com.mchange.v2.c3p0.PoolBackedDataSource@1516490 [
> connectionPoolDataSource ->
> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1636731 [
> acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
> 1000, autoCommitOnClose -> false, automaticTestTable -> null,
> breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
> connectionTesterClassName ->
> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
> null, forceIgnoreUnresolvedTransactions -> false, identityToken ->
> 1636731, idleConnectionTestPeriod -> 3000, initialPoolSize -> 5,
> maxIdleTime -> 300, maxPoolSize -> 20, maxStatements -> 0,
> maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource ->
> com.mchange.v2.c3p0.DriverManagerDataSource@1128ee5 [ description -> null,
> driverClass -> null, factoryClassLocation -> null, identityToken ->
> 1128ee5, jdbcUrl -> jdbc:mysql://localhost:3306/test, properties ->
> {user=******, password=******, release_mode=on_close} ],
> preferredTestQuery -> null, propertyCycle -> 300, testConnectionOnCheckin
> -> false, testConnectionOnCheckout -> false,
> usesTraditionalReflectiveProxies -> false; userOverrides: {} ],
> dataSourceName -> 1516490, factoryClassLocation -> null, identityToken ->
> 1516490, numHelperThreads -> 3 ]
> 10:00:01,700 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory   81 | RDBMS: MySQL, version:
> 5.0.27-community-nt
> 10:00:01,700 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory   82 | JDBC driver: MySQL-AB JDBC Driver,
> version: mysql-connector-java-5.0.4 ( $Date: 2006-10-19 17:47:48 +0200
> (Thu, 19 Oct 2006) $, $Revision: 5908 $ )
> 10:00:01,715 | INFO  | Thread-7   | Dialect                  |
> org.hibernate.dialect.Dialect   151 | Using dialect:
> org.hibernate.dialect.MySQLDialect
> 10:00:01,715 | INFO  | Thread-7   | ransactionFactoryFactory |
> tion.TransactionFactoryFactory   31 | Using default transaction strategy
> (direct JDBC transactions)
> 10:00:01,715 | INFO  | Thread-7   | tionManagerLookupFactory |
> ransactionManagerLookupFactory   33 | No TransactionManagerLookup
> configured (in JTA environment, use of read-write or transactional
> second-level cache is not recommended)
> 10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  134 | Automatic flush during
> beforeCompletion(): disabled
> 10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  138 | Automatic session close at end of
> transaction: disabled
> 10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  145 | JDBC batch size: 20
> 10:00:01,715 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  148 | JDBC batch updates for versioned
> data: disabled
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  153 | Scrollable result sets: enabled
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  161 | JDBC3 getGeneratedKeys(): enabled
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  169 | Connection release mode: on_close
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  193 | Maximum outer join fetch depth: 2
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  196 | Default batch fetch size: 1
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  200 | Generate SQL with comments: disabled
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  204 | Order SQL updates by primary key:
> disabled
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  369 | Query translator:
> org.hibernate.hql.ast.ASTQueryTranslatorFactory
> 10:00:01,731 | INFO  | Thread-7   | STQueryTranslatorFactory |
> .ast.ASTQueryTranslatorFactory   24 | Using ASTQueryTranslatorFactory
> 10:00:01,731 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  212 | Query language substitutions:
> {false='F', true='T'}
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  217 | JPA-QL strict compliance: disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  222 | Second-level cache: enabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  226 | Query cache: disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  356 | Cache provider:
> org.hibernate.cache.NoCacheProvider
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  241 | Optimize cache for minimal puts:
> disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  250 | Structured second-level cache
> entries: disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  270 | Echoing all SQL to stdout
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  277 | Statistics: disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  281 | Deleted entity synthetic identifier
> rollback: disabled
> 10:00:01,746 | INFO  | Thread-7   | SettingsFactory          |
> .hibernate.cfg.SettingsFactory  296 | Default entity-mode: pojo
> 10:00:01,762 | INFO  | Thread-7   | DatabaseMetadata         |
> .tool.hbm2ddl.DatabaseMetadata   96 | table not found:
> Customer_Relationship
> 10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
> nection.C3P0ConnectionProvider   50 | C3P0 using driver:
> com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/test
> 10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
> nection.C3P0ConnectionProvider   51 | Connection properties: {user=root,
> password=****, release_mode=on_close}
> 10:00:01,762 | INFO  | Thread-7   | C3P0ConnectionProvider   |
> nection.C3P0ConnectionProvider   54 | autocommit mode: false
> 10:00:01,825 | INFO  | Thread-7   | PoolBackedDataSource     |
> e.v2.c3p0.PoolBackedDataSource  269 | Initializing c3p0 pool...
> com.mchange.v2.c3p0.PoolBackedDataSource@1fccfe3 [
> connectionPoolDataSource ->
> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@a53e68 [
> acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay ->
> 1000, autoCommitOnClose -> false, automaticTestTable -> null,
> breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
> connectionTesterClassName ->
> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation ->
> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> a53e68,
> idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime ->
> 300, maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection ->
> 0, minPoolSize -> 5, nestedDataSource ->
> com.mchange.v2.c3p0.DriverManagerDataSource@e2cf81 [ description -> null,
> driverClass -> null, factoryClassLocation -> null, identityToken ->
> e2cf81, jdbcUrl -> jdbc:mysql://localhost:3306/test, properties ->
> {user=******, password=******, release_mode=on_close} ],
> preferredTestQuery -> null, propertyCycle -> 300, testConnectionOnCheckin
> -> false, testConnectionOnCheckout -> false,
> usesTraditionalReflectiveProxies -> false; userOverrides: {} ],
> dataSourceName -> 1fccfe3, factoryClassLocation -> null, identityToken ->
> 1fccfe3, numHelperThreads -> 3 ]
> 10:00:21,840 | WARN  | Timer-123  | adPoolAsynchronousRunner |
> hronousRunner$DeadlockDetector  429 |
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1cb4a6a
> -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending
> tasks!
> 10:00:21,840 | WARN  | Timer-123  | adPoolAsynchronousRunner |
> hronousRunner$DeadlockDetector  435 |
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1cb4a6a
> -- APPARENT DEADLOCK!!! Complete Status: [num_managed_threads: 3,
> num_active: 3; activeTasks:
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@182815a
> (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1),
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@fa4dec
> (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0),
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@111e86f
> (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2);
> pendingTasks:
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@b2f2d6,
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@64cd4b]
> 10:00:31,167 | WARN  |
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0 |
> BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@fa4dec --
> Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
> acquire a needed new resource, we failed to succeed more than the maximum
> number of allowed acquisition attempts (30). Last acquisition attempt
> exception: 
> com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data
> source rejected establishment of connection,  message from server: "Too
> many connections"
> 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
> 	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
> 	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
> 	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
> 	at
> com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
> 	at
> com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
> 	at
> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
> 	at
> com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
> 	at
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
> 10:00:31,230 | WARN  |
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2 |
> BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@111e86f --
> Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
> acquire a needed new resource, we failed to succeed more than the maximum
> number of allowed acquisition attempts (30). Last acquisition attempt
> exception: 
> com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data
> source rejected establishment of connection,  message from server: "Too
> many connections"
> 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
> 	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
> 	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
> 	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
> 	at
> com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
> 	at
> com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
> 	at
> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
> 	at
> com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
> 	at
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
> 10:00:31,167 | WARN  |
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1 |
> BasicResourcePool        | .BasicResourcePool$AcquireTask 1277 |
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@182815a --
> Acquisition Attempt Failed!!! Clearing pending acquires. While trying to
> acquire a needed new resource, we failed to succeed more than the maximum
> number of allowed acquisition attempts (30). Last acquisition attempt
> exception: 
> com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Data
> source rejected establishment of connection,  message from server: "Too
> many connections"
> 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:921)
> 	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:997)
> 	at com.mysql.jdbc.Connection.createNewIO(Connection.java:2670)
> 	at com.mysql.jdbc.Connection.<init>(Connection.java:1531)
> 	at
> com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
> 	at
> com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:107)
> 	at
> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
> 	at
> com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:113)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:728)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:32)
> 	at
> com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1258)
> 	at
> com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
> 
> ......
> .....
> ...... (on and on)
> #############################
> 
> FYI, before this exception occurs, the above situation is repeated about
> 20+ times for the different tables (POJOs) before coming into a deadlock. 
> I guess each table *creation* gets a connection from c3p0 and holds on
> while the others are doing the same, causing the deadlock.  Thanks in
> advance.
> 
> Using:  hibernate-3.2.1.ga, c3p0-0.9.1-pre6, mysql-connector-java-5.0.4,
> smx 3.0.1
> 
> -los
> 

-- 
View this message in context: http://www.nabble.com/issues-with-deadlocking-upon-deployment-onto-SMX-w--hibernate%2C-c3p0-tf2775487s12049.html#a7743610
Sent from the ServiceMix - User mailing list archive at Nabble.com.