C3PO：客户端在等待获取资源时超时答案

【问题标题】：C3PO: A client timed out while waiting to acquire a resourceC3PO：客户端在等待获取资源时超时
【发布时间】：2021-01-10 06:34:22
【问题描述】：

当前设置：

服务主机 (Java) 连接到 (JDBC) 主数据库 (MySQL RW) 并具有工作程序（只读）以确保可靠性。连接管理由 C3PO 处理

场景：

如果发生翻转，我需要将其中一名工作人员提升为主数据库。当前主节点变为只读，新主节点提升为读写。我希望可靠地，自动将 C3P0 连接池刷新到新的主数据库。哪种现在有效，但在某些情况下被破坏了。

技术：服务有一个数据库主机作为 cname，它会在翻转时更新。在 DNS 更改传播且新 db 为 RW 之前，所有连接都会失败。尝试在连接池上无限地设置 C3PO 重试，直到连接 RW 通过（acquireRetryAttempts）

现有 C3PO 配置：

Generic configuration, inherited by primary and worker DB
    <property name="maxIdleTime" value="44000"/>
    <property name="idleConnectionTestPeriod" value="30"/>
    <property name="maxStatements" value="50"/>
    <property name="minPoolSize" value="3"/>
    <property name="maxPoolSize" value="3"/>
    <property name="acquireIncrement" value="2"/>
    <property name="checkoutTimeout" value="15000"/>
    <property name="acquireRetryDelay" value="1000"/>

Primary DB specific config
    <property name="acquireRetryAttempts" value="0"/>
    <property name="minPoolSize" value="3"/>
    <property name="maxPoolSize" value="5"/>
    <property name="testConnectionOnCheckout" value="true"/>
    <property name="connectionTesterClassName" value="${Custom.connectionTesterClassName}"/>

问题：

自定义连接测试器检查连接是否可写（@@global.read_only）并返回连接无效或有效。 C3PO 遇到问题，它将按照中间日志中的说明翻新（杀死并重新初始化）连接池。最终，它会检查所有 (max_pool_size, 5) 个连接（在 4-5 分钟内），并在连接不检查回池的状态下挂起。这会导致所有后续数据库连接检查超时并失败，如最终日志中所述。强制重启服务，以便重新初始化 C3PO 池。

理想情况下，如果connectionTesterClassName 返回 false 或在idleConnectionTestPeriod 上或在某个随机时间段，我需要连接池继续终止和重新初始化。由于已签出连接，因此它们不会属于空闲连接，也不会刷新。

尝试使用unreturnedConnectionTimeout 和debugUnreturnedConnectionStackTraces 进行调试，如C3PO documentation 中所述，但没有成功。

日志：

中间日志

com.mchange.v2.resourcepool.BasicResourcePool: Resource [com.mchange.v2.c3p0.impl.NewPooledConnection@24e7ebec] could not be refurbished in preparation for checkout. Will try to find a better resource.
    (C3P0PooledConnectionPoolManager[identityToken->2tyqoiac1gfqk68krloa8|7e2c64]-HelperThread-#6) com.mchange.v2.resourcepool.BasicResourcePool: Preparing to destroy resource: com.mchange.v2.c3p0.impl.NewPooledConnection@24e7ebec
23 Sep 2020 22:06:23,780 [DEBUG]com.mchange.v2.resourcepool.BasicResourcePool: acquire test -- pool size: 0; target_pool_size: 3; desired target? 1
23 Sep 2020 22:06:23,780 [DEBUG]  com.mchange.v2.resourcepool.BasicResourcePool: awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@4b52cf0c
23 Sep 2020 22:06:23,780 [DEBUG]  (C3P0PooledConnectionPoolManager[identityToken->2tyqoiac1gfqk68krloa8|7e2c64]-HelperThread-#6) com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool: Preparing to destroy PooledConnection: com.mchange.v2.c3p0.impl.NewPooledConnection@24e7ebec
23 Sep 2020 22:06:23,780 [DEBUG]  (C3P0PooledConnectionPoolManager[identityToken->2tyqoiac1gfqk68krloa8|7e2c64]-HelperThread-#6) com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool: Successfully destroyed PooledConnection: com.mchange.v2.c3p0.impl.NewPooledConnection@24e7ebec
23 Sep 2020 22:06:23,780 [DEBUG]  (C3P0PooledConnectionPoolManager[identityToken->2tyqoiac1gfqk68krloa8|7e2c64]-HelperThread-#6) com.mchange.v2.resourcepool.BasicResourcePool: Successfully destroyed resource: com.mchange.v2.c3p0.impl.NewPooledConnection@24e7ebec
23 Sep 2020 22:06:23,781 [DEBUG]  com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool: Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@7fff041e] on CHECKOUT.
23 Sep 2020 22:06:23,782 [INFO]  ReadWriteConnectionTester: Connection com.mchange.v2.c3p0.impl.NewProxyConnection@21eb35f6 [wrapping: com.mysql.jdbc.JDBC4Connection@44732406] is read only!
23 Sep 2020 22:06:23,782 [DEBUG]  com.mchange.v2.c3p0.impl.NewProxyConnection: com.mchange.v2.c3p0.impl.NewProxyConnection@21eb35f6 [wrapping: null]: close() called more than once.
23 Sep 2020 22:06:23,782 [DEBUG]  com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool: Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@7fff041e] on CHECKOUT has FAILED.
java.sql.SQLException: Connection is invalid

最终日志：

org.hibernate.engine.jdbc.internal.LogicalConnectionImpl: Obtaining JDBC connection
com.mchange.v2.resourcepool.BasicResourcePool: acquire test -- pool is already maxed out. [managed: 5; max: 5]
com.mchange.v2.resourcepool.BasicResourcePool: awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@4b52cf0c

com.mchange.v2.sql.SqlUtils: Converting Throwable to SQLException...
com.mchange.v2.resourcepool.TimeoutException: A client timed out while waiting to acquire a resource from com.mchange.v2.resourcepool.BasicResourcePool@43aeb5e0 -- timeout at awaitAvailable()
    at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1467) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140) ~[c3p0-0.9.5.1.jar:0.9.5.1]

org.hibernate.engine.jdbc.spi.SqlExceptionHelper: Could not open connection [n/a]
java.sql.SQLException: An attempt by a client to checkout a Connection has timed out.
    at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118) ~[mchange-commons-java-0.2.10.jar:0.2.10]
    at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:77) ~[mchange-commons-java-0.2.10.jar:0.2.10]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:690) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at org.springframework.jdbc.datasource.lookup.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:164) ~[spring-jdbc-4.3.24.RELEASE.jar:4.3.24.RELEASE]
    at org.hibernate.service.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:141) ~[hibernate-core-4.2.2.Final.jar:4.2.2.Final]
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292) ~[hibernate-core-4.2.2.Final.jar:4.2.2.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214) ~[hibernate-core-4.2.2.Final.jar:4.2.2.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157) ~[hibernate-core-4.2.2.Final.jar:4.2.2.Final]
    at org.hibernate.internal.SessionImpl.connection(SessionImpl.java:550) ~[hibernate-core-4.2.2.Final.jar:4.2.2.Final]

Caused by: com.mchange.v2.resourcepool.TimeoutException: A client timed out while waiting to acquire a resource from com.mchange.v2.resourcepool.BasicResourcePool@43aeb5e0 -- timeout at awaitAvailable()
    at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1467) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685) ~[c3p0-0.9.5.1.jar:0.9.5.1]
    ... 51 more

org.hibernate.engine.jdbc.spi.SqlExceptionHelper: SQL Error: 0, SQLState: null
org.hibernate.engine.jdbc.spi.SqlExceptionHelper: An attempt by a client to checkout a Connection has timed out

【问题讨论】：

标签： mysql hibernate c3p0

【解决方案1】：

所以，这不是“翻新（杀死并重新初始化）连接池”的正确解释。

游泳池正试图在这里“翻新”的是个人Connection。它试图更新Connection 以供客户使用。由于您已将 testConnectionOnCheckout 设置为 true，并且数据库已“翻转”，因此您的 ReadWriteConnectionTester 将声明当前池中的每个 Connection 无效（因为只读），直到池用完 Connections 来尝试或用完时间到期到客户端超时。

当您的 ReadWriteConnectionTester 发现 Connection 无效时，它是否返回 ConnectionTester.CONNECTION_IS_INVALID 或 ConnectionTester.DATABASE_IS_INVALID？您应该希望它返回 ConnectionTester.DATABASE_IS_INVALID 以使其重置整个池。

【讨论】：

为了清楚起见，在检测 RO 模式时，我应该返回 ConnectionTester.DATABASE_IS_INVALID，这将继续杀死并刷新整个连接池。以更大的重试延迟（可能是acquireRetryDelay = 30000）继续无限重试（acquireRetryAttempts = 0）有没有更好的方法来实现相同的目标？
如果您返回 ConnectionTester.DATABASE_IS_INVALID，它将重置池。它将杀死所有未完成的连接，并尝试替换minPoolSize。当它尝试替换连接时，如果 DBMS 尚未准备好，则可能一轮获取尝试失败。很酷，它会在下一个客户端请求时重试，直到最终成功并可以重新组装。
我明白了，有道理。但是，如果 ReadWriteConnectionTester 返回一个单独的连接CONNECTION_IS_INVALID，它是否会终止并重新初始化连接（以保持最小池大小）？我已经看到在新的主数据库（RW）上出现连接的实例（mysql：show process_list;）。但是，有时随着时间的推移，我会看到如上所示的超时。
知道了，会试试的。感谢您的投入史蒂夫。我看到两者之间的性能权衡。非常感谢您的帮助
连接池仍然因史蒂夫相同的错误而失败。我监视了 mysql 数据库上的进程，我看到了几分钟 writer user 线程不断杀死和重生（因为 db 设置为 RO 模式）并且他们在一段时间内放弃了。我没有看到新线程被杀死并重新连接（显示进程列表），它们会挂起很长时间，直到它们被maxIdleTime 属性搅动。假设它在某个时候成功，是否可以从 C3PO 做一些事情来无限地自动刷新。