Search code examples
springc3p0

Apparent Deadlock c3p0 issue


I am having an issue with C3P0 APPARENT DEAD. I have looked many other related questions on here but could not resolve the issue. If someone can suggest any possible solution it would be thankful!

c3p0 version: c3p0-0.9.5.2

c3p0 configuration xml file

<bean id="dataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource"
    destroy-method="close">
    <property name="driverClass" value="oracle.jdbc.driver.OracleDriver" />
    <property name="jdbcUrl"
        value="jdbc:oracle:thin:@transport-crash-ora-tst.cee.wisc.edu:1521:DTCRDBT" />
    <property name="user" value="transdev" />
    <property name="password" value="Its2$123" />
    <property name="maxPoolSize" value="10" />
    <property name="maxStatements" value="0" />
    <property name="minPoolSize" value="5" />
    <property name="statementCacheNumDeferredCloseThreads" value="1"></property>
</bean>

Messages in the console view

[localhost-startStop-1] INFO com.mchange.v2.c3p0.C3P0Registry - Initializing c3p0-0.9.5.2 [built 08-December-2015 22:06:04 -0800; debug? true; trace: 10]
ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.
[localhost-startStop-1] INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, dataSourceName -> 72r5me9i3xucoj6ds3mi|10319844, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> oracle.jdbc.driver.OracleDriver, extensions -> {}, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, forceUseNamedDriverClass -> false, identityToken -> 72r5me9i3xucoj6ds3mi|10319844, idleConnectionTestPeriod -> 0, initialPoolSize -> 3, jdbcUrl -> jdbc:oracle:thin:@transport-crash-ora-tst.cee.wisc.edu:1521:DTCRDBT, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 10, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, preferredTestQuery -> null, privilegeSpawnedThreads -> false, properties -> {user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 1, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, userOverrides -> {}, usesTraditionalReflectiveProxies -> false ]
[localhost-startStop-1] WARN com.mchange.v2.resourcepool.BasicResourcePool - Bad pool size config, start 3 < min 5. Using 5 as start.
[C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-AdminTaskTimer] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7bd1346f -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
[C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-AdminTaskTimer] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7bd1346f -- APPARENT DEADLOCK!!! Complete Status: 
Managed Threads: 3
Active Threads: 3
Active Tasks: 
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@342bcf5e
        on thread: C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#2
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@46abe7f8
        on thread: C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#1
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5d53fa5
        on thread: C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#0
Pending Tasks: 
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3ebf49a7
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@54043011
Pool thread stack traces:
Thread[C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#2,5,main]
    java.net.PlainSocketImpl.socketConnect(Native Method)
    java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
    java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
    java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
    java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
    java.net.Socket.connect(Socket.java:589)
    oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:162)
    oracle.net.nt.ConnOption.connect(ConnOption.java:133)
    oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:411)
    oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:464)
    oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:594)
    oracle.net.ns.NSProtocol.connect(NSProtocol.java:229)
    oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1360)
    oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:486)
    oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:715)
    oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:385)
    oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:30)
    oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:564)
    com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
    com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
    com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
    com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
Thread[C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#0,5,main]
    java.net.PlainSocketImpl.socketConnect(Native Method)
    java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
    java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
    java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
    java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
    java.net.Socket.connect(Socket.java:589)
    oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:162)
    oracle.net.nt.ConnOption.connect(ConnOption.java:133)
    oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:411)
    oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:464)
    oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:594)
    oracle.net.ns.NSProtocol.connect(NSProtocol.java:229)
    oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1360)
    oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:486)
    oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:715)
    oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:385)
    oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:30)
    oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:564)
    com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
    com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
    com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
    com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
Thread[C3P0PooledConnectionPoolManager[identityToken->72r5me9i3xucoj6ds3mi|10319844]-HelperThread-#1,5,main]
    java.net.PlainSocketImpl.socketConnect(Native Method)
    java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
    java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
    java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
    java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
    java.net.Socket.connect(Socket.java:589)
    oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:162)
    oracle.net.nt.ConnOption.connect(ConnOption.java:133)
    oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:411)
    oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:464)
    oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:594)
    oracle.net.ns.NSProtocol.connect(NSProtocol.java:229)
    oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1360)
    oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:486)
    oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:715)
    oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:385)
    oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:30)
    oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:564)
    com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
    com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
    com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
    com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
    com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
    com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
    com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)

Solution

  • Threads that are trying to acquire Connections from your DBMS are neither succeeding, nor failing with an Exception. They are just freezing. That is the issue that you'll need to debug. It may be some kind of network / firewall-ish kind of issue. For example, over AWS, attempting to connect to a machine or service without configuration of a security group to permit the Connection often leads to such hangs.

    A first thing to do is to make sure you can Connect from wherever you app lives using DriverManager.getConnection().

    (If you want, you can temporarily change "com.mchange.v2.c3p0.ComboPooledDataSource" to "com.mchange.v2.c3p0.DriverManagerDataSource" in your bean xml, and see if things "work". The performance will be poor, because DriverManagerDataSource does no pooling, but you can see whether all or some client Threads hang when trying to acquire Connections.)

    If your app is usually able to acquire Connections, but they occasionally hang like this, and you are not able to resolve the hang, you can try working around it with two c3p0 config properties:

    maxAdministrativeTaskTime lets you set a timeout after which c3p0's thread pool will try to interrupt() frozen tasks

    numHelperThreads lets you increase the number of Threads that have to get caught by the freeze before you start seeing APPARENT DEADLOCK messages.