postgresql Connection.setNetworkTimeout() not supported

[Aaron Masino]

Hi everyone,

Thanks in advance for any help you can provide on the following.

I am running a postgresql 9.4.5 DB in a Docker container on a MAC. 

I am attempting to connect via a simple Slick (no Play) app. My application.conf is as below. I have tried a number of other configurations all producing the same error given below.

dbclient = {

  driver = org.postgresql.Driver

  url = "jdbc:postgresql://192.168.99.100:32771/postgres"

  user = "postgres"

  password = "mysecretpassword"

  numThreads = 10

}

My dependencies are:

libraryDependencies := Seq(

  "com.typesafe"        % "config"            % "1.3.0",

  "com.typesafe.slick"  %% "slick"            % "3.1.0",

  "com.typesafe.slick"  %% "slick-hikaricp"   % "3.1.0",

  "ch.qos.logback"      % "logback-classic"   % "1.1.3",

  "org.postgresql"      % "postgresql"        % "9.4-1204-jdbc42",

  "com.zaxxer" % "HikariCP" % "2.4.1"

)

My code is simply:

def main(args:Array[String]): Unit ={

    val config = ConfigFactory.parseFile(new File("./conf/application.conf"))

    val db = Database.forConfig("dbclient", config)

    db.close()

  }

I am getting a Connection.setNetworkTimeout not supported error (full stack trace below). As far as I can tell from the postgresql jdbc docs, this method is implemented. Any insight is appreciated.

08:47:11.213 [main] DEBUG com.zaxxer.hikari.HikariConfig - HikariCP pool mydb configuration:

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - allowPoolSuspension.............false

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - autoCommit......................true

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - catalog.........................

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionCustomizer............com.zaxxer.hikari.AbstractHikariConfig$1@4e096385

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionCustomizerClassName...

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionInitSql...............

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTestQuery.............

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTimeout...............1000

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSource......................

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceClassName.............org.postgresql.ds.PGSimpleDataSource

08:47:11.295 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceJNDI..................

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceProperties............{user=postgres, url=jdbc:postgresql://192.168.99.100:32771/postgres, password=<masked>}

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - driverClassName.................

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckProperties...........{}

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckRegistry.............

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - idleTimeout.....................600000

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - initializationFailFast..........false

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - isolateInternalQueries..........false

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - jdbc4ConnectionTest.............false

08:47:11.296 [main] DEBUG com.zaxxer.hikari.HikariConfig - jdbcUrl.........................

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - leakDetectionThreshold..........0

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - maxLifetime.....................1800000

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................50

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricRegistry..................

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - minimumIdle.....................10

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - password........................<masked>

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - poolName........................mydb

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - readOnly........................false

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - registerMbeans..................false

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - threadFactory...................

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - transactionIsolation............

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - username........................

08:47:11.297 [main] DEBUG com.zaxxer.hikari.HikariConfig - validationTimeout...............1000

08:47:11.309 [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariCP pool mydb is starting.

08:47:11.388 [main] INFO  com.zaxxer.hikari.pool.HikariPool - HikariCP pool mydb is shutting down.

08:47:11.388 [main] DEBUG com.zaxxer.hikari.pool.HikariPool - Before shutdown pool stats mydb (total=0, inUse=0, avail=0, waiting=0)

08:47:11.493 [HikariCP connection filler (pool mydb)] DEBUG com.zaxxer.hikari.pool.PoolUtilities - mydb - Connection.setNetworkTimeout() not supported

08:47:11.516 [HikariCP connection filler (pool mydb)] INFO  com.zaxxer.hikari.util.ConcurrentBag - ConcurrentBag has been closed, ignoring add()

08:47:11.516 [HikariCP connection filler (pool mydb)] DEBUG com.zaxxer.hikari.pool.PoolUtilities - Closing connection org.postgresql.jdbc42.Jdbc42Connection@99a2a7d

08:47:11.528 [HikariCP connection filler (pool mydb)] DEBUG com.zaxxer.hikari.pool.HikariPool - Connection attempt to database mydb failed: ConcurrentBag has been closed, ignoring add()

java.lang.IllegalStateException: ConcurrentBag has been closed, ignoring add()

at com.zaxxer.hikari.util.ConcurrentBag.add(ConcurrentBag.java:178) ~[HikariCP-java6-2.3.7.jar:na]

at com.zaxxer.hikari.pool.BaseHikariPool.addConnection(BaseHikariPool.java:453) ~[HikariCP-java6-2.3.7.jar:na]

at com.zaxxer.hikari.pool.BaseHikariPool$1.run(BaseHikariPool.java:413) [HikariCP-java6-2.3.7.jar:na]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_40]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_40]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_40]

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

at java.lang.Thread.run(Thread.java:745) [na:1.8.0_40]

08:47:11.732 [HikariCP connection filler (pool mydb)] DEBUG com.zaxxer.hikari.pool.HikariPool - After fill pool stats mydb (total=0, inUse=0, avail=0, waiting=0)

08:47:11.733 [main] DEBUG com.zaxxer.hikari.pool.HikariPool - After shutdown pool stats mydb (total=0, inUse=0, avail=0, waiting=0)

Process finished with exit code 0

[Brett Wooldridge]

The log message and the exception are unrelated.  The log message comes from here, and is purely informational.  The exception you see is because your simple code is starting the HikariDataSource and immediately calling db.close().  When the pool initializes it starts filling the pool asynchronously.  When you call db.close() and the filler thread tries to add a new connection ... concurrent with the shutdown underway ... HikariCP logs an exception that a connection is being added while the pool is shutting down.

Simple as that.

-Brett

[Aaron Masino]

Very helpful. I guess sometime "simple code" is too simple. Thank you Brett.