0

Environment

HikariCP version     : 2.4.2 
JDK version          : 1.7.0_141 
Database             : MySQL
MySQL Driver version : 5.6.27 
Hibernate            : 4.3.4

We have successfully migrated Hikari from C3PO and everything was running smooth until recently when we encountered the following exception.

org.hibernate.exception.JDBCConnectionException: Could not open connection Caused by: java.sql.SQLTransientConnectionException: HikariPool-0 - Connection is not available, request timed out after 30006ms.

We deploy our webapp in AWS EC2 and database is hosted in RDS. We have deployed the web app on 4 tomcats. The max connection pool size is configured at 250 per tomcat web app. A total of 4000 logins happened in about 2 hours.

The use case is as follows

We have scheduled Online Tests which the student users take within a given period of time (say 9:00 am to 12:30 pm). There are simultaneous logins ( say 4000 logins )

We are able to reproduce the issue by using Locust. And we enable log4j for logging. Following is the logs

DEBUG [http-apr-8080-exec-4] - HikariPool-0 - configuration:
DEBUG [http-apr-8080-exec-4] - allowPoolSuspension.............false *
DEBUG [http-apr-8080-exec-4] - autoCommit......................true *
DEBUG [http-apr-8080-exec-4] - catalog.........................
DEBUG [http-apr-8080-exec-4] - connectionInitSql...............
DEBUG [http-apr-8080-exec-4] - connectionTestQuery.............
DEBUG [http-apr-8080-exec-4] - connectionTimeout...............30000 *
DEBUG [http-apr-8080-exec-4] - dataSource......................
DEBUG [http-apr-8080-exec-4] - dataSourceClassName.............
DEBUG [http-apr-8080-exec-4] - dataSourceJNDI..................
DEBUG [http-apr-8080-exec-4] - dataSourceProperties............{useUnicode=true, password=, prepStmtCacheSqlLimit=2048, characterEncoding=utf8, cachePrepStmts=true, useServerPrepStmts=true, prepStmtCacheSize=250}
DEBUG [http-apr-8080-exec-4] - driverClassName.................
DEBUG [http-apr-8080-exec-4] - healthCheckProperties...........{}
DEBUG [http-apr-8080-exec-4] - healthCheckRegistry.............
DEBUG [http-apr-8080-exec-4] - idleTimeout.....................600000 *
DEBUG [http-apr-8080-exec-4] - initializationFailFast..........true *
DEBUG [http-apr-8080-exec-4] - isolateInternalQueries..........false *
DEBUG [http-apr-8080-exec-4] - jdbc4ConnectionTest.............false *
DEBUG [http-apr-8080-exec-4] - jdbcUrl.........................jdbc:mysql://rds url
DEBUG [http-apr-8080-exec-4] - leakDetectionThreshold..........0 *
DEBUG [http-apr-8080-exec-4] - maxLifetime.....................1800000 *
DEBUG [http-apr-8080-exec-4] - maximumPoolSize.................250
DEBUG [http-apr-8080-exec-4] - metricRegistry..................
DEBUG [http-apr-8080-exec-4] - metricsTrackerFactory...........
DEBUG [http-apr-8080-exec-4] - minimumIdle.....................5
DEBUG [http-apr-8080-exec-4] - password........................
DEBUG [http-apr-8080-exec-4] - poolName........................HikariPool-0
DEBUG [http-apr-8080-exec-4] - readOnly........................false *
DEBUG [http-apr-8080-exec-4] - registerMbeans..................false *
DEBUG [http-apr-8080-exec-4] - scheduledExecutorService........
DEBUG [http-apr-8080-exec-4] - threadFactory...................
DEBUG [http-apr-8080-exec-4] - transactionIsolation............
DEBUG [http-apr-8080-exec-4] - username........................username
DEBUG [http-apr-8080-exec-4] - validationTimeout...............5000 *

There are few defaulted value which are marked * whereas others are set explicitly.

HikariConfig    config = new HikariConfig();
            config.setJdbcUrl(JDBC URL);
            config.setUsername(USER_NAME);
            config.setPassword(PASSWOrD);
            config.setMinimumIdle(5);
            config.setMaximumPoolSize(250);
            config.addDataSourceProperty("cachePrepStmts", true);
            config.addDataSourceProperty("prepStmtCacheSize", 250);
            config.addDataSourceProperty("prepStmtCacheSqlLimit", 2048);
            config.addDataSourceProperty("useServerPrepStmts", true);
                datasource = new HikariDataSource(config)

Within 20 seconds or so, the connection pool is exhausted

DEBUG [http-apr-8080-exec-494] - Timeout failure pool HikariPool-0 stats

(total=100, active=100, idle=0, waiting=194) waiting count is increasing and finally the fore mentioned exceptions are thrown.

We are not able to pinpoint what causes the issue. We tried variants of the configuration but unable to solve it yet.

Mark Rotteveel
  • 100,966
  • 191
  • 140
  • 197
pinkb
  • 543
  • 2
  • 6
  • 15
  • 1
    This usually means you are not closing your connections in a timely manner, which leads to exhaustion of the pool. Check all your usages of connection, and make sure you close the connection when you are done. – Mark Rotteveel Nov 15 '17 at 10:25
  • 1
    Try configuring `leakDetectionThreshold` (0 means disabled, minimum accepted value is 2000 (2 seconds)), and see what gets reported by the logging. – Mark Rotteveel Nov 15 '17 at 10:28
  • Both spot on advice. There is a high likelihood of a leak. A leak tends to stay a leak, so you can set the ``leakDetectionThreshold`` to a higher value, like 30 seconds (30000ms) or 1 minute (60000ms), then watch the log. C3P0 was likely tolerant of leaks, HikariCP has zero tolerance for leaks. – brettw Nov 15 '17 at 12:13
  • We have done a very well code walk through for unclosed connections as well as we have checked the connections using JProfiler. By the way there are some parent child tree building is done at the login time which are somewhat expensive. When we run mysql information_schema.processlist , we found that most of the connections are in SLEEP mode. Does SLEEP mode affect in this scenario. – pinkb Nov 15 '17 at 13:29

0 Answers0