Connection is closed with data-envers

Question

I am working with data-envers in my Spring-Boot project in a development environment. When the microservice has been up for approximately 8 hours, the connection to the database stops working (only the queries that are used with data-envers, that is, any query with JPA for example continues to work).

Every time I restart a microservice (pod), the connection to the database works again, and the queries made with data-envers work again (about another 8h).

I have read many articles and posts on SO, but they have not worked for me. I have added to my .yml file the following properties:

testOnBorrow : true
validationQuery : SELECT 1

I have also added

url: jdbc:mysql://localhost:3306/mydatabase?autoReconnect=true

and can't reconnect.

I have updated the version of Hikari, since I also read that it could be that, but it is not. My data-envers version is 2.7.6

Any ideas how to prevent the connection from closing, or automatically reconnecting?

This is my .yml

spring:
  datasource:
    driver-class-name: com.mysql.jdbc.Driver
    url: jdbc:mysql://localhost:3306/mydatabase?autoReconnect=true
    username: X
    password: X
    testOnBorrow : true
    validationQuery : SELECT 1
    hikari:
      connection-timeout: 20000
      maximum-pool-size: 5

and the Stack trace:

java.sql.SQLException: Connection is closed
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:515) ~[HikariCP-5.0.0.jar!/:na]
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection$$Lambda$718/0x00000000558ea900.invoke(Unknown Source) ~[na:na]
    at com.sun.proxy.$Proxy105.prepareStatement(Unknown Source) ~[na:na]
    at com.zaxxer.hikari.pool.ProxyConnection.prepareStatement(ProxyConnection.java:337) ~[HikariCP-5.0.0.jar!/:na]
    at com.zaxxer.hikari.pool.HikariProxyConnection.prepareStatement(HikariProxyConnection.java) ~[HikariCP-5.0.0.jar!/:na]
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2122) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2059) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2037) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.doQuery(Loader.java:956) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:357) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.doList(Loader.java:2868) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.doList(Loader.java:2850) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2682) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.Loader.list(Loader.java:2677) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:540) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1459) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1649) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1617) ~[hibernate-core-5.6.12.Final.jar!/:5.6.12.Final]
    at org.hibernate.envers.query.internal.impl.AbstractAuditQuery.buildAndExecuteQuery(AbstractAuditQuery.java:106) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.RevisionsOfEntityQuery.getQueryResults(RevisionsOfEntityQuery.java:173) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.RevisionsOfEntityQuery.list(RevisionsOfEntityQuery.java:136) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.AbstractAuditQuery.getResultList(AbstractAuditQuery.java:112) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]

There is another Stack trace:

com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 35,850,470 milliseconds ago. The last packet sent successfully to the server was 35,850,472 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
    at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174) ~[mysql-connector-java-8.0.28.jar!/:8.0.28]
    at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64) ~[mysql-connector-java-8.0.28.jar!/:8.0.28]
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953) ~[mysql-connector-java-8.0.28.jar!/:8.0.28]
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1009) ~[mysql-connector-java-8.0.28.jar!/:8.0.28]
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) ~[HikariCP-4.0.3.jar!/:na]
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar!/:na]
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.getResultSet(Loader.java:2322) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2075) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2037) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.doQuery(Loader.java:956) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:357) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.doList(Loader.java:2868) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.doList(Loader.java:2850) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2682) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.Loader.list(Loader.java:2677) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:540) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1459) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1649) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1617) ~[hibernate-core-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.AbstractAuditQuery.buildAndExecuteQuery(AbstractAuditQuery.java:106) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.RevisionsOfEntityQuery.getQueryResults(RevisionsOfEntityQuery.java:173) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.RevisionsOfEntityQuery.list(RevisionsOfEntityQuery.java:136) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]
    at org.hibernate.envers.query.internal.impl.AbstractAuditQuery.getResultList(AbstractAuditQuery.java:112) ~[hibernate-envers-5.6.8.Final.jar!/:5.6.8.Final]

UPDATED:

This is my service, which uses auditQuery

public List<Revision> getRevisions(Integer id) {
        AuditQuery auditQuery = null;
        List<Revision> revisionList = new ArrayList<Revision>();
        //Find all modifications
        try {       
            auditQuery = auditReader.createQuery()
                .forRevisionsOfEntityWithChanges(MyEntity.class, true)
                .addOrder(AuditEntity.revisionNumber().desc());
            
        }

        catch (Exception exception) {
            log.error("Can not get revisions. Return empty list without revisions.");
            log.error(exception.getMessage());
            return new ArrayList<Revision>();
        }
        
        List<Object[]> result = auditQuery.getResultList();

The last line is when I receive the error when conection is closed.

And this is the config class

@Configuration
public class AuditConfiguration {

    private final EntityManagerFactory entityManagerFactory;

    AuditConfiguration(EntityManagerFactory entityManagerFactory) {
        this.entityManagerFactory = entityManagerFactory;
    }

    @Bean
    AuditReader auditReader() {
        return AuditReaderFactory.get(entityManagerFactory.createEntityManager());
    }
}

Andrey B. Panfilov · Accepted Answer · 2023-01-30T07:36:57.193

based on your stacktraces I would say the root cause is somewhere in your application.

I. Following settings has no effect for hikari connection poll:

testOnBorrow : true
validationQuery : SELECT 1

those settings are valid for Tomcat JDBC Connection Pool, note the configuration prefix for those settings should be spring.datasource.tomcat.

if you need to set up validation query for hikari connection pool the valid configuration setting is spring.datasource.hikari.connection-test-query, however in the most cases it is not required, moreover hikari author is strongly discouraging from using this feature:

If your driver supports JDBC4 we strongly recommend not setting this property. This is for "legacy" drivers that do not support the JDBC4 Connection.isValid() API. This is the query that will be executed just before a connection is given to you from the pool to validate that the connection to the database is still alive. Again, try running the pool without this property, HikariCP will log an error if your driver is not JDBC4 compliant to let you know. Default: none

II. you should not use autoReconnect=true as well:

Should the driver try to re-establish stale and/or dead connections? If enabled the driver will throw an exception for queries issued on a stale or dead connection, which belong to the current transaction, but will attempt reconnect before the next query issued on the connection in a new transaction. The use of this feature is not recommended, because it has side effects related to session state and data consistency when applications don't handle SQLExceptions properly, and is only designed to be used when you are unable to configure your application to handle SQLExceptions resulting from dead and stale connections properly. Alternatively, as a last option, investigate setting the MySQL server variable 'wait_timeout' to a high value, rather than the default of 8 hours.

III. take a closer look at following stacktrace:

java.sql.SQLException: Connection is closed
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:515) ~[HikariCP-5.0.0.jar!/:na]
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection$$Lambda$718/0x00000000558ea900.invoke(Unknown Source) ~[na:na]
    at com.sun.proxy.$Proxy105.prepareStatement(Unknown Source) ~[na:na]

note that exception was thrown in com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection class, hikari replaces the real jdbc connection instance by proxy based on com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection when JDBC connection either gets closed or receives fatal error, thus it is definitely clear that your application is continue using JDBC connection after it has been closed or get fatal error

UPD.

Well, now it is clear what is going on. The configuration below:

@Configuration
public class AuditConfiguration {

    private final EntityManagerFactory entityManagerFactory;

    AuditConfiguration(EntityManagerFactory entityManagerFactory) {
        this.entityManagerFactory = entityManagerFactory;
    }

    @Bean
    AuditReader auditReader() {
        return AuditReaderFactory.get(entityManagerFactory.createEntityManager());
    }
}

creates single/application-wide EntityManager instance and binds it to the single instance of AuditReader, that is why you never release underlying JDBC connection to pool and getting those dumb errors.

The quick fix would be to remove that premature optimization and rewrite service class, something like (here I believe EMF is managed by spring):

@Autowired
private EntityManager entityManager;

@Transactional
public List<Revision> getRevisions(Integer id) {
    AuditReader auditReader = AuditReaderFactory.get(entityManager);
    AuditQuery auditQuery = null;
    List<Revision> revisionList = new ArrayList<Revision>();

I updated the post with my service and config code. Please tell me if you need something more — Talenel, Jan 26 '23 at 06:33
thanks so much, I'll try this solution, if this works, I'll check this to correct answer but I need to wait at least 8h to see if works — Talenel, Jan 26 '23 at 07:15

Connection is closed with data-envers

1 Answers1

Linked