使用c3p0,Oracle和Hibernate重复出现明显的死锁

Question

我们的生产系统经常出现明显的僵局,我们似乎无法深入到底.我们无法跟踪在线用户数量的任何相关性,似乎我们的可用连接不足.

我们有一个Java EE应用程序通过Hibernate和c3p0连接到Oracle.我们的c3p0配置是:

minPoolSize=10
maxPoolSize=300
initialPoolSize=30
acquireIncrement=10
maxIdleTime=1800
maxStatementsPerConnection=0
numHelperThreads=5

明显的死锁日志输出总是看起来或多或少像这样:

[com.mchange.v2.async.ThreadPoolAsynchronousRunner] (Timer-1) com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@4c9f1b4d -- APPARENT DEADLOCK!!! Complete Status:
    Managed Threads: 5
    Active Threads: 5
    Active Tasks:
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7fe1ab86 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@38c42c01 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@572512c4 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4)
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@42f32e8e (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6b758ef8 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#3)
    Pending Tasks:
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@72fd72e5
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@5d82535d
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@172f2ea1
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@1a9e57eb
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@20ee5a35

实际的池线程堆栈跟踪有所不同,我在下面添加了一些示例:

Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4,5,jboss]
            java.lang.AbstractStringBuilder.<init>(AbstractStringBuilder.java:45)
            java.lang.StringBuilder.<init>(StringBuilder.java:80)
            oracle.net.ns.Packet.<init>(Packet.java:513)
            oracle.net.ns.ConnectPacket.<init>(ConnectPacket.java:64)
            oracle.net.ns.NSProtocol.connect(NSProtocol.java:278)
            oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1042)
            oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:301)
            oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:531)
            oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:221)
            oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
            oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:503)
            com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)

Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,jboss]
            oracle.jdbc.driver.T4CTTIoauthenticate.processRPA(T4CTTIoauthenticate.java:491)
            oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:295)
            oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:186)
            oracle.jdbc.driver.T4CTTIoauthenticate.doOSESSKEY(T4CTTIoauthenticate.java:390)
            oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:356)
            oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:531)
            oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:221)
            oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
            oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:503)
            com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
            com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:1

Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,jboss]
            oracle.net.ns.NSProtocol.connect(NSProtocol.java:346)
            oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1042)
            oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:301)
            oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:531)
            oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:221)
            oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
            oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:503)
            com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
            com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
            com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
            com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
            com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
            com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
            com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

我们调查的地方有什么建议吗？这是c3p0,我们的查询,我们的代码,数据库？

Answer 1

因此，您的辅助线程显然因连接获取而饱和。这意味着在很长一段时间内多次尝试获取连接既不会成功，也不会因异常而失败。这最终是您需要调试的问题。

我要做的第一件事是升级到 c3p0-0.9.2.1，它使用“分散”获取任务，可以在获取失败时节省对池线程的使用。第二个建议可能是将名为 numHelperThreads 的 c3p0 配置参数增加到比其默认值 3 甚至您正在使用的 5 高得多的值。看起来您的线程实际上被占用在连接获取的各个阶段，因此增加可获取连接的“通道”数量可能会有所帮助。[但请参阅下面的后记！]

但最终问题将归结为为什么连接获取完成得如此缓慢（对于要声明的明显死锁，在大约 10 秒的时间内没有任何获取会成功）。这可能是数据库或网络问题。

但请尝试升级到 0.9.2 并增加 numHelperThreads。[numHelperThreads 的默认值可能已过时；在多核机器时代，专用于 IO 绑定任务的线程池可能应该是核心数量的倍数]这些调整可能会很好地解决问题，或者带来有关下一步要寻找的更好信息。

祝你好运！

ps 我猜测您显示的线程堆栈跟踪实际上并不是在建立明显死锁期间的堆栈跟踪。很难计算这些时间，因为在 c3p0 宣布之前你不知道明显的死锁即将发生。我敢打赌，在死锁中，这些堆栈跟踪彼此更加相似，并且正在等待某种 IO。