HikariCP icon indicating copy to clipboard operation
HikariCP copied to clipboard

No operations allowed after connection closed.

Open sonus21 opened this issue 1 year ago • 3 comments

Application

Spring Boot: 2.3.12 Hikari Version: 3.4.5

Hikari Configuration:

  • connectionTimeout = 3 seconds
  • idleTimeout = 10 minutes
  • maxLifeTime = 30 minutes
  • minimumIde = 15
  • maximumPoolSize = 150
  • leakDetectionThreshold=3000

Error

We observed a large number of errors like No operations allowed after connection closed. post database restart, this error continues to occur until we restarted the application.

Our Aurora RDS Replica node was restarted due to some issue (unknown to us), post replica restart all existing and new connections started throwing errors and the application kept getting the same error. Even after digging through the Hikari code, I'm not able to find why Hikari kept getting the same error even though the database had recovered after some time.

For timeline, the database recovered at 7:48 PM but the application kept getting the same error till 8:02 PM (until restart).

All stack traces are the same that looks like

com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed.
at sun.reflect.GeneratedConstructorAccessor330.newInstance(Unknown Source) ~[na:na]at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_342]at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_342]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:761) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:568) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:2481) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
... 143 common frames omitted
Wrapped by: java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed.
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:73) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.mysql.cj.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:2485) ~[mysql-connector-java-8.0.29.jar!/:8.0.29]
at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:560) ~[HikariCP-3.4.5.jar!/:na]
at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:173) ~[HikariCP-3.4.5.jar!/:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:186) ~[HikariCP-3.4.5.jar!/:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-3.4.5.jar!/:na]
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100) ~[HikariCP-3.4.5.jar!/:na]

Also, we observed another warning message Failed to validate connection that lasted only for a few seconds, from the code it seems this error occurs when Hikari is able to catch the exception in try-catch block in isConnectionAlive method.

Screenshot 2023-03-28 at 7 43 37 PM

In this case, as a database would have closed the connection so the driver is saying the connection has been closed but Hikari keeps trying to use the same connection again and again for a very long time.

Screenshot 2023-03-28 at 7 40 40 PM

Why is Hikari not discarding/closing the connection?

sonus21 avatar Mar 28 '23 12:03 sonus21

I'm encountering something similar to the above. While attempting a migration from Aurora 2.X (MySql 5.7.x) to Aurora 3 (MySql 8) we encounter a similar error.

"HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@... (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value."

The settings for Hikari are: minimumIdle = 1 maximumPoolSize = 10

I've tried setting: connectionTimeout to 30s, 180s, and 1800s. (Server Timeout is 28,800 seconds)

I've tried increasing the minimumIdle to 2.

I've tried adding a validationTimeout, and have also attempted to use leakDetectionThreshold to try identifying any leaks without success.

Environment is Spring 5.6, and Hikari 4.0.3. on Java 11. It is using jdbcUrl or jdbc-url for specifying the connection.

Any thoughts on what other configuration we can try would be appreciated.

Thank you,

Additional info: Cannot duplicate issue in Windows (OpenJDK 11)

Issue occurs when the service is under load. The service runs in a docker container running Java 11.

When these warnings appear in our logs, the service becomes unresponsive and does not return data.

The warnings are often clustered in the logs.

tse-jt avatar Jul 21 '23 04:07 tse-jt

@tse-jt do you have any long-running queries or transactions? If you're using spring boot check the OSIV setting, and turn it off, that may help you to recover from this issue. In my case, the issue was happening due to the repetitive use of the closed connection, still I'm not able to reproduce this issue as we can't perform host replacement.

sonus21 avatar Jul 22 '23 06:07 sonus21

@sonus21

Thank you for your reply, and yes, we have some long running queries.

I also found another source of confusion where in order to configure our datasources we had to put the configuration properties on the datasource in the .yml file not under a hikari section on the datasource.

datasource:
  maximumPoolSize: 10
  

Instead of

datasource:
  hikari:
    maximumPoolSize: 10

I'll try looking at and disabling OSIV and see if that does anything. Though, I don't think that's going to be the case for us, because we're not using JPA.

Thank you,

tse-jt avatar Jul 25 '23 01:07 tse-jt