MySQL/Hibernate - 如何调试不断丢弃的MySQL池连接?

gwg*_*gwg 11 java mysql database orm hibernate

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

这就是我所知道的:

  1. 连接似乎每隔几个小时就会消失.有时在白天,但总是在夜间.
  2. 我的实验室有一台MySQL服务器,可托管多个应用程序的数据库
  3. 目前,我们与MySQL服务器有46个连接.
  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>
    
    Run Code Online (Sandbox Code Playgroud)
  7. 该问题与有人试图使用应用程序的RESTful API下载数据的时间大致相同.这个用户 - 实际上是一个协作者 - 有一个小脚本迭代特定表中的每一行并请求所有元数据.

  8. 这个问题也开始于我的实验室开始提供Coursera大规模开放在线课程的同时.我不知道这些数字是什么,但网站上的实际使用量必须已经增加.

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

编辑:

围绕其他应用程序挖掘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
        }
    }
}
Run Code Online (Sandbox Code Playgroud)

它似乎迭代堆栈跟踪,找到带有文本的跟踪"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)
Run Code Online (Sandbox Code Playgroud)

这是来自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    |
+-----------------------------+----------+
Run Code Online (Sandbox Code Playgroud)

编辑22/9/2015:

将一个SEVERETomcat的错误导致的问题?我看到一个与数据库无关的错误,关于解析日期:

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 &lt;parseDate&gt;, a parse locale can not be established] with root cause
 javax.servlet.jsp.JspException: In &lt;parseDate&gt;, a parse locale can not be established
    at org.apache.taglibs.standard.tag.common.fmt.ParseDateSupport.doEndTag(ParseDateSupport.java:147)
Run Code Online (Sandbox Code Playgroud)

附加堆内存使用的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
Run Code Online (Sandbox Code Playgroud)

回想起来,这似乎......有问题.我不知道什么时候Hibernate"放开"对象.

Vla*_*cea 3

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

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

我建议您开始使用FlexyPool,它支持 Tomcat DBCP 并更好地了解连接和事务的使用。FlexyPool 提供了许多您可能感兴趣的直方图,例如连接获取时间和租用时间。

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