Hibernate ehcache/jcache custom expiry policy hangs after a few hundred select queries

Question

The getResultList call in the findAll_test method is hanging after many hundreds of requests.

public Session openSession() {
    return this.sessionFactory.openSession(); // org.hibernate.SessionFactory
}

public <R> R with(Function<Session, R> function) throws SqlException {
    try {
        Session session = this.openSession();
        R result = function.apply(session);

        if (session.isDirty())
            session.flush();

        if (session.isOpen())
            session.close();

        return result;
    } catch (Exception exception) {
        throw new SqlException(exception); // SqlException extends RuntimeException
    }
}

public final ConcurrentList<T> findAll_test() {
    return this.with(session -> {
        Class<T> tClass = this.getTClass();
        // This is the database model/entity class,
        // it's passed in the constructor,
        // it's the class with @Entity, @Table annotations

        CriteriaBuilder criteriaBuilder = session.getCriteriaBuilder();
        CriteriaQuery<T> criteriaQuery = criteriaBuilder.createQuery(tClass);
        Root<T> rootEntry = criteriaQuery.from(tClass);
        CriteriaQuery<T> all = criteriaQuery.select(rootEntry);

        // Concurrent.newList is just a thread-safe list,
        // it's not being used downstream for the purposes of this example,
        return Concurrent.newList(
            session.createQuery(all)
                .setCacheable(true)
                .getResultList() // This works ~1245 times, then hangs
        );
    });
}

If I run the above method approximately 1,245 times total, across tens of models/entities, it hangs inside getResultList.

Here are my Hibernate/HikariCP/ehcache properties.

Properties properties = new Properties() {{
    // Connection
    put("hibernate.dialect", config.getDatabaseDriver().getDialectClass());
    put("hibernate.connection.driver_class", config.getDatabaseDriver().getDriverClass());
    put("hibernate.connection.url", config.getDatabaseDriver().getConnectionUrl(config.getDatabaseHost(), config.getDatabasePort(), config.getDatabaseSchema()));
    put("hibernate.connection.username", config.getDatabaseUser());
    put("hibernate.connection.password", config.getDatabasePassword());
    put("hibernate.connection.provider_class", "org.hibernate.hikaricp.internal.HikariCPConnectionProvider");

    // SQL
    put("hibernate.generate_statistics", config.isDatabaseDebugMode());
    put("hibernate.show_sql", false);
    put("hibernate.format_sql", false); // Log Spam
    put("hibernate.use_sql_comments", true);
    put("hibernate.order_inserts", true);
    put("hibernate.order_updates", true);
    put("hibernate.globally_quoted_identifiers", true);

    // Prepared Statements
    put("hikari.cachePrepStmts", true);
    put("hikari.prepStmtCacheSize", 256);
    put("hikari.prepStmtCacheSqlLimit", 2048);
    put("hikari.useServerPrepStmts", true);

    // Caching
    put("hibernate.cache.use_second_level_cache", true);
    put("hibernate.cache.use_query_cache", true);
    put("hibernate.cache.region.factory_class", "org.hibernate.cache.jcache.JCacheRegionFactory");
    put("hibernate.cache.provider_class", "org.ehcache.jsr107.EhcacheCachingProvider");
    put("hibernate.cache.use_structured_entries", config.isDatabaseDebugMode());
}};

Here are two scenarios that "hide" the problem:

If I remove hibernate.cache.use_query_cache (or set it to false), my application gets significantly slower, but it no longer encounters this problem.
If I change the expiry policy from a duration of one minute, to five minutes then it also prolongs how long I can run the above method by a factor of 5.

The problem lies with the hibernate query cache. When disabled, this problem does not occur. There appears to be a deadlock when querying the way I do (for all entities) as the cache expires.

Dependencies:

Hibernate and HikariCP 5.5.7.Final
ehcache 3.9.9
mariadb-java-client 2.7.4
MariaDB server 10.3.28

Your thread dump shows the thread is RUNNABLE, so it's not stuck. It's waiting for data - presumably from the database. Are there any errors in the database logs? Your error handling is suspect, the session does not get closed if an exception is thrown. I'd wrap that statement in try (Session session = this.openSession()) { ... } — munyengm, Jan 25 '22 at 21:12
@munyengm I get no exceptions thrown, and closing the session in a finally block does not address the problem, although I've made the change you suggested since that's desirable. I am getting a ton of `[Warning] Aborted connection # to db: 'db' user: 'user' host: 'localhost' (Got an error reading communication packets)` on my server's logs. — Nahydrin, Jan 25 '22 at 21:23
There probably is an exception being thrown, leading to connection being aborted prematurely. The exception is probably swallowed and not logged. If you can run the program under an IDE you should enable exception breakpoints to halt the program when ANY exception occurs you can then inspect the cause of the exception. — munyengm, Jan 25 '22 at 21:48
This is a very barebones project. The main method runs a loop inside a Runnable, and all that loop does is run that `findAll_test` (for simplicity's sake) and the only exception handling is inside that one method, and there are no exceptions being thrown. It hangs on getResultList, as explained in my post and is visible in the thread dump. — Nahydrin, Jan 25 '22 at 22:10

score 0 · Accepted Answer · answered Mar 05 '22 at 20:20

The problem I was encountering stems from how I query the database, and how I was using hibernate.cache.use_second_level_cache and hibernate.cache.use_query_cache simultaneously.

Second Level Cache (hibernate.cache.use_second_level_cache): The second level cache is an application level cache for storing entity data when queried via primary key.

Query Cache (hibernate.cache.use_query_cache): The query cache is a separate cache that stores query results only. (My code from in findAll_test is accessing this cache)

The Problem

The issue lies with overlapping cache entry expiry. If you enable both caches, their cached entity objects overlap and the expiry policy of the Second Level Cache ends will overriding the Query Cache. Setting entities to expire at anything below never will decouple the Query Cache from re-caching any entities when it expires, leading to the deadlock condition.

The Solution

Don't use both at the same time. This appears to be bug, because you should be able to specify separate cache locations to use both caches simultaneously, but doing so does not prevent the problem from occurring.

There may be a way to solve this problem and leave the second level cache enabled, but I did not find it after extensive testing.

See Hibernate Caching for more information.

Hibernate ehcache/jcache custom expiry policy hangs after a few hundred select queries

1 Answers1