在 java se 应用程序上与 C3P0 发生死锁

DEADLOCK with C3P0 on java se application

我在 Java SE 应用程序中使用的 c3p0 库(版本 0.9.5.2)遇到了严重问题。

我的应用程序使用线程池通过执行作业来并行化任务。

每个作业使用数据库读取、更新或删除数据至少一次(在极少数情况下但可能发生)超过 10,000 次。

因此,我在我的项目 c3p0 库中包含了一个到数据库的连接池,以便我的线程池中的所有工作人员都可以同时与之交互。

在我的开发环境 (OSX 10.11) 上 运行 我的应用程序没有任何问题,但是当我在生产环境中 运行 它时 (Linux Debian 8) 我遇到了一个大问题!确实它冻结了....

起初是死锁,跟踪堆栈如下:

[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.C3P0PooledConnectionPoolPooledConnectionResourcePoolManager.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.access0(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.C3P0PooledConnectionPoolPooledConnectionResourcePoolManager.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.access0(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.C3P0PooledConnectionPoolPooledConnectionResourcePoolManager.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.access0(BasicResourcePool.java:44)
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)

后来我根据不同网站的建议做了一些修改:

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 
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() ;

经过这些修改后,在执行某些作业后,应用程序会冻结数十秒,然后显示此错误消息:

[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.BasicResourcePoolDestroyResourceTask@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.BasicResourcePoolDestroyResourceTask@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.BasicResourcePoolDestroyResourceTask@70a3328f
[WARNING] Thread [Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx9l1ao3z0x88z7oi|4dd889bd]-HelperThread-#0,5,main]] interrupted.

我的问题是:

  1. 为什么应用程序在开发环境中运行完美,而在生产环境中遇到这些问题?
  2. 最重要的是,如何补救?
  3. 当连接达到 setMaxStatements 和 setMaxStatementsPerConnection 定义的最大语句数时,会发生什么情况?连接关闭然后另一个接管,同时创建另一个连接?
  4. 我不太了解 setStatementCacheNumDeferredCloseThreads 函数对我的应用程序的影响。

非常感谢!祝你有个美好的一天。

好的。所以。你的基本问题很简单。在您的生产环境中,Connection 获取尝试最终会冻结,也就是说它们既没有成功也没有因异常而失败,它们只是挂起。最终,这就是您必须调试的内容:为什么当 c3p0 尝试连接到您的生产数据库时,有时对 Driver.connect() 的调用会挂起?无论是什么原因造成的,都不在 c3p0 的控制范围内。您可能会在 DBMS 端达到总连接数的限制(不是来自此应用程序,您的 maxPoolSize 非常适中,但也许您的生产服务器已过度扩展)。如果您 运行 在较旧的 JVM 上,则存在 SQLServer 挂起的已知问题,请参见例如JDBC connection hangs with no response from SQL Server 2008 r2 Driver.getConnection hangs using SQLServer driver and Java 1.6.0_29 但我怀疑你现在是 运行 Java 6,而且我不知道最近的问题。无论如何,从您的日志中可以清楚地看出正在发生的事情:c3p0 正在尝试从 DBMS 获取连接,DBMS 无限期挂起,最终所有 c3p0 的辅助线程都被挂起的任务饱和,您会看到 APPARENT DEADLOCK。要解决此问题,您必须调试为什么 JDBC 驱动程序尝试连接到 DBMS 有时会挂起。

你在搜索随机故障排除帖子后所做的大部分事情与这个问题不是很相关。确实导致您的日志更改的是此设置

cpds.setMaxAdministrativeTaskTime( 60 );

这以一种丑陋的方式解决了这个问题。如果任务挂起很长一段时间,该设置会导致 c3p0 interrupt() 它所在的线程 运行 并放弃它。这可以防止死锁,但不能解决死锁的原因。

不过,两个日志之间有一个令人惊讶的变化。替换 APPARENT DEADLOCK 的报告显示 'task has exceeded the maximum allowable task time' 是可以预期的。但有趣的是,在您的第二个日志中,获得 interrupt()ed 的任务不是连接获取尝试,而是连接销毁尝试。我不知道为什么会发生变化,但核心问题是相同的:您的 JDBC 驱动程序与您的 DBMS 交互的尝试无限期地冻结,既不会成功也不会迅速失败并出现异常。这就是你需要调试的。

如果您无法解决问题,您也许可以解决它。这非常丑陋,但如果你减少 maxAdministrativeTaskTime(比如 30)并增加 numHelperThreads(比如 20),你可以在很大程度上消除应用程序暂停,只要冻结不频繁。增加 numHelperThreads 会增加 c3p0 的线程池在被完全阻塞之前可以容忍的冻结任务数。减少 maxAdministrativeTaskTime 会缩短阻塞的寿命。显然,正确的做法是调试 JDBC 驱动程序和 DBMS 之间的问题。但是,如果事实证明那是不可能的,有时您最好采用变通办法。

我会消除(至少现在)这三个设置:

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

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

前两个打开语句缓存,从您的应用程序的性能角度来看,这可能是合意的,也可能不是合意的。但它们增加了 c3p0 与 DBMS 交互的复杂性。 SQLServer(在几个数据库中)在连接的多线程使用方面非常脆弱(至少根据 JDBC 规范的早期版本,这应该是合法的,但太糟糕了)。将 statementCacheNumDeferredCloseThreads 设置为 1 可确保语句缓存不会在连接正在使用时尝试关闭过期语句,从而防止冻结,APPARENT DEADLOCKs 通常显示为hung 语句关闭任务,不是你的问题。如果打开语句缓存,一定要将 statementCacheNumDeferredCloseThreads 设置为 1 以避免冻结。但最安全、最明智的做法是在调试主要问题之前避免语句缓存的所有复杂性。您可以稍后恢复这些设置以测试它们是否可以提高应用程序的性能。 (如果您确实重新打开了语句缓存,我的建议是您只设置 maxStatementsPerConnection,不要设置全局 maxStatements,或者如果您同时设置两者,请设置 per-Connection 限制到一个比全局限制小得多的值。但是,现在,再次关闭所有这些东西。)

要解决您的具体问题:

  1. Why does the application work perfectly in a development environment and encounters these problems during production?

这是一条重要线索,您可以在调试 JDBC 驱动程序和 DBMS 之间的挂起时使用它。与您的生产服务器有关的某些事情会导致挂起,但不会出现在您的开发服务器中。这可能只是开发服务器负载相对较低而生产服务器负载较高的问题。但是在提供挂起线索的设置中可能存在其他差异。

  1. Above all, how to remedy it?

调试挂起。如果您无法调试挂起,请尝试使用更短的 maxAdministrativeTaskTime 和更大的 numHelperThreads.

解决问题
  1. 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?

连接无法到达任何这些东西。这些是描述语句缓存的参数。当缓存语句的总数达到 maxStatements 时,关闭 least-recently-used 缓存语句(只是语句,而不是它的连接)。当连接的 maxStatementsPerConnection 被击中时,onnection 的 least-recently-used 缓存语句已关闭(但连接本身保持打开和活动状态)。

  1. I did not quite understand the impact that the setStatementCacheNumDeferredCloseThreads function has on my application.

如果您正在使用语句缓存(同样,我建议您暂时将其关闭),此设置可确保过期语句(见上文)在其父连接正在使用时不会 close()ed通过其他线程。该设置创建一个专用线程(或多个线程),其唯一目的是等待不再使用连接并仅在那时关闭它们(因此,语句缓存延迟关闭线程)。

希望对您有所帮助!

更新:您遇到的错误与Java 6 bug 非常相似。如果你是 运行 Java 6,那么你很幸运,修复可能只是将你的生产 JVM 更新到最新版本的 Java 6.