Hikaricp: Failed to validate connection

[daveyx]

Environment

HikariCP version: 2.7.8
JDK version     : 1.8.0_161
Database        : MariaDB 10.2.14
Driver version  : ?
-----------------------------------------------------------------------------------------
Spring Boot 2.0.0.RELEASE

In the log i very often get WARN messages like this:

2018-04-04 04:20:20.620  WARN 5611 --- [http-nio-127.0.0.1-8081-exec-1] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@3668b047 (Connection.setNetworkTimeout cannot be called on a closed connection)

I enabled DEBUG log and see:

2018-04-07 04:34:30.009  WARN 20157 --- [pool-3-thread-1] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@7b76d704 (Connection.setNetworkTimeout cannot be called on a closed connection)
2018-04-07 04:34:30.009 DEBUG 20157 --- [HikariPool-1 connection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection org.mariadb.jdbc.MariaDbConnection@7b76d704: (connection is dead)
2018-04-07 04:34:30.010 DEBUG 20157 --- [HikariPool-1 connection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection org.mariadb.jdbc.MariaDbConnection@7b76d704 failed

java.sql.SQLException: Connection.setNetworkTimeout cannot be called on a closed connection
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getSqlException(ExceptionMapper.java:211)
    at org.mariadb.jdbc.MariaDbConnection.setNetworkTimeout(MariaDbConnection.java:1597)
    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:541)
    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:129)
    at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1(HikariPool.java:434)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

Looks like HakiriCP wants to close a dead connection.

Why HikiriCP thinks that the connection is dead?
How can i find out why HikiriCP thinks that the connection is dead?
How can i find more information about the dead connection?
What can i do in order to not get this WARN anymore?

Kind regards

[brettwooldridge]

This usually means that MySQL closed the connection from its side. Set maxLifetime to a shorter limit, such as 10 minutes (600000ms).

[daveyx]

thx @brettwooldridge it solved the issue:
spring.datasource.hikari.max-lifetime=600000

[mindhaq]

@brettwooldridge I experience the same problem, connecting to a MariaDB docker host. Changing max-lifetime didn't help at all.

[adewaleShotobi]

@brettwooldridge I experience the same problem, connecting to a MariaDB docker host. Changing max-lifetime didn't help at all.

Same here

[sag1]

max-lifetime didn't help me too. Any solution ?

[brettwooldridge]

@sag1 Can you enable DEBUG logging for the package com.zaxxer.hikari and attach the log here ... including logs 2 minutes before and after the error.

[sag1]

@brettwooldridge here is the log:

2018-11-29 13:09:47,010 DEBUG com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2018-11-29T14:09:47.011+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:09:47,010 DEBUG com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - After cleanup stats (total=1, active=0, idle=1, waiting=0)
2018-11-29T14:10:17.011+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:17,011 DEBUG com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2018-11-29T14:10:17.011+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:17,011 DEBUG com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - After cleanup stats (total=1, active=0, idle=1, waiting=0)
2018-11-29T14:10:24.414+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,414 INFO com.XXXX.silvercom.controller.PhonelineAgreementController : Calling PhonelineAgreementService to findByIdPhonelineContract
2018-11-29T14:10:24.415+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,414 INFO com.XXXX.silvercom.service.PhonelineAgreementServiceImpl : In findByIdPhonelineContract
2018-11-29T14:10:24.433+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,433 WARN com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@20527746 (Connection.setNetworkTimeout cannot be called on a closed connection)
2018-11-29T14:10:24.434+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,434 DEBUG com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection org.mariadb.jdbc.MariaDbConnection@20527746: (connection is dead)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,438 DEBUG com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection org.mariadb.jdbc.MariaDbConnection@20527746 failed
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] java.sql.SQLException: Connection.setNetworkTimeout cannot be called on a closed connection
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getSqlException(ExceptionMapper.java:211)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at org.mariadb.jdbc.MariaDbConnection.setNetworkTimeout(MariaDbConnection.java:1597)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:541)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:129)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1(HikariPool.java:434)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2018-11-29T14:10:24.438+01:00 [APP/PROC/WEB/0] [OUT] at java.lang.Thread.run(Thread.java:748)
2018-11-29T14:10:24.445+01:00 [APP/PROC/WEB/0] [OUT] 2018-11-29 13:10:24,444 DEBUG com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection org.mariadb.jdbc.MariaDbConnection@33633434

[TimoSchlatter]

@brettwooldridge I experience the same problem, connecting to a MariaDB docker host. Changing max-lifetime didn't help at all.

same here