Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Play - HikariCP connections not released back to pool

In a Play project which has two sub-projects, we are trying HikariCP and it does not seem to release connections back to pool and throws this exception:

java.sql.SQLException: Timeout of 30000ms encountered waiting for connection.

Here's what debug shows after six simple queries:

[DEBUG] c.z.h.p.HikariPool - Before cleanup pool stats pool1 (total=5, inUse=5, avail=0, waiting=1)
[DEBUG] c.z.h.p.HikariPool - After cleanup pool stats pool1 (total=5, inUse=5, avail=0, waiting=1)
[DEBUG] c.z.h.p.HikariPool - Timeout failure pool stats pool1 (total=5, inUse=5, avail=0, waiting=0)
[ERROR] application - Error in datastore operation detected.
java.sql.SQLException: Timeout of 30000ms encountered waiting for connection.
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:207) ~[HikariCP-java6-2.0.1.jar:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93) ~[HikariCP-java6-2.0.1.jar:na]
    at scala.slick.jdbc.JdbcBackend$DatabaseFactoryDef$$anon$3.createConnection(JdbcBackend.scala:47) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
[DEBUG] c.z.h.p.HikariPool - Before cleanup pool stats pool1 (total=5, inUse=4, avail=1, waiting=0)
[DEBUG] c.z.h.p.HikariPool - After cleanup pool stats pool1 (total=5, inUse=4, avail=1, waiting=0)

We are using two Postgres databases with two pools and versions are:

Play: 2.3.3
Scala: 2.11.1
HikariCP: 2.0.1
Play-hikaricp: 1.4.1
Postgres: 9.3

UPDATE:

Enabling leak detection (leakDetectionThreshold=10000) generates following warnings:

[WARN] c.z.h.p.LeakTask - Connection leak detection triggered, stack trace follows
java.lang.Exception: null
    at scala.slick.jdbc.JdbcBackend$DatabaseFactoryDef$$anon$3.createConnection(JdbcBackend.scala:47) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:152) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:389) ~[slick_2.11-2.1.0.jar:0.8.0]
[WARN] c.z.h.p.LeakTask - Connection leak detection triggered, stack trace follows
java.lang.Exception: null
    at scala.slick.jdbc.JdbcBackend$DatabaseFactoryDef$$anon$3.createConnection(JdbcBackend.scala:47) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:397) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:152) ~[slick_2.11-2.1.0.jar:0.8.0]
    at scala.slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:389) ~[slick_2.11-2.1.0.jar:0.8.0]
like image 654
centr Avatar asked Oct 20 '22 23:10

centr


1 Answers

As I said in the bug report on github, this appears to be answered here. I am not a Play/slick developer, so I do not know what the underlying issue is. But I do know that it is not a bug in HikariCP. Connections that are closed are returned to the pool immediately.

Asynchronous systems like Scala, if not properly used when accessing resources that can block, can develop a backlog of pending execution tasks that start to suffer from resource timeouts. This is typically mediated by separate thread execution pools for blocking access. I would expect that kind of thing to be wired into the Slick framework, but as I said above I am not really familiar with Slick.

like image 184
brettw Avatar answered Nov 15 '22 15:11

brettw