Connection is not available, request timed out after 30003ms

java connection connection-pooling hikaricp
user9695387 picture user9695387 · May 15, 2018 · Viewed 9.6k times · Source

I'm getting this exception for last few days.

This problem occurs when I process 10++ form and connection keep on increasing every 30 seconds to 1 minute 30 seconds until reach max size.

I've ensure all connection already close. Why am I keep getting this error?

Environment:

  • HikariCP version: 2.5.1
  • JDK version: 1.8.0_152
  • Database: MySQL

I keep on getting this error:

Configuration:

09:05:37,908 DEBUG com.zaxxer.hikari.HikariConfig :841 - ConcolePool - configuration:
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - allowPoolSuspension.............false
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - autoCommit......................true
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - catalog.........................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - connectionInitSql...............null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - connectionTestQuery............."SELECT current_timestamp"
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - connectionTimeout...............30000
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - dataSource......................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - dataSourceClassName............."com.mysql.jdbc.jdbc2.optional.MysqlDataSource"
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - dataSourceJNDI..................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - dataSourceProperties............{port=3307, user=root, password=<masked>, prepStmtCacheSqlLimit=2048, cachePrepStmts=true, prepStmtCacheSize=500, serverName=localhost}
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - driverClassName.................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - healthCheckProperties...........{}
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - healthCheckRegistry.............null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - idleTimeout.....................600000
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - initializationFailFast..........true
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - isolateInternalQueries..........false
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - jdbc4ConnectionTest.............false
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - jdbcUrl.........................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - leakDetectionThreshold..........30000
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - maxLifetime.....................1800000
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - maximumPoolSize.................10
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - metricRegistry..................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - metricsTrackerFactory...........null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - minimumIdle.....................5
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - password........................<masked>
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - poolName........................"ConcolePool"
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - readOnly........................false
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - registerMbeans..................false
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - scheduledExecutorService........null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - threadFactory...................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - transactionIsolation............null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - username........................null
09:05:37,924 DEBUG com.zaxxer.hikari.HikariConfig :857 - validationTimeout...............5000
09:05:37,924  INFO com.zaxxer.hikari.HikariDataSource :70 - ConcolePool - Started.

Debug for pool status:

2018-05-14 12:48:19  [ ConcolePool connection adder:5403109 ] - [ DEBUG ]  ConcolePool - After adding stats (total=5, active=0, idle=5, waiting=0)
2018-05-14 12:48:49  [ ConcolePool housekeeper:5433109 ] - [ DEBUG ]  ConcolePool - Pool stats (total=5, active=1, idle=4, waiting=0)
2018-05-14 12:48:49  [ ConcolePool connection adder:5433109 ] - [ DEBUG ]  ConcolePool - Added connection com.mysql.jdbc.JDBC4Connection@39193bcd
2018-05-14 12:48:49  [ ConcolePool connection adder:5433109 ] - [ DEBUG ]  ConcolePool - After adding stats (total=6, active=1, idle=5, waiting=0)
2018-05-14 12:49:07  [ ConcolePool housekeeper:5450750 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@160af66e, stack trace follows
2018-05-14 12:49:19  [ ConcolePool housekeeper:5463125 ] - [ DEBUG ]  ConcolePool - Pool stats (total=6, active=1, idle=5, waiting=0)
2018-05-14 12:49:49  [ ConcolePool housekeeper:5493140 ] - [ DEBUG ]  ConcolePool - Pool stats (total=6, active=2, idle=4, waiting=0)
2018-05-14 12:49:49  [ ConcolePool connection adder:5493140 ] - [ DEBUG ]  ConcolePool - Added connection com.mysql.jdbc.JDBC4Connection@207b7ac0
2018-05-14 12:49:49  [ ConcolePool connection adder:5493140 ] - [ DEBUG ]  ConcolePool - After adding stats (total=7, active=2, idle=5, waiting=0)
2018-05-14 12:49:54  [ ConcolePool housekeeper:5497687 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@10429350, stack trace follows
2018-05-14 12:50:19  [ ConcolePool housekeeper:5523156 ] - [ DEBUG ]  ConcolePool - Pool stats (total=7, active=2, idle=5, waiting=0)
2018-05-14 12:50:49  [ ConcolePool housekeeper:5553172 ] - [ DEBUG ]  ConcolePool - Pool stats (total=7, active=3, idle=4, waiting=0)
2018-05-14 12:50:49  [ ConcolePool connection adder:5553172 ] - [ DEBUG ]  ConcolePool - Added connection com.mysql.jdbc.JDBC4Connection@4721d5d3
2018-05-14 12:50:49  [ ConcolePool connection adder:5553172 ] - [ DEBUG ]  ConcolePool - After adding stats (total=8, active=3, idle=5, waiting=0)
2018-05-14 12:50:58  [ ConcolePool housekeeper:5561656 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@76ff6438, stack trace follows
2018-05-14 12:51:19  [ ConcolePool housekeeper:5583187 ] - [ DEBUG ]  ConcolePool - Pool stats (total=8, active=4, idle=4, waiting=0)
2018-05-14 12:51:19  [ ConcolePool connection adder:5583187 ] - [ DEBUG ]  ConcolePool - Added connection com.mysql.jdbc.JDBC4Connection@1f4c60a8
2018-05-14 12:51:19  [ ConcolePool connection adder:5583187 ] - [ DEBUG ]  ConcolePool - After adding stats (total=9, active=4, idle=5, waiting=0)
2018-05-14 12:51:42  [ ConcolePool housekeeper:5606359 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@1cff4d1c, stack trace follows
2018-05-14 12:51:49  [ ConcolePool housekeeper:5613203 ] - [ DEBUG ]  ConcolePool - Pool stats (total=9, active=4, idle=5, waiting=0)
2018-05-14 12:52:19  [ ConcolePool housekeeper:5643219 ] - [ DEBUG ]  ConcolePool - Pool stats (total=9, active=4, idle=5, waiting=0)
2018-05-14 12:52:49  [ ConcolePool housekeeper:5673234 ] - [ DEBUG ]  ConcolePool - Pool stats (total=9, active=5, idle=4, waiting=0)
2018-05-14 12:52:49  [ ConcolePool connection adder:5673234 ] - [ DEBUG ]  ConcolePool - Added connection com.mysql.jdbc.JDBC4Connection@2d750b07
2018-05-14 12:52:49  [ ConcolePool connection adder:5673234 ] - [ DEBUG ]  ConcolePool - After adding stats (total=10, active=5, idle=5, waiting=0)
2018-05-14 12:52:53  [ ConcolePool housekeeper:5676453 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@708cdc47, stack trace follows
2018-05-14 12:53:19  [ ConcolePool housekeeper:5703250 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=6, idle=4, waiting=0)
2018-05-14 12:53:43  [ ConcolePool housekeeper:5726594 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@39193bcd, stack trace follows
2018-05-14 12:53:49  [ ConcolePool housekeeper:5733265 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=6, idle=4, waiting=0)
2018-05-14 12:54:19  [ ConcolePool housekeeper:5763281 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=7, idle=3, waiting=0)
2018-05-14 12:54:39  [ ConcolePool housekeeper:5782984 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@207b7ac0, stack trace follows
2018-05-14 12:54:49  [ ConcolePool housekeeper:5793297 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=7, idle=3, waiting=0)
2018-05-14 12:55:19  [ ConcolePool housekeeper:5823312 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:55:45  [ ConcolePool housekeeper:5848906 ] - [ WARN ]  Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@4721d5d3, stack trace follows
2018-05-14 12:55:49  [ ConcolePool housekeeper:5853328 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:56:19  [ ConcolePool housekeeper:5883344 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:56:49  [ ConcolePool housekeeper:5913359 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:57:20  [ ConcolePool housekeeper:5943375 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:57:50  [ ConcolePool housekeeper:5973390 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:58:20  [ ConcolePool housekeeper:6003406 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:58:50  [ ConcolePool housekeeper:6033422 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=8, idle=2, waiting=0)
2018-05-14 12:59:20  [ ConcolePool housekeeper:6063437 ] - [ DEBUG ]  ConcolePool - Pool stats (total=10, active=10, idle=0, waiting=1)

How to troubleshoot this problem? Is there something I need to change?

Edit:

public Connection getConnection(){
    try{
        return datas.getConnection();

    } catch (SQLException e){
        e.printStackTrace();
        datas.resumePool();
        return null;
    }
}

Example close connection:

protected void doPost(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {

    DataSource datas = (DataSource) getServletContext().getAttribute("ds");
    Connection conn = null;
    Statement stmt = null;

    try{
        conn = datas.getConnection();
        stmt = conn.createStatement();

        //some sql
        //process form
        //pass the return values

        stmt.close();
        conn.close();
    } catch (Exception e) {
        e.printStackTrace();
    }
}

Answer

user7294900 picture user7294900 · May 15, 2018

You aren't closing the connections always and therefore the connection pool reaches its limits.

You must close connection and statement when finished block (as all resources), also if an exception occurred, The right/easy way is with try with resources approach:

protected void doPost(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {

  DataSource datas = (DataSource) getServletContext().getAttribute("ds");

  try (Connection conn = datas.getConnection();Statement stmt = conn.createStatement()){
    

    //some sql
    //process form
    //pass the return values

  } catch (Exception e) {
    e.printStackTrace();
  }
}

The try-with-resources Statement The try-with-resources statement is a try statement that declares one or more resources. A resource is an object that must be closed after the program is finished with it. The try-with-resources statement ensures that each resource is closed at the end of the statement.

Related questions

Need Code to create Connection Pool in java

Need code to create the connection pool in java? How does we make sure that connection pool doesn't return the same object which is already in use? How happens if client closed the connection after taking it out from Connection …

Read More
Hibernate connections are not closed even with C3P0 + explicit session.close()

Hibernate connections to MySQL my db are not closing. After clicking 10 times in like 10 second, I get this connection statistics from MySQL Workbench (in my development machine. I'm the only user).MySQL Workbench Server Status I have those in place …

Read More
Tomcat JDBC connection pool VS c3p0 Connection pool

I recently came across this connection pool implementation. http://people.apache.org/~fhanik/jdbc-pool/jdbc-pool.html I find it quite interesting. Did anyone try this out? I think it looks great except the fact that it does not support automatic …

Read More