We have a Spring based application and recently we went into production. We are using Spring @Controller
that ultimately hit DAOs that use JDBCTemplate. It is using c3p0's ComboPooledDataSource
On an increased load (something like 150 concurrent users), the application hangs for all users - the DataSource gets locked by something - on a thread dump, there are like 200 threads that say - obviously the DataSource is deadlocked.
"http-bio-8080-exec-440" - Thread t@878
java.lang.Thread.State: WAITING
at java.lang.Object.wait(Native Method)
- waiting on <146d984e> (a com.mchange.v2.resourcepool.BasicResourcePool)
at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1418)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:606)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:526)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:756)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:683)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:573)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:674)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:718)
After that point the application becomes unusable unless restarted. When this happened DBA team didn't observe any load on the database.
At that time c3p0 was configured like that:
app_en.driverClass=com.mysql.jdbc.Driver
app_en.user=tapp_en
app_en.password=tapp_en
app_en.jdbcUrl=jdbc:mysql://10.10.0.102:3306/tapp_en?useUnicode=true&characterEncoding=utf-8&autoReconnect=true
app_en.acquireIncrement=5
app_en.maxIdleTime=3600
app_en.maxIdleTimeExcessConnections=300
app_en.unreturnedConnectionTimeout=3600
app_en.numHelperThreads=6
app_en.minPoolSize=20
app_en.maxPoolSize=100
app_en.idleConnectionTestPeriod=120
app_en.testConnectionOnCheckin=true
After that, I changed c3p0's configuration as follows - and enabled DEBUG logging for com.mchange.v2.c3p0
package:
app_en.driverClass=com.mysql.jdbc.Driver
app_en.user=tapp_en
app_en.password=tapp_en
app_en.jdbcUrl=jdbc:mysql://10.10.0.102:3306/tapp_en? useUnicode=true&characterEncoding=utf-8&autoReconnect=true
app_en.acquireIncrement=5
app_en.maxIdleTime=180
app_en.maxIdleTimeExcessConnections=60
app_en.unreturnedConnectionTimeout=30
app_en.checkoutTimeout=10000
app_en.numHelperThreads=12
app_en.debugUnreturnedConnectionStackTraces=true
app_en.initialPoolSize=10
app_en.maxPoolSize=100
app_en.idleConnectionTestPeriod=120
app_en.preferredTestQuery="select 1 from tbl_users"
With this configuration in place, I again ran load tests and the application still hanged... although the threads recover after they are unable to obtain connection to the database. Even though, the game hanged for too many users even though the threads recovered unlike the previous configuration - so they had to restart their clients. Although all logging was enabled, the c3p0 logs don't log any deadlock messages. The error messages I see are just that:
[06/24/2015 12:20:54] [C3P0PooledConnectionPoolManager[identityToken->1oed6dl9a9ak8qsgqfvdu|4d6145af]-HelperThread-#10] DEBUG NewPooledConnection - com.mchange.v2.c3p0.impl.NewPooledConnection@7f0bc55a closed by a client.
java.lang.Exception: DEBUG -- CLOSE BY CLIENT STACK TRACE
at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:659)
at com.mchange.v2.c3p0.impl.NewPooledConnection.closeMaybeCheckedOut(NewPooledConnection.java:255)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.destroyResource(C3P0PooledConnectionPool.java:621)
at com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask.run(BasicResourcePool.java:1024)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
There aren't any transactions in the application made, nor are we using any TransactionManager or TransactionTemplate. I wonder if this may be some kind of bug in the frameworks used, or misconfiguration. These are the relevant frameworks used:
c3p0-0.9.5-pre8
mysql-connector-java-5.1.24
spring-core-3.2.1.RELEASE
spring-web-3.2.1.RELEASE
mchange-commons-java-0.2.7
We really appreciate any help because this is blocking our efforts to release our product.
P.S. EDIT: Here is the configuration of the DataSource:
<bean id="app_en_DataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource"
destroy-method="close">
<property name="driverClass" value="${app_en.driverClass}" />
<property name="jdbcUrl" value="${app_en.jdbcUrl}" />
<property name="user" value="${app_en.user}" />
<property name="password" value="${app_en.password}" />
<property name="acquireIncrement" value="${app_en.acquireIncrement}"></property>
<property name="maxIdleTime" value="${app_en.maxIdleTime}"></property>
<property name="maxIdleTimeExcessConnections" value="${app_en.maxIdleTimeExcessConnections}"></property>
<property name="unreturnedConnectionTimeout" value="${app_en.unreturnedConnectionTimeout}"></property>
<property name="checkoutTimeout" value="${app_en.checkoutTimeout}"></property>
<property name="numHelperThreads" value="${app_en.numHelperThreads}"></property>
<property name="debugUnreturnedConnectionStackTraces" value="${app_en.debugUnreturnedConnectionStackTraces}"></property>
<property name="initialPoolSize" value="${app_en.initialPoolSize}"></property>
<property name="maxPoolSize" value="${app_en.maxPoolSize}"></property>
<property name="idleConnectionTestPeriod" value="${app_en.idleConnectionTestPeriod}"></property>
<property name="preferredTestQuery" value="${app_en.preferredTestQuery}"></property>
</bean>
And here is some code inside the application that isn't using the jdbcTemplate directly. There is nothing else that does that, everything else is jdbcTemplate.update, jdbcTemplate.query:
Connection conn = null;
ResultSet getItemsRS = null;
try {
JdbcTemplate jdbcTemplate = getJdbcTemplate(database);
conn = jdbcTemplate.getDataSource().getConnection();
UserItems items;
if (!action.areItemsNew()) {
conn.setAutoCommit(false);
conn.setTransactionIsolation(Connection.TRANSACTION_SERIALIZABLE);
PreparedStatement getItemsPS = conn.prepareStatement("select * from tbl_items where ownerId = ? for update",
ResultSet.TYPE_FORWARD_ONLY,
ResultSet.CONCUR_UPDATABLE);
getItemsPS.setLong(1, userId);
getItemsRS = getItemsPS.executeQuery();
getItemsRS.next();
items = new UserItemsRowMapper().mapRow(getItemsRS, getItemsRS.getRow());
} else {
items = new UserItems();
}
action.doUserItemsAction(items);
ByteArrayOutputStream baos = new ByteArrayOutputStream();
ObjectOutputStream oos = new ObjectOutputStream(baos);
oos.writeObject(items.getItemContainers());
oos.close();
byte[] data = baos.toByteArray();
Blob blob = conn.createBlob();
blob.setBytes(1, data);
if (!action.areItemsNew()) {
getItemsRS.updateBlob("data", blob);
getItemsRS.updateRow();
} else {
jdbcTemplate.update("insert into tbl_items(ownerId,data) values(?,?)", userId, data);
}
} catch (Exception e) {
logger.error(e);
throw new RuntimeException(e);
} finally {
if (!action.areItemsNew()) {
try {
conn.commit();
conn.close();
} catch (SQLException e) {
logger.error(e);
throw new RuntimeException(e);
}
}
}
The reason for this code is that I would like to block reading/writing to the user's items before they are updated by this operation action.doUserItemsAction(items)
as written above.