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