英文:
C3P0 APPARENT DEADLOCK in Apache Tomcat application
问题
我在Apache Tomcat应用程序中发现了C3P0日志死锁问题。不久后,Tomcat开始因资源限制而出现故障。这导致httpd子进程的数量增加,直到达到maxRequestWorkers限制,然后服务器发生死锁。根据我的初步研究,C3P0问题可能是Hibernate与PostgreSQL通信失败的原因。
是否可以确认这是否是根本问题,并提供关于可能发生的情况的任何见解将不胜感激。
这是C3P0问题的初始日志:
[警告] [Wed Feb 08 05:52:41.589 2023] [C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-AdminTaskTimer|ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@578de344 -- 明显死锁!正在为未分配的待处理任务创建紧急线程!
[警告] [Wed Feb 08 05:52:42.270 2023] [C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-AdminTaskTimer|ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@578de344 -- 明显死锁!完整状态:
托管线程:10
活动线程:10
活动任务:
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@148953c6
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#2
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@33ec4718
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#5
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@7a772c6f
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#7
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5e288adc
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#0
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@e1f5bc
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#4
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@51e4b63f
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#8
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@1233fc38
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#3
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@857fac8
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#6
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@794b26b
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#1
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@73b5a9e8
在线程上:C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#9
待处理任务:
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@7e6a499a
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@49dc7d25
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6b79999f
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@355d97f1
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@19572e59
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@33c84d03
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@145a8f84
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@4d6160e1
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@6de4aaf2
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@1cb54218
池线程堆栈跟踪:
...
不久之后,Tomcat开始记录资源问题:
08-Feb-2023 05:52:49.672 严重 [ajp-nio-127.0.0.1-8009-exec-123] org.apache.coyote.AbstractProtocol$ConnectionHandler.process 未能完成请求的处理
java.lang.OutOfMemoryError: 无法创建本机线程:可能内存不足或达到了进程/资源限制
在java.base/java.lang.Thread.start0(Native Method)
ps显示,不久后Tomcat开始出错,大量httpd进程开始生成。这将持续数小时,直到达到500的限制。
英文:
I am seeing a C3P0 log dead lock issue in an Apache Tomcat application.
Not long after this I begin to see failures in Tomcat due to resource limits.
This then causes the number of httpd daughter processes to increase until the maxRequestWorkers limit is hit and the server then deadlocks.
From my initial research it looks like the C3P0 issue could be a failure of hibernate to communicate with postgres.
A confirmation of whether that is the root issue would be appreciated as well as any insight into what might be going on here.
This is this initial log that C3P0 issues:
[WARN] [Wed Feb 08 05:52:41.589 2023] [C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-AdminTaskTimer|ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@578de344 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
[WARN] [Wed Feb 08 05:52:42.270 2023] [C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-AdminTaskTimer|ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@578de344 -- APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 10
Active Threads: 10
Active Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@148953c6
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#2
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@33ec4718
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#5
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@7a772c6f
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#7
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5e288adc
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#0
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@e1f5bc
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#4
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@51e4b63f
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#8
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@1233fc38
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#3
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@857fac8
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#6
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@794b26b
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#1
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@73b5a9e8
on thread: C3P0PooledConnectionPoolManager[identityToken->2t53wqaub1kdwl1wutziz|421f447f]-HelperThread-#9
Pending Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@7e6a499a
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@49dc7d25
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6b79999f
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@355d97f1
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@19572e59
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@33c84d03
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@145a8f84
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@4d6160e1
com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@6de4aaf2
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@1cb54218
Pool thread stack traces:
...
Not long after this is the resource issues that tomcat starts to log:
08-Feb-2023 05:52:49.672 SEVERE [ajp-nio-127.0.0.1-8009-exec-123] org.apache.coyote.AbstractProtocol$ConnectionHandler.process Failed to complete processing of a request
java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached
at java.base/java.lang.Thread.start0(Native Method)
ps shows that soon after Tomcat begins to error a large number of httpd processes begins to spawn. This continues for several hours until the limit of 500 is hit.
[vcr@qa-9440 ~]$ ps auxwww |grep httpd
root 4154 0.0 0.0 23504 10668 - Ss Mon17 0:33.03 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 45854 0.0 0.0 23504 11452 - I 05:53 0:01.41 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 46742 0.0 0.0 23504 11448 - I 05:54 0:00.84 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 46986 0.0 0.0 23504 11412 - I 05:55 0:00.67 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47031 0.0 0.0 23504 11436 - I 05:55 0:00.54 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47034 0.0 0.0 23504 11444 - I 05:55 0:00.60 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47223 0.0 0.0 26064 11600 - I 05:55 0:00.43 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47390 0.0 0.0 23504 11412 - I 05:56 0:00.40 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47411 0.0 0.0 23504 11428 - I 05:56 0:00.32 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47520 0.0 0.0 23504 11384 - I 05:56 0:00.30 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47617 0.0 0.0 23504 11408 - I 05:56 0:00.28 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47619 0.0 0.0 23504 11336 - I 05:56 0:00.22 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47653 0.0 0.0 23504 11356 - I 05:56 0:00.23 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47716 0.0 0.0 23504 11340 - I 05:56 0:00.20 /usr/local/sbin/httpd -DNOHTTPACCEPT
www 47735 0.0 0.0 23504 11364 - I 05:56 0:00.18 /usr/local/sbin/httpd -DNOHTTPACCEPT
...
C3P0/Hibernate configurations:
<!-- Configure the dataSource.-->
<bean id="dataSource"
class="com.mchange.v2.c3p0.ComboPooledDataSource">
<property name="driverClass">
<value>${db.driver}</value>
</property>
<property name="jdbcUrl">
<value>${db.url}</value>
</property>
<property name="user">
<value>${db.username}</value>
</property>
<property name="password">
<value>${db.password}</value>
</property>
<property name="acquireRetryAttempts" value="0" />
<property name="acquireRetryDelay" value="2000" />
<property name="initialPoolSize" value="10" />
<property name="minPoolSize" value="1" />
<property name="maxPoolSize" value="20" />
<property name="maxIdleTime" value="5" />
<property name="autoCommitOnClose" value="false" />
<property name="numHelperThreads" value="10" />
</bean>
<!--
Setup Hibernate based on config file
classpath:com/niksun/resources/hibernate.cfg.xml.
PostgreSQLDialect
-->
<bean id="sessionFactory"
class="org.springframework.orm.hibernate5.LocalSessionFactoryBean">
<property name="dataSource" ref="dataSource">
</property>
<property name="hibernateProperties">
<props>
<prop key="hibernate.dialect">
org.hibernate.dialect.PostgreSQL10Dialect
</prop>
<prop key="hibernate.show_sql">false</prop>
<prop key="hibernate.format_sql">false</prop>
<prop key="hibernate.c3p0.maxPoolSize">100</prop>
<prop key="hibernate.c3p0.min_size">10</prop>
<prop key="hibernate.jdbc.batch_size">20</prop>
<!--prop key="hibernate.hbm2ddl.auto">validate</prop-->
</props>
</property>
</bean>
答案1
得分: 1
以下是翻译好的部分:
"ScatteredAcquireTask" 是导致线程池饱和并挂起的任务,它是 c3p0 尝试从后端数据库获取新连接的任务。这些尝试是"挂起"的,意味着它们既不成功,也不失败,也没有抛出异常。它们只是无限期地阻塞着尝试运行它们的线程。这个挂起是你需要调试的问题。这种类型的挂起可能是由于在AWS上配置不正确的身份验证配置引起的,但也可能来自许多其他未知因素。如果在发生这些事件时,你可以尝试一个简单的测试程序,该程序仅尝试使用相同的 dbUrl/user/password 来获取连接,这可能会提供一些见解。
失败是正常的。c3p0 对于连接获取有时失败的情况非常有弹性,网络和数据库都是不完美的。但它不能容忍既不成功也不失败的情况。它期望获取尝试要么成功,要么在一个相当宽松的时间窗口内失败。无限期的挂起将耗尽其线程。
英文:
The task that's hanging and saturating your thread pool is ScatteredAcquireTask
, which is c3p0 trying to get new Connections from the backend DB. Those attempts are hanging, meaning they are neither succeeding nor failing with an Exception
. They are just indefinitely holding up the Thread
that tries to run them. This hang is what you need to debug. This sort of hang can come from, e.g. incorrect authentication configuration on AWS, but also from lots of other mysteries. If you can try a test program that simply tries to acquire a Connection
with the same dbUrl/user/password when these events happen, that might give some insight.
Failure is normal. c3p0
is very resilient to the fact that Connection
acquisition sometimes fails, networks and databases are imperfect. But it is not resilient to neither failing nor succeeding. It expects acquisition attempts to either succeed, or fail within a pretty generous time window. Indefinite hangs will eat up its threads.
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库,让每个人都能够通过互相帮助和分享经验来进步。
评论