c3p0 连接检查有时需要 15 分钟才能失败

Question

使用 c3p0 遇到问题。在大多数情况下工作正常，但在防火墙后面的 prod env 中偶尔无法检查连接。问题是识别连接不可用需要 15 分钟。在这 15 分钟的时间间隔内，池没有耗尽，因为其他连接正在被签出并愉快地使用。

日志：

23 Apr 2015 09:08:16.426 [EventProcessor-1] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282] on CHECKOUT.

15 分钟后：

23 Apr 2015 09:23:43.073 [EventProcessor-1] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282] on CHECKOUT has FAILED. 
java.sql.SQLException: Connection is invalid
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:572) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.finerLoggingTestPooledConnection(C3P0PooledConnectionPool.java:451) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.finerLoggingTestPooledConnection(C3P0PooledConnectionPool.java:443) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishResourceOnCheckout(C3P0PooledConnectionPool.java:336) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.resourcepool.BasicResourcePool.attemptRefurbishResourceOnCheckout(BasicResourcePool.java:1727) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:553) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:756) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:683) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140) [c3p0-0.9.5.jar:0.9.5]

然后是更多日志：

23 Apr 2015 09:23:43.073 [EventProcessor-1] DEBUG c.m.v.r.BasicResourcePool - A resource could not be refurbished for checkout. [com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282] 
java.sql.SQLException: Connection is invalid
...
23 Apr 2015 09:23:43.074 [EventProcessor-1] DEBUG c.m.v.r.BasicResourcePool - Resource [com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282] could not be refurbished in preparation for checkout. Will try to find a better resource. 
23 Apr 2015 09:23:43.074 [C3P0PooledConnectionPoolManager[identityToken->67oy4j981qzvkd716hgow4|4177fc5c]-HelperThread-#2] DEBUG c.m.v.r.BasicResourcePool - Preparing to destroy resource: com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282 
23 Apr 2015 09:23:43.074 [EventProcessor-1] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@41318736] on CHECKOUT. 
23 Apr 2015 09:23:43.074 [C3P0PooledConnectionPoolManager[identityToken->67oy4j981qzvkd716hgow4|4177fc5c]-HelperThread-#2] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Preparing to destroy PooledConnection: com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282 
23 Apr 2015 09:23:43.076 [C3P0PooledConnectionPoolManager[identityToken->67oy4j981qzvkd716hgow4|4177fc5c]-HelperThread-#2] DEBUG c.m.v.c3p0.impl.NewPooledConnection - Failed to close physical Connection: oracle.jdbc.driver.T4CConnection@25145762 
java.sql.SQLRecoverableException: IO Error: Broken pipe
    at oracle.jdbc.driver.T4CConnection.logoff(T4CConnection.java:612) ~[ojdbc6_g-11.2.0.1.0.jar:11.2.0.1.0]
    at oracle.jdbc.driver.PhysicalConnection.close(PhysicalConnection.java:5094) ~[ojdbc6_g-11.2.0.1.0.jar:11.2.0.1.0]
    at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:642) [c3p0-0.9.5.jar:0.9.5]

c3p0 配置：

        ComboPooledDataSource ods = new ComboPooledDataSource();
...
        ods.setInitialPoolSize(5);
        ods.setMinPoolSize(5);
        ods.setMaxPoolSize(10);
        ods.setMaxStatements(50);

        ods.setTestConnectionOnCheckout(true);

所以没有什么太异国情调了。我知道连接丢失是可能的，因此在结帐时测试连接。任何想法为什么需要这么长时间来验证/失败连接？我们正在使用 Oracle 数据库。 谢谢。

Answer 1

看起来这是一种情况，当连接被防火墙终止时，根本没有任何响应发回，即使是没有数据的 TCP ACK。在这种情况下，验证连接的查询将永远不会返回。这是在 socket/jdbc 驱动级别。

解决方案：

• 找出防火墙断开策略（在我们的例子中是 1 小时）
• 设置 c3p0.maxConnectionAge 属性以强制 c3p0 每 X 秒重新连接一次。

Answer 2

首先，我假设您已经确认在您的日志消息之间没有签出该连接。显然，您会期待很多消息，例如...

Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@5a886282] on CHECKOUT.

...在失败之前的最后一条消息之前。许多这些消息会更早地出现。理想情况下，只有在故障之前的最后一条消息应该比您看到的 15 分钟更接近检测到故障。

假设这是这样的最后一条消息，那么问题与您的连接如何消亡有关。 c3p0 运行测试，然后等待成功完成或异常。如果您的 Connection 以某种方式终止，以至于 Connection 测试仅挂起 15 分钟，那么您可能会看到您所看到的。

这里有一些建议。

1. 最好使用 c3p0 的 idleConnectionTestPeriod 在客户端结帐之前检测这些故障，从而减少客户端长时间挂起的可能性。 （您也可以在入住时进行测试。）
2. 找出正在运行的连接测试类型。您使用的是 c3p0 0.9.5，因此如果您的驱动程序支持它，默认测试是调用 Connection.isValid()，这应该很快。我在任何日志中都没有看到您引用了实际测试失败的堆栈跟踪（也许它是一个截断的根本原因异常？它肯定会由一个名为 com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool 的记录器在 FINER/DEBUG 级别记录）验证（从堆栈跟踪）您的驱动程序正在使用快速isValid() 连接测试，而不是 c3p0 的慢速默认连接测试。如果不是（可能是因为您的驱动程序不支持），那么请考虑设置一个快速的preferredTestQuery。
3. 您可以尝试maxAdministrativeTaskTime，但这只有在挂起的连接测试响应中断（）调用时才可能真正有帮助。

无论如何，我希望这不是完全没用！