MySQL/Hibernate --如何调试不断下降的MySQL池连接？

Question

几个月来，我的web应用程序运行顺利，但在过去的一两周里，它一直放弃与MySQL服务器的连接。我不是一个DBA的家伙，不知道如何调试这个。

以下是我所知道的：

1. 这种联系似乎每隔几个小时就会减少一次。有时在白天，但总是在晚上。
2. 我的实验室有一个MySQL服务器，用于托管多个应用程序的数据库。
3. 目前，我们有46个连接到MySQL服务器。
4. 据我所知，没有任何其他应用程序会遇到这个问题。
5. 我的应用程序正在使用相同的堆栈、配置，甚至代码作为另一个应用程序连接到DB --这个应用程序每天支持大约200个用户，自2013年以来运行一直很顺利。
6. 这两个应用程序都使用Hibernate ORM；这是我所知道的唯一配置：
7. 当有人试图使用应用程序的RESTful API下载我们的数据时，问题就开始了。这个用户--实际上是一个协作者--有一个小脚本遍历特定表中的每一行，并请求所有元数据。
8. 这个问题也是在我的实验室开始提供一个大规模的在线开放课程的同时开始的。我不知道是什么数字，但网站上的实际使用肯定已经跳过了。

我知道这是一个广泛的问题，但我真的不知道如何调试这个问题。如有任何建议，敬请见谅。

编辑：

深入研究另一个应用程序的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"的跟踪，并手动停止它。可能这跟我的问题有关吧？

编辑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> 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，并更好地理解连接和事务使用。FlexyPool提供了许多您可能感兴趣的直方图，比如连接获取时间和租约时间。

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

Answer 2

您的连接池似乎无法在超时期间将空闲连接返回给Hibernate。这是因为您的应用程序有很长的事务或事务死锁。您可以尝试使用以下选项来修复该错误。

1. 在下一行中更改连接池大小 <property name="hibernate.connection.pool_size">5</property>

使池的大小在10左右，然后测试。您应该密切关注到数据库的连接数。如果超出mysql数据库的连接限制，更改mysql服务器的max_connections并继续进行测试。

1. 使用另一个连接池。我建议使用。dbcp2的Maven依赖项如下所示。 <dependency> <groupId>org.apache.commons</groupId> <artifactId>commons-dbcp2</artifactId> <version>2.1</version> </dependency>

将dbcp2添加到POM中，然后与应用程序一起配置dbcp2。

如果是解决方案，您的应用程序只有长事务。有时，它可能会将事件减少到最低程度，如果仍然发生这种情况，您的应用程序就会有事务死锁。因此，您必须确定您的代码可能存在哪些问题。

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