java - MySQL/Hibernate - 如何调试不断掉线的 MySQL 池连接？

Question

几个月来，我的 Web 应用程序运行顺利，但在过去的一两周内，它不断断开与 MySQL 服务器的连接。我不是 DBA，不知道如何调试。

这是我所知道的:

1. 连接似乎每隔几个小时就会断开一次。有时在白天，但总是在夜间。
2. 我的实验室有一台 MySQL 服务器，用于托管多个应用程序的数据库。
3. 目前，我们有 46 个连接到 MySQL 服务器。
4. 据我所知，没有其他应用程序遇到此问题。
5. 我的应用程序使用与另一个应用程序相同的堆栈、配置甚至代码来连接到数据库 - 这个另一个应用程序每天支持大约 200 个用户，并且自 2013 年以来一直平稳运行。

6. 两个应用程序都使用 Hibernate ORM；这是我所知道的唯一配置:

   <!-- TomcatJDBCConnectionProvider class is common to both applications -->
   <property name="hibernate.connection.provider_class">org.hibernate.connection.TomcatJDBCConnectionProvider</property>
   <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
   <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property>
   <property name="hibernate.connection.pool_size">5</property>
   <property name="hibernate.current_session_context_class">thread</property>
   <property name="hibernate.tomcatJdbcPool.validationQuery">SELECT 1</property>
   <property name="hibernate.tomcatJdbcPool.testOnBorrow">true</property>
   <property name="hibernate.enable_lazy_load_no_trans">true</property>
   

7. 这个问题大约是在有人试图使用应用程序的 RESTful API 下载我们的数据时开始的。这个用户——实际上是一个协作者——有一个小脚本迭代特定表中的每一行并请求所有元数据。

8. 这个问题也是在我的实验室开始提供 Coursera 大规模开放在线类(class)的同时开始的。我不知道这些数字是多少，但网站上的实际使用量肯定有所增加。

我知道这是一个广泛的问题，但我真的不知道如何进行调试。任何建议表示赞赏。

编辑:

挖掘其他应用程序的 ServletContextListener，我发现我的 contextDestroyed 函数没有这段代码:

// TODO: Find memory leak that requires server to be restarted after hot deploying several (3?) times.
Set<Thread> threadSet = Thread.getAllStackTraces().keySet();
for (Thread t : threadSet) {
    if (t.getName().contains("Abandoned connection cleanup thread")) {
        synchronized (t) {
            System.out.println("Forcibly stopping thread to avoid memory leak: " + t.getName());
            t.stop(); // don't complain, it works
        }
    }
}

它似乎在遍历堆栈跟踪，找到带有文本 "Abandoned connection cleanup thread" 的那个并手动停止它。好像和我的问题有关？

2015 年 9 月 21 日编辑:

本周末我的申请失败了。这是昨天错误日志中的堆栈跟踪(当我相信它发生故障时):

20-Sep-2015 14:22:18.160 SEVERE [http-apr-8080-exec-35] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [edu.mssm.pharm.maayanlab.Harmonizome.api.GeneMetadataApi] in context with path [/Harmonizome] threw exception
 org.hibernate.exception.GenericJDBCException: Could not open connection
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:304)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:169)
    at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67)
    at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:160)
    at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1395)
    at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:224)
    at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:545)
    at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:124)
    at org.hibernate.collection.internal.PersistentSet.iterator(PersistentSet.java:180)
    at edu.mssm.pharm.maayanlab.Harmonizome.json.serdes.GeneMetadataSerializer.serialize(GeneMetadataSerializer.java:54)
    at edu.mssm.pharm.maayanlab.Harmonizome.json.serdes.GeneMetadataSerializer.serialize(GeneMetadataSerializer.java:23)
    at com.google.gson.TreeTypeAdapter.write(TreeTypeAdapter.java:70)
    at com.google.gson.Gson.toJson(Gson.java:600)
    at com.google.gson.Gson.toJson(Gson.java:579)
    at com.google.gson.Gson.toJson(Gson.java:534)
    at edu.mssm.pharm.maayanlab.Harmonizome.api.GeneMetadataApi.doGet(GeneMetadataApi.java:65)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:622)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:673)
    at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2440)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.tomcat.jdbc.pool.PoolExhaustedException: [http-apr-8080-exec-35] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:5; busy:5; idle:0; lastwait:30000].
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:672)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:186)
    at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:127)
    at org.hibernate.connection.TomcatJDBCConnectionProvider.getConnection(TomcatJDBCConnectionProvider.java:208)
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:297)

这是我在 MySQL 中的连接变量:

mysql>  SHOW VARIABLES LIKE '%connect%';
+-----------------------------------------------+-----------------+
| Variable_name                                 | Value           |
+-----------------------------------------------+-----------------+
| character_set_connection                      | utf8            |
| collation_connection                          | utf8_general_ci |
| connect_timeout                               | 5               |
| default_master_connection                     |                 |
| extra_max_connections                         | 1               |
| init_connect                                  |                 |
| max_connect_errors                            | 100             |
| max_connections                               | 100             |
| max_user_connections                          | 0               |
| performance_schema_session_connect_attrs_size | 512             |
+-----------------------------------------------+-----------------+

mysql>  SHOW VARIABLES LIKE '%timeout%';
+-----------------------------+----------+
| Variable_name               | Value    |
+-----------------------------+----------+
| connect_timeout             | 5        |
| deadlock_timeout_long       | 50000000 |
| deadlock_timeout_short      | 10000    |
| delayed_insert_timeout      | 300      |
| innodb_flush_log_at_timeout | 1        |
| innodb_lock_wait_timeout    | 50       |
| innodb_rollback_on_timeout  | OFF      |
| interactive_timeout         | 28800    |
| lock_wait_timeout           | 31536000 |
| net_read_timeout            | 30       |
| net_write_timeout           | 60       |
| slave_net_timeout           | 3600     |
| thread_pool_idle_timeout    | 60       |
| wait_timeout                | 28800    |
+-----------------------------+----------+

2015 年 9 月 22 日编辑:

SEVERE Tomcat 错误会导致问题吗？我看到一个与数据库无关的关于解析日期的错误:

22-Sep-2015 10:09:53.481 SEVERE [http-apr-8080-exec-26] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [edu.mssm.pharm.maayanlab.Harmonizome.page.DatasetPage] in context with path [/Harmonizome] threw exception [javax.servlet.ServletException: javax.servlet.jsp.JspException: In <parseDate>, a parse locale can not be established] with root cause
 javax.servlet.jsp.JspException: In <parseDate>, a parse locale can not be established
    at org.apache.taglibs.standard.tag.common.fmt.ParseDateSupport.doEndTag(ParseDateSupport.java:147)

附加堆内存使用的JConsole输出:

线程使用的 JConsole 输出；它开始于 24-25 左右，一旦我开始使用该网站，它就会跃升至 34 岁。即使在关闭浏览器窗口后，它仍然存在:

2015 年 9 月 23 日编辑:

在问题开始之前我改变的一件事是我如何处理 Hibernate 事务。以前，我禁用了 enable_lazy_load_no_trans (这是默认设置)。以前，我使用的是“open session in view”模式。似乎人们不喜欢 View 模式中的打开 session ，所以我启用了 enable_lazy_load_no_trans。因此，我有这样的代码:

List<MyObjects> myObjects = null;
try {
    HibernateUtil.beginTransaction();
    myObjects = // fetch my objects from the DB
    HibernateUtil.commitTransaction();
} catch (HibernateException he) {
    HibernateUtil.rollbackTransaction();
} finally {
    HibernateUtil.close();
}

// render myObjects in JSP/JSTL
// this JSP may lazily load related objects

回想起来，这似乎……有问题。我不知道 Hibernate 什么时候“放开”这些对象。

Answer 1

根据您提供的堆栈跟踪，我可以得出一个结论:您只是用完了连接。

这可能是由长时间运行的事务引起的，可能是由于查询速度慢或应用程序事务边界不正确。

我建议你开始使用 FlexyPool ，它支持 Tomcat DBCP 并更好地了解连接和事务使用情况。FlexyPool 提供了许多 histograms您可能会感兴趣，例如连接获取时间和租用时间。

而且，为了安全起见，还要检查 MySQL 驱动程序版本，看看您是否在过时的库上运行。