java - 我怎么知道为什么我的应用程序使用 PostgreSQL 9、hibernate 4.3.5 和 c3p0 挂起？

Question

我正在开发一个基于 PostgreSQL 9、hibernate 4.3.5.Final、c3p0、Tomcat 7 和 JDK 7 的应用程序。

这是 c3p0 配置:

hibernate.c3p0.min_size=5
hibernate.c3p0.max_size=20
hibernate.c3p0.timeout=1800
hibernate.c3p0.max_statements=50

使用几个小时后，应用程序挂起。所有屏幕都卡住了，因为似乎无法打开数据库的新事务。

我在 tomcat 7 进程(部署了一个应用程序)上执行了 kill -3 以查看所有线程被锁定的位置。这是输出的一部分:

"ajp-bio-8127-exec-274" daemon prio=10 tid=0x0000000001365000 nid=0x257b in Object.wait() [0x0000000045242000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1414)
    at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:606)
    - locked <0x000000078567cb70> (a com.mchange.v2.resourcepool.BasicResourcePool)
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:526)
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectio

所有的http请求过程都是一样的。因此所有请求都在无限期地等待池中的可用连接。

我们查看了 postgres，看到打开了 20 个连接(20 是池的最大大小):

foobar=# select datname, usename, client_port, query from  pg_stat_activity where usename='foobar';
 datname | usename | client_port |  query
---------+---------+-------------+----------
 foobar  | foobar  |       52992 | ROLLBACK
 foobar  | foobar  |       52993 | ROLLBACK
 foobar  | foobar  |       52991 | ROLLBACK
 foobar  | foobar  |       52994 | ROLLBACK
 foobar  | foobar  |       52995 | ROLLBACK
 foobar  | foobar  |       36398 | ROLLBACK
 foobar  | foobar  |       36399 | ROLLBACK
 foobar  | foobar  |       36400 | ROLLBACK
 foobar  | foobar  |       51766 | ROLLBACK
 foobar  | foobar  |       56689 | ROLLBACK
 foobar  | foobar  |       56690 | ROLLBACK
 foobar  | foobar  |       39582 | ROLLBACK
 foobar  | foobar  |       39581 | ROLLBACK
 foobar  | foobar  |       39583 | ROLLBACK
 foobar  | foobar  |       39590 | ROLLBACK
 foobar  | foobar  |       39592 | ROLLBACK
 foobar  | foobar  |       39591 | ROLLBACK
 foobar  | foobar  |       41799 | ROLLBACK
 foobar  | foobar  |       36105 | ROLLBACK
 foobar  | foobar  |       36103 | ROLLBACK
(20 rows)

因此，我们将池日志配置为 DEBUG，我们可以看到如下语句:

2014/07/09 05:24:40 DEBUG (BasicResourcePool.java:1747) trace trace com.mchange.v2.resourcepool.BasicResourcePool@12c39c9e [managed: 19, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@4fc04747)

它们表明托管连接数增长缓慢，直到 managed: 20 和 usused: 0 这个最终状态保持稳定并且应用程序被卡住，因为所有线程都期望池中的连接可用。

这是一个 Web 应用程序，我们在请求模式中使用 session ，因此在处理每个请求后(在 finally 语句中)正确关闭连接。应用程序日志中没有 ERROR 或 WARN 之类的东西。

我怎么知道我做错了什么？

Answer 1

很明显，这些查询在未发布的情况下被阻止。可能是您遇到了一些异常或您没有看到的东西，因为查询被标记为 ROLLBACK，并且由于某种原因线程挂起等待查询完成或类似的事情种类。没有看到代码很难说清楚。

您可以做的是等待这种情况再次发生，然后获取完整的线程转储。这应该为您提供每个线程挂起位置的完整详细信息，这样您就可以看到 20 个连接正在等待什么。

您可以使用 jstack为此，它随 JDK 一起提供。

您还可以在 Tomcat 上启用 JMX 并使用 jconsole 或 jvisualvm 连接到它以实时查看线程在做什么。