java - 分析 Spring/JPA/Mysql/Tomcat 应用程序中的连接关闭异常

Question

问题

我最近负责一个 Java Web 应用程序，其中的代码已经编写好并就位。该应用程序接收中等高流量，并且每天上午 11 点至下午 3 点之间的流量高峰时段。
该应用程序使用 Spring、JPA(Hibernate)、MYSQL DB。
Spring 已被配置为使用 tomcat jdbc 连接池来建立与 DB 的连接。
(具体配置见文末)

过去几天，在应用程序的高峰负载时段，由于 tomcat 对请求没有响应，应用程序一直在宕机。它需要多次重启 tomcat。

通过 tomcat catalina.out 日志，我注意到了很多

Caused by: java.sql.SQLException: Connection has already been closed.
    at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:117)
    at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:109)
    at org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(DisposableConnectionFacade.java:80)
    at com.sun.proxy.$Proxy28.prepareStatement(Unknown Source)
    at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:505)
    at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:423)
    at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
    at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
    at org.hibernate.loader.Loader.doQuery(Loader.java:673)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
    at org.hibernate.loader.Loader.loadCollection(Loader.java:1994)
    ... 115 more

这些经常在崩溃前出现。

在这些异常之前更早一点，我注意到大量 Connections 在 Connection Closed 异常之前被放弃。

WARNING: Connection has been abandoned PooledConnection[com.mysql.jdbc.Connection@543c2ab5]:java.lang.Exception
    at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1065)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:782)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:618)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
    at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
    at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
    at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
    at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
    at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)

这些似乎经常出现在 Connection Closed 异常之前。这些似乎是日志中即将到来的厄运的第一个症状。

分析

根据日志，我开始查看是否有任何可能导致问题的连接池配置/mysql 配置。
浏览了几篇优秀的文章，展示了生产环境池的调整。友情链接 1 & 2

通过这些文章，我注意到:

JHanik 的文章(链接 1)中的以下行提到了这一点

Setting the value of abandonWhenPercentageFull to 100 would mean that connections are not > considered abandoned unless we've reached our maxActive limit.

我认为这对我来说可能很重要，因为我看到很多连接被放弃了。

我的 max_connections 设置与推荐的不匹配(在链接 2 中)

mysql max_connections should be equal to max_active+max_idle

我试过的

因此，根据文章中的建议，我做了以下两件事:

将放弃时百分比全更改为 100

在我的 MYSQL 服务器中，max_connections 设置为 500。将其增加到 600
在我的连接池设置中，max_active 为 200，max_idle 为 50。
将其更改为 max_active=350, max_idle = 250

这没有帮助

第二天，在高峰时段进行了以下观察:

Tomcat 没有宕机。该应用程序在整个高峰时段都保持运行状态。
然而，性能变得越来越差，然后该应用程序几乎无法使用，即使它并没有真正下降。

DB 连接池虽然增加了大小，但得到了充分利用，我可以看到 350 个与 DB 的 Activity 连接。

最后，我的问题:

从应用程序服务器建立数据库连接的方式显然存在问题。
所以我有两个方向来推进这个分析。

我的问题是我应该服用哪些？

1. 问题不在于连接池设置。代码是导致问题的原因

代码中可能存在未关闭数据库连接的地方。这导致大量连接被打开。

代码使用在每个 Dao 类中扩展的 GenericDao。 GenericDao 使用 Spring 的 JpaTemplate 来获取一个 EntityManager 实例，该实例又用于所有数据库操作。我的理解是使用 JpaTemplate 处理内部关闭数据库连接的细节。

那么，我应该在哪里寻找可能的连接泄漏？

2. 问题在于连接池/mysql 配置参数。但是，我所做的优化需要进一步调整

如果是，我应该查看哪些参数？
我是否应该收集一些数据来为我的连接池确定更合适的值。 (例如，对于 max_active、max_idle、max_connections)

附录:完整的连接池配置

   <bean id="dataSource" class="org.apache.tomcat.jdbc.pool.DataSource" destroy-method="close">
        <property name="driverClassName" value="com.mysql.jdbc.Driver" />
        <property name="url" value="jdbc:mysql://xx.xx.xx.xx" />
        <property name="username" value="xxxx" />
        <property name="password" value="xxxx" />
        <property name="initialSize" value="10" />
        <property name="maxActive" value="350" />
        <property name="maxIdle" value="250" />
        <property name="minIdle" value="90" />
        <property name="timeBetweenEvictionRunsMillis" value="30000" />
        <property name="removeAbandoned" value="true" />
        <property name="removeAbandonedTimeout" value="60" />
        <property name="abandonWhenPercentageFull" value="100" />
        <property name="testOnBorrow" value="true" />
        <property name="validationQuery" value="SELECT 1" />
        <property name="validationInterval" value="30000" />
        <property name="logAbandoned" value="true" />
        <property name="jmxEnabled" value="true" />
    </bean>

Answer 1

这对于 OP 来说太晚了，但也许将来会对其他人有所帮助:

我在具有长时间运行的批处理作业的生产环境中遇到了类似的问题。问题是如果您的代码需要比属性指定的时间更长的连接:
name="removeAbandonedTimeout" value="60
并且您已启用:
<property name="removeAbandoned" value="true" />
然后它将在 60 秒后的处理过程中断开连接。一种可能的解决方法(对我不起作用)是启用拦截器:
jdbcInterceptors="ResetAbandonedTimer"
这将为发生的每次读/写重置该连接的废弃计时器。不幸的是，在我的情况下，在将任何内容读/写到数据库之前，处理有时仍会比超时时间更长。所以我被迫要么增加超时长度，要么禁用 removeAbandonded(我选择了前一种解决方案)。

希望这可以帮助其他人，如果他们遇到类似的事情!