getConnection timeouts

[Nadav Samet]

We are seeing frequently (4-5 times a day) an exception like this:

java.sql.SQLTransientConnectionException: db - Connection is not available, request timed out after 2007ms.

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

What's puzzling to me is that we see a few milliseconds before the exception comes that there are 16 idle connections, yet it fails to provide one within the time limit.

We are using HikariCP 2.4.5, Play 2.4.6, Slick 3.1.1, Aurora over Amazon RDS.

Following is HikariConfig logs and production logs around the time this failure happens. We've been trying to solve it for a while by tweaking different settings... Any advice will be appreciated!

2016-03-22T00:13:44.434+00:00 com.zaxxer.hikari.HikariConfig main  db - configuration: 

2016-03-22T00:13:44.441+00:00 com.zaxxer.hikari.HikariConfig main  allowPoolSuspension.............false 

2016-03-22T00:13:44.441+00:00 com.zaxxer.hikari.HikariConfig main  autoCommit......................true 

2016-03-22T00:13:44.441+00:00 com.zaxxer.hikari.HikariConfig main  catalog.........................null 

2016-03-22T00:13:44.442+00:00 com.zaxxer.hikari.HikariConfig main  connectionInitSql...............null 

2016-03-22T00:13:44.442+00:00 com.zaxxer.hikari.HikariConfig main  connectionTestQuery.............null 

2016-03-22T00:13:44.442+00:00 com.zaxxer.hikari.HikariConfig main  connectionTimeout...............2000 

2016-03-22T00:13:44.442+00:00 com.zaxxer.hikari.HikariConfig main  dataSource......................null 

2016-03-22T00:13:44.442+00:00 com.zaxxer.hikari.HikariConfig main  dataSourceClassName............."com.mysql.jdbc.jdbc2.optional.MysqlDataSource" 

2016-03-22T00:13:44.443+00:00 com.zaxxer.hikari.HikariConfig main  dataSourceJNDI..................null 

2016-03-22T00:13:44.443+00:00 com.zaxxer.hikari.HikariConfig main  dataSourceProperties............{characterEncoding=utf8, serverName=db2, defaultFetchSize=20000, cachePrepStmts=true, user=prod, useJDBCCompliantTimezoneShift=true, prepStmtCacheSize=250, useTimezone=true, useLegacyDatetimeCode=false, databaseName=dbname, verifyServerCertificate=false, serverTimezone=UTC, prepStmtCacheSqlLimit=2048, useCursorFetch=true, password=<masked>, useGmtMillisForDatetimes=true} 

2016-03-22T00:13:44.443+00:00 com.zaxxer.hikari.HikariConfig main  driverClassName.................null 

2016-03-22T00:13:44.443+00:00 com.zaxxer.hikari.HikariConfig main  healthCheckProperties...........{} 

2016-03-22T00:13:44.444+00:00 com.zaxxer.hikari.HikariConfig main  healthCheckRegistry.............null 

2016-03-22T00:13:44.444+00:00 com.zaxxer.hikari.HikariConfig main  idleTimeout.....................600000 

2016-03-22T00:13:44.444+00:00 com.zaxxer.hikari.HikariConfig main  initializationFailFast..........false 

2016-03-22T00:13:44.444+00:00 com.zaxxer.hikari.HikariConfig main  isolateInternalQueries..........false 

2016-03-22T00:13:44.444+00:00 com.zaxxer.hikari.HikariConfig main  jdbc4ConnectionTest.............false 

2016-03-22T00:13:44.445+00:00 com.zaxxer.hikari.HikariConfig main  jdbcUrl.........................null 

2016-03-22T00:13:44.445+00:00 com.zaxxer.hikari.HikariConfig main  leakDetectionThreshold..........0 

2016-03-22T00:13:44.445+00:00 com.zaxxer.hikari.HikariConfig main  maxLifetime.....................1800000 

2016-03-22T00:13:44.445+00:00 com.zaxxer.hikari.HikariConfig main  maximumPoolSize.................150 

2016-03-22T00:13:44.445+00:00 com.zaxxer.hikari.HikariConfig main  metricRegistry..................null 

2016-03-22T00:13:44.446+00:00 com.zaxxer.hikari.HikariConfig main  metricsTrackerFactory...........null 

2016-03-22T00:13:44.446+00:00 com.zaxxer.hikari.HikariConfig main  minimumIdle.....................20 

2016-03-22T00:13:44.446+00:00 com.zaxxer.hikari.HikariConfig main  password........................<masked> 

2016-03-22T00:13:44.446+00:00 com.zaxxer.hikari.HikariConfig main  poolName........................"db" 

2016-03-22T00:13:44.446+00:00 com.zaxxer.hikari.HikariConfig main  readOnly........................false 

2016-03-22T00:13:44.447+00:00 com.zaxxer.hikari.HikariConfig main  registerMbeans..................true 

2016-03-22T00:13:44.447+00:00 com.zaxxer.hikari.HikariConfig main  scheduledExecutorService........null 

2016-03-22T00:13:44.447+00:00 com.zaxxer.hikari.HikariConfig main  threadFactory...................null 

2016-03-22T00:13:44.447+00:00 com.zaxxer.hikari.HikariConfig main  transactionIsolation............null 

2016-03-22T00:13:44.447+00:00 com.zaxxer.hikari.HikariConfig main  username........................null 

2016-03-22T00:13:44.448+00:00 com.zaxxer.hikari.HikariConfig main  validationTimeout...............1000 

2016-03-22T00:13:44.449+00:00 com.zaxxer.hikari.HikariDataSource main  db - Started. 

2016-03-22T00:13:44.535+00:00 com.zaxxer.hikari.pool.HikariPool db housekeeper  db - Pool stats (total=0, active=0, idle=0, waiting=0) 

Logs

2016-03-22T16:21:32.409+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@16173974: (connection is evicted or dead) 

2016-03-22T16:21:32.420+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@16173974 failed com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_66-internal]

    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_66-internal]

    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_66-internal]

    at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_66-internal]

    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.Util.getInstance(Util.java:387) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:917) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:896) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:885) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1235) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1230) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:5558) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:464) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:112) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool$1.run(HikariPool.java:423) [com.zaxxer.HikariCP-2.4.5.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66-internal]

2016-03-22T16:21:32.622+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@61fdd9ab: (connection is evicted or dead) 

2016-03-22T16:21:32.624+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@61fdd9ab failed com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_66-internal]

    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_66-internal]

    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_66-internal]

    at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_66-internal]

    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.Util.getInstance(Util.java:387) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:917) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:896) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:885) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1235) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1230) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:5558) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:464) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:112) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool$1.run(HikariPool.java:423) [com.zaxxer.HikariCP-2.4.5.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66-internal]

2016-03-22T16:21:33.410+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@53570624: (connection is evicted or dead) 

2016-03-22T16:21:33.410+00:00 com.zaxxer.hikari.pool.HikariPool db-10  db - Timeout failure stats (total=17, active=1, idle=16, waiting=0) 

2016-03-22T16:21:33.411+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@53570624 failed com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_66-internal]

    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_66-internal]

    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_66-internal]

    at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_66-internal]

    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.Util.getInstance(Util.java:387) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:917) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:896) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:885) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1235) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1230) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:5558) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:464) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:112) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool$1.run(HikariPool.java:423) [com.zaxxer.HikariCP-2.4.5.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66-internal]

2016-03-22T16:21:33.413+00:00 com.trueaccord.storage.Repos$ application-akka.actor.default-dispatcher-14  2c0b432c18dc4b77b03744823c9bb6f2: repo lookup FAILED 2022ms java.sql.SQLTransientConnectionException: db - Connection is not available, request timed out after 2020ms.

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:83) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at slick.jdbc.hikaricp.HikariCPJdbcDataSource.createConnection(HikariCPJdbcDataSource.scala:12) ~[com.typesafe.slick.slick-hikaricp_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:415) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:414) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:297) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:407) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.results(StatementInvoker.scala:33) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.iteratorTo(StatementInvoker.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.Invoker$class.foreach(Invoker.scala:48) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:16) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StreamingInvokerAction$class.run(StreamingInvokerAction.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.liftedTree1$1(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.run(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_66-internal]

2016-03-22T16:21:33.624+00:00 com.zaxxer.hikari.pool.HikariPool db-15  db - Timeout failure stats (total=16, active=0, idle=16, waiting=0) 

2016-03-22T16:21:33.624+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@601f9f60: (connection is evicted or dead) 

2016-03-22T16:21:33.626+00:00 com.zaxxer.hikari.pool.PoolBase db connection closer  db - Closing connection com.mysql.jdbc.JDBC4Connection@601f9f60 failed com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_66-internal]

    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_66-internal]

    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_66-internal]

    at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_66-internal]

    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.Util.getInstance(Util.java:387) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:917) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:896) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:885) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1235) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1230) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.mysql.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:5558) ~[mysql.mysql-connector-java-5.1.38.jar:5.1.38]

    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:464) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:112) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool$1.run(HikariPool.java:423) [com.zaxxer.HikariCP-2.4.5.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66-internal]

2016-03-22T16:21:33.627+00:00 com.trueaccord.storage.Repos$ application-akka.actor.default-dispatcher-16  ff98c24f0c9c44e68313d4167d75cc1f: repo lookup FAILED 2007ms java.sql.SQLTransientConnectionException: db - Connection is not available, request timed out after 2007ms.

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:83) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at slick.jdbc.hikaricp.HikariCPJdbcDataSource.createConnection(HikariCPJdbcDataSource.scala:12) ~[com.typesafe.slick.slick-hikaricp_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:415) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:414) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:297) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:407) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.results(StatementInvoker.scala:33) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.iteratorTo(StatementInvoker.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.Invoker$class.foreach(Invoker.scala:48) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:16) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StreamingInvokerAction$class.run(StreamingInvokerAction.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.liftedTree1$1(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.run(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_66-internal]

2016-03-22T16:21:33.735+00:00 application application-akka.actor.default-dispatcher-14  

! @6pfmnnf4o - Internal server error, for (GET) [/api/v1/ok] ->

  play.api.UnexpectedException: Unexpected exception[SQLTransientConnectionException: db - Connection is not available, request timed out after 2020ms.]

    at play.api.http.HttpErrorHandlerExceptions$.throwableToUsefulException(HttpErrorHandler.scala:261) ~[com.typesafe.play.play_2.11-2.4.6.jar:2.4.6]

    at play.api.http.DefaultHttpErrorHandler.onServerError(HttpErrorHandler.scala:191) ~[com.typesafe.play.play_2.11-2.4.6.jar:2.4.6]

    at modules.TrueAccordErrorHandler.onServerError(Modules.scala:65) [api.api-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]

    at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$9$$anonfun$apply$1.applyOrElse(PlayDefaultUpstreamHandler.scala:151) [com.typesafe.play.play-netty-server_2.11-2.4.6.jar:2.4.6]

    at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$9$$anonfun$apply$1.applyOrElse(PlayDefaultUpstreamHandler.scala:148) [com.typesafe.play.play-netty-server_2.11-2.4.6.jar:2.4.6]

    at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:36) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.util.Failure$$anonfun$recover$1.apply(Try.scala:216) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.util.Try$.apply(Try.scala:192) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.util.Failure.recover(Try.scala:216) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.Future$$anonfun$recover$1.apply(Future.scala:324) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.Future$$anonfun$recover$1.apply(Future.scala:324) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.CallbackRunnable.run_aroundBody0(Promise.scala:32) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.CallbackRunnable$AjcClosure1.run(Promise.scala:1) [org.scala-lang.scala-library-2.11.7.jar:na]

    at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149) [org.aspectj.aspectjrt-1.8.6.jar:na]

    at kamon.scala.instrumentation.FutureInstrumentation$$anonfun$aroundExecution$1.apply(FutureInstrumentation.scala:44) [io.kamon.kamon-scala_2.11-0.5.2.jar:0.5.2]

    at kamon.trace.Tracer$.withContext(TracerModule.scala:53) [io.kamon.kamon-core_2.11-0.5.2.jar:0.5.2]

    at kamon.scala.instrumentation.FutureInstrumentation.aroundExecution(FutureInstrumentation.scala:43) [io.kamon.kamon-scala_2.11-0.5.2.jar:0.5.2]

    at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:31) [org.scala-lang.scala-library-2.11.7.jar:na]

    at play.api.libs.iteratee.Execution$trampoline$.executeScheduled(Execution.scala:109) [com.typesafe.play.play-iteratees_2.11-2.4.6.jar:2.4.6]

    at play.api.libs.iteratee.Execution$trampoline$.execute(Execution.scala:71) [com.typesafe.play.play-iteratees_2.11-2.4.6.jar:2.4.6]

    at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:40) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:248) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.Promise$class.complete(Promise.scala:55) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:153) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.Future$PromiseCompletingRunnable.run_aroundBody0(Future.scala:23) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.impl.Future$PromiseCompletingRunnable$AjcClosure1.run(Future.scala:1) [org.scala-lang.scala-library-2.11.7.jar:na]

    at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149) [org.aspectj.aspectjrt-1.8.6.jar:na]

    at kamon.scala.instrumentation.FutureInstrumentation$$anonfun$aroundExecution$1.apply(FutureInstrumentation.scala:44) [io.kamon.kamon-scala_2.11-0.5.2.jar:0.5.2]

    at kamon.trace.Tracer$.withContext(TracerModule.scala:53) [io.kamon.kamon-core_2.11-0.5.2.jar:0.5.2]

    at kamon.scala.instrumentation.FutureInstrumentation.aroundExecution(FutureInstrumentation.scala:43) [io.kamon.kamon-scala_2.11-0.5.2.jar:0.5.2]

    at scala.concurrent.impl.Future$PromiseCompletingRunnable.run(Future.scala:23) [org.scala-lang.scala-library-2.11.7.jar:na]

    at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39) [com.typesafe.akka.akka-actor_2.11-2.4.1.jar:na]

    at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:399) [com.typesafe.akka.akka-actor_2.11-2.4.1.jar:na]

    at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979) [org.scala-lang.scala-library-2.11.7.jar:na]

    at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107) [org.scala-lang.scala-library-2.11.7.jar:na]

Caused by: java.sql.SQLTransientConnectionException: db - Connection is not available, request timed out after 2020ms.

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:83) ~[com.zaxxer.HikariCP-2.4.5.jar:na]

    at slick.jdbc.hikaricp.HikariCPJdbcDataSource.createConnection(HikariCPJdbcDataSource.scala:12) ~[com.typesafe.slick.slick-hikaricp_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:415) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:414) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:297) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:407) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.results(StatementInvoker.scala:33) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.iteratorTo(StatementInvoker.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.Invoker$class.foreach(Invoker.scala:48) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:16) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.jdbc.StreamingInvokerAction$class.run(StreamingInvokerAction.scala:22) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run(JdbcActionComponent.scala:218) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.liftedTree1$1(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.run(DatabaseComponent.scala:237) ~[com.typesafe.slick.slick_2.11-3.1.1.jar:na]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_66-internal]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_66-internal]

    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_66-internal]