search

swaldman / c3p0

a mature, highly concurrent JDBC Connection pooling library, with support for caching and reuse of PreparedStatements.
http://www.mchange.com/projects/c3p0
Other
1.29k stars 338 forks source link

DEADLOCK with C3P0 on java se application #84

Closed TheSkay closed 7 years ago

TheSkay commented 7 years ago

Hi !

I encountered a critical problem with the c3p0 library (version 0.9.5.2) that I use in my Java SE application.

My application uses a Thread Pool to parallelize task by executing jobs.

Each job uses the database to read, update or delete data at least once up to (in very rare cases but it can happen) more than 10,000 times.

I therefore included in my project c3p0 library to have a connection pool to the database so that all workers in my thread pool can simultaneously interact with it.

I do not have any problems when running my application on my development environment (OSX 10.11), but when I run it in production (Linux Debian 8) I encounter a big problem ! Indeed it freezes....

At first it was a deadlock with the following trace stack:

[WARNING] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@479d237b -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
[WARNING] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@479d237b -- APPARENT DEADLOCK!!! Complete Status: 
    Managed Threads: 3
    Active Threads: 3
    Active Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@264fb34f
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#2
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@39a5576b
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#1
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5e676544
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#0
    Pending Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@6848208c
Pool thread stack traces:
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#2,5,main]
        sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocketUsingJavaNIO(IOBuffer.java:2438)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocket(IOBuffer.java:2290)
        com.microsoft.sqlserver.jdbc.TDSChannel.open(IOBuffer.java:551)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:1962)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:1627)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1458)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:772)
        com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:1168)
        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->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#1,5,main]
        sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocketUsingJavaNIO(IOBuffer.java:2438)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocket(IOBuffer.java:2290)
        com.microsoft.sqlserver.jdbc.TDSChannel.open(IOBuffer.java:551)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:1962)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:1627)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1458)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:772)
        com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:1168)
        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->z8kfsx9l1adv4kd1qtfdi6|659f3099]-HelperThread-#0,5,main]
        sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocketUsingJavaNIO(IOBuffer.java:2438)
        com.microsoft.sqlserver.jdbc.SocketFinder.findSocket(IOBuffer.java:2290)
        com.microsoft.sqlserver.jdbc.TDSChannel.open(IOBuffer.java:551)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:1962)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:1627)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1458)
        com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:772)
        com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:1168)
        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)

Subsequently I made some changes following the advice on different websites:

System.setProperty("com.mchange.v2.log.MLog", "com.mchange.v2.log.FallbackMLog");
System.setProperty("com.mchange.v2.log.FallbackMLog.DEFAULT_CUTOFF_LEVEL", "WARNING");

// Create db pool
final ComboPooledDataSource cpds = new ComboPooledDataSource() ;

// Driver
cpds.setDriverClass( "com.microsoft.sqlserver.jdbc.SQLServerDriver" ); // loads the jdbc driver                     

// Url
cpds.setJdbcUrl( "jdbc:xxxx://xxxxx:xxxx;database=xxxxx;" );

// Username / Password
cpds.setUser( "xxxx" ) ;
cpds.setPassword( "xxxx" ) ;                                  

// Start size of db pool
cpds.setInitialPoolSize( 8 );

// Min and max db pool size
cpds.setMinPoolSize(  8 ) ;
cpds.setMaxPoolSize( 10 ) ;

// ????
cpds.setNumHelperThreads( 5 ) ;

// Max allowed time to execute statement for a connection
// @See http://stackoverflow.com/questions/14730379/apparent-deadlock-creating-emergency-threads-for-unassigned-pending-tasks
cpds.setMaxAdministrativeTaskTime( 60 ) ;

// ?????
cpds.setMaxStatements( 180 ) ;
cpds.setMaxStatementsPerConnection( 180 ) ;

// ?????
cpds.setUnreturnedConnectionTimeout( 60 ) ;

// ?????
cpds.setStatementCacheNumDeferredCloseThreads(1);

// We make a test : open and close opened connection
cpds.getConnection().close() ;

After these changes, after the execution of some jobs, the application freezes for several ten of seconds and then displays this error message:

[WARNING] A task has exceeded the maximum allowable task time. Will interrupt() thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#4,5,main]], with current task: com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@4128b402
[WARNING] Thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#4,5,main]] interrupted.
[WARNING] A task has exceeded the maximum allowable task time. Will interrupt() thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#3,5,main]], with current task: com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@5d6aab6d
[WARNING] Thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#3,5,main]] interrupted.
[WARNING] A task has exceeded the maximum allowable task time. Will interrupt() thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#0,5,main]], with current task: com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@70a3328f
[WARNING] Thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#0,5,main]] interrupted.
  1. Why does the application work perfectly in a development environment and encounters these problems during production?
  2. Above all, how to remedy it?
  3. When a connection reaches the maximum number of statements defined with setMaxStatements and setMaxStatementsPerConnection, what happens to it? The connection is closed then another takes over while another one is created?
  4. I did not quite understand the impact that the setStatementCacheNumDeferredCloseThreads function has on my application.

Thank you !

swaldman commented 7 years ago

Hi!

It looks like you've posted this issue on Stack Overflow as well, where I've responded at length.

I'll close this issue here, and we can continue the conversation there.