MySQL / Hibernate – 如何调试不断丢弃的MySQL池连接？

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

这就是我所知道的：

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

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

    org.hibernate.connection.TomcatJDBCConnectionProvider org.hibernate.dialect.MySQLDialect com.mysql.jdbc.Driver 5 thread SELECT 1 true true 

7. 该问题与有人试图使用应用程序的RESTful API下载数据的时间大致相同。 这个用户 – 实际上是一个协作者 – 有一个小脚本迭代特定表中的每一行并请求所有元数据。

8. 这个问题也开始于我的实验室开始提供Coursera Massive Open Online课程的同时。 我不知道这些数字是什么，但网站上的实际使用量必须已经增加。

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

编辑：

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

 // TODO: Find memory leak that requires server to be restarted after hot deploying several (3?) times. Set 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"的文本并手动停止它。 这似乎与我的问题有关？

编辑21/9/2015：

我的申请本周末下降了。 这是昨天错误日志中的堆栈跟踪（当我认为它已经关闭时）：

 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 | +-----------------------------+----------+ 

编辑22/9/2015：

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。 即使在关闭浏览器窗口后，它仍然存在：

编辑23/9/2015：

在问题开始之前我改变的一件事是我如何处理Hibernate事务。 以前，我禁用了enable_lazy_load_no_trans （这是默认设置）。 以前，我使用的是“ 在视图中打开会话 ”模式。 看起来人们不喜欢视图模式中的开放会话，所以我启用了enable_lazy_load_no_trans 。 因此，我有这样的代码：

 List 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

从您提供的堆栈跟踪中，我可以得出一个结论：您只是耗尽了连接。

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

我建议您开始使用支持Tomcat DBCP的FlexyPool ，并更好地了解连接和事务使用情况。 本文介绍了您可能感兴趣的直方图，例如连接获取时间和连接租用时间。

为了安全起见，请检查MySQL驱动程序版本，看看你是否在一个过时的库上运行。

Answer 2

Hibernate错误有点抽象，有时通过堆栈跟踪找到错误可能很棘手。 我认为这可能是您的应用程序的问题，也许您在某些情况下没有正确关闭Hibernate连接，或者您的应用程序可能有内存泄漏。

您是否尝试过使用JDK的jconsole监控应用程序？

您可以在Java参数的Tomcat配置控制台上设置它（我假设您正在使用Tomcat），以启用jconsole

 -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8086 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false 

然后连接到远程进程

 localhost:8086 

通过使应用程序停止的操作来观察线程。

编辑

如果您没有使用Tomcat并且在Windows环境中运行应用程序，则可以使用Process Explorer监视线程并监视应用程序。

Answer 3

在超时持续时间内，您的连接池似乎无法返回与Hibernate的空闲连接。 发生这种情况是因为您的应用程序具有很长的事务或事务死锁。 您可以尝试以下选项来修复错误。

1. 在以下行中更改连接池大小

   5

使池大小约10并测试。 您应该密切关注数据库的连接数。 如果超过mysql数据库连接限制，请更改mysql服务器的max_connections并继续测试。

2. 使用另一个连接池。 我建议使用apache commons dbcp2。 dbcp2的Maven依赖关系如下。

   org.apache.commons commons-dbcp2 2.1

将dbcp2添加到POM中，然后使用您的应用程序配置dbcp2。

如果是解决方案，您的应用程序只有很长的交易。 有时它可以最小化发生，如果它仍然发生肯定你的应用程序有事务死锁。 因此，您必须确定代码可能存在的问题。

还有其他替代解决方案，例如将等待超时更改为更高的值。 但它对您的应用程序性能不利，对事务死锁没有任何意义。 最后，您应该记住在进一步开发中关心事务管理和数据库结构，以获得更好的数据库性能。